Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

analyze table report error when usingd dynamic partition_prun_mode #34228

Closed
311ybb opened this issue Apr 26, 2022 · 16 comments · Fixed by #34364
Closed

analyze table report error when usingd dynamic partition_prun_mode #34228

311ybb opened this issue Apr 26, 2022 · 16 comments · Fixed by #34364
Labels
affects-5.0 This bug affects 5.0.x versions. affects-5.1 This bug affects 5.1.x versions. affects-5.2 This bug affects 5.2.x versions. affects-5.3 This bug affects 5.3.x versions. affects-5.4 This bug affects 5.4.x versions. affects-6.0 component/tablepartition This issue is related to Table Partition of TiDB. severity/major sig/planner SIG: Planner type/bug The issue is confirmed as a bug.

Comments

@311ybb
Copy link

311ybb commented Apr 26, 2022

version:v5.2.3
analyze table report error when usingd dynamic partition_prun_mode
mysql> set @@session.tidb_partition_prune_mode = ‘static’;
Query OK, 0 rows affected (0.00 sec)

mysql> analyze table oracle_cb_metric_dbtime;
Query OK, 0 rows affected (13.97 sec)

mysql> set @@session.tidb_partition_prune_mode = ‘dynamic’;
Query OK, 0 rows affected (0.00 sec)

mysql> analyze table oracle_cb_metric_dbtime;
ERROR 1105 (HY000): invalid encoded key flag 9
mysql> set @@session.tidb_partition_prune_mode = ‘static’;
Query OK, 0 rows affected (0.00 sec)

mysql> analyze table oracle_cb_metric_dbtime;
Query OK, 0 rows affected (14.06 sec)

mysql> set @@session.tidb_partition_prune_mode = ‘dynamic’;
Query OK, 0 rows affected (0.00 sec)

mysql> analyze table oracle_cb_metric_dbtime;
ERROR 1105 (HY000): invalid encoded key flag 9
mysql>

@311ybb 311ybb added the type/bug The issue is confirmed as a bug. label Apr 26, 2022
@aytrack aytrack added sig/planner SIG: Planner severity/major component/tablepartition This issue is related to Table Partition of TiDB. labels Apr 28, 2022
@ti-chi-bot ti-chi-bot added may-affects-4.0 This bug maybe affects 4.0.x versions. may-affects-5.0 This bug maybe affects 5.0.x versions. may-affects-5.1 This bug maybe affects 5.1.x versions. may-affects-5.2 This bug maybe affects 5.2.x versions. may-affects-5.3 This bug maybe affects 5.3.x versions. may-affects-5.4 This bug maybe affects 5.4.x versions. may-affects-6.0 labels Apr 28, 2022
@Yisaer
Copy link
Contributor

Yisaer commented Apr 28, 2022

Could you provided the table structures by show create table oracle_cb_metric_dbtime?

@311ybb
Copy link
Author

311ybb commented Apr 28, 2022

| oracle_cb_metric_dbtime | CREATE TABLE oracle_cb_metric_dbtime (
id bigint(20) NOT NULL AUTO_INCREMENT,
instance_name varchar(12) NOT NULL,
end_time datetime NOT NULL,
metric_name varchar(64) DEFAULT NULL,
value decimal(10,0) DEFAULT NULL,
PRIMARY KEY (id,instance_name,end_time) /*T![clustered_index] NONCLUSTERED */,
KEY io_idx1 (end_time,instance_name,metric_name),
KEY idx1 (id)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin AUTO_INCREMENT=18037099 /*T! SHARD_ROW_ID_BITS=3 PRE_SPLIT_REGIONS=2 */
PARTITION BY RANGE COLUMNS(end_time) (
PARTITION p202110 VALUES LESS THAN ("2021-11-01"),
PARTITION p202111 VALUES LESS THAN ("2021-12-01"),
PARTITION p202112 VALUES LESS THAN ("2022-01-01"),
PARTITION p202201 VALUES LESS THAN ("2022-02-01"),
PARTITION p202202 VALUES LESS THAN ("2022-03-01"),
PARTITION p202203 VALUES LESS THAN ("2022-04-01"),
PARTITION p202204 VALUES LESS THAN ("2022-05-01"),
PARTITION p202205 VALUES LESS THAN ("2022-06-01"),
PARTITION p202206 VALUES LESS THAN ("2022-07-01"),
PARTITION p202207 VALUES LESS THAN ("2022-08-01"),
PARTITION p202208 VALUES LESS THAN ("2022-09-01"),
PARTITION p202209 VALUES LESS THAN ("2022-10-01"),
PARTITION p202210 VALUES LESS THAN ("2022-11-01"),
PARTITION p202211 VALUES LESS THAN ("2022-12-01"),
PARTITION p202212 VALUES LESS THAN ("2023-01-01"),
PARTITION pmax VALUES LESS THAN (MAXVALUE)
) |

@Yisaer
Copy link
Contributor

Yisaer commented Apr 28, 2022

I tested it with tidb v5.2.3 by following sqls, and I can't reproduced the error:

mysql> CREATE TABLE oracle_cb_metric_dbtime (
    -> id bigint(20) NOT NULL AUTO_INCREMENT,
    -> instance_name varchar(12) NOT NULL,
    -> end_time datetime NOT NULL,
    -> metric_name varchar(64) DEFAULT NULL,
    -> value decimal(10,0) DEFAULT NULL,
    -> PRIMARY KEY (id,instance_name,end_time) /*T![clustered_index] NONCLUSTERED */,
    -> KEY io_idx1 (end_time,instance_name,metric_name),
    -> KEY idx1 (id)
    -> ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin AUTO_INCREMENT=18037099 /*T! SHARD_ROW_ID_BITS=3 PRE_SPLIT_REGIONS=2 */
    -> PARTITION BY RANGE COLUMNS(end_time) (
    -> PARTITION p202110 VALUES LESS THAN ("2021-11-01"),
    -> PARTITION p202111 VALUES LESS THAN ("2021-12-01"),
    -> PARTITION p202112 VALUES LESS THAN ("2022-01-01"),
    -> PARTITION p202201 VALUES LESS THAN ("2022-02-01"),
    -> PARTITION p202202 VALUES LESS THAN ("2022-03-01"),
    -> PARTITION p202203 VALUES LESS THAN ("2022-04-01"),
    -> PARTITION p202204 VALUES LESS THAN ("2022-05-01"),
    -> PARTITION p202205 VALUES LESS THAN ("2022-06-01"),
    -> PARTITION p202206 VALUES LESS THAN ("2022-07-01"),
    -> PARTITION p202207 VALUES LESS THAN ("2022-08-01"),
    -> PARTITION p202208 VALUES LESS THAN ("2022-09-01"),
    -> PARTITION p202209 VALUES LESS THAN ("2022-10-01"),
    -> PARTITION p202210 VALUES LESS THAN ("2022-11-01"),
    -> PARTITION p202211 VALUES LESS THAN ("2022-12-01"),
    -> PARTITION p202212 VALUES LESS THAN ("2023-01-01"),
    -> PARTITION pmax VALUES LESS THAN (MAXVALUE)
    -> );
Query OK, 0 rows affected (0.14 sec)

mysql> set @@session.tidb_partition_prune_mode = 'dynamic';                                   Query OK, 0 rows affected (0.00 sec)

mysql> analyze table oracle_cb_metric_dbtime;
Query OK, 0 rows affected (3.99 sec)

Could you provide the minimum reproducible steps? @311ybb

@311ybb
Copy link
Author

311ybb commented Apr 28, 2022

image

@311ybb
Copy link
Author

311ybb commented Apr 28, 2022

mysql>
mysql> select version();
+--------------------+
| version() |
+--------------------+
| 5.7.25-TiDB-v5.2.3 |
+--------------------+
1 row in set (0.00 sec)
[tidb@crmhist5 ~]$ uname -a
Linux crmhist5 3.10.0-957.el7.x86_64 #1 SMP Thu Oct 4 20:48:51 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
[tidb@crmhist5 ~]$

@Yisaer
Copy link
Contributor

Yisaer commented Apr 28, 2022

@mjonss Did you meet the errors like this before for dynamic prune mode?

@311ybb
Copy link
Author

311ybb commented Apr 28, 2022

no ,it's my first time to analyze table under dynamic prune mode?

@Yisaer
Copy link
Contributor

Yisaer commented Apr 29, 2022

@311ybb I think the error might be related with the data. Is it possible to dump data for table oracle_cb_metric_dbtime following this document? It will be quite helpful for us to reproduce the error and locate the problem.

@tiancaiamao
Copy link
Contributor

@mjonss Please keep an eye on this

@tiancaiamao
Copy link
Contributor

The tidb log may contain the error stack information, and would be helpful for us to know from where the error is throw
@311ybb

@311ybb
Copy link
Author

311ybb commented Apr 29, 2022

[2022/04/06 21:30:40.629 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:1.016002785s txnStartTS:432341470533648387 region_id:3069864 store_addr:10.161.69.183:20160 kv_process_ms:1015 kv_wait_ms:0 kv_read_ms:0 processed_versions:1267596 total_versions:1267599 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:1267598 rocksdb_cache_hit_count:9 rocksdb_read_count:956 rocksdb_read_byte:28454960"]
[2022/04/06 21:30:40.666 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:911.148477ms txnStartTS:432341470533648387 region_id:3070449 store_addr:10.161.69.185:20160 kv_process_ms:910 kv_wait_ms:0 kv_read_ms:0 processed_versions:1104796 total_versions:1104797 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:1104796 rocksdb_cache_hit_count:9 rocksdb_read_count:833 rocksdb_read_byte:17813877"]
[2022/04/06 21:30:41.096 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:429.958746ms txnStartTS:432341470533648387 region_id:2911225 store_addr:10.161.69.185:20160 kv_process_ms:428 kv_wait_ms:1 kv_read_ms:0 processed_versions:439424 total_versions:439425 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:439424 rocksdb_cache_hit_count:9 rocksdb_read_count:333 rocksdb_read_byte:7150495"]
[2022/04/06 21:30:41.264 +08:00] [INFO] [analyze.go:128] [“analyze table skyalarm.oracle_cb_metric_dbtime has finished”] [conn=7765] [partition=p202203] [“job info”=“analyze index idx1”] [“start time”=2022/04/06 21:30:38.911 +08:00] [“end time”=2022/04/06 21:30:41.264 +08:00] [cost=2.352774409s]
[2022/04/06 21:30:41.540 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:910.879738ms txnStartTS:432341470533648387 region_id:2678295 store_addr:10.161.69.183:20160 kv_process_ms:910 kv_wait_ms:0 kv_read_ms:0 processed_versions:1260077 total_versions:1260078 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:1260077 rocksdb_cache_hit_count:468 rocksdb_read_count:490 rocksdb_read_byte:18392738"]
[2022/04/06 21:30:41.677 +08:00] [INFO] [analyze.go:128] [“analyze table skyalarm.oracle_cb_metric_dbtime has finished”] [conn=7765] [partition=p202201] [“job info”=“analyze index idx1”] [“start time”=2022/04/06 21:30:36.587 +08:00] [“end time”=2022/04/06 21:30:41.677 +08:00] [cost=5.089503488s]
[2022/04/06 21:30:42.130 +08:00] [INFO] [tidb.go:242] [“rollbackTxn called due to ddl/autocommit failure”]
[2022/04/06 21:30:42.130 +08:00] [WARN] [session.go:1686] [“run statement failed”] [conn=7765] [schemaVersion=853] [error=“invalid encoded key flag 9”] [session="{\n “currDBName”: “skyalarm”,\n “id”: 7765,\n “status”: 2,\n “strictMode”: true,\n “user”: {\n “Username”: “root”,\n “Hostname”: “10.161.69.187”,\n “CurrentUser”: false,\n “AuthUsername”: “root”,\n “AuthHostname”: “%”\n }\n}"]
[2022/04/06 21:30:42.130 +08:00] [INFO] [conn.go:1007] [“command dispatched failed”] [conn=7765] [connInfo=“id:7765, addr:10.161.69.187:13802 status:10, collation:utf8mb4_0900_ai_ci, user:root”] [command=Query] [status=“inTxn:0, autocommit:1”] [sql=“analyze table oracle_cb_metric_dbtime”] [txn_mode=PESSIMISTIC] err=“invalid encoded key flag 9[ngithub.com/pingcap/tidb/util/codec.DecodeAsDateTime\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/util/codec/codec.go:885\ngithub.com/pingcap/tidb/statistics.MergePartTopN2GlobalTopN\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/statistics/cmsketch.go:758\ngithub.com/pingcap/tidb/statistics/handle.(*Handle.mergePartitionStats2GlobalStats\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/statistics/handle/handle.go:448[ngithub.com/pingcap/tidb/statistics/handle.(*Handle](http://ngithub.com/pingcap/tidb/statistics/handle.(*Handle)).MergePartitionStats2GlobalStatsByTableID\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/statistics/handle/handle.go:334\[ngithub.com/pingcap/tidb/executor.(*AnalyzeExec](http://ngithub.com/pingcap/tidb/executor.(*AnalyzeExec)).Next\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/executor/analyze.go:186\[ngithub.com/pingcap/tidb/executor.Next\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/executor/executor.go:285\ngithub.com/pingcap/tidb/executor.(*ExecStmt](http://ngithub.com/pingcap/tidb/executor.Next%5Cn%5Ct/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/executor/executor.go:285%5Cngithub.com/pingcap/tidb/executor.(*ExecStmt)).handleNoDelayExecutor\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/executor/adapter.go:590\[ngithub.com/pingcap/tidb/executor.(*ExecStmt](http://ngithub.com/pingcap/tidb/executor.(*ExecStmt)).handleNoDelay\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/executor/adapter.go:471\[ngithub.com/pingcap/tidb/executor.(*ExecStmt](http://ngithub.com/pingcap/tidb/executor.(*ExecStmt)).Exec\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/executor/adapter.go:420\[ngithub.com/pingcap/tidb/session.runStmt\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/session/session.go:1789\ngithub.com/pingcap/tidb/session.(*session](http://ngithub.com/pingcap/tidb/session.runStmt%5Cn%5Ct/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/session/session.go:1789%5Cngithub.com/pingcap/tidb/session.(*session)).ExecuteStmt\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/session/session.go:1683\[ngithub.com/pingcap/tidb/server.(*TiDBContext](http://ngithub.com/pingcap/tidb/server.(*TiDBContext)).ExecuteStmt\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/driver_tidb.go:218\[ngithub.com/pingcap/tidb/server.(*clientConn](http://ngithub.com/pingcap/tidb/server.(*clientConn)).handleStmt\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/conn.go:1830\[ngithub.com/pingcap/tidb/server.(*clientConn](http://ngithub.com/pingcap/tidb/server.(*clientConn)).handleQuery\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/conn.go:1702\[ngithub.com/pingcap/tidb/server.(*clientConn](http://ngithub.com/pingcap/tidb/server.(*clientConn)).dispatch\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/conn.go:1227\[ngithub.com/pingcap/tidb/server.(*clientConn](http://ngithub.com/pingcap/tidb/server.(*clientConn)).Run\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/conn.go:990\[ngithub.com/pingcap/tidb/server.(*Server](http://ngithub.com/pingcap/tidb/server.(*Server)).onConn\n\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/server.go:501\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1371”]

@311ybb
Copy link
Author

311ybb commented Apr 29, 2022

dumpling data
链接:https://pan.baidu.com/s/1Q9ntxknZsxPrJx-asRGvvw
提取码:mofl

@Yisaer
Copy link
Contributor

Yisaer commented Apr 29, 2022

@311ybb Thanks for your dumping data. After I loaded the data and set the global tidb_analyze version = 1, I can reproduce the error now

mysql> set @@session.tidb_partition_prune_mode = 'static';
Query OK, 0 rows affected (0.00 sec)

mysql> analyze table oracle_cb_metric_dbtime;
Query OK, 0 rows affected (19.38 sec)

mysql>  set @@session.tidb_partition_prune_mode ='dynamic';
Query OK, 0 rows affected (0.00 sec)

mysql> analyze table oracle_cb_metric_dbtime;
ERROR 1105 (HY000): invalid encoded key flag 9

We will focus on it to locate the problem later.

@mjonss mjonss added the affects-5.2 This bug affects 5.2.x versions. label May 2, 2022
@ti-chi-bot ti-chi-bot removed the may-affects-5.2 This bug maybe affects 5.2.x versions. label May 2, 2022
@mjonss mjonss added the affects-5.1 This bug affects 5.1.x versions. label May 2, 2022
@ti-chi-bot ti-chi-bot removed the may-affects-5.1 This bug maybe affects 5.1.x versions. label May 2, 2022
@mjonss mjonss added the affects-5.3 This bug affects 5.3.x versions. label May 2, 2022
@ti-chi-bot ti-chi-bot removed the may-affects-5.3 This bug maybe affects 5.3.x versions. label May 2, 2022
@mjonss mjonss added the affects-5.4 This bug affects 5.4.x versions. label May 2, 2022
@ti-chi-bot ti-chi-bot removed the may-affects-5.4 This bug maybe affects 5.4.x versions. label May 2, 2022
@mjonss mjonss added the affects-5.0 This bug affects 5.0.x versions. label May 2, 2022
@ti-chi-bot ti-chi-bot removed the may-affects-5.0 This bug maybe affects 5.0.x versions. label May 2, 2022
@mjonss
Copy link
Contributor

mjonss commented May 2, 2022

In v5.0.6 this error is given instead:

ERROR 1105 (HY000): [stats]: some partition level statistics are not in statistics version 2, please set tidb_analyze_version to 2 and analyze the this table

@mjonss mjonss removed the may-affects-4.0 This bug maybe affects 4.0.x versions. label May 2, 2022
@311ybb
Copy link
Author

311ybb commented May 3, 2022

mysql> select a.table_name,b.stats_ver from information_schema.tables a, mysql.stats_histograms b where a.tidb_table_id=b.table_id and a.table_name='oracle_cb_metric_dbtime';
+-------------------------+-----------+
| table_name | stats_ver |
+-------------------------+-----------+
| oracle_cb_metric_dbtime | 1 |
| oracle_cb_metric_dbtime | 1 |
| oracle_cb_metric_dbtime | 1 |
+-------------------------+-----------+
3 rows in set (0.03 sec)

mysql> show variables like '%analyze_version%';
+----------------------+-------+
| Variable_name | Value |
+----------------------+-------+
| tidb_analyze_version | 1 |
+----------------------+-------+

@mjonss
Copy link
Contributor

mjonss commented May 3, 2022

Smaller test case:

CREATE TABLE `t` (
  `id` bigint(20) NOT NULL,
  `dt` datetime NOT NULL,
  PRIMARY KEY (`id`,`dt`)
)
PARTITION BY RANGE COLUMNS(`dt`)
(PARTITION `p202201` VALUES LESS THAN ("2022-02-01"),
 PARTITION `p202202` VALUES LESS THAN ("2022-03-01"));
INSERT INTO t VALUES (1, '2022-02-01 00:00:02'), (2, '2022-02-01 00:00:02');
SET @@global.tidb_analyze_version = 1;
SET @@session.tidb_partition_prune_mode = 'dynamic';
ANALYZE TABLE t;

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
affects-5.0 This bug affects 5.0.x versions. affects-5.1 This bug affects 5.1.x versions. affects-5.2 This bug affects 5.2.x versions. affects-5.3 This bug affects 5.3.x versions. affects-5.4 This bug affects 5.4.x versions. affects-6.0 component/tablepartition This issue is related to Table Partition of TiDB. severity/major sig/planner SIG: Planner type/bug The issue is confirmed as a bug.
Projects
None yet
6 participants