Tidb auto analyze returns error [parser:1064]

Application environment:

production

TiDB version: 6.5.1

Problem:

If I check SHOW ANALYZE STATUS; I see a lot of failed queries with exception:
[parser:1064]You have an error in your SQL syntax; check the manual that corresponds to your TiDB version for the right syntax to use run multiple statements internally is not supported"

I stopped auto analyze, and tried to run analyze manually with query:
analyze table test_table; and got same error in my MySQL client:
SQL Error [1064] [42000]: You have an error in your SQL syntax; check the manual that corresponds to your TiDB version for the right syntax to use run multiple statements internally is not supported

What I’ve noticed that all failed tables are present in TiFlash.

1 Like

Could you share the output of SHOW ANALYZE STATUS?

Did you upgrade from a earlier version or is this a new installation that started with v6.5.1?

The syntax you posted is fine:

sql> CREATE TABLE test_table (id SERIAL PRIMARY KEY);
Query OK, 0 rows affected (0.1628 sec)

sql> analyze table test_table;
Query OK, 0 rows affected, 1 warning (0.1118 sec)
Note (code 1105): Analyze use auto adjusted sample rate 1.000000 for table test.test_table

Is there something in the logs of tidb-server that might give more details on what happened?

No upgrades, started from v6.5.1. Deployed in k8s, using tidb operator. Attaching analyze status output.
_SHOW_ANALYZE_STATUS__202304131332.csv (1.2 KB)

And If I create new table, analyze works fine on it. I have same result as you above.

The error message seems to be related to this setting: tidb_multi_statement_mode.

However I would not expect this to give issues for running ANALYZE.

There should be a similar message in the logs of tidb-server. Could you share that?

Tidb log:
2023-04-13 12:51:08 [2023/04/13 11:51:08.861 +00:00] [ERROR] [analyze.go:318] [“save table stats to storage failed”] [conn=7866431751669379465] [error=“[parser:1064]You have an error in your SQL syntax; check the manual that corresponds to your TiDB version for the right syntax to use run multiple statements internally is not supported”] [tableID=1251]

Also, I found a table that is not in tiflash, also the same error.

This is where it seems to go wrong:

Based on the logging I can’t tell where in this function the error is coming from.

Are there any log messages from around the same time that might be related?

Is tidb_analyze_version set to 2?

yes tidb_analyze_version = 2

To troubleshoot this further one option is to see if SET GLOBAL tidb_multi_statement_mode=ON and a restart of TiDB allows the analyze process to run without issues.

So I’ve enabled tidb_multi_statement_mode=ON, with SET GLOBAL tidb_multi_statement_mode=ON

Restarted all tidb replicas, and still the same issue. Which services need to be restarted only tidb? No need to restart pd/tikv/tiflash?

For tidb we have WARN log level, messages around:


[2023/04/13 18:45:46.637 +00:00] [WARN] [pd.go:152] ["get timestamp too slow"] ["cost time"=118.628969ms]
[2023/04/13 18:45:46.764 +00:00] [WARN] [pd.go:152] ["get timestamp too slow"] ["cost time"=35.760627ms]
[2023/04/13 18:45:46.765 +00:00] [WARN] [pd.go:152] ["get timestamp too slow"] ["cost time"=31.645138ms]
[2023/04/13 18:45:47.415 +00:00] [ERROR] [analyze.go:318] ["save table stats to storage failed"] [conn=5369196753406920077] [error="[parser:1064]You have an error in your SQL syntax; check the manual that corresponds to your TiDB version for the right syntax to use run multiple statements internally is not supported"] [tableID=1267]
[2023/04/13 18:45:47.429 +00:00] [WARN] [session.go:2220] ["run statement failed"] [conn=5369196753406920077] [schemaVersion=1265] [error="[parser:1064]You have an error in your SQL syntax; check the manual that corresponds to your TiDB version for the right syntax to use run multiple statements internally is not supported"] [session="{\n  \"currDBName\": \"masked-name\",\n  \"id\": 5369196753406920077,\n  \"status\": 514,\n  \"strictMode\": true,\n  \"user\": {\n    \"Username\": \"root\",\n    \"Hostname\": \"10.100.0.13\",\n    \"CurrentUser\": false,\n    \"AuthUsername\": \"root\",\n    \"AuthHostname\": \"%\"\n  }\n}"]
[2023/04/13 18:48:35.985 +00:00] [WARN] [pd.go:152] ["get timestamp too slow"] ["cost time"=30.858497ms]
[2023/04/13 18:57:35.911 +00:00] [WARN] [pd.go:152] ["get timestamp too slow"] ["cost time"=103.274251ms]

Only restarting TiDB is enough. No need to restart anything else.

I assume there are no messages with “parse SQL failed” in them?

@dveeden

Found some WARN messages from yesterday:

"[parser:1064]You have an error in your SQL syntax; check the manual that corresponds to your TiDB version for the right syntax to use line 1 column 67 near \"yze table active\" "

But I tried to run analyze table active; today also, no such messages from today.

@dveeden
maybe we should try to switch to tidb_analyze_version 1 ?

Nope, it didn’t help. tidb_enable_fast_analyze 1 also didn’t help.

More logs:

2023-04-15 11:15:21	
[2023/04/15 10:15:21.522 +00:00] [ERROR] [update.go:1290] ["[stats] auto analyze failed"] [sql="analyze table `masked-name`.`source_table`"] [cost_time=4h52m22.130447809s] [error="runtime error: slice bounds out of range [-1:]"]Show context
2023-04-15 11:15:21	
[2023/04/15 10:15:21.511 +00:00] [ERROR] [analyze.go:308] ["analyze failed"] [error="runtime error: slice bounds out of range [-1:]"]

and this one new:
2023-04-15 11:35:03	
[2023/04/15 10:35:03.180 +00:00] [ERROR] [handle.go:623] ["[stats] error occurred when read table stats"] [table=logs] [error="proto: CMSketch: wiretype end group for non-group"]

For the message about the logs table, could you check what’s in the stats tables?

-- Find the TableID for the logs table:
SELECT TIDB_TABLE_ID FROM information_schema.TABLES WHERE TABLE_NAME='logs';

SELECT * FROM mysql.stats_meta WHERE table_id=...;
SELECT * FROM mysql.stats_histograms WHERE table_id=...;
SELECT * FROM mysql.stats_extended WHERE table_id=...;

Uploading a full dump of these tables would also work.

If there is anything special it is probably in the cm_sketch column of the mysql.stats_histograms table.

For the other message: The “Show context”, is that in the log file or is that something from the log viewer that can reveal more details? If so, could you post the details/context?

SELECT * FROM mysql.stats_extended WHERE table_id=...;

Empty result.

for stats_meta and stats_histograms, Yes, there is something weird in cm_sketch column where stats_ver=1

But I see no more cm_sketch errors now, seems it is related to my attempt to switch to 1 version of tidb_analyze_version

Here is all context around this ERROR:

[2023/04/15 10:15:43.843 +00:00] [INFO] [2pc.go:672] ["[BIG_TXN]"] [session=2944193072021373767] ["key sample"=7480000000000003f85f72800000000000375d] [size=5059588] [keys=1] [puts=1] [dels=0] [locks=0] [checks=0] [txnStartTS=440809224541569035]
[2023/04/15 10:15:39.086 +00:00] [INFO] [advancer.go:189] ["[log backup advancer hint] sample range."] [sample="([7480000000000004305F698000000000000004040000000000001EA80419AE82000000000003800000003A80D6BE, 7480000000000004305F698000000000000004040000000000001EAB0419A814000000000003800000000600645B), 440809149174906915)"] [total-len=1]
[2023/04/15 10:15:27.086 +00:00] [INFO] [advancer.go:189] ["[log backup advancer hint] sample range."] [sample="([7480000000000004305F698000000000000004040000000000001EA80419AE82000000000003800000003A80D6BE, 7480000000000004305F698000000000000004040000000000001EAB0419A814000000000003800000000600645B), 440809149174906915)"] [total-len=1]
[2023/04/15 10:15:21.522 +00:00] [WARN] [session.go:2220] ["run statement failed"] [schemaVersion=1453] [error="runtime error: slice bounds out of range [-1:]"] [session="{\n  \"currDBName\": \"\",\n  \"id\": 2944193072021372931,\n  \"status\": 2,\n  \"strictMode\": true,\n  \"user\": null\n}"]
[2023/04/15 10:15:21.522 +00:00] [INFO] [tidb.go:270] ["rollbackTxn called due to ddl/autocommit failure"]
[2023/04/15 10:15:21.521 +00:00] [INFO] [analyze.go:575] ["analyze table `masked-name`.`source_table` has failed"] [partition=] ["job info"="auto analyze table all columns with 256 buckets, 500 topn, 0.0003319489643193822 samplerate"] ["start time"=2023/04/15 05:22:59.418 +00:00] ["end time"=2023/04/15 10:15:21.511 +00:00] [cost=4h52m22.092857036s]
[2023/04/15 10:15:21.511 +00:00] [ERROR] [analyze.go:308] ["analyze failed"] [error="runtime error: slice bounds out of range [-1:]"]
[2023/04/15 10:15:21.511 +00:00] [ERROR] [analyze_col_v2.go:644] ["analyze worker panicked"] [recover="runtime error: slice bounds out of range [-1:]"] [stack="github.com/pingcap/tidb/executor.(*AnalyzeColumnsExecV2).subBuildWorker.func1\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/executor/analyze_col_v2.go:644\nruntime.gopanic\n\t/usr/local/go/src/runtime/panic.go:884\nruntime.goPanicSliceB\n\t/usr/local/go/src/runtime/panic.go:153\ngithub.com/pingcap/tidb/statistics.BuildHistAndTopN\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/statistics/builder.go:378\ngithub.com/pingcap/tidb/executor.(*AnalyzeColumnsExecV2).subBuildWorker\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/executor/analyze_col_v2.go:778\ngithub.com/pingcap/tidb/executor.(*AnalyzeColumnsExecV2).buildSamplingStats.func3\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/executor/analyze_col_v2.go:347\ngithub.com/pingcap/tidb/executor.(*notifyErrorWaitGroupWrapper).Run.func1\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/executor/analyze_utils.go:127"]
[2023/04/15 10:15:19.081 +00:00] [WARN] [expensivequery.go:118] [expensive_query] [cost_time=17539.689596235s] [conn_id=2944193072021372931] [txn_start_ts=0] [mem_max="1187689735 Bytes (1.11 GB)"] [sql="analyze table `masked-name`.`source_table`"]```

@dveeden any idea?