tidb 4.0.12 升级到 7.5.2 tidb日志一直打印"read packet timeout, close this connection",且交互式连接也会被自动退出登录

【 TiDB 使用环境】测试
【 TiDB 版本】7.5.2
【复现路径】tidb 4.0.12 升级到 7.5.2
【遇到的问题:问题现象及影响】

【现象一】: 交互式登录被自动退出

  1. 空闲连接被自动退出

  2. 一直在执行sql,交互式登录依然被退出

【现象二】:tidb日志一直打印“ [INFO] [conn.go:1048] [“read packet timeout, close this connection”] [conn=3731180098] [session_alias=] [idle=10m0.000528797s] [waitTimeout=600] [error=“read tcp 127.0.0.1:9486->127.0.0.1:64494: i/o timeout”]”

[2024/08/26 08:31:47.698 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179964] [session_alias=] [idle=10m0.00109763s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:52520: i/o timeout"]
[2024/08/26 08:31:47.800 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179966] [session_alias=] [idle=10m0.001012739s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:52572: i/o timeout"]
[2024/08/26 08:31:47.826 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179968] [session_alias=] [idle=10m0.000946335s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:52624: i/o timeout"]
[2024/08/26 08:31:47.970 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179970] [session_alias=] [idle=10m0.000946191s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:52712: i/o timeout"]
[2024/08/26 08:31:47.979 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179972] [session_alias=] [idle=10m0.000460053s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:52716: i/o timeout"]
[2024/08/26 08:31:48.036 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179974] [session_alias=] [idle=10m0.000794544s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:52886: i/o timeout"]
[2024/08/26 08:31:48.052 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179976] [session_alias=] [idle=10m0.000600776s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:52892: i/o timeout"]
[2024/08/26 08:31:48.545 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179978] [session_alias=] [idle=10m0.000457608s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:52946: i/o timeout"]
[2024/08/26 08:31:50.291 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179980] [session_alias=] [idle=10m0.000926532s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:53100: i/o timeout"]
[2024/08/26 08:31:50.422 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179982] [session_alias=] [idle=10m0.000773337s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:53126: i/o timeout"]
[2024/08/26 08:31:50.477 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179984] [session_alias=] [idle=10m0.000945755s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:53132: i/o timeout"]
[2024/08/26 08:31:50.495 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731179986] [session_alias=] [idle=10m0.000783442s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:53136: i/o timeout"]
[2024/08/26 08:32:06.438 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180002] [session_alias=] [idle=10m0.000466568s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:55260: i/o timeout"]
[2024/08/26 08:32:18.244 +00:00] [INFO] [domain.go:2892] ["refreshServerIDTTL succeed"] [serverID=1779] ["lease id"=1699917e3b1554e2]
[2024/08/26 08:32:46.097 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180042] [session_alias=] [idle=10m0.000153058s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:59770: i/o timeout"]
[2024/08/26 08:32:48.586 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180046] [session_alias=] [idle=10m0.001111667s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:60030: i/o timeout"]
[2024/08/26 08:33:06.407 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180064] [session_alias=] [idle=10m0.000641805s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:62312: i/o timeout"]
[2024/08/26 08:33:26.404 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180098] [session_alias=] [idle=10m0.000528797s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:64494: i/o timeout"]
[2024/08/26 08:35:18.845 +00:00] [INFO] [gc_worker.go:421] ["starts the whole job"] [category="gc worker"] [uuid=645f91a3550000c] [safePoint=452041669020745728] [concurrency=1]
[2024/08/26 08:35:18.850 +00:00] [INFO] [gc_worker.go:1178] ["start resolve locks"] [category="gc worker"] [uuid=645f91a3550000c] [safePoint=452041669020745728] [concurrency=1]
[2024/08/26 08:35:18.851 +00:00] [INFO] [range_task.go:137] ["range task started"] [name=resolve-locks-runner] [startKey=] [endKey=] [concurrency=1]
[2024/08/26 08:35:19.720 +00:00] [INFO] [range_task.go:246] ["range task finished"] [name=resolve-locks-runner] [startKey=] [endKey=] ["cost time"=869.441123ms] ["completed regions"=1288]
[2024/08/26 08:35:19.720 +00:00] [INFO] [gc_worker.go:1203] ["finish resolve locks"] [category="gc worker"] [uuid=645f91a3550000c] [safePoint=452041669020745728] [regions=1288]
[2024/08/26 08:35:25.425 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180202] [session_alias=] [idle=10m0.000350701s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:53680: i/o timeout"]
[2024/08/26 08:36:18.794 +00:00] [INFO] [gc_worker.go:379] ["there's already a gc job running, skipped"] [category="gc worker"] ["leaderTick on"=645f91a3550000c]
[2024/08/26 08:36:59.732 +00:00] [INFO] [gc_worker.go:831] ["start delete ranges"] [category="gc worker"] [uuid=645f91a3550000c] [ranges=0]
[2024/08/26 08:36:59.732 +00:00] [INFO] [gc_worker.go:884] ["finish delete ranges"] [category="gc worker"] [uuid=645f91a3550000c] ["num of ranges"=0] ["cost time"=624ns]
[2024/08/26 08:36:59.734 +00:00] [INFO] [gc_worker.go:907] ["start redo-delete ranges"] [category="gc worker"] [uuid=645f91a3550000c] ["num of ranges"=0]
[2024/08/26 08:36:59.734 +00:00] [INFO] [gc_worker.go:936] ["finish redo-delete ranges"] [category="gc worker"] [uuid=645f91a3550000c] ["num of ranges"=0] ["cost time"=9.205µs]
[2024/08/26 08:36:59.739 +00:00] [INFO] [gc_worker.go:1574] ["sent safe point to PD"] [category="gc worker"] [uuid=645f91a3550000c] ["safe point"=452041669020745728]
[2024/08/26 08:37:05.893 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180308] [session_alias=] [idle=10m0.00012586s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:41210: i/o timeout"]
[2024/08/26 08:37:18.243 +00:00] [INFO] [domain.go:2892] ["refreshServerIDTTL succeed"] [serverID=1779] ["lease id"=1699917e3b1554e2]
[2024/08/26 08:38:58.534 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180428] [session_alias=] [idle=10m0.000551066s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:55522: i/o timeout"]
[2024/08/26 08:40:40.419 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180528] [session_alias=] [idle=10m0.000384399s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:42814: i/o timeout"]
[2024/08/26 08:40:44.980 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180532] [session_alias=] [idle=10m0.00029398s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:43568: i/o timeout"]
[2024/08/26 08:40:45.012 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180534] [session_alias=] [idle=10m0.00070168s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:43574: i/o timeout"]
[2024/08/26 08:41:46.105 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180610] [session_alias=] [idle=10m0.000284272s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50860: i/o timeout"]
[2024/08/26 08:41:46.106 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180602] [session_alias=] [idle=10m0.000340839s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50848: i/o timeout"]
[2024/08/26 08:41:46.106 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180604] [session_alias=] [idle=10m0.000329486s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50854: i/o timeout"]
[2024/08/26 08:41:46.105 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180606] [session_alias=] [idle=10m0.000141561s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50856: i/o timeout"]
[2024/08/26 08:41:46.106 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180600] [session_alias=] [idle=10m0.000190395s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50842: i/o timeout"]
[2024/08/26 08:41:46.106 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180608] [session_alias=] [idle=10m0.00025125s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50858: i/o timeout"]
[2024/08/26 08:41:46.412 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180612] [session_alias=] [idle=10m0.000430258s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50896: i/o timeout"]
[2024/08/26 08:41:46.418 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180614] [session_alias=] [idle=10m0.000611657s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50900: i/o timeout"]
[2024/08/26 08:41:46.419 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180616] [session_alias=] [idle=10m0.000037966s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50904: i/o timeout"]
[2024/08/26 08:41:46.426 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180618] [session_alias=] [idle=10m0.000337752s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50908: i/o timeout"]
[2024/08/26 08:41:46.452 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180620] [session_alias=] [idle=10m0.001122734s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50918: i/o timeout"]
[2024/08/26 08:41:46.791 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180622] [session_alias=] [idle=10m0.000722537s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:50954: i/o timeout"]
[2024/08/26 08:41:47.695 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180624] [session_alias=] [idle=10m0.000903709s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51086: i/o timeout"]
[2024/08/26 08:41:47.733 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180626] [session_alias=] [idle=10m0.00041575s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51136: i/o timeout"]
[2024/08/26 08:41:47.838 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180628] [session_alias=] [idle=10m0.000652592s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51260: i/o timeout"]
[2024/08/26 08:41:47.857 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180630] [session_alias=] [idle=10m0.000549646s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51264: i/o timeout"]
[2024/08/26 08:41:47.977 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180632] [session_alias=] [idle=10m0.001694321s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51298: i/o timeout"]
[2024/08/26 08:41:48.013 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180634] [session_alias=] [idle=10m0.001019583s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51380: i/o timeout"]
[2024/08/26 08:41:48.070 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180636] [session_alias=] [idle=10m0.000743718s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51540: i/o timeout"]
[2024/08/26 08:41:48.088 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180638] [session_alias=] [idle=10m0.000169156s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51546: i/o timeout"]
[2024/08/26 08:41:48.551 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180640] [session_alias=] [idle=10m0.000711821s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51588: i/o timeout"]
[2024/08/26 08:41:50.296 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180642] [session_alias=] [idle=10m0.000826603s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51782: i/o timeout"]
[2024/08/26 08:41:50.428 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180644] [session_alias=] [idle=10m0.000722542s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51794: i/o timeout"]
[2024/08/26 08:41:50.482 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180646] [session_alias=] [idle=10m0.000156388s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51798: i/o timeout"]
[2024/08/26 08:41:50.501 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180648] [session_alias=] [idle=10m0.000632129s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:51802: i/o timeout"]
[2024/08/26 08:42:06.443 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180668] [session_alias=] [idle=10m0.000094471s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:53346: i/o timeout"]
[2024/08/26 08:42:18.243 +00:00] [INFO] [domain.go:2892] ["refreshServerIDTTL succeed"] [serverID=1779] ["lease id"=1699917e3b1554e2]
[2024/08/26 08:42:46.103 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180716] [session_alias=] [idle=10m0.00150102s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:58614: i/o timeout"]
[2024/08/26 08:42:48.593 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180718] [session_alias=] [idle=10m0.002201211s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:59088: i/o timeout"]
[2024/08/26 08:43:06.414 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180728] [session_alias=] [idle=10m0.001055426s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:61516: i/o timeout"]
[2024/08/26 08:43:26.410 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180758] [session_alias=] [idle=10m0.000974213s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:63908: i/o timeout"]
[2024/08/26 08:45:18.806 +00:00] [INFO] [gc_worker.go:421] ["starts the whole job"] [category="gc worker"] [uuid=645f91a3550000c] [safePoint=452041826307145728] [concurrency=1]
[2024/08/26 08:45:18.808 +00:00] [INFO] [gc_worker.go:1178] ["start resolve locks"] [category="gc worker"] [uuid=645f91a3550000c] [safePoint=452041826307145728] [concurrency=1]
[2024/08/26 08:45:18.808 +00:00] [INFO] [range_task.go:137] ["range task started"] [name=resolve-locks-runner] [startKey=] [endKey=] [concurrency=1]
[2024/08/26 08:45:19.323 +00:00] [INFO] [range_task.go:246] ["range task finished"] [name=resolve-locks-runner] [startKey=] [endKey=] ["cost time"=514.923935ms] ["completed regions"=1288]
[2024/08/26 08:45:19.323 +00:00] [INFO] [gc_worker.go:1203] ["finish resolve locks"] [category="gc worker"] [uuid=645f91a3550000c] [safePoint=452041826307145728] [regions=1288]
[2024/08/26 08:45:25.474 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180866] [session_alias=] [idle=10m0.000497166s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:53380: i/o timeout"]
[2024/08/26 08:46:18.756 +00:00] [INFO] [gc_worker.go:379] ["there's already a gc job running, skipped"] [category="gc worker"] ["leaderTick on"=645f91a3550000c]
[2024/08/26 08:46:59.339 +00:00] [INFO] [gc_worker.go:831] ["start delete ranges"] [category="gc worker"] [uuid=645f91a3550000c] [ranges=0]
[2024/08/26 08:46:59.339 +00:00] [INFO] [gc_worker.go:884] ["finish delete ranges"] [category="gc worker"] [uuid=645f91a3550000c] ["num of ranges"=0] ["cost time"=4.929µs]
[2024/08/26 08:46:59.345 +00:00] [INFO] [gc_worker.go:907] ["start redo-delete ranges"] [category="gc worker"] [uuid=645f91a3550000c] ["num of ranges"=0]
[2024/08/26 08:46:59.345 +00:00] [INFO] [gc_worker.go:936] ["finish redo-delete ranges"] [category="gc worker"] [uuid=645f91a3550000c] ["num of ranges"=0] ["cost time"=475ns]
[2024/08/26 08:46:59.365 +00:00] [INFO] [gc_worker.go:1574] ["sent safe point to PD"] [category="gc worker"] [uuid=645f91a3550000c] ["safe point"=452041826307145728]
[2024/08/26 08:47:05.898 +00:00] [INFO] [conn.go:1048] ["read packet timeout, close this connection"] [conn=3731180974] [session_alias=] [idle=10m0.000529782s] [waitTimeout=600] [error="read tcp 127.0.0.1:9486->127.0.0.1:65174: i/o timeout"]
[2024/08/26 08:47:18.244 +00:00] [INFO] [domain.go:2892] ["refreshServerIDTTL succeed"] [serverID=1779] ["lease id"=1699917e3b1554e2]

【疑惑点】

  1. 为什么 交互式登录 就算 一直在执行sql 依然被退出登录
  2. tidb 日志为何一直打印"read packet timeout, close this connection"
  3. 这个是否会对tidb服务造成影响

在 client 端执行 show variables like ‘%timeout%’; 看一下参数配置情况,目前默认参数没有 10min 限制,需要再确认一下呢

image

这些变量和升级之前一样吗?改长一下interactive_timeout和wait_timeout看看呢

@TiDBer_h63MwG4e 可以排查一下 TiDB 上层 proxy 这边的连接到 TiDB 的配置方法,比如长连接没有配置探活机制,导致连接超时。