dump failed due to wait timeout

[dbakit]

Bug Report

On production environment, we set wait_timeout=600, so if mysql connection pool has some connections idle longer than 600s, the dumping will fail.

as we known, mysql driver support function SetConnMaxIdleTime, so I fixed it by add a max-idle-time variables on CLI.

Dumpling & MySQL Version

Release version: v5.0.1
Git commit hash: 4cb115746bb658b6d1a12c0e49932bfd3a08afac
Git branch:      heads/refs/tags/v5.0.1
Build timestamp: 2021-04-23 06:01:59Z
Go version:      go version go1.13 linux/amd64

[2021/05/07 09:01:32.727 +08:00] [INFO] [versions.go:55] ["Welcome to dumpling"] ["Release Version"=v5.0.1] ["Git Commit Hash"=4cb115746bb658b6d1a12c0e49932bfd3a08afac] ["Git Branch"=heads/refs/tags/v5.0.1] ["Build timestamp"="2021-04-23 06:01:59"] ["Go Version"="go version go1.13 linux/amd64"]
[2021/05/07 09:01:32.738 +08:00] [INFO] [config.go:599] ["detect server type"] [type=MySQL]
[2021/05/07 09:01:32.738 +08:00] [INFO] [config.go:618] ["detect server version"] [version=5.7.18-log]

Error Log

[2021/05/07 10:17:35.503 +08:00] [INFO] [collector.go:188] ["backup Failed summary : total backup ranges: 0, total success: 0, total failed: 0"]
[mysql] 2021/05/07 10:17:36 packets.go:122: closing bad idle connection: EOF
[2021/05/07 10:17:36.396 +08:00] [ERROR] [writer_util.go:199] ["fail to scan from sql.Row"] [error="context canceled"] [errorVerbose="context canceled\ngithub.com/pingcap/errors.AddStack\n\tgithub.com/pingcap/errors@v0.11.5-0.20201126102027-b0a155152ca3/errors.go:174\ngithub.com/pingcap/errors.Trace\n\tgithub.com/pingcap/errors@v0.11.5-0.20201126102027-b0a155152ca3/juju_adaptor.go:15\ngithub.com/pingcap/dumpling/v4/export.decodeFromRows\n\tgithub.com/pingcap/dumpling@/v4/export/ir.go:68\ngithub.com/pingcap/dumpling/v4/export.(*rowIter).Decode\n\tgithub.com/pingcap/dumpling@/v4/export/ir_impl.go:39\ngithub.com/pingcap/dumpling/v4/export.WriteInsert\n\tgithub.com/pingcap/dumpling@/v4/export/writer_util.go:198\ngithub.com/pingcap/dumpling/v4/export.FileFormat.WriteInsert\n\tgithub.com/pingcap/dumpling@/v4/export/writer_util.go:600\ngithub.com/pingcap/dumpling/v4/export.(*Writer).tryToWriteTableData\n\tgithub.com/pingcap/dumpling@/v4/export/writer.go:204\ngithub.com/pingcap/dumpling/v4/export.(*Writer).WriteTableData.func1\n\tgithub.com/pingcap/dumpling@/v4/export/writer.go:189\ngithub.com/pingcap/br/pkg/utils.WithRetry\n\tgithub.com/pingcap/br@v4.0.0-beta.2.0.20210203034957-7bc483ab69d5+incompatible/pkg/utils/retry.go:34\ngithub.com/pingcap/dumpling/v4/export.(*Writer).WriteTableData\n\tgithub.com/pingcap/dumpling@/v4/export/writer.go:160\ngithub.com/pingcap/dumpling/v4/export.(*Writer).handleTask\n\tgithub.com/pingcap/dumpling@/v4/export/writer.go:103\ngithub.com/pingcap/dumpling/v4/export.(*Writer).run\n\tgithub.com/pingcap/dumpling@/v4/export/writer.go:85\ngithub.com/pingcap/dumpling/v4/export.(*Dumper).startWriters.func4\n\tgithub.com/pingcap/dumpling@/v4/export/dump.go:273\ngolang.org/x/sync/errgroup.(*Group).Go.func1\n\tgolang.org/x/sync@v0.0.0-20201020160332-67f06af15bc9/errgroup/errgroup.go:57\nruntime.goexit\n\truntime/asm_amd64.s:1357"]
[2021/05/07 10:17:36.396 +08:00] [ERROR] [writer_util.go:199] ["fail to scan from sql.Row"] [error="context canceled"] [errorVerbose="context canceled\ngithub.com/pingcap/errors.AddStack\n\tgithub.com/pingcap/errors@v0.11.5-0.20201126102027-b0a155152ca3/errors.go:174\ngithub.com/pingcap/errors.Trace\n\tgithub.com/pingcap/errors@v0.11.5-0.20201126102027-b0a155152ca3/juju_adaptor.go:15\ngithub.com/pingcap/dumpling/v4/export.decodeFromRows\n\tgithub.com/pingcap/dumpling@/v4/export/ir.go:68\ngithub.com/pingcap/dumpling/v4/export.(*rowIter).Decode\n\tgithub.com/pingcap/dumpling@/v4/export/ir_impl.go:39\ngithub.com/pingcap/dumpling/v4/export.WriteInsert\n\tgithub.com/pingcap/dumpling@/v4/export/writer_util.go:198\ngithub.com/pingcap/dumpling/v4/export.FileFormat.WriteInsert\n\tgithub.com/pingcap/dumpling@/v4/export/writer_util.go:600\ngithub.com/pingcap/dumpling/v4/export.(*Writer).tryToWriteTableData\n\tgithub.com/pingcap/dumpling@/v4/export/writer.go:204\ngithub.com/pingcap/dumpling/v4/export.(*Writer).WriteTableData.func1\n\tgithub.com/pingcap/dumpling@/v4/export/writer.go:189\ngithub.com/pingcap/br/pkg/utils.WithRetry\n\tgithub.com/pingcap/br@v4.0.0-beta.2.0.20210203034957-7bc483ab69d5+incompatible/pkg/utils/retry.go:34\ngithub.com/pingcap/dumpling/v4/export.(*Writer).WriteTableData\n\tgithub.com/pingcap/dumpling@/v4/export/writer.go:160\ngithub.com/pingcap/dumpling/v4/export.(*Writer).handleTask\n\tgithub.com/pingcap/dumpling@/v4/export/writer.go:103\ngithub.com/pingcap/dumpling/v4/export.(*Writer).run\n\tgithub.com/pingcap/dumpling@/v4/export/writer.go:85\ngithub.com/pingcap/dumpling/v4/export.(*Dumper).startWriters.func4\n\tgithub.com/pingcap/dumpling@/v4/export/dump.go:273\ngolang.org/x/sync/errgroup.(*Group).Go.func1\n\tgolang.org/x/sync@v0.0.0-20201020160332-67f06af15bc9/errgroup/errgroup.go:57\nruntime.goexit\n\truntime/asm_amd64.s:1357"]
[2021/05/07 10:17:36.396 +08:00] [ERROR] [main.go:77] ["dump failed error stack info"] [error="sql: SELECT COLUMN_NAME,EXTRA FROM INFORMATION_SCHEMA.COLUMNS WHERE TABLE_SCHEMA=? AND TABLE_NAME=? ORDER BY ORDINAL_POSITION;: driver: bad connection"] [errorVerbose="driver: bad connection\nsql: SELECT COLUMN_NAME,EXTRA FROM INFORMATION_SCHEMA.COLUMNS WHERE TABLE_SCHEMA=? AND TABLE_NAME=? ORDER BY ORDINAL_POSITION;\ngithub.com/pingcap/dumpling/v4/export.buildSelectField\n\tgithub.com/pingcap/dumpling@/v4/export/sql.go:588\ngithub.com/pingcap/dumpling/v4/export.dumpTableMeta\n\tgithub.com/pingcap/dumpling@/v4/export/dump.go:686\ngithub.com/pingcap/dumpling/v4/export.(*Dumper).dumpDatabases\n\tgithub.com/pingcap/dumpling@/v4/export/dump.go:302\ngithub.com/pingcap/dumpling/v4/export.(*Dumper).Dump\n\tgithub.com/pingcap/dumpling@/v4/export/dump.go:223\nmain.main\n\tgithub.com/pingcap/dumpling@/cmd/dumpling/main.go:74\nruntime.main\n\truntime/proc.go:203\nruntime.goexit\n\truntime/asm_amd64.s:1357"]

dump failed: sql: SELECT COLUMN_NAME,EXTRA FROM INFORMATION_SCHEMA.COLUMNS WHERE TABLE_SCHEMA=? AND TABLE_NAME=? ORDER BY ORDINAL_POSITION;: driver: bad connection

[dbakit]

diff --git a/v4/export/config.go b/v4/export/config.go
index a5b99f7..49a72ef 100644
--- a/v4/export/config.go
+++ b/v4/export/config.go
@@ -68,6 +68,7 @@ const (
        flagCompleteInsert           = "complete-insert"
        flagParams                   = "params"
        flagReadTimeout              = "read-timeout"
+       flagMaxIdleTime              = "max-idle-time"
        flagTransactionalConsistency = "transactional-consistency"
        flagCompress                 = "compress"
 
@@ -124,6 +125,7 @@ type Config struct {
        OutputFileTemplate *template.Template `json:"-"`
        Rows               uint64
        ReadTimeout        time.Duration
+       MaxIdleTime        time.Duration
        TiDBMemQuotaQuery  uint64
        FileSize           uint64
        StatementSize      uint64
@@ -242,7 +243,7 @@ func (conf *Config) DefineFlags(flags *pflag.FlagSet) {
        flags.StringToString(flagParams, nil, `Extra session variables used while dumping, accepted format: --params "character_set_client=latin1,character_set_connection=latin1"`)
        flags.Bool(FlagHelp, false, "Print help message and quit")
        flags.Duration(flagReadTimeout, 15*time.Minute, "I/O read timeout for db connection.")
+       flags.Duration(flagMaxIdleTime, 600*time.Second, "max idle time for db connection.")
        flags.Bool(flagTransactionalConsistency, true, "Only support transactional consistency")
        _ = flags.MarkHidden(flagTransactionalConsistency)
        flags.StringP(flagCompress, "c", "", "Compress output file type, support 'gzip', 'no-compression' now")
@@ -384,6 +385,10 @@ func (conf *Config) ParseFromFlags(flags *pflag.FlagSet) error {
        if err != nil {
                return errors.Trace(err)
        }
+       conf.MaxIdleTime, err = flags.GetDuration(flagMaxIdleTime)
+       if err != nil {
+               return errors.Trace(err)
+       }
        conf.TransactionalConsistency, err = flags.GetBool(flagTransactionalConsistency)
        if err != nil {
                return errors.Trace(err)
diff --git a/v4/export/dump.go b/v4/export/dump.go
index 1ad1ca6..cec86e3 100755
--- a/v4/export/dump.go
+++ b/v4/export/dump.go
@@ -996,6 +996,7 @@ func openSQLDB(d *Dumper) error {
        if err != nil {
                return errors.Trace(err)
        }
+       pool.SetConnMaxIdleTime(conf.MaxIdleTime)
        d.dbHandle = pool
        return nil
 }
@@ -1155,5 +1156,6 @@ func setSessionParam(d *Dumper) error {
        if d.dbHandle, err = resetDBWithSessionParams(d.tctx, pool, conf.GetDSN(""), conf.SessionParams); err != nil {
                return errors.Trace(err)
        }
+       d.dbHandle.SetConnMaxIdleTime(conf.MaxIdleTime)
        return nil
 }

[lichunzhu]

SetConnMaxIdleTime is a newly added function in go 1.15. The CI releasing dumpling is still using go 1.13. We are trying to upgrade to go 1.16 recently. We will do this later after the CI is upgraded.
https://golang.org/doc/go1.15#database/sql

[cyliu0]

/type bug

[lichunzhu]

@dba-kit Dumpling has already upgraded go version to v1.16. Could you please help us file a pull request?

[recall704]

Maybe this can work for you: #265 (comment)

--params="net_read_timeout=86400,interactive_timeout=28800,wait_timeout=2147483,net_write_timeout=86400"

[dbakit]

Yep, it's fine for me