panic index out of bounds in pyspy

[korniltsev]

thread '<unnamed>' panicked at /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/py-spy-0.3.14/src/python_interpreters.rs:296:20:
index out of bounds: the len is 20 but the index is 20
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
thread '<unnamed>' panicked at /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/py-spy-0.3.14/src/sampler.rs:218:22:
called `Result::unwrap()` on an `Err` value: Any { .. }

thread '<unnamed>' panicked at /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/py-spy-0.3.14/src/python_interpreters.rs:296:20:
index out of bounds: the len is 20 but the index is 20
stack backtrace:
   0:     0x77d17220e6b9 - std::backtrace_rs::backtrace::libunwind::trace::hbee8a7973eeb6c93
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/../../backtrace/src/backtrace/libunwind.rs:104:5
   1:     0x77d17220e6b9 - std::backtrace_rs::backtrace::trace_unsynchronized::hc8ac75eea3aa6899
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:     0x77d17220e6b9 - std::sys_common::backtrace::_print_fmt::hc7f3e3b5298b1083
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/sys_common/backtrace.rs:68:5
   3:     0x77d17220e6b9 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hbb235daedd7c6190
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/sys_common/backtrace.rs:44:22
   4:     0x77d171ec77b0 - core::fmt::rt::Argument::fmt::h76c38a80d925a410
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/fmt/rt.rs:142:9
   5:     0x77d171ec77b0 - core::fmt::write::h3ed6aeaa977c8e45
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/fmt/mod.rs:1120:17
   6:     0x77d1721e45b2 - std::io::Write::write_fmt::h78b18af5775fedb5
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/io/mod.rs:1810:15
   7:     0x77d17221024e - std::sys_common::backtrace::_print::h5d645a07e0fcfdbb
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/sys_common/backtrace.rs:47:5
   8:     0x77d17221024e - std::sys_common::backtrace::print::h85035a511aafe7a8
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/sys_common/backtrace.rs:34:9
   9:     0x77d17220f9d0 - std::panicking::default_hook::{{closure}}::hcce8cea212785a25
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/panicking.rs:272:22
  10:     0x77d172210b9c - std::panicking::default_hook::hf5fcb0f213fe709a
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/panicking.rs:292:9
  11:     0x77d172210b9c - std::panicking::rust_panic_with_hook::h095fccf1dc9379ee
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/panicking.rs:779:13
  12:     0x77d1722105a0 - std::panicking::begin_panic_handler::{{closure}}::h032ba12139b353db
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/panicking.rs:657:13
  13:     0x77d1722104f6 - std::sys_common::backtrace::__rust_end_short_backtrace::h9259bc2ff8fd0f76
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/sys_common/backtrace.rs:171:18
  14:     0x77d1722104ef - rust_begin_unwind
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/panicking.rs:645:5
  15:     0x77d171e65a04 - core::panicking::panic_fmt::h784f20a50eaab275
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/panicking.rs:72:14
  16:     0x77d171e65b01 - core::panicking::panic_bounds_check::h8331054858f0bf20
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/panicking.rs:208:5
  17:     0x77d171fb5df6 - <py_spy::python_bindings::v3_11_0::PyCodeObject as py_spy::python_interpreters::CodeObject>::get_line_number::hc40c2b3930500475
  18:     0x77d171fca4c7 - py_spy::stack_trace::get_stack_trace::h2984b0c2c50f18c4
  19:     0x77d171fd5993 - py_spy::python_spy::PythonSpy::get_stack_traces::h390f5c0b51e4996a
  20:     0x77d17200480a - std::sys_common::backtrace::__rust_begin_short_backtrace::h9546e53b048bf1a3
  21:     0x77d172004317 - core::ops::function::FnOnce::call_once{{vtable.shim}}::ha96c120161699459
  22:     0x77d172211c56 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h12de4fc57affb195
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/alloc/src/boxed.rs:2015:9
  23:     0x77d172211c56 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h3c619f45059d5cf1
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/alloc/src/boxed.rs:2015:9
  24:     0x77d172211c56 - std::sys::unix::thread::Thread::new::thread_start::hbac657605e4b7389
                               at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/sys/unix/thread.rs:108:17
  25:     0x77d174694ac3 - start_thread
                               at ./nptl/pthread_create.c:442:8
  26:     0x77d174726850 - __GI___clone3
                               at ./misc/../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
  27:                0x0 - <unknown>

[draincoder]

Hello! Is it possible to somehow catch panics and restart the profiling process in runtime?

[korniltsev]

I don't think so. We need to fix panics

[ethervoid]

Do you know what is causing it? We're experiencing it too

[korniltsev]

I suspect it is the nonblocking way of operating of pyspy. One of the ways to reproduce this is to import+del some module in a loop.

[knowald]

Same error here with pyspy version 0.4.0. Celery workers with the same entrypoint are properly tracked, while our FastAPI uvicorn logs this on start with the thread crashing out of bounds. Good that it's nonblocking, but first question would be how to properly handle this background panic? It looks like the problem might be related to line number handling, and a possibly relevant PR is open here: benfred/py-spy#736

thread '<unnamed>' panicked at /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/py-spy-0.4.0/src/python_interpreters.rs:251:20:
index out of bounds: the len is 21 but the index is 21
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
thread '<unnamed>' panicked at /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/py-spy-0.4.0/src/sampler.rs:264:22:
called `Result::unwrap()` on an `Err` value: Any { .. }