search

pingcap / tidb

TiDB is an open-source, cloud-native, distributed, MySQL-Compatible database for elastic scale and real-time analytics. Try AI-powered Chat2Query free at : https://www.pingcap.com/tidb-serverless/
https://pingcap.com
Apache License 2.0
36.5k stars 5.74k forks source link

There are a lot of logs about "limit executor close takes a long time" #52771

Open crazycs520 opened 2 months ago

crazycs520 commented 2 months ago 
# rg "limit executor close takes a long time" tidb.log
12789:[2024/04/19 19:10:22.385 +08:00] [INFO] [executor.go:1424] ["limit executor close takes a long time"] [elapsed=2.107365ms]
12791:[2024/04/19 19:10:22.628 +08:00] [INFO] [executor.go:1424] ["limit executor close takes a long time"] [elapsed=1.822869ms]
12801:[2024/04/19 19:10:23.781 +08:00] [INFO] [executor.go:1424] ["limit executor close takes a long time"] [elapsed=4.897655ms]
...
13561:[2024/04/19 19:15:47.328 +08:00] [INFO] [executor.go:1424] ["limit executor close takes a long time"] [elapsed=1.374016ms]
...

# rg "limit executor close takes a long time" tidb.log | wc
    205    2665   25251

Look like the log is useless, can we remove it?

TiDB Version

nightly, 72e5460ee85fa06f193e1ad1c346a57247529ee6

crazycs520 commented 2 months ago

@tiancaiamao PTAL

time-and-fate commented 2 months ago

This log has been useful in some internal emulation workloads. Maybe we can increase the threshold instead of removing it directly.

Related: https://github.com/pingcap/tidb/issues/50377 https://github.com/pingcap/tidb/issues/40441#issuecomment-1376617440

crazycs520 commented 2 months ago

Because this log contains so little information, there is no conn id, txn_ts, nor can we locate which query caused this.

If it's for performance optimization, might it be more useful to grab a profile with proof?

If it is use to locate a slow query, it is more appropriate to obtain more information, such as conn id, txn_ts, etc.?