py-spy icon indicating copy to clipboard operation
py-spy copied to clipboard

Published 20 hours ago • verified publisher icon benfred

Support profiling debug builds of Python

Open msjyoo opened this issue 5 years ago • 4 comments

Hi,

After using this awesome tool for a while, I tried to use py-spy on a debug build of Python, but it does not seem to work.

$ RUST_LOG=info py-spy record --output ....svg --duration 60 --native --threads --idle -- python3.7-dbg test.py
[2019-10-02T03:05:47.551944654Z INFO  py_spy::config] Command line args: ArgMatches { args: {}, subcommand: Some(SubCommand { name: "record", matches: ArgMatches { args: {"native": MatchedArg { occurs: 1, indices: [5], vals: [] }, "python_program": MatchedArg { occurs: 2, indices: [8, 9], vals: ["python3.7-dbg", "test.py"] }, "threads": MatchedArg { occurs: 1, indices: [6], vals: [] }, "output": MatchedArg { occurs: 1, indices: [2], vals: ["....svg"] }, "duration": MatchedArg { occurs: 1, indices: [4], vals: ["60"] }, "rate": MatchedArg { occurs: 0, indices: [11], vals: ["100"] }, "idle": MatchedArg { occurs: 1, indices: [7], vals: [] }, "format": MatchedArg { occurs: 0, indices: [10], vals: ["flamegraph"] }}, subcommand: None, usage: Some("USAGE:\n    py-spy record [OPTIONS] --output <filename> --pid <pid> [python_program]...") } }), usage: Some("USAGE:\n    py-spy <SUBCOMMAND>") }
[2019-10-02T03:05:47.552375546Z INFO  py_spy::python_spy] Got virtual memory maps from pid 22706:
[2019-10-02T03:05:47.552414497Z INFO  remoteprocess::linux] Target process is running in same namespace - not changing
[2019-10-02T03:05:47.558168229Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2019-10-02T03:05:47.559805762Z INFO  py_spy::version] Found matching version string '3.7.3 (default, Apr  3 2019, 19:16:38) '
[2019-10-02T03:05:47.559850692Z INFO  py_spy::python_spy] python version 3.7.3 detected
[2019-10-02T03:05:47.559857293Z INFO  py_spy::python_spy] got symbol _PyRuntime (0x0000000000ad0540) from python binary
[2019-10-02T03:05:47.559875454Z WARN  py_spy::python_spy] Interpreter address from _PyRuntime symbol is invalid 0000000000addff0
[2019-10-02T03:05:47.559889534Z INFO  py_spy::python_spy] Failed to get interp_head from symbols, scanning BSS section from main binary
[2019-10-02T03:05:47.573073682Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Failed to find a python interpreter in the .data section
[2019-10-02T03:05:47.593579612Z INFO  py_spy::python_spy] Got virtual memory maps from pid 22706:
[2019-10-02T03:05:47.593709265Z INFO  remoteprocess::linux] Target process is running in same namespace - not changing
[2019-10-02T03:05:47.598966154Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2019-10-02T03:05:47.599233581Z INFO  py_spy::version] Found matching version string '3.7.3 (default, Apr  3 2019, 19:16:38) '
[2019-10-02T03:05:47.599325283Z INFO  py_spy::python_spy] python version 3.7.3 detected
[2019-10-02T03:05:47.599384504Z INFO  py_spy::python_spy] got symbol _PyRuntime (0x0000000000ad0540) from python binary
[2019-10-02T03:05:47.599466826Z WARN  py_spy::python_spy] Interpreter address from _PyRuntime symbol is invalid 0000000000addff0
[2019-10-02T03:05:47.599526488Z INFO  py_spy::python_spy] Failed to get interp_head from symbols, scanning BSS section from main binary
[2019-10-02T03:05:47.626178831Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Failed to find a python interpreter in the .data section
[2019-10-02T03:05:47.646697261Z INFO  py_spy::python_spy] Got virtual memory maps from pid 22706:
[2019-10-02T03:05:47.646819564Z INFO  remoteprocess::linux] Target process is running in same namespace - not changing
[2019-10-02T03:05:47.651522468Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2019-10-02T03:05:47.651812465Z INFO  py_spy::version] Found matching version string '3.7.3 (default, Apr  3 2019, 19:16:38) '
[2019-10-02T03:05:47.651876738Z INFO  py_spy::python_spy] python version 3.7.3 detected
[2019-10-02T03:05:47.651922618Z INFO  py_spy::python_spy] got symbol _PyRuntime (0x0000000000ad0540) from python binary
[2019-10-02T03:05:47.651992130Z WARN  py_spy::python_spy] Interpreter address from _PyRuntime symbol is invalid 0000000000addff0
[2019-10-02T03:05:47.652052992Z INFO  py_spy::python_spy] Failed to get interp_head from symbols, scanning BSS section from main binary
[2019-10-02T03:05:47.682267758Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Failed to find a python interpreter in the .data section
[2019-10-02T03:05:47.702916012Z INFO  py_spy::python_spy] Got virtual memory maps from pid 22706:
[2019-10-02T03:05:47.703026345Z INFO  remoteprocess::linux] Target process is running in same namespace - not changing
[2019-10-02T03:05:47.707977155Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2019-10-02T03:05:47.708254503Z INFO  py_spy::version] Found matching version string '3.7.3 (default, Apr  3 2019, 19:16:38) '
[2019-10-02T03:05:47.708343225Z INFO  py_spy::python_spy] python version 3.7.3 detected
[2019-10-02T03:05:47.708393067Z INFO  py_spy::python_spy] got symbol _PyRuntime (0x0000000000ad0540) from python binary
[2019-10-02T03:05:47.708458778Z WARN  py_spy::python_spy] Interpreter address from _PyRuntime symbol is invalid 0000000000addff0
[2019-10-02T03:05:47.708506570Z INFO  py_spy::python_spy] Failed to get interp_head from symbols, scanning BSS section from main binary
[2019-10-02T03:05:47.741174109Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Failed to find a python interpreter in the .data section
[2019-10-02T03:05:47.761779900Z INFO  py_spy::python_spy] Got virtual memory maps from pid 22706:
[2019-10-02T03:05:47.761891203Z INFO  remoteprocess::linux] Target process is running in same namespace - not changing
[2019-10-02T03:05:47.766879984Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2019-10-02T03:05:47.767150360Z INFO  py_spy::version] Found matching version string '3.7.3 (default, Apr  3 2019, 19:16:38) '
[2019-10-02T03:05:47.767211722Z INFO  py_spy::python_spy] python version 3.7.3 detected
[2019-10-02T03:05:47.767256994Z INFO  py_spy::python_spy] got symbol _PyRuntime (0x0000000000ad0540) from python binary
[2019-10-02T03:05:47.767317536Z WARN  py_spy::python_spy] Interpreter address from _PyRuntime symbol is invalid 0000000000addff0
[2019-10-02T03:05:47.767362406Z INFO  py_spy::python_spy] Failed to get interp_head from symbols, scanning BSS section from main binary
[2019-10-02T03:05:47.800676511Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Failed to find a python interpreter in the .data section
[2019-10-02T03:05:47.821471727Z INFO  py_spy::python_spy] Got virtual memory maps from pid 22706:
[2019-10-02T03:05:47.821597280Z INFO  remoteprocess::linux] Target process is running in same namespace - not changing
[2019-10-02T03:05:47.826472178Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2019-10-02T03:05:47.826753466Z INFO  py_spy::version] Found matching version string '3.7.3 (default, Apr  3 2019, 19:16:38) '
[2019-10-02T03:05:47.826821747Z INFO  py_spy::python_spy] python version 3.7.3 detected
[2019-10-02T03:05:47.826871809Z INFO  py_spy::python_spy] got symbol _PyRuntime (0x0000000000ad0540) from python binary
[2019-10-02T03:05:47.826939051Z WARN  py_spy::python_spy] Interpreter address from _PyRuntime symbol is invalid 0000000000addff0
[2019-10-02T03:05:47.826988433Z INFO  py_spy::python_spy] Failed to get interp_head from symbols, scanning BSS section from main binary
[2019-10-02T03:05:47.861231212Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Failed to find a python interpreter in the .data section
[2019-10-02T03:05:47.882040998Z INFO  py_spy::python_spy] Got virtual memory maps from pid 22706:
[2019-10-02T03:05:47.882155000Z INFO  remoteprocess::linux] Target process is running in same namespace - not changing
[2019-10-02T03:05:47.887485571Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2019-10-02T03:05:47.887852130Z INFO  py_spy::version] Found matching version string '3.7.3 (default, Apr  3 2019, 19:16:38) '
[2019-10-02T03:05:47.887932592Z INFO  py_spy::python_spy] python version 3.7.3 detected
[2019-10-02T03:05:47.887989454Z INFO  py_spy::python_spy] got symbol _PyRuntime (0x0000000000ad0540) from python binary
[2019-10-02T03:05:47.888066006Z WARN  py_spy::python_spy] Interpreter address from _PyRuntime symbol is invalid 0000000000addff0
[2019-10-02T03:05:47.888127198Z INFO  py_spy::python_spy] Failed to get interp_head from symbols, scanning BSS section from main binary
[2019-10-02T03:05:47.924172344Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Failed to find a python interpreter in the .data section
[2019-10-02T03:05:47.945050573Z INFO  py_spy::python_spy] Got virtual memory maps from pid 22706:
[2019-10-02T03:05:47.945184456Z INFO  remoteprocess::linux] Target process is running in same namespace - not changing
[2019-10-02T03:05:47.950012852Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2019-10-02T03:05:47.950355222Z INFO  py_spy::version] Found matching version string '3.7.3 (default, Apr  3 2019, 19:16:38) '
[2019-10-02T03:05:47.950434213Z INFO  py_spy::python_spy] python version 3.7.3 detected
[2019-10-02T03:05:47.950490385Z INFO  py_spy::python_spy] got symbol _PyRuntime (0x0000000000ad0540) from python binary
[2019-10-02T03:05:47.950569257Z WARN  py_spy::python_spy] Interpreter address from _PyRuntime symbol is invalid 0000000000addff0
[2019-10-02T03:05:47.950628418Z INFO  py_spy::python_spy] Failed to get interp_head from symbols, scanning BSS section from main binary

Error: Failed to find a python interpreter in the .data section

(As you can see, ASLR was disabled.)

Thanks!

msjyoo avatar Oct 02 '19 03:10 msjyoo

This seems to be because the memory layout for debug builds of python is different.

https://github.com/python/cpython/blob/9e71917e0290972f65711f75510078f799cf0b59/Include/object.h#L67-L71 :

#ifdef Py_TRACE_REFS
/* Define pointers to support a doubly-linked list of all live heap objects. */
#define _PyObject_HEAD_EXTRA            \
    struct _object *_ob_next;           \
    struct _object *_ob_prev;

Those two extra pointers at the head of all the python objects shift things around enough that everything here breaks.

We might be able to detect this somehow (using Py_DebugFlag global?), but even then we would need to generate a complete set of other python bindings for all the debug versions and wire them all in =(

benfred avatar Oct 07 '19 03:10 benfred

If py-spy is using the Python ABI (instead of API), then for Python >= 3.8, this won't be a problem, because the ABI between release and debug is the same. I'm not sure, but I would guess that py-spy is built against the CPython API though.

codypiersall avatar Oct 07 '19 13:10 codypiersall

We're not using the ABI here - and support python going back to v2.3 =(

benfred avatar Oct 11 '19 04:10 benfred

Whoa, Python back to v2.3! I did not realize that. Cool!

codypiersall avatar Oct 11 '19 13:10 codypiersall