升版5.3.0之后 tidb log出现大量[ERROR] [terror.go:307] ["encountered error"] [error=EOF]

eddiechiang · 2021 年12 月 2 日 08:16

各位大大好秉持着研究精神，在TIDB每次出新版本时都抢先更新
自从上次更新5.2.2，TIDB log有出现问题后更关注log方面，昨天升到5.3.0之后，有发现tidb log频繁刷新以下讯息

[ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log
\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307
github.com/pingcap/tidb/server.(*Server).onConn
\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/server.go:519”]

频率约1~3秒一次

有将log调整为debug模式，错误讯息也是一样，tidb共有三台，将一台连线全部调走，没有连线进入，还是会持续刷log，去看源码似乎是某些keep alive或是health check机制，但这边都没有使用，想请问各位大大还有什么办法能更深入了解这次问题

非常感谢～

zhenjiaogao · 2021 年12 月 2 日 09:20

上面这个报错，是否影响到正常使用 TiDB 集群？

方便将这个没有链接的 tidb server 的 general log 打开，并 show processlist 看下链接情况，最后帮忙拿下 tidb server 的 tidb.log 这边看下 ~

eddiechiang · 2021 年12 月 3 日 02:59

使用上没有影响，只是log一直刷新，会影响查找问题，tidb.log档案约300Mb，不太好上传，这边先上传有开general log的前后几分钟，麻烦大大了

tidb.log (291.1 KB)

eddiechiang · 2021 年12 月 8 日 02:40

自己推一下有大大有相同状况吗

zhenjiaogao · 2021 年12 月 9 日 10:57

抱歉现在才回复，在 github 上看到有一个相似的问题，请参考下。对比下打开 debug 后，tidb 日志输出的内容和 github 中 log 信息是否一致：

https://github.com/pingcap/tidb/issues/28308

eddiechiang · 2021 年12 月 10 日 03:36

看起来类似但没有记录到以下这种详细连接ip
[2021/10/21 07:26:25.822 +00:00] [DEBUG] [conn.go:260] [“writeError failed”] [conn=5] [error=“write tcp 10.244.0.52:4000->10.244.0.1:51772: write: broken pipe”]

以下是我这边开启debug纪录的讯息
[2021/12/10 11:14:04.660 +08:00] [DEBUG] [ddl_worker.go:180] ["[ddl] wait to check DDL status again"] [worker=“worker 1, tp general”] [interval=1s]
[2021/12/10 11:14:04.660 +08:00] [DEBUG] [ddl_worker.go:180] ["[ddl] wait to check DDL status again"] [worker=“worker 2, tp add index”] [interval=1s]
[2021/12/10 11:14:04.660 +08:00] [DEBUG] [ddl.go:225] ["[ddl] check whether is the DDL owner"] [isOwner=false] [selfID=8dbec179-fea5-4b27-9885-0971409272be]
[2021/12/10 11:14:04.661 +08:00] [DEBUG] [ddl.go:225] ["[ddl] check whether is the DDL owner"] [isOwner=false] [selfID=8dbec179-fea5-4b27-9885-0971409272be]
[2021/12/10 11:14:05.205 +08:00] [DEBUG] [conn.go:609] [“wait handshake response fail due to connection has be closed by client-side”] [conn=111]
[2021/12/10 11:14:05.205 +08:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/server.go:519”]
[2021/12/10 11:14:05.246 +08:00] [DEBUG] [conn.go:609] [“wait handshake response fail due to connection has be closed by client-side”] [conn=113]
[2021/12/10 11:14:05.246 +08:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/server.go:519”]
[2021/12/10 11:14:05.659 +08:00] [DEBUG] [ddl_worker.go:180] ["[ddl] wait to check DDL status again"] [worker=“worker 1, tp general”] [interval=1s]
[2021/12/10 11:14:05.659 +08:00] [DEBUG] [ddl_worker.go:180] ["[ddl] wait to check DDL status again"] [worker=“worker 2, tp add index”] [interval=1s]
[2021/12/10 11:14:05.660 +08:00] [DEBUG] [ddl.go:225] ["[ddl] check whether is the DDL owner"] [isOwner=false] [selfID=8dbec179-fea5-4b27-9885-0971409272be]
[2021/12/10 11:14:05.660 +08:00] [DEBUG] [ddl.go:225] ["[ddl] check whether is the DDL owner"] [isOwner=false] [selfID=8dbec179-fea5-4b27-9885-0971409272be]

spc_monkey · 2021 年12 月 17 日 06:28

看日志内容：wait handshake response fail due to connection has be closed by client-side，咱们程序连接似乎有问题，建议根据一个连接来跟踪一下*比如连接是否是空连接，程序是否有检查机制

ichn-hu · 2021 年12 月 22 日 09:39

@eddiechiang 可以尝试用 wireshark 抓一下包，看看连接来源是啥

eddiechiang · 2021 年12 月 24 日 05:53

这边有抓封包，有发现问题点了，是内部人员的hc机制造成的，非常感谢协助

zhenjiaogao · 2021 年12 月 24 日 05:54

g114486803g · 2022 年5 月 6 日 01:43

我的刚刚部署完就报这些东西了，都还没使用

2022/05/06 01:38:14.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:38:24.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:38:34.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:38:44.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=“read tcp 10.244.1.109:4000->10.244.1.1:48172: read: connection reset by peer”] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:38:54.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=“read tcp 10.244.1.109:4000->10.244.1.1:48254: read: connection reset by peer”] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:38:56.299 +00:00] [INFO] [data_window.go:249] [“Error exists when getting the SQL Metric.”]
[2022/05/06 01:39:04.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:39:14.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=“read tcp 10.244.1.109:4000->10.244.1.1:48368: read: connection reset by peer”] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:39:24.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:39:34.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:39:44.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:39:54.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:39:56.304 +00:00] [INFO] [data_window.go:249] [“Error exists when getting the SQL Metric.”]
[2022/05/06 01:40:04.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:40:14.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:40:24.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=“read tcp 10.244.1.109:4000->10.244.1.1:48848: read: connection reset by peer”] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:40:34.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:40:44.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]
[2022/05/06 01:40:54.562 +00:00] [ERROR] [terror.go:307] [“encountered error”] [error=EOF] [stack=“github.com/pingcap/tidb/parser/terror.Log\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/parser/terror/terror.go:307\ github.com/pingcap/tidb/server.(*Server).onConn\ \t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/server/server.go:516”]

代码工地头号民工 · 2022 年10 月 20 日 02:25

请问这个hc机制是什么原因

system · 2022 年10 月 31 日 19:25

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