TIKV 少量数据 SCHEDULER_WORKER_CPU 24核依然满载问题

Chen_Hank · 2025 年3 月 27 日 05:10

【TiDB 使用环境】生产环境
【TiDB 版本】v8.5.1
【操作系统】opensuse 15.6
【部署方式】
物理机部署

【集群数据量】
全部库数据<30G

【集群节点数】
48c96线程双路- 2tikv
48c96线程双路- 1tikv
16c64g虚拟机 n* tidb

【问题复现路径】做过哪些操作出现的问题
【遇到的问题：问题现象及影响】

近期该指标满载后会导致一些列问题sql无法执行

【资源配置】进入到 TiDB Dashboard -集群信息 (Cluster Info) -主机(Hosts) 截图此页面
【复制黏贴 ERROR 报错的日志】

[2025/03/25 18:46:43.851 +08:00] [ERROR] [time.rs:375] ["monotonic time jumped back, 12108062.157 -> 12108036.198"] [thread_id=214]
[2025/03/25 18:46:43.851 +08:00] [ERROR] [time.rs:375] ["monotonic time jumped back, 12108062.157 -> 12108036.198"] [thread_id=213]
[2025/03/26 09:52:31.224 +08:00] [ERROR] [errors.rs:487] ["txn aborts"] [err_code=KV:Storage:PessimisticLockNotFound] [err="Error(Txn(Error(Mvcc(Error(PessimisticLockNotFound { start_ts: TimeStamp(456904881508712475), key: [116, 128, 0, 0, 0, 0, 2, 219, 147, 95, 114, 1, 98, 102, 54, 100, 100, 53, 102, 49, 255, 55, 102, 100, 57, 99, 54, 48, 54, 255, 57, 48, 98, 53, 98, 51, 51, 100, 255, 57, 55, 48, 49, 55, 49, 53, 97, 255, 0, 0, 0, 0, 0, 0, 0, 0, 247], reason: LockMissingAmendFail })))))"] [thread_id=143]

【其他附件：截图/日志/监控】

Caused by: java.sql.SQLException: Error: KV error safe to retry Error(Txn(Error(Mvcc(Error(TxnLockNotFound { start_ts: TimeStamp(456864970831822858), commit_ts: TimeStamp(456864979993755651), key: [116, 128, 0, 0, 0, 0, 2, 246, 245, 95, 114, 1, 50, 55, 56, 54, 56, 51, 49, 99, 255, 45, 48, 56, 56, 50, 45, 49, 49, 255, 102, 48, 45, 56, 100, 48, 56, 45, 255, 55, 56, 97, 99, 52, 52, 57, 102, 255, 100, 101, 49, 101, 0, 0, 0, 0, 251] }))))) {tableID=194293, handle={2786831c-0882-11f0-8d08-78ac449fde1e}} [try again later] at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:965) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3933) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3869)

该节点该时间段监控：

Chen_Hank · 2025 年3 月 27 日 05:58

limit_valid_duration
max_ts_drift_allowance 这俩参数我查个底掉也没有找到相关文档啊

tidb菜鸟一只 · 2025 年3 月 28 日 01:00

系统有做时钟同步吗？看下各个节点的时间差异

buddyyuan · 2025 年3 月 28 日 01:43

这个上面的日志，应该没多大关系。

github.com/tikv/tikv

GC worker still uses ConcurrencyManager::new which leads to annoying error logs

已打开 05:16AM - 13 Feb 25 UTC

已关闭 07:57AM - 19 Feb 25 UTC

zyguan

type/bug sig/transaction severity/moderate report/customer affects-8.5

## Bug Report ### What version of TiKV are you using? v8.5.1 ### What opera…ting system and CPU are you using? unreleated ### Steps to reproduce run tikv-server ### What did you expect? No annoying error message ### What did happened? TiKV prints a lot of following logs because GC worker still uses ConcurrencyManager::new ``` [2025/02/12 14:15:22.320 +08:00] [ERROR] [lib.rs:133 ["improper setting: limit_valid_duration >= max_ts_drift_allowance; consider increasing max-ts-drift-allowance or decreasing max-ts-sync-interval"] [max_ts_drift_allowance=0ns] [limit_valid_duration=45s] [thread_id=32] [2025/02/12 14:15:22.321 +08:00] [ERROR] [lib.rs:133 ["improper setting: limit_valid_duration >= max_ts_drift_allowance; consider increasing max-ts-drift-allowance or decreasing max-ts-sync-interval"] [max_ts_drift_allowance=0ns] [limit_valid_duration=45s] [thread_id=32] ``` The backtrace ``` backtrace=" 0: tikv_util::set_panic_hook::{{closure}} at /home/ywxk/src/tikv_master/components/tikv_util/src/lib.rs:480:18 1: <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/alloc/src/boxed.rs:2029:9 2: std::panicking::rust_panic_with_hook at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:783:13 3: std::panicking::begin_panic_handler::{{closure}} at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:649:13 4: std::sys_common::backtrace::__rust_end_short_backtrace at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys_common/backtrace.rs:171:18 5: rust_begin_unwind at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:645:5 6: core::panicking::panic_fmt at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/panicking.rs:72:14 7: concurrency_manager::ConcurrencyManager::new_with_config at /home/ywxk/src/tikv_master/components/concurrency_manager/src/lib.rs:136:13 8: concurrency_manager::ConcurrencyManager::new at /home/ywxk/src/tikv_master/components/concurrency_manager/src/lib.rs:109:9 9: tikv::server::gc_worker::gc_worker::GcRunnerCore<E>::new_txn at /home/ywxk/src/tikv_master/src/server/gc_worker/gc_worker.rs:371:35 10: tikv::server::gc_worker::gc_worker::GcRunnerCore<E>::gc_keys at /home/ywxk/src/tikv_master/src/server/gc_worker/gc_worker.rs:466:27 11: tikv::server::gc_worker::gc_worker::GcRunnerCore<E>::gc at /home/ywxk/src/tikv_master/src/server/gc_worker/gc_worker.rs:417:13 12: tikv::server::gc_worker::gc_worker::GcRunnerCore<E>::run at /home/ywxk/src/tikv_master/src/server/gc_worker/gc_worker.rs:973:27 13: <tikv::server::gc_worker::gc_worker::GcRunner<E> as tikv_util::worker::pool::Runnable>::run::{{closure}} at /home/ywxk/src/tikv_master/src/server/gc_worker/gc_worker.rs:1132:13 14: yatp::task::future::RawTask<F>::poll at /home/ywxk/.cargo/git/checkouts/yatp-e704b73c3ee279b6/793be4d/src/task/future.rs:59:9 15: yatp::task::future::TaskCell::poll at /home/ywxk/.cargo/git/checkouts/yatp-e704b73c3ee279b6/793be4d/src/task/future.rs:103:9 16: <yatp::task::future::Runner as yatp::pool::runner::Runner>::handle at /home/ywxk/.cargo/git/checkouts/yatp-e704b73c3ee279b6/793be4d/src/task/future.rs:387:20 17: <tikv_util::yatp_pool::YatpPoolRunner<T> as yatp::pool::runner::Runner>::handle at /home/ywxk/src/tikv_master/components/tikv_util/src/yatp_pool/mod.rs:199:24 18: yatp::pool::worker::WorkerThread<T,R>::run at /home/ywxk/.cargo/git/checkouts/yatp-e704b73c3ee279b6/793be4d/src/pool/worker.rs:48:13 19: yatp::pool::builder::LazyBuilder<T>::build::{{closure}} at /home/ywxk/.cargo/git/checkouts/yatp-e704b73c3ee279b6/793be4d/src/pool/builder.rs:114:25 20: std::sys_common::backtrace::__rust_begin_short_backtrace at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys_common/backtrace.rs:155:18 21: std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}} at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/thread/mod.rs:529:17 22: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/panic/unwind_safe.rs:272:9 23: std::panicking::try::do_call at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:552:40 24: __rust_try 25: std::panicking::try at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:516:19 26: std::panic::catch_unwind at /home/ywxk/.rustup/toolchains/nightly-2023-12-28-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panic.rs:142:14 ``` When `compaction filter is disabled` by setting ``` [gc] enable-compaction-filter = false ``` it is likely to happen.

感觉问题可能还是出在回表太高，消耗资源太大

小龙虾爱大龙虾 · 2025 年3 月 28 日 02:51

先解决时间回调问题吧，这玩意可能导致监控数据异常？

Chen_Hank · 2025 年3 月 28 日 02:56

有的，使用的是同一时钟服务器

Chen_Hank · 2025 年3 月 28 日 02:59

调整一个节点的numa “0,1”->"0"后异常状态大幅降低

当前有存在1000%的凸起，还需要继续排查。

Chen_Hank · 2025 年3 月 28 日 02:59

调整numa后正常了许多，我下边有新的监控图

Chen_Hank · 2025 年3 月 28 日 03:00

有好的消息

Chen_Hank · 2025 年3 月 31 日 02:34

一个涉及几十行的delete依然会导致schedulercpu暴增到2400%，当前又修改了tikv绑定到/dev/sdb所在的numa节点。继续观察凸起。

Tidb_kk · 2025 年3 月 31 日 02:41

跟日志关联不大，看一看sql消耗

Chen_Hank · 2025 年4 月 1 日 03:15

找到问题了：
该值设置错误，不是我配置的就没注意，检查了一遍参数关注到这里。
storage.block-cache.capacity
需要设置尽量符合主机内存配置。我单NUMA 190G暂时设置了30G。
当前监控正常，降到了其他环境的scheduler cpu范围

总结：

storage.block-cache.capacity 内存给足（主要）
tikv 绑定到NUMA节点（效果明显）
tikv 绑定到 SSDRAID卡NUMA节点（效果不明显）

system · 2025 年4 月 8 日 03:16

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

TIKV 少量数据 SCHEDULER_WORKER_CPU 24核 依然满载问题

TIKV 少量数据 SCHEDULER_WORKER_CPU 24核依然满载问题