TiDB might OOM if dumpling without --params "tidb_enable_chunk_rpc=0"

[fubinzh]

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

TiDB might OOM if use dumpling to dump data from TiDB, without specifying --params "tidb_enable_chunk_rpc=0"

/dumpling  -h "downstream-tidb.brie-acceptance-tps-631157-1-802" -P "4000" -u "root" --output "s3://tmp/dumpling-view8778b93a-a5f7-4cda-a3ef-aea6cded7caa?access-key=minioadmin&secret-access-key=minioadmin&endpoint=http%3a%2f%2fminio.pingcap.net%3a9000&force-path-style=true" --filet
ype "csv" --rows "200" --threads "20"
Release version: v5.5.0-nightly
Git commit hash: 05b0b48d711a95ae330c08d07ec09543254cea6b
Git branch:      heads/refs/tags/v5.5.0-nightly
Build timestamp: 2022-01-25 06:08:53Z
Go version:      go version go1.16.4 linux/amd64

[2022/01/26 02:45:08.691 +00:00] [INFO] [versions.go:55] ["Welcome to dumpling"] ["Release Version"=v5.5.0-nightly] ["Git Commit Hash"=05b0b48d711a95ae330c08d07ec09543254cea6b] ["Git Branch"=heads/refs/tags/v5.5.0-nightly] ["Build timestamp"="2022-01-25 06:08:53"] ["Go Version"="go version go1.16.4 linux/amd64"]
[2022/01/26 02:45:08.695 +00:00] [INFO] [config.go:609] ["detect server type"] [type=TiDB]
[2022/01/26 02:45:08.695 +00:00] [INFO] [config.go:628] ["detect server version"] [version=5.5.0-nightly]
[2022/01/26 02:45:08.719 +00:00] [INFO] [client.go:215] ["[pd] create pd client with endpoints"] [pd-address="[downstream-pd-0.downstream-pd-peer.brie-acceptance-tps-631157-1-802.svc:2379]"]
[2022/01/26 02:45:08.722 +00:00] [INFO] [base_client.go:364] ["[pd] switch leader"] [new-leader=http://downstream-pd-0.downstream-pd-peer.brie-acceptance-tps-631157-1-802.svc:2379] [old-leader=]
[2022/01/26 02:45:08.722 +00:00] [INFO] [base_client.go:127] ["[pd] init cluster id"] [cluster-id=7057081336229436235]
[2022/01/26 02:45:08.722 +00:00] [INFO] [client.go:239] ["[pd] create tso dispatcher"] [dc-location=global]
[2022/01/26 02:45:08.723 +00:00] [INFO] [dump.go:1151] ["generate dumpling gc safePoint id"] [id=dumpling_1643165108723672951]
[2022/01/26 02:45:08.728 +00:00] [INFO] [dump.go:93] ["begin to run Dump"] [conf="{\"s3\":{\"endpoint\":\"http://minio.pingcap.net:9000\",\"region\":\"us-east-1\",\"storage-class\":\"\",\"sse\":\"\",\"sse-kms-key-id\":\"\",\"acl\":\"\",\"access-key\":\"minioadmin\",\"secret-access-key\":\"minioadmin\",\"provider\":\"\",\"force-path-style\":true,\"use-accelerate-endpoint\":false},\"gcs\":{\"endpoint\":\"\",\"storage-class\":\"\",\"predefined-acl\":\"\",\"credentials-file\":\"\"},\"AllowCleartextPasswords\":false,\"SortByPk\":true,\"NoViews\":true,\"NoHeader\":false,\"NoSchemas\":false,\"NoData\":false,\"CompleteInsert\":false,\"TransactionalConsistency\":true,\"EscapeBackslash\":true,\"DumpEmptyDatabase\":true,\"PosAfterConnect\":false,\"CompressType\":0,\"Host\":\"downstream-tidb.brie-acceptance-tps-631157-1-802\",\"Port\":4000,\"Threads\":20,\"User\":\"root\",\"Security\":{\"CAPath\":\"\",\"CertPath\":\"\",\"KeyPath\":\"\"},\"LogLevel\":\"info\",\"LogFile\":\"\",\"LogFormat\":\"text\",\"OutputDirPath\":\"s3://tmp/dumpling-view8778b93a-a5f7-4cda-a3ef-aea6cded7caa?access-key=minioadmin\\u0026secret-access-key=minioadmin\\u0026endpoint=http%3a%2f%2fminio.pingcap.net%3a9000\\u0026force-path-style=true\",\"StatusAddr\":\":8281\",\"Snapshot\":\"430745874259771394\",\"Consistency\":\"snapshot\",\"CsvNullValue\":\"\\\\N\",\"SQL\":\"\",\"CsvSeparator\":\",\",\"CsvDelimiter\":\"\\\"\",\"Databases\":[],\"Where\":\"\",\"FileType\":\"csv\",\"ServerInfo\":{\"HasTiKV\":true,\"ServerType\":3,\"ServerVersion\":\"5.5.0-nightly\"},\"Rows\":200,\"ReadTimeout\":900000000000,\"TiDBMemQuotaQuery\":0,\"FileSize\":0,\"StatementSize\":1000000,\"SessionParams\":{\"tidb_snapshot\":\"430745874259771394\"},\"Tables\":null}"]
[2022/01/26 02:45:10.050 +00:00] [WARN] [writer.go:230] ["no data written in table chunk"] [database=ens_mars] [table=fw_sequences] [chunkIdx=0]
[2022/01/26 02:45:10.053 +00:00] [WARN] [dump.go:473] ["fallback to concurrent dump tables using rows due to tidb error"] [database=ens_mars] [table=fw_sequences_cluster] [error="empty handleVals for TiDB table `ens_mars`.`fw_sequences_cluster`"]
[2022/01/26 02:45:10.053 +00:00] [INFO] [dump.go:491] ["get estimated rows count"] [database=ens_mars] [table=fw_sequences_cluster] [estimateCount=10000]
[2022/01/26 02:45:10.055 +00:00] [WARN] [dump.go:580] ["no data to dump"] [database=ens_mars] [table=fw_sequences_cluster]

...
[2022/01/26 02:46:03.901 +00:00] [INFO] [dump.go:491] ["get estimated rows count"] [database=ens_rb002] [table=rb_acct_stats] [estimateCount=10000]
[2022/01/26 02:46:03.915 +00:00] [WARN] [dump.go:580] ["no data to dump"] [database=ens_rb002] [table=rb_acct_stats]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[mysql] 2022/01/26 02:46:06 packets.go:37: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:37: read tcp 10.233.103.5:57222->10.99.130.132:4000: read: connection reset by peer
[mysql] 2022/01/26 02:46:06 packets.go:37: read tcp 10.233.103.5:57190->10.99.130.132:4000: read: connection reset by peer
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[mysql] 2022/01/26 02:46:06 packets.go:37: read tcp 10.233.103.5:57182->10.99.130.132:4000: read: connection reset by peer
[mysql] 2022/01/26 02:46:06 packets.go:37: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[2022/01/26 02:46:06.332 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=190337] ["finished size"=109064723] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.332 +00:00] [INFO] [collector.go:194] ["backup failed summary"] [total-ranges=0] [ranges-succeed=0] [ranges-failed=0]
[2022/01/26 02:46:06.332 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=207052] ["finished size"=118642418] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.332 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=77085] ["finished size"=44171327] [error="invalid connection"]
[2022/01/26 02:46:06.332 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=35896] ["finished size"=20570030] [error="invalid connection"]
[2022/01/26 02:46:06.332 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=207766] ["finished size"=119051540] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.333 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=193275] ["finished size"=110748197] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.340 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=210515] ["finished size"=120626717] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.341 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=87646] ["finished size"=50222780] [error="invalid connection"]
[2022/01/26 02:46:06.342 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=1451] ["finished size"=833045] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.346 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=110340] ["finished size"=63226442] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.351 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=67238] ["finished size"=38528996] [error="invalid connection"]
[2022/01/26 02:46:06.351 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=194583] ["finished size"=111497681] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.366 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=192266] ["finished size"=110170040] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.367 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=115911] ["finished size"=66418625] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.372 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=228011] ["finished size"=130651925] [error="invalid connection"]
[mysql] 2022/01/26 02:46:06 packets.go:73: unexpected EOF
[mysql] 2022/01/26 02:46:06 packets.go:428: busy buffer
[2022/01/26 02:46:06.373 +00:00] [WARN] [writer_util.go:319] ["fail to dumping table(chunk), will revert some metrics and start a retry if possible"] [database=ens_rb002] [table=rb_acct] ["finished rows"=41978] ["finished size"=24055016] [error="invalid connection"]
[2022/01/26 02:46:06.374 +00:00] [ERROR] [main.go:77] ["dump failed error stack info"] [error="sql: SHOW COLUMNS FROM `ens_rb002`.`rb_acct_tran_stats`: invalid connection"] [errorVerbose="invalid connection\nsql: SHOW COLUMNS FROM `ens_rb002`.`rb_acct_tran_stats`\ngithub.com/pingcap/dumpling/v4/export.buildSelectField\n\tgithub.com/pingcap/dumpling/v4/export/sql.go:717\ngithub.com/pingcap/dumpling/v4/export.dumpTableMeta\n\tgithub.com/pingcap/dumpling/v4/export/dump.go:889\ngithub.com/pingcap/dumpling/v4/export.(*Dumper).dumpDatabases\n\tgithub.com/pingcap/dumpling/v4/export/dump.go:313\ngithub.com/pingcap/dumpling/v4/export.(*Dumper).Dump\n\tgithub.com/pingcap/dumpling/v4/export/dump.go:231\nmain.main\n\tcommand-line-arguments/main.go:74\nruntime.main\n\truntime/proc.go:225\nruntime.goexit\n\truntime/asm_amd64.s:1371"]

dump failed: sql: SHOW COLUMNS FROM `ens_rb002`.`rb_acct_tran_stats`: invalid connection

For detailed dumpling log, please refer to: http://172.16.4.180:31714/artifacts/testground/plan-exec-631157/plan-exec-631157-683899576/main-logs

2. What did you expect to see? (Required)

• Dumpling should succeed.

3. What did you see instead (Required)

Dumpling failed due to TiDB OOM, refer to TiDB memory usage differences while dumpling without/with --params "tidb_enable_chunk_rpc=0".

TiDB Log:
tidb (8).log

4. What is your TiDB version? (Required)

["Welcome to TiDB."] ["Release Version"=v5.5.0-nightly] [Edition=Community] ["Git Commit Hash"=8fb83195c5766e9fb794c5ebbafdeb68c5f358d4] ["Git Branch"=heads/refs/tags/v5.5.0-nightly] ["UTC Build Time"="2022-01-25 06:11:45"]

[fubinzh]

The workaround (-params "tidb_enable_chunk_rpc=0") was provided as part of issue #30880, we still need a real fix for this issue.