drainer报错Error 1292: Incorrect datetime value

qhd2004 · 2022 年4 月 19 日 03:23

【 TiDB 使用环境】生产
【 TiDB 版本】
v5.2.2
【遇到的问题】
drainer日志报错：
[2022/04/19 11:10:20.617 +08:00] [ERROR] [executor.go:111] [“Exec fail, will rollback”] [query=“REPLACE INTO dbname.table_name_20220418(bindDate,id,lastLoginDat e,oId,type,unionId,uCode,uId) VALUES(?,?,?,?,?,?,?,?)”] [args="[“2022-04-15 09:49:55”,180024,“0000-00-00 00:00:00”,“oJBprwy7foiiE10QN1dRHmx26b_A”,1,“oJBprwy7foiiE1
0QN1dRHmx26b_A”,"",1980188]"] [error=“Error 1292: Incorrect datetime value: ‘0000-00-00 00:00:00’ for column ‘lastLoginDate’ at row 1”]

上、下游都为tidb，sql_mode都为默认
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.08 sec)

【复现路径】做过哪些操作出现的问题
昨天是创建了table_name_20220418，然后
insert into table_name_20220418 select * from table_name;

CREATE TABLE table_name_20220418 (
id bigint(20) NOT NULL AUTO_INCREMENT,
uId bigint(20) NOT NULL,
uCode varchar(50) NOT NULL,
oId varchar(50) NOT NULL,
unionId varchar(50) NOT NULL,
type int(11) NOT NULL,
bindDate datetime NOT NULL,
lastLoginDate datetime NOT NULL,
PRIMARY KEY (id) /*T![clustered_index] CLUSTERED */,
UNIQUE KEY oId (oId),
KEY uId_IDX (uId),
KEY uCode_IDX (uCode),
KEY unionId_IDX (unionId)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin

【问题现象及影响】
下游同步数据报错，不再同步

【附件】

相关日志、配置文件、Grafana 监控（https://metricstool.pingcap.com/)
TiUP Cluster Display 信息
TiUP CLuster Edit config 信息
TiDB-Overview 监控
对应模块的 Grafana 监控（如有 BR、TiDB-binlog、TiCDC 等）
对应模块日志（包含问题前后 1 小时日志）

若提问为性能优化、故障排查类问题，请下载脚本运行。终端输出的打印结果，请务必全选并复制粘贴上传。

啦啦啦啦啦 · 2022 年4 月 19 日 03:33

看看上下游sql_mode一致吗

qhd2004 · 2022 年4 月 19 日 03:41

一致的

qhd2004 · 2022 年4 月 19 日 03:42

目前我是在drainer中过滤掉这张表，让同步继续的（没办法，业务催的急）

啦啦啦啦啦 · 2022 年4 月 19 日 03:49

NO_ZERO_DATE去掉

小王同学Plus · 2022 年4 月 19 日 03:49

你这个 sql_mode 之前修改过吧？如果是这个 sql_mode，上游这条数据也插入不了啊。。。下游也无法写入是正常的，先把下游 sql_mode 设置为空吧。

qhd2004 · 2022 年4 月 19 日 03:53

上、下游的sql_mode都没修改过，但在上游做过上面的操作，我也没想明白，这个insert在上游执行是没问题的，但到下游就不行了。

Christophe · 2022 年4 月 19 日 04:00

可以在asktug搜下这个标题，有些已解决了，不知道对你有用没

啦啦啦啦啦 · 2022 年4 月 19 日 04:03

上游客户端可能会设置一些参数导致sql_mode失效，如果一定要使用0000-00-00 00:00:00这种，上下游的sql_mode都去掉NO_ZERO_DATE吧

qhd2004 · 2022 年4 月 19 日 04:07

现在是下游的sql_mode置为空了，同步后，我会把这个表删除，然后再把sql_mode设置为与上游一致

qhd2004 · 2022 年4 月 19 日 04:08

在设置sql_mode为空后，在drainer的日志中会报另一个错

[2022/04/19 12:09:10.185 +08:00] [ERROR] [pump.go:152] [“pump receive binlog failed”] [id=10.xx.xx.xx:8250] [error=“rpc error: code = Internal desc = unexpected EOF”]

qhd2004 · 2022 年4 月 19 日 04:27

现在是不再应用binlog了，好像是卡住一样，如下是drainer的日志

如下是drainer的状态

小王同学Plus · 2022 年4 月 19 日 06:37

确认下你这个 pump 的 log 吧，看起来有点问题。

qhd2004 · 2022 年4 月 19 日 06:54

我们测试了一下，发现点有意思的东西，如下：
mysql [db@test]> select version();
±-------------------+
| version() |
±-------------------+
| 5.7.25-TiDB-v5.2.2 |
±-------------------+
1 row in set (0.01 sec)

下面是创建测试用表
mysql [db@test]> CREATE TABLE table_20220419 (
-> id bigint(20) NOT NULL AUTO_INCREMENT,
-> lastLoginDate datetime NOT NULL,
-> PRIMARY KEY (id) /*T![clustered_index] CLUSTERED */
-> ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin;
Query OK, 0 rows affected (0.34 sec)

下面是sql_mode
mysql [db@test]> 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.02 sec)

insert正常数据是没有问题的
mysql [db@test]> insert into table_20220419 values(1,‘2022-04-19 14:00:00’);
Query OK, 1 row affected (0.10 sec)

这里insert全0数据出现报错，也是正常的
mysql [db@test]> insert into table_20220419 values(1,‘0000-00-00 00:00:00’);
ERROR 1292 (22007): Incorrect datetime value: ‘0000-00-00 00:00:00’ for column ‘lastLoginDate’ at row 1

这里做update出现报错，也是正常的
mysql [db@test]> update table_20220419 set lastLoginDate=‘0000-00-00 00:00:00’;
ERROR 1292 (22007): Incorrect datetime value: ‘0000-00-00 00:00:00’

这update时加了where条件，却可以更新了，这里我有些不理解
mysql [db@test]> UPDATE table_20220419 SET lastLoginDate=‘0000-00-00 00:00:00’ WHERE id = 1;
Query OK, 1 row affected (0.07 sec)
Rows matched: 1 Changed: 1 Warnings: 0

这里where换成范围，也出现报错了，因为表中只有一行数据
mysql [db@test]> UPDATE table_20220419 SET lastLoginDate=‘0000-00-00 00:00:00’ WHERE id >= 1;
ERROR 1292 (22007): Incorrect datetime value: ‘0000-00-00 00:00:00’
mysql [db@test]> select * from table_20220419;
±—±--------------------+
| id | lastLoginDate |
±—±--------------------+
| 1 | 0000-00-00 00:00:00 |
±—±--------------------+
1 row in set (0.02 sec)

insert into select这种方式不报错，这里我也理解不了
mysql [db@test]> insert into table_20220419(lastLoginDate) select lastLoginDate from table_20220419;
Query OK, 1 row affected (0.06 sec)
Records: 1 Duplicates: 0 Warnings: 0

mysql [db@test]> select * from table_20220419;
±—±--------------------+
| id | lastLoginDate |
±—±--------------------+
| 1 | 0000-00-00 00:00:00 |
| 2 | 0000-00-00 00:00:00 |
±—±--------------------+
2 rows in set (0.01 sec)

表中有两行数据，这里where也换成范围，也出现报错了
mysql [db@test]> UPDATE table_20220419 SET lastLoginDate=‘0000-00-00 00:00:00’ WHERE id >= 1;
ERROR 1292 (22007): Incorrect datetime value: ‘0000-00-00 00:00:00’

所以，我想问一下，在等值更新时可以成功，insert into select这种方式也可以成功，那sql_mode在这两种操作时的行为是什么呢？还是说在低层逻辑上有什么不同吗？

小王同学Plus · 2022 年4 月 19 日 09:19

这个我试了下 6.0 是报错的，和 MySQL 行为一致。应该是已知 bug 修复了。

这个确实是 NO_ZERO_DATE 没生效，可以在 https://github.com/pingcap/tidb/issues/34099 跟进进度。

system · 2022 年10 月 31 日 19:18

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