Panics at times when sampling a Django app

[Salaah01]

Testing out py-spy locally the Django development server and so I have the following running:

python manage.py runserver 8001

I've then got py-spy running in a separate shell as sudo with the following args:

sudo venv/bin/py-spy record --duration 200 --rate 100 -p 10993 --output pyspy.svg --nonblocking

Now and again I get the following panic:

thread '<unnamed>' panicked at 'index out of bounds: the len is 1 but the index is 1', src/python_interpreters.rs:296:20
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Any { .. }', src/sampler.rs:218:22

Apologies if this has already been reported, I had a quick skim, but I didn't find it.

Some info about my system:

Processor: AMD Ryzen 9 7950X RAM: 32GB Main OS: Windows 10 but running on WSL 2 Python version of the running program: 3.11.7 py-spy version: 0.3.14

Let me know if you need any other info from me.

[sliedes]

Here's a backtrace I got. So far didn't manage yet to get a RUST_BACKTRACE=full. It sometimes works, sometimes hits this, and sometimes segfaults with the same target.

$ RUST_BACKTRACE=1 .../py-spy record -r 1000 -o profile.speedscope -f speedscope --idle --nonblocking -- python -m ...
py-spy> Sampling process 1000 times a second. Press Control-C to exit.

thread '<unnamed>' panicked at src/python_interpreters.rs:396:16:
index out of bounds: the len is 2 but the index is 2
stack backtrace:
   0: rust_begin_unwind
             at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/panicking.rs:645:5
   1: core::panicking::panic_fmt
             at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/panicking.rs:72:14
   2: core::panicking::panic_bounds_check
             at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/panicking.rs:208:5
   3: py_spy::python_interpreters::read_varint
             at /home/sami/proj/chat/py-spy/src/python_interpreters.rs:396:16
   4: py_spy::python_interpreters::read_signed_varint
             at /home/sami/proj/chat/py-spy/src/python_interpreters.rs:405:24
   5: <py_spy::python_bindings::v3_11_0::PyCodeObject as py_spy::python_interpreters::CodeObject>::get_line_number
             at /home/sami/proj/chat/py-spy/src/python_interpreters.rs:461:33
   6: py_spy::stack_trace::get_line_number
             at /home/sami/proj/chat/py-spy/src/stack_trace.rs:224:8
   7: py_spy::stack_trace::get_stack_trace
             at /home/sami/proj/chat/py-spy/src/stack_trace.rs:141:46
   8: py_spy::python_spy::PythonSpy::_get_stack_traces
             at /home/sami/proj/chat/py-spy/src/python_spy.rs:241:29
   9: py_spy::python_spy::PythonSpy::get_stack_traces
             at /home/sami/proj/chat/py-spy/src/python_spy.rs:180:18
  10: py_spy::sampler::Sampler::new_sampler::{{closure}}
             at /home/sami/proj/chat/py-spy/src/sampler.rs:66:36
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread 'main' panicked at src/sampler.rs:264:22:
called `Result::unwrap()` on an `Err` value: Any { .. }
stack backtrace:
   0: rust_begin_unwind
             at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/std/src/panicking.rs:645:5
   1: core::panicking::panic_fmt
             at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/panicking.rs:72:14
   2: core::result::unwrap_failed
             at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/result.rs:1649:5
   3: core::result::Result<T,E>::unwrap
             at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/result.rs:1073:23
   4: <py_spy::sampler::Sampler as core::ops::drop::Drop>::drop
             at /home/sami/proj/chat/py-spy/src/sampler.rs:264:13
   5: core::ptr::drop_in_place<py_spy::sampler::Sampler>
             at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/ptr/mod.rs:507:1
   6: py_spy::record_samples
             at /home/sami/proj/chat/py-spy/src/main.rs:232:5
   7: py_spy::run_spy_command
             at /home/sami/proj/chat/py-spy/src/main.rs:378:13
   8: py_spy::pyspy_main
             at /home/sami/proj/chat/py-spy/src/main.rs:452:22
   9: py_spy::main
             at /home/sami/proj/chat/py-spy/src/main.rs:488:23
  10: core::ops::function::FnOnce::call_once
             at /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

I think it may have something to do with the fairly large number of threads my app spawns (it has a thread pool of ~45 workers). It also uses asyncio.

The precise version I'm running is HEAD as of today (7cbbc015980c5db4d517b62523cf8488296fa2fd) with this added patch IIRC to help make more sense of some threaded code:

diff --git a/src/python_spy.rs b/src/python_spy.rs
index f5e36d6..e8c02da 100644
--- a/src/python_spy.rs
+++ b/src/python_spy.rs
@@ -347,6 +347,8 @@ impl PythonSpy {
         } else {
             let frame = &frames[0];
             (frame.name == "wait" && frame.filename.ends_with("threading.py"))
+                || (frame.name == "_worker" && frame.filename.ends_with("concurrent/futures/thread.py"))
+                || (frame.name == "_recv" && frame.filename.ends_with("multiprocessing/connection.py"))
                 || (frame.name == "select" && frame.filename.ends_with("selectors.py"))
                 || (frame.name == "poll"
                     && (frame.filename.ends_with("asyncore.py")

[humbertogontijo]

Any update on this? Like @sliedes I also use some threads

[Jiehong]

I get a similar issue with python 3.11 and py-spy 0.3.14 (without django, byt just by using pyroscope-io on a python project).

thread '<unnamed>' panicked at /root/.cargo/registry/src/index.crates.io-6f17d22bba15001f/py-spy-0.3.14/src/python_interpreters.rs:302:16:
index out of bounds: the len is 71 but the index is 71