[ERROR] [write.go:179] ["data too long for column"] [colName=feedback] [rowIndex=1]

TUG微尘 · 2020 年8 月 20 日 08:34

为提高效率，提问时请提供以下信息，问题描述清晰可优先响应。

【TiDB 版本】： v3.0.5
【问题描述】：

tidb日志中出现报错

{"log":"[2020/08/20 16:14:19.918 +08:00] [ERROR] [write.go:179] [\"data too long for column\"] [colName=feedback] [rowIndex=1] [stack=\"github.com/pingcap/tidb/executor.resetErrDataTooLong\\
\\tgithub.com/pingcap/tidb@/executor/write.go:179\\
github.com/pingcap/tidb/executor.(*InsertValues).handleErr\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:232\\
github.com/pingcap/tidb/executor.(*InsertValues).evalRow\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:272\\
github.com/pingcap/tidb/executor.(*InsertValues).insertRows\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:198\\
github.com/pingcap/tidb/executor.(*InsertExec).Next\\
\\tgithub.com/pingcap/tidb@/executor/insert.go:237\\
github.com/pingcap/tidb/executor.Next\\
\\tgithub.com/pingcap/tidb@/executor/executor.go:191\\
github.com/pingcap/tidb/executor.(*ExecStmt).handleNoDelayExecutor\\
\\tgithub.com/pingcap/tidb@/executor/adapter.go:431\\
github.com/pingcap/tidb/executor.(*ExecStmt).Exec\\
\\tgithub.com/pingcap/tidb@/executor/adapter.go:295\\
github.com/pingcap/tidb/session.runStmt\\
\\tgithub.com/pingcap/tidb@/session/tidb.go:238\\
github.com/pingcap/tidb/session.(*session).executeStatement\\
\\tgithub.com/pingcap/tidb@/session/session.go:961\\
github.com/pingcap/tidb/session.(*session).execute\\
\\tgithub.com/pingcap/tidb@/session/session.go:1076\\
github.com/pingcap/tidb/session.(*session).Execute\\
\\tgithub.com/pingcap/tidb@/session/session.go:999\\
github.com/pingcap/tidb/statistics/handle.(*Handle).DumpFeedbackToKV\\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:404\\
github.com/pingcap/tidb/statistics/handle.(*Handle).DumpFeedbackForIndex\\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:1081\\
github.com/pingcap/tidb/statistics/handle.(*Handle).DumpStatsFeedbackToKV\\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:378\\
github.com/pingcap/tidb/domain.(*Domain).updateStatsWorker\\
\\tgithub.com/pingcap/tidb@/domain/domain.go:991\"]\
","stream":"stdout","time":"2020-08-20T08:14:19.919502716Z"}

MySQL [mysql]> desc stats_feedback;
+----------+------------+------+------+---------+-------+
| Field    | Type       | Null | Key  | Default | Extra |
+----------+------------+------+------+---------+-------+
| table_id | bigint(64) | NO   | MUL  | NULL    |       |
| is_index | tinyint(2) | NO   |      | NULL    |       |
| hist_id  | bigint(64) | NO   |      | NULL    |       |
| feedback | blob       | NO   |      | NULL    |       |
+----------+------------+------+------+---------+-------+
4 rows in set (0.00 sec)

这个报错会有什么影响，应该怎么处理

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

来了老弟 · 2020 年8 月 20 日 08:40

该 log 上下文是否有打印具体的 sql 呢，

TUG微尘 · 2020 年8 月 20 日 08:46

  1 {"log":"[2020/08/20 16:12:54.520 +08:00] [INFO] [server.go:416] [\"connection closed\"] [conn=61360]\
","stream":"stdout","time":"2020-08-20T08:12:54.520261363Z"}
  2 {"log":"[2020/08/20 16:13:20.879 +08:00] [INFO] [server.go:413] [\"new connection\"] [conn=61361] [remoteAddr=172.18.180.138:54236]\
","stream":"stdout","time":"2020-08-20T08:13:20.879177165Z"}
  3 {"log":"[2020/08/20 16:13:20.879 +08:00] [INFO] [server.go:416] [\"connection closed\"] [conn=61361]\
","stream":"stdout","time":"2020-08-20T08:13:20.879494064Z"}
  4 {"log":"[2020/08/20 16:13:55.147 +08:00] [INFO] [server.go:413] [\"new connection\"] [conn=61362] [remoteAddr=addr_1111]\
","stream":"stdout","time":"2020-08-20T08:13:55.147901656Z"}
  5 {"log":"[2020/08/20 16:13:55.148 +08:00] [INFO] [server.go:416] [\"connection closed\"] [conn=61362]\
","stream":"stdout","time":"2020-08-20T08:13:55.148708259Z"}
  6 {"log":"[2020/08/20 16:14:19.918 +08:00] [ERROR] [write.go:179] [\"data too long for column\"] [colName=feedback] [rowIndex=1] [stack=\"github.com/pingcap/tidb/executor.resetErrDataTooLong\\
\\tgithub    .com/pingcap/tidb@/executor/write.go:179\\
github.com/pingcap/tidb/executor.(*InsertValues).handleErr\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:232\\
github.com/pingcap/tidb/executor.(*I    nsertValues).evalRow\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:272\\
github.com/pingcap/tidb/executor.(*InsertValues).insertRows\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:1    98\\
github.com/pingcap/tidb/executor.(*InsertExec).Next\\
\\tgithub.com/pingcap/tidb@/executor/insert.go:237\\
github.com/pingcap/tidb/executor.Next\\
\\tgithub.com/pingcap/tidb@/executor/executor.go    :191\\
github.com/pingcap/tidb/executor.(*ExecStmt).handleNoDelayExecutor\\
\\tgithub.com/pingcap/tidb@/executor/adapter.go:431\\
github.com/pingcap/tidb/executor.(*ExecStmt).Exec\\
\\tgithub.com/ping    cap/tidb@/executor/adapter.go:295\\
github.com/pingcap/tidb/session.runStmt\\
\\tgithub.com/pingcap/tidb@/session/tidb.go:238\\
github.com/pingcap/tidb/session.(*session).executeStatement\\
\\tgithub.    com/pingcap/tidb@/session/session.go:961\\
github.com/pingcap/tidb/session.(*session).execute\\
\\tgithub.com/pingcap/tidb@/session/session.go:1076\\
github.com/pingcap/tidb/session.(*session).Execute    \\
\\tgithub.com/pingcap/tidb@/session/session.go:999\\
github.com/pingcap/tidb/statistics/handle.(*Handle).DumpFeedbackToKV\\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:404\\
github.com/    pingcap/tidb/statistics/handle.(*Handle).DumpFeedbackForIndex\\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:1081\\
github.com/pingcap/tidb/statistics/handle.(*Handle).DumpStatsFeedbackToKV    \\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:378\\
github.com/pingcap/tidb/domain.(*Domain).updateStatsWorker\\
\\tgithub.com/pingcap/tidb@/domain/domain.go:991\"]\
","stream":"stdout","    time":"2020-08-20T08:14:19.919502716Z"}
  7 {"log":"[2020/08/20 16:14:19.919 +08:00] [INFO] [tidb.go:169] [\"rollbackTxn for ddl/autocommit error.\"]\
","stream":"stdout","time":"2020-08-20T08:14:19.919556745Z"}
  8 {"log":"[2020/08/20 16:14:19.919 +08:00] [WARN] [session.go:964] [\"run statement error\"] [schemaVersion=318] [error=\"[types:1406]Data too long for column 'feedback' at row 1\"] [errorVerbose=\"[typ    es:1406]Data too long for column 'feedback' at row 1\\
github.com/pingcap/errors.AddStack\\
\\tgithub.com/pingcap/errors@v0.11.4/errors.go:174\\
github.com/pingcap/parser/terror.(*Error).GenWithStack\    \
\\tgithub.com/pingcap/parser@v0.0.0-20191018040038-555b97093a2a/terror/terror.go:231\\
github.com/pingcap/tidb/executor.resetErrDataTooLong\\
\\tgithub.com/pingcap/tidb@/executor/write.go:178\\
gith    ub.com/pingcap/tidb/executor.(*InsertValues).handleErr\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:232\\
github.com/pingcap/tidb/executor.(*InsertValues).evalRow\\
\\tgithub.com/pingcap/ti    db@/executor/insert_common.go:272\\
github.com/pingcap/tidb/executor.(*InsertValues).insertRows\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:198\\
github.com/pingcap/tidb/executor.(*InsertE    xec).Next\\
\\tgithub.com/pingcap/tidb@/executor/insert.go:237\\
github.com/pingcap/tidb/executor.Next\\
\\tgithub.com/pingcap/tidb@/executor/executor.go:191\\
github.com/pingcap/tidb/executor.(*ExecS    tmt).handleNoDelayExecutor\\
\\tgithub.com/pingcap/tidb@/executor/adapter.go:431\\
github.com/pingcap/tidb/executor.(*ExecStmt).Exec\\
\\tgithub.com/pingcap/tidb@/executor/adapter.go:295\\
github.com/    pingcap/tidb/session.runStmt\\
\\tgithub.com/pingcap/tidb@/session/tidb.go:238\\
github.com/pingcap/tidb/session.(*session).executeStatement\\
\\tgithub.com/pingcap/tidb@/session/session.go:961\\
gith    ub.com/pingcap/tidb/session.(*session).execute\\
\\tgithub.com/pingcap/tidb@/session/session.go:1076\\
github.com/pingcap/tidb/session.(*session).Execute\\
\\tgithub.com/pingcap/tidb@/session/session.    go:999\\
github.com/pingcap/tidb/statistics/handle.(*Handle).DumpFeedbackToKV\\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:404\\
github.com/pingcap/tidb/statistics/handle.(*Handle).DumpFe    edbackForIndex\\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:1081\\
github.com/pingcap/tidb/statistics/handle.(*Handle).DumpStatsFeedbackToKV\\
\\tgithub.com/pingcap/tidb@/statistics/handl    e/update.go:378\\
github.com/pingcap/tidb/domain.(*Domain).updateStatsWorker\\
\\tgithub.com/pingcap/tidb@/domain/domain.go:991\\
runtime.goexit\\
\\truntime/asm_amd64.s:1357\"] [session=\"{\\
  \\\"c    urrDBName\\\": \\\"\\\",\\
  \\\"id\\\": 0,\\
  \\\"status\\\": 2,\\
  \\\"strictMode\\\": true,\\
  \\\"user\\\": null\\
}\"]\
","stream":"stdout","time":"2020-08-20T08:14:19.919565256Z"}
  9 {"log":"[2020/08/20 16:14:21.116 +08:00] [INFO] [server.go:413] [\"new connection\"] [conn=61363] [remoteAddr=addr_2222]\
","stream":"stdout","time":"2020-08-20T08:14:21.116258683Z"}
 10 {"log":"[2020/08/20 16:14:21.116 +08:00] [INFO] [server.go:416] [\"connection closed\"] [conn=61363]\
","stream":"stdout","time":"2020-08-20T08:14:21.116412962Z"}
 11 {"log":"[2020/08/20 16:14:54.959 +08:00] [INFO] [server.go:413] [\"new connection\"] [conn=61364] [remoteAddr=addr_3333]\
","stream":"stdout","time":"2020-08-20T08:14:54.95977169Z"}
 12 {"log":"[2020/08/20 16:14:54.960 +08:00] [INFO] [server.go:416] [\"connection closed\"] [conn=61364]\
","stream":"stdout","time":"2020-08-20T08:14:54.960711832Z"}
 13 {"log":"[2020/08/20 16:15:20.341 +08:00] [INFO] [server.go:413] [\"new connection\"] [conn=61365] [remoteAddr=addr_4444]\
","stream":"stdout","time":"2020-08-20T08:15:20.341288074Z"}
 14 {"log":"[2020/08/20 16:15:20.341 +08:00] [INFO] [server.go:416] [\"connection closed\"] [conn=61365]\
","stream":"stdout","time":"2020-08-20T08:15:20.341421199Z"}
 15 {"log":"[2020/08/20 16:15:55.152 +08:00] [INFO] [server.go:413] [\"new connection\"] [conn=61366] [remoteAddr=addr_5555]\
","stream":"stdout","time":"2020-08-20T08:15:55.152498461Z"}
 16 {"log":"[2020/08/20 16:15:55.153 +08:00] [INFO] [server.go:416] [\"connection closed\"] [conn=61366]\
","stream":"stdout","time":"2020-08-20T08:15:55.153082241Z"}
 17 {"log":"[2020/08/20 16:16:20.352 +08:00] [INFO] [server.go:413] [\"new connection\"] [conn=61367] [remoteAddr=addr_6666]\
","stream":"stdout","time":"2020-08-20T08:16:20.352986111Z"}

TUG微尘 · 2020 年8 月 20 日 10:11

没有，只有这些日志

来了老弟 · 2020 年8 月 20 日 11:45

  6 {"log":"[2020/08/20 16:14:19.918 +08:00] [ERROR] [write.go:179] [\"data too long for column\"] [colName=feedback] [rowIndex=1] [stack=\"github.com/pingcap/tidb/executor.resetErrDataTooLong\\
\\tgithub    .com/pingcap/tidb@/executor/write.go:179\\
github.com/pingcap/tidb/executor.(*InsertValues).handleErr\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:232\\
github.com/pingcap/tidb/executor.(*I    nsertValues).evalRow\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:272\\
github.com/pingcap/tidb/executor.(*InsertValues).insertRows\\
\\tgithub.com/pingcap/tidb@/executor/insert_common.go:1    98\\
github.com/pingcap/tidb/executor.(*InsertExec).Next\\
\\tgithub.com/pingcap/tidb@/executor/insert.go:237\\
github.com/pingcap/tidb/executor.Next\\
\\tgithub.com/pingcap/tidb@/executor/executor.go    :191\\
github.com/pingcap/tidb/executor.(*ExecStmt).handleNoDelayExecutor\\
\\tgithub.com/pingcap/tidb@/executor/adapter.go:431\\
github.com/pingcap/tidb/executor.(*ExecStmt).Exec\\
\\tgithub.com/ping    cap/tidb@/executor/adapter.go:295\\
github.com/pingcap/tidb/session.runStmt\\
\\tgithub.com/pingcap/tidb@/session/tidb.go:238\\
github.com/pingcap/tidb/session.(*session).executeStatement\\
\\tgithub.    com/pingcap/tidb@/session/session.go:961\\
github.com/pingcap/tidb/session.(*session).execute\\
\\tgithub.com/pingcap/tidb@/session/session.go:1076\\
github.com/pingcap/tidb/session.(*session).Execute    \\
\\tgithub.com/pingcap/tidb@/session/session.go:999\\
github.com/pingcap/tidb/statistics/handle.(*Handle).DumpFeedbackToKV\\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:404\\
github.com/    pingcap/tidb/statistics/handle.(*Handle).DumpFeedbackForIndex\\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:1081\\
github.com/pingcap/tidb/statistics/handle.(*Handle).DumpStatsFeedbackToKV    \\
\\tgithub.com/pingcap/tidb@/statistics/handle/update.go:378\\
github.com/pingcap/tidb/domain.(*Domain).updateStatsWorker\\
\\tgithub.com/pingcap/tidb@/domain/domain.go:991\"]\
","stream":"stdout","    time":"2020-08-20T08:14:19.919502716Z"}
  7 {"log":"[2020/08/20 16:14:19.919 +08:00] [INFO] [tidb.go:169] [\"rollbackTxn for ddl/autocommit error.\"]\
","stream":"stdout","time":"2020-08-20T08:14:19.919556745Z"}
  8 {"log":"[2020/08/20 16:14:19.919 +08:00] [WARN] [session.go:964] [\"run statement error\"] [schemaVersion=318] [error=\"[types:1406]Data too long for column 'feedback' at row 1\"]

重点是这三行日志吧。这个 sql 是被回滚掉了，没有成功插入到 tidb 中，看是是否有数据源可以追溯？

TUG微尘 · 2020 年8 月 20 日 14:02

追溯不到数据源，出了这几条Error log其余的也没啥有用的信息

zhenjiaogao · 2020 年8 月 21 日 02:41

1、如果这个问题是稳定复现的，建议在 tidb server 开启 general log，看下是否可以拿到完整的 sql 语句~

2、如果可以拿到，请将 sql 语句，以及该 sql 涉及的表的表结构上传下，这里再看下，感谢配合~

来了老弟 · 2020 年8 月 21 日 09:22

data too long for column 日子再往下翻一fan，看看能找到 sql 不，可以 search Data too long for column 多找找。

如果找不到，上游也追溯不到就无法确认被 roll back 的事务是什么了（事务级别，可能不是一个 sql）

TUG微尘 · 2020 年8 月 21 日 09:53

反复找过了，追溯不到源数据，就一条ERROR log，平均10min一条；

另外我另起一个tidb节点，不接入业务，跑了两个多小时，没报这个ERROR (这个点日志级别给的debug)；

zhenjiaogao · 2020 年8 月 21 日 10:25

确认是每隔 10 分钟就会稳定出现的哈，如果是这样，可能是 TiDB 的 feedback-probability 功能，请确认下该参数的值。如果允许，请将该参数关闭，然后再观察下~~

https://docs.pingcap.com/zh/tidb/v3.0/tidb-configuration-file#feedback-probability

https://docs.pingcap.com/zh/tidb/stable/statistics#自动更新

TUG微尘 · 2020 年8 月 21 日 10:33

问题一：
关闭这个功能会有什么影响？

问题二：
什么版本开始这个功能是默认打开的，什么版本开始又是默认关闭的，（这个集群是从2.1.4升级到3.1.5）的

问题三：
如果这个功能默认就是打开的，报这个ERROR是否说明tidb这里有个bug ？

zhenjiaogao · 2020 年8 月 21 日 11:14

1、关闭这个功能会有什么影响？
在查询语句执行时，TiDB 会以 feedback-probability 的概率收集反馈信息，并将其用于更新直方图和 Count-Min Sketch。反之关闭后，相应的信息将不再收集。

上面建议关闭这个信息是怀疑 feedback 导致的报错，如果允许建议临时关闭看下是否关闭后，该问题不再出现。

2、什么版本开始这个功能是默认打开的，什么版本开始又是默认关闭的，（这个集群是从 2.1.4 升级到 3.0.5）的

确认下当前版本该参数的值，然后看下是开启还是关闭状态，另外，该参数在 TiDB 中默认开启。

3、如果这个功能默认就是打开的，报这个 ERROR 是否说明tidb这里有个 bug ？

恩恩，如果关闭后，该报错消失，我们内部再看下这个问题

以上感谢配合~~