[CDC:ErrMySQLTxnError]Error 1292: Incorrect time value

🌞 建议反馈 产品缺陷
1

TiCDC同步报错：[CDC:ErrMySQLTxnError]Error 1292: Incorrect time value

[2022/02/24 09:01:53.241 +08:00] [WARN] [mysql.go:882] ["execute DMLs with error, retry later"] [error="[CDC:ErrMySQLTxnError]Error 1292: Incorrect time value: '{0 0 0 0 0 0 48}'"] [errorVerbose="[CDC:ErrMySQLTxnError]Error 1292: Incorrect time value: '{0 0 0 0 0 0 48}'\
github.com/pingcap/errors.AddStack\
\tgithub.com/pingcap/errors@v0.11.5-0.20201126102027-b0a155152ca3/errors.go:174\
github.com/pingcap/errors.(*Error).GenWithStackByCause\
\tgithub.com/pingcap/errors@v0.11.5-0.20201126102027-b0a155152ca3/normalize.go:279\
github.com/pingcap/ticdc/pkg/errors.WrapError\
\tgithub.com/pingcap/ticdc/pkg/errors/helper.go:28\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLWithMaxRetries.func2.3\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:905\
github.com/pingcap/ticdc/cdc/sink.(*Statistics).RecordBatchExecution\
\tgithub.com/pingcap/ticdc/cdc/sink/statistics.go:99\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLWithMaxRetries.func2\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:893\
github.com/pingcap/ticdc/pkg/retry.Run.func1\
\tgithub.com/pingcap/ticdc/pkg/retry/retry.go:32\
github.com/cenkalti/backoff.RetryNotify\
\tgithub.com/cenkalti/backoff@v2.2.1+incompatible/retry.go:37\
github.com/cenkalti/backoff.Retry\
\tgithub.com/cenkalti/backoff@v2.2.1+incompatible/retry.go:24\
github.com/pingcap/ticdc/pkg/retry.Run\
\tgithub.com/pingcap/ticdc/pkg/retry/retry.go:31\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLWithMaxRetries\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:885\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLs\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:1044\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSinkWorker).run.func3\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:799\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSinkWorker).run\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:837\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).createSinkWorkers.func1\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:640\
runtime.goexit\
\truntime/asm_amd64.s:1371"]
[2022/02/24 09:01:53.739 +08:00] [WARN] [mysql.go:882] ["execute DMLs with error, retry later"] [error="[CDC:ErrMySQLTxnError]Error 1292: Incorrect time value: '{0 0 0 0 0 0 48}'"] [errorVerbose="[CDC:ErrMySQLTxnError]Error 1292: Incorrect time value: '{0 0 0 0 0 0 48}'\
github.com/pingcap/errors.AddStack\
\tgithub.com/pingcap/errors@v0.11.5-0.20201126102027-b0a155152ca3/errors.go:174\
github.com/pingcap/errors.(*Error).GenWithStackByCause\
\tgithub.com/pingcap/errors@v0.11.5-0.20201126102027-b0a155152ca3/normalize.go:279\
github.com/pingcap/ticdc/pkg/errors.WrapError\
\tgithub.com/pingcap/ticdc/pkg/errors/helper.go:28\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLWithMaxRetries.func2.3\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:905\
github.com/pingcap/ticdc/cdc/sink.(*Statistics).RecordBatchExecution\
\tgithub.com/pingcap/ticdc/cdc/sink/statistics.go:99\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLWithMaxRetries.func2\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:893\
github.com/pingcap/ticdc/pkg/retry.Run.func1\
\tgithub.com/pingcap/ticdc/pkg/retry/retry.go:32\
github.com/cenkalti/backoff.RetryNotify\
\tgithub.com/cenkalti/backoff@v2.2.1+incompatible/retry.go:37\
github.com/cenkalti/backoff.Retry\
\tgithub.com/cenkalti/backoff@v2.2.1+incompatible/retry.go:24\
github.com/pingcap/ticdc/pkg/retry.Run\
\tgithub.com/pingcap/ticdc/pkg/retry/retry.go:31\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLWithMaxRetries\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:885\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLs\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:1044\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSinkWorker).run.func3\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:799\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSinkWorker).run\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:837\
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).createSinkWorkers.func1\
\tgithub.com/pingcap/ticdc/cdc/sink/mysql.go:640\
runtime.goexit\
\truntime/asm_amd64.s:1371"]

格式化后为:

[CDC:ErrMySQLTxnError]Error 1292: Incorrect time value: '{0 0 0 0 0 0 48}'
github.com/pingcap/errors.AddStack
	github.com/pingcap/errors@v0.11.5-0.20201126102027-b0a155152ca3/errors.go:174
github.com/pingcap/errors.(*Error).GenWithStackByCause
	github.com/pingcap/errors@v0.11.5-0.20201126102027-b0a155152ca3/normalize.go:279
github.com/pingcap/ticdc/pkg/errors.WrapError
	github.com/pingcap/ticdc/pkg/errors/helper.go:28
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLWithMaxRetries.func2.3
	github.com/pingcap/ticdc/cdc/sink/mysql.go:905
github.com/pingcap/ticdc/cdc/sink.(*Statistics).RecordBatchExecution
	github.com/pingcap/ticdc/cdc/sink/statistics.go:99
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLWithMaxRetries.func2
	github.com/pingcap/ticdc/cdc/sink/mysql.go:893
github.com/pingcap/ticdc/pkg/retry.Run.func1
	github.com/pingcap/ticdc/pkg/retry/retry.go:32
github.com/cenkalti/backoff.RetryNotify
	github.com/cenkalti/backoff@v2.2.1+incompatible/retry.go:37
github.com/cenkalti/backoff.Retry
	github.com/cenkalti/backoff@v2.2.1+incompatible/retry.go:24
github.com/pingcap/ticdc/pkg/retry.Run
	github.com/pingcap/ticdc/pkg/retry/retry.go:31
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLWithMaxRetries
	github.com/pingcap/ticdc/cdc/sink/mysql.go:885
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).execDMLs
	github.com/pingcap/ticdc/cdc/sink/mysql.go:1044
github.com/pingcap/ticdc/cdc/sink.(*mysqlSinkWorker).run.func3
	github.com/pingcap/ticdc/cdc/sink/mysql.go:799
github.com/pingcap/ticdc/cdc/sink.(*mysqlSinkWorker).run
	github.com/pingcap/ticdc/cdc/sink/mysql.go:837
github.com/pingcap/ticdc/cdc/sink.(*mysqlSink).createSinkWorkers.func1
	github.com/pingcap/ticdc/cdc/sink/mysql.go:640
runtime.goexit
	runtime/asm_amd64.s:1371

上下游TiDB sql_mode都有设置NO_ZERO_IN_DATE,NO_ZERO_DATE，理论上不该有0值时间写入成功的。其次报错信息没有带表名和字段名，想排查都无从入手。。

## 上游TiDB
mysql> show variables like 'sql_mode';
+---------------+-------------------------------------------------------------------------------------------------------------------------------------------+
| Variable_name | Value                                                                                                                                     |
+---------------+-------------------------------------------------------------------------------------------------------------------------------------------+
| sql_mode      | ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION |
+---------------+-------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.01 sec)


## 下游TiDB
mysql> show variables like 'sql_mode';
+---------------+-------------------------------------------------------------------------------------------------------------------------------------------+
| Variable_name | Value                                                                                                                                     |
+---------------+-------------------------------------------------------------------------------------------------------------------------------------------+
| sql_mode      | ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION |
+---------------+-------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.01 sec)
2 个赞
2

应该是有漏掉的，或者是有将null值转换为0的

1 个赞
3

主要是没有排查方向，报错没有给出有用信息，表名，字段名，出错的SQL内容这些都没有

4

源表的历史值，可以排查下,字典表字段排查

5

上游的表有几千个，是全量同步到备份的TiDB集群，挨个表排查根本不现实。。。

6

其实如果有哪个地方能知道是哪个表的问题，处理起来也方便了

7

排查的方向就是看日期事件类型的字段值有没有异常的

8

标准的「正确但无用的话」，当90%的表都有时间类型的字段时候，排查难度会非常大。
那我还不如先用BR工具做下增量同步，跳过这段时间，然后再创建新的changefeed，来从最新的tso来同步

9

我抛出来这个问题，不是说没办法解决这个问题，而是想知道一下有没有更优雅的解决方法。如果没有的话，希望官方修改一下日志输出提供足够信息。

10

更新一下，问题最终原因找到了。是下游的TiDB里存在了异常的数据，导致对这条数据的某个字段增删改查都会有报错。具体操作如下面实验所示，是create_time和update_time被截断了，不过create_time是显示0值，update_time直接报Data Truncated或Incorrect time value(前者是范围查询报错，后者是主键查询报错)。
因为没办法删除这条数据，所以只能将这个表drop掉，重新导入。

mysql> delete from ying99_asset.ic_asset_days where account3_id='48098' and begin_txn_day='2021-11-22' and year='2022' and po_code='*' and broker='0008';
ERROR 1292 (22007): Incorrect time value: '{0 0 0 0 0 0 49}'
mysql> update ying99_asset.ic_asset_days set create_time='2022-01-04 18:09:50', update_time='2022-02-28 14:13:15' where account3_id='48098' and begin_txn_day='2021-11-22' and year='2022';
ERROR 1105 (HY000): Data Truncated
mysql> update ying99_asset.ic_asset_days set create_time='2022-01-04 18:09:50', update_time='2022-02-28 14:13:15' where  account3_id='48098' and begin_txn_day='2021-11-22' and year='2022' and po_code='*' and broker='0008';
ERROR 1292 (22007): Incorrect time value: '{0 0 0 0 0 0 49}'
mysql> select * from ying99_asset.ic_asset_days where account3_id='48098' and begin_txn_day='2021-11-22';
ERROR 1105 (HY000): Data Truncated
mysql>  select * from ying99_asset.ic_asset_days where account3_id='48098' and begin_txn_day='2021-11-22' and year='2022' and po_code='*' and broker='0008';
ERROR 1292 (22007): Incorrect time value: '{0 0 0 0 0 0 49}'
mysql> select account3_id,broker,po_code,begin_txn_day,year,end_txn_day,create_time from ying99_asset.ic_asset_days where  account3_id='48098' and begin_txn_day='2021-11-22' and year='2022' and po_code='*' and broker='0008';
+-------------+--------+---------+---------------+------+-------------+---------------------+
| account3_id | broker | po_code | begin_txn_day | year | end_txn_day | create_time         |
+-------------+--------+---------+---------------+------+-------------+---------------------+
|       48098 | 0008   | *       | 2021-11-22    | 2022 | NULL        | 0000-00-00 00:00:00 |
+-------------+--------+---------+---------------+------+-------------+---------------------+
1 row in set (0.00 sec)

mysql> select account3_id,broker,po_code,begin_txn_day,year,end_txn_day,create_time,update_time from ying99_asset.ic_asset_days where  account3_id='48098' and begin_txn_day='2021-11-22' and year='2022'
ERROR 1292 (22007): Incorrect time value: '{0 0 0 0 0 0 49}'
1 个赞
11

为什么这条数据有问题，跟我之前的操作有关系，在用BR工具同步增量数据到下游TiDB时，漏了一个TSO的数据。详细原因可以见另外一个帖子。

1 个赞
12

此话题已在最后回复的 1 分钟后被自动关闭。不再允许新回复。