TiKV Restart

translator_bot · June 24, 2024, 5:33am

Note:
This topic has been translated from a Chinese forum by GPT and might contain errors.

Original topic: tikv重启

[TiDB Usage Environment] Production Environment / Test / Poc Production Environment
[TiDB Version]
[Reproduction Path] What operations were performed to cause the issue
[Encountered Issue: Problem Phenomenon and Impact]
tikv restart

[2024/06/21 21:55:46.474 +03:00] [WARN] [endpoint.rs:606] [error-response] [err=“Key is locked (will clean up) primary_lock: 7480000000000000DD5F69800000000000000203800000000002053603800000000E265CE6 lock_version: 450624525816037503 key: 7480000000000000DD5F698000000000000003038000000015281FFC03800000000002053603800000000000000003800000000000000003800000000000000003800000000E265CE6 lock_ttl: 3000 txn_size: 1 use_async_commit: true min_commit_ts: 450624525816037509”]
[2024/06/21 21:55:53.833 +03:00] [WARN] [endpoint.rs:606] [error-response] [err=“Key is locked (will clean up) primary_lock: 7480000000000000DD5F69800000000000000203800000000002053603800000000E260410 lock_version: 450624527742795973 key: 7480000000000000DD5F69800000000000000303800000001528203A03800000000002053603800000000000000003800000000000000003800000000000000003800000000E260410 lock_ttl: 3000 txn_size: 1 use_async_commit: true min_commit_ts: 450624527742795974”]
[2024/06/21 21:55:56.222 +03:00] [WARN] [endpoint.rs:606] [error-response] [err=“Key is locked (will clean up) primary_lock: 7480000000000000DD5F69800000000000000203800000000002053603800000000E260414 lock_version: 450624528371941463 key: 7480000000000000DD5F69800000000000000303800000001527F1F503800000000002053603800000000000000003800000000000000003800000000000000003800000000E260414 lock_ttl: 3000 txn_size: 1 use_async_commit: true min_commit_ts: 450624528371941464”]
[2024/06/21 21:55:58.324 +03:00] [WARN] [endpoint.rs:606] [error-response] [err=“Key is locked (will clean up) primary_lock: 7480000000000000DD5F69800000000000000203800000000002053603800000000E260419 lock_version: 450624528922443934 key: 7480000000000000DD5F698000000000000003038000000015281FFB03800000000002053603800000000000000003800000000000000003800000000000000003800000000E260419 lock_ttl: 3000 txn_size: 1 use_async_commit: true min_commit_ts: 450624528922443935”]
[2024/06/21 21:55:59.526 +03:00] [WARN] [endpoint.rs:606] [error-response] [err=“Key is locked (will clean up) primary_lock: 7480000000000000DD5F69800000000000000203800000000002053603800000000E26A8A1 lock_version: 450624529237016691 key: 7480000000000000DD5F69800000000000000303800000000A7A8C6A03800000000002053603800000000000000003800000000000000003800000000000000003800000000E26A8A1 lock_ttl: 3000 txn_size: 1 use_async_commit: true min_commit_ts: 450624529237016692”]
[2024/06/21 21:56:01.372 +03:00] [WARN] [endpoint.rs:606] [error-response] [err=“Key is locked (will clean up) primary_lock: 7480000000000000DD5F69800000000000000203800000000002053603800000000E26041C lock_version: 450624529721983078 key: 7480000000000000DD5F698000000000000003038000000015281EDA03800000000002053603800000000000000003800000000000000003800000000000000003800000000E26041C lock_ttl: 3000 txn_size: 1 use_async_commit: true min_commit_ts: 450624529721983079”]
[2024/06/21 21:56:02.768 +03:00] [WARN] [endpoint.rs:606] [error-response] [err=“Key is locked (will clean up) primary_lock: 7480000000000000DD5F69800000000000000203800000000002053603800000000E26A8A6 lock_version: 450624530088984628 key: 7480000000000000DD5F69800000000000000303800000001528155203800000000002053603800000000000000003800000000000000003800000000000000003800000000E26A8A6 lock_ttl: 3000 txn_size: 1 use_async_commit: true min_commit_ts: 450624530088984629”]

Error logs show a large number of errors, then the tikv node restarts,
Monitoring shows a large number of not leader errors

Then tikv restarts
[2024/06/21 21:56:12.399 +03:00] [INFO] [] [“New connected subchannel at 0x7efa158c3350 for subchannel 0x7efce064f540”]
[2024/06/21 21:56:12.414 +03:00] [FATAL] [lib.rs:465] [“index out of bounds: the len is 6 but the index is 6”] [backtrace=" 0: tikv_util::set_panic_hook::{{closure}}\n at /home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tikv/components/tikv_util/src/lib.rs:464:18\n 1: std::panicking::rust_panic_with_hook\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panicking.rs:626:17\n 2: std::panicking::begin_panic_handler::{{closure}}\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panicking.rs:519:13\n 3: std::sys_common::backtrace::__rust_end_short_backtrace\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/sys_common/backtrace.rs:141:18\n 4: rust_begin_unwind\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panicking.rs:515:5\n 5: core::panicking::panic_fmt\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/core/src/panicking.rs:92:14\n 6: core::panicking::panic_bounds_check\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/core/src/panicking.rs:69:5\n 7: <usize as core::slice::index::SliceIndex<[T]>>::index_mut\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/core/src/slice/index.rs:190:14\n core::slice::index::<impl core::ops::index::IndexMut for [T]>::index_mut\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/core/src/slice/index.rs:26:9\n <alloc::vec::Vec<T,A> as core::ops::index::IndexMut>::index_mut\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/alloc/src/vec/mod.rs:2445:9\n tokio_timer::Wheel::insert\n at /rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/wheel/mod.rs:114:9\n tokio_timer::Timer<T,N>::add_entry\n at /rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/timer/mod.rs:324:15\n 8: tokio_timer::Timer<T,N>::process_queue\n at /rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/timer/mod.rs:301:21\n 9: <tokio_timer::Timer<T,N> as tokio_executor::Park>::park\n at /rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/timer/mod.rs:361:9\n tokio_timer::Timer<T,N>::turn\n at /rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/timer/mod.rs:256:21\n 10: tikv_util::start_global_timer::{{closure}}\n at /home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tikv/components/tikv_util/src/timer.rs:98:17\n 11: std::sys_common::backtrace::__rust_begin_short_backtrace\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/sys_common/backtrace.rs:125:18\n 12: std::Builder::spawn_unchecked::{{closure}}::{{closure}}\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/thread/mod.rs:476:17\n 13: <std::panic::AssertUnwindSafe as core::ops::function::FnOnce<()>>::call_once\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panic.rs:347:9\n 14: std::panicking::try::do_call\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panicking.rs:401:40\n std::panicking::try\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panicking.rs:365:19\n std::panic::catch_unwind\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panic.rs:434:14\n std::Builder::spawn_unchecked::{{closure}}\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/thread/mod.rs:475:30\n core::ops::function::FnOnce::call_once{{vtable.shim}}\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/core/src/ops/function.rs:227:5\n 15: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce>::call_once\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/alloc/src/boxed.rs:1572:9\n <alloc::boxed::Box<F,A> as core::ops::function::FnOnce>::call_once\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/alloc/src/boxed.rs:1572:9\n std::sys::unix::thread_start\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/sys/unix/thread.rs:91:17\n 16: start_thread\n 17: __clone\n"] [location=/rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/wheel/mod.rs:114] [thread_name=timer]

[Resource Configuration] Go to TiDB Dashboard - Cluster Info - Hosts and take a screenshot of this page
[Attachments: Screenshots/Logs/Monitoring]

translator_bot · June 24, 2024, 5:33am

| username: zhaokede | Original post link

Did you perform this operation while there were still transactions occurring?

translator_bot · June 24, 2024, 5:33am

| username: TiDBer_P49NMjIm | Original post link

Everything is normal business, there have been no anomalies.

translator_bot · June 24, 2024, 5:33am

| username: TiDBer_P49NMjIm | Original post link

Looking at online posts, this seems to be a bug. How should we handle this bug?

translator_bot · July 19, 2024, 8:22am

| username: Kongdom | Original post link

Based on similar previous issues, it was due to a bug triggered by not restarting for a long time.

TiDB 的问答社区 – 2 Aug 23

5.0.1 集群 3台tikv 同一时间重启（不是oom）

🪐 TiDB 技术问题部署&运维管理

【 TiDB 使用环境】生产环境【 TiDB 版本】5.0.1 【复现路径】未复现【遇到的问题：问题现象及影响】集群共8台tikv，3台tikv 重启导致集群不可用。根据帖子排查，所有过程都正常专栏 - TiKV主要内存结构和OOM排查总结 | TiDB 社区报错日志： [2023/07/29 07:10:02.331 +08:00] [FATAL] [lib.rs:465] ["index out of bounds: the len is 6 but...

阅读时间: 2 mins 🕑 赞: 1 ❤

translator_bot · July 19, 2024, 8:22am

| username: TiDBer_P49NMjIm | Original post link

Indeed it is

github.com/tikv/tikv

TiKV running over 2 years may panic

opened 04:33AM - 09 Feb 22 UTC

closed 06:57AM - 28 Feb 22 UTC

you06

type/bug severity/critical affects-4.0 affects-5.0 affects-5.1 affects-5.2 affects-5.3 affects-5.4

## Bug Report ### What version of TiKV are you using? `nightly`(this cas…e also appears on v3.0.5) ### What operating system and CPU are you using? ### Steps to reproduce Running TiKV for 795 days, then some RPC failure may cause panic. A simple reproduce using [Chaos Mesh](https://github.com/chaos-mesh/chaos-mesh/): ```bash tiup playground --tiflash=0 --monitor=false sudo kill {pid_of_pd} sudo ./watchmaker -pid {pid_of_tikv} -sec_delta 68719436 -clk_ids=CLOCK_MONOTONIC ``` ### What did you expect? No fatal error with TiKV. ### What did happened? TiKV quits with fatal error. ```log [2022/02/08 20:32:34.418 +08:00] [ERROR] [util.rs:419] ["request failed, retry"] [err_code=KV:PD:Unknown] [err="Other(\"[components/pd_client/src/tso.rs:85]: TimestampRequest channel is closed\")"] [2022/02/08 20:32:34.418 +08:00] [ERROR] [util.rs:419] ["request failed, retry"] [err_code=KV:PD:Unknown] [err="Other(\"[components/pd_client/src/tso.rs:85]: TimestampRequest channel is closed\")"] [2022/02/08 20:32:34.418 +08:00] [ERROR] [util.rs:419] ["request failed, retry"] [err_code=KV:PD:Unknown] [err="Other(\"[components/pd_client/src/tso.rs:85]: TimestampRequest channel is closed\")"] [2022/02/08 20:32:34.418 +08:00] [ERROR] [util.rs:419] ["request failed, retry"] [err_code=KV:PD:Unknown] [err="Other(\"[components/pd_client/src/tso.rs:85]: TimestampRequest channel is closed\")"] [2022/02/08 20:32:34.421 +08:00] [FATAL] [lib.rs:465] ["index out of bounds: the len is 6 but the index is 6"] [backtrace=" 0: tikv_util::set_panic_hook::{{closure}}\n at /home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tikv/components/tikv_util/src/lib.rs:464:18\n 1: std::panicking::rust_panic_with_hook\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panicking.rs:626:17\n 2: std::panicking::begin_panic_handler::{{closure}}\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panicking.rs:519:13\n 3: std::sys_common::backtrace::__rust_end_short_backtrace\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/sys_common/backtrace.rs:141:18\n 4: rust_begin_unwind\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panicking.rs:515:5\n 5: core::panicking::panic_fmt\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/core/src/panicking.rs:92:14\n 6: core::panicking::panic_bounds_check\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/core/src/panicking.rs:69:5\n 7: <usize as core::slice::index::SliceIndex<[T]>>::index_mut\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/core/src/slice/index.rs:190:14\n core::slice::index::<impl core::ops::index::IndexMut<I> for [T]>::index_mut\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/core/src/slice/index.rs:26:9\n <alloc::vec::Vec<T,A> as core::ops::index::IndexMut<I>>::index_mut\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/alloc/src/vec/mod.rs:2445:9\n tokio_timer::wheel::Wheel<T>::insert\n at /rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/wheel/mod.rs:114:9\n tokio_timer::timer::Timer<T,N>::add_entry\n at /rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/timer/mod.rs:324:15\n 8: tokio_timer::timer::Timer<T,N>::process_queue\n at /rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/timer/mod.rs:301:21\n 9: <tokio_timer::timer::Timer<T,N> as tokio_executor::park::Park>::park\n at /rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/timer/mod.rs:361:9\n tokio_timer::timer::Timer<T,N>::turn\n at /rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/timer/mod.rs:256:21\n 10: tikv_util::timer::start_global_timer::{{closure}}\n at /home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tikv/components/tikv_util/src/timer.rs:98:17\n 11: std::sys_common::backtrace::__rust_begin_short_backtrace\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/sys_common/backtrace.rs:125:18\n 12: std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}}\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/thread/mod.rs:476:17\n 13: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panic.rs:347:9\n 14: std::panicking::try::do_call\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panicking.rs:401:40\n std::panicking::try\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panicking.rs:365:19\n std::panic::catch_unwind\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/panic.rs:434:14\n std::thread::Builder::spawn_unchecked::{{closure}}\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/thread/mod.rs:475:30\n core::ops::function::FnOnce::call_once{{vtable.shim}}\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/core/src/ops/function.rs:227:5\n 15: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/alloc/src/boxed.rs:1572:9\n <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/alloc/src/boxed.rs:1572:9\n std::sys::unix::thread::Thread::new::thread_start\n at /rustc/2faabf579323f5252329264cc53ba9ff803429a3/library/std/src/sys/unix/thread.rs:91:17\n 16: start_thread\n 17: __GI___clone\n"] [location=/rust/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/wheel/mod.rs:114] [thread_name=timer] ```

translator_bot · July 19, 2024, 8:22am

| username: Kongdom | Original post link

Then we can only consider upgrading.

translator_bot · July 19, 2024, 8:22am

| username: tidb菜鸟一只 | Original post link

The bug in version 5.4.0 causes TiKV to restart once every two years. Upgrade to resolve it.

translator_bot · July 19, 2024, 8:22am

| username: h5n1 | Original post link

Upgrade to the latest minor version.

translator_bot · July 19, 2024, 8:22am

| username: TiDBer_7S8XqKfl-1158 | Original post link

The error “Key is locked” in the logs usually indicates that a key is locked by another transaction during execution. This may be due to a transaction not being properly committed or rolled back.