benfred / py-spy

Sampling profiler for Python programs
MIT License
12.8k stars 430 forks source link

In "Ubuntu" docker container on Joyent's Triton platform, py-spy exits with os error 38 #22

Closed jgysland closed 3 years ago

jgysland commented 6 years ago

Triton implements the docker API and can run sort of faux-Linux containers that are (to the best of my non-expert understanding) actually built on top of Solaris zones, as the host OS of Triton compute nodes is SmartOS, which is based on illumos, which is based on OpenSolaris, which is based on BSD and proprietary UNIX implementations.

The README says BSD is not yet supported, so I'm not surprised that it didn't work. It'd be awfully nice if it did, though, and I thought I'd open an issue in case anyone else is trying to use py-spy in a SmartOS container or another BSD or BSD-like environment.

The specific error message I get is:

Error: Function not implemented (os error 38)
benfred commented 6 years ago

I'm guessing it is failing in the call to process_vm_readv - which is a linux system call. It doesn't seem like it's failing for the normal reasons on docker though (permissions denied because of missing ptrace capability: https://github.com/benfred/py-spy/issues/12#issuecomment-419250064), so I'm wondering if it is because of the underlying BSD host OS.

Can you get the full back trace/log ? (

export RUST_BACKTRACE=1
export RUST_LOG=info
py-spy -- python myprogram.py

I would like to support BSD with py-spy, but I'm not sure if that would still be enough to support your use case though =(

ashb commented 6 years ago

Likely related it doesn't run on alpine linux host either - probably cos the function isn't implemented in musl libc either.

Stack trace:

 INFO 2018-10-28T01:14:04Z: py_spy::python_spy: Found libpython binary @ /usr/local/lib/libpython3.6m.so.1.0
 INFO 2018-10-28T01:14:04Z: py_spy::python_spy: Getting version from python binary BSS
 WARN 2018-10-28T01:14:04Z: benfred_read_process_memory: copy_address failed for 202070: Os { code: 38, kind: Other, message: "Function not implemented" }

Error: Function not implemented (os error 38)
stack backtrace:
   0:           0x4bfe4c - backtrace::backtrace::trace::h01cf2d01ec0161d9
   1:           0x4be662 - backtrace::capture::Backtrace::new_unresolved::hbdfd09be0ee84b2d
   2:           0x4be00f - failure::backtrace::internal::InternalBacktrace::new::h8ecd573a5ba932c3
   3:           0x4be1d1 - <failure::backtrace::Backtrace as core::default::Default>::default::h04329fc06ea682e1
   4:           0x4be228 - failure::backtrace::Backtrace::new::hfdb157cb4cdfccdc
   5:           0x4071cd - py_spy::python_spy::PythonSpy::new::h0bf94de2c7deb452
   6:           0x40a2f5 - py_spy::python_spy::PythonSpy::retry_new::he6e1ad36289929c4
   7:           0x41ad75 - py_spy::main::hc9c80267124a1d21
   8:           0x4206f2 - std::rt::lang_start::{{closure}}::h9113eab099ec369c
   9:           0x637882 - std::rt::lang_start_internal::{{closure}}::hb94c47f3eedfaa55
                        at libstd/rt.rs:59
                         - std::panicking::try::do_call::h9a1cf6ef7a2bbed3
                        at libstd/panicking.rs:310
  10:           0x647229 - __rust_maybe_catch_panic
                        at libpanic_unwind/lib.rs:105
  11:           0x62a3ad - std::panicking::try::hb22e57d7731fdf53
                        at libstd/panicking.rs:289
                         - std::panic::catch_unwind::h813102482f9fd064
                        at libstd/panic.rs:392
                         - std::rt::lang_start_internal::h45c8433e0c8ada66
                        at libstd/rt.rs:58
  12:           0x41bb33 - main

(Separate issue? Possibly an un-solvable one?)

benfred commented 6 years ago

@ashb I've tested py-spy with alpine linux (using docker, with the python:3.6-alpine image), and it worked for me. There are some hassles installing py-spy with pip under alpine linux, but it should all work (details here https://github.com/benfred/py-spy/issues/23 )

Did you compile py-spy yourself from source or use the binary wheels on pypi? The linux wheels on pypi are compiled with the musl libc toolchain for portability - so should work on alpine linux (also since it's a statically linked binary, this should remove issues with old versions of glibc.

What version of the linux kernel are you using? the underlying process_vm_readv call requires at least a linux 3.2 kernel. (like what does uname -a show for you?)

ashb commented 6 years ago

pip-wheel based install, and uname reports 4.1.15-2. I wouldn't worry to much about it as this VM is kind of odd and oddly configured in ways I can't remember. I can dig more in to this if you like. This is also an alpine linux host os, but a non-alpine image (python:3.6-slim).

lilydjwg commented 5 years ago

I have a Function not implemented (os error 38) for process_vm_readv too, with alpine (host) and a docker container. I bypassed docker things by nsenter -m -t pid ... but it still doesn't work. uname reports 4.14.69-0-vanilla.

pjz commented 5 years ago

FWIW, I get the same issue trying to run py-spy under docker under CoreOS.

I'd love to hear that this has been solved sometime in the last 9 months!

codypiersall commented 5 years ago

Sounds like this is potentially a kernel configuration problem. If the kernel was built without CONFIG_CROSS_MEMORY_ATTACH, the syscall process_vm_readv won't exist. There are different ways to check kernel config options on different platforms.

If your host OS kernel is not built with that option, any container running on that OS won't work, since they're running on the same kernel. VM's are completely isolated though and don't depend on the host OS.

So I don't think this isn't a musl issue, or a libc issue, but a kernel configuration issue. I'm not sure if there are any workarounds that py-spy can do, like reading /proc/mem, or if the only solution is to build a kernel with the right config options set.

benfred commented 5 years ago

@codypiersall I think that you are probably right on this, it's the best explanation I've seen for a weird problem. If anyone that is affected by this can verify their kernel config to see if they are lacking CONFIG_CROSS_MEMORY_ATTACH, I'd really appreciate it.

Reading from /proc/PID/mem will work as a workaround most of the time- but not if we're in nonblocking mode (proc/mem requires a ptrace attach). It's still probably worth trying as a workaround in this case though

lilydjwg commented 5 years ago

Yes, the Alpine vanilla kernel with which I met this issue has:

# CONFIG_CROSS_MEMORY_ATTACH is not set
sebageek commented 3 years ago

I'm affected by this, py-spy top -p $pid does not work on host or in a container, fails with Error: Function not implemented (os error 38). CONFIG_CROSS_MEMORY_ATTACH is not set. The stacktrace looks exactly the same when comparing a run inside or outside the container, so this part is not making any difference (which makes sense, as the underlying host kernel has to have CONFIG_CROSS_MEMORY_ATTACH enabled). My host in question is a Kubernetes node running Flatcar Linux.

Host system:

user@host ~ $ uname -r
5.4.72-flatcar
user@host ~ $ zgrep CONFIG_CROSS_MEMORY_ATTACH /proc/config.gz
# CONFIG_CROSS_MEMORY_ATTACH is not set

py-spy launched in container:

root@container:~# py-spy --version
py-spy 0.3.3

root@container:~# export RUST_BACKTRACE=1
root@container:~# export RUST_LOG=info
root@container:~# py-spy top --pid 54864
[2021-01-07T12:54:22.728253583Z INFO  py_spy::config] Command line args: ArgMatches { args: {}, subcommand: Some(SubCommand { name: "top", matches: ArgMatches { args: {"pid": MatchedArg { occurs: 1, indices: [2], vals: ["54864"] }, "rate": MatchedArg { occurs: 0, indices: [3], vals: ["100"] }}, subcommand: None, usage: Some("USAGE:\n    py-spy top [OPTIONS] --pid <pid> [python_program]...") } }), usage: Some("USAGE:\n    py-spy <SUBCOMMAND>") }
[2021-01-07T12:54:22.729078633Z INFO  py_spy::python_spy] Got virtual memory maps from pid 54864:
[2021-01-07T12:54:22.730095477Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2021-01-07T12:54:22.730763109Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Function not implemented (os error 38)
[2021-01-07T12:54:22.751412496Z INFO  py_spy::python_spy] Got virtual memory maps from pid 54864:
[2021-01-07T12:54:22.751968585Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2021-01-07T12:54:22.752568258Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Function not implemented (os error 38)
[2021-01-07T12:54:22.773197395Z INFO  py_spy::python_spy] Got virtual memory maps from pid 54864:
[2021-01-07T12:54:22.773725150Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2021-01-07T12:54:22.774302865Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Function not implemented (os error 38)
[2021-01-07T12:54:22.795146504Z INFO  py_spy::python_spy] Got virtual memory maps from pid 54864:
[2021-01-07T12:54:22.795697551Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2021-01-07T12:54:22.796280308Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Function not implemented (os error 38)
[2021-01-07T12:54:22.816906027Z INFO  py_spy::python_spy] Got virtual memory maps from pid 54864:
[2021-01-07T12:54:22.817584826Z INFO  py_spy::python_spy] Getting version from python binary BSS
Error: Function not implemented (os error 38)
   0: failure::backtrace::internal::InternalBacktrace::new
   1: <failure::backtrace::Backtrace as core::default::Default>::default
   2: py_spy::python_spy::PythonSpy::new
   3: py_spy::python_spy::PythonSpy::retry_new
   4: std::sys_common::backtrace::__rust_begin_short_backtrace
   5: std::panicking::try::do_call
   6: __rust_maybe_catch_panic
             at src/libpanic_unwind/lib.rs:78
   7: core::ops::function::FnOnce::call_once{{vtable.shim}}
   8: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at /rustc/5e1a799842ba6ed4a57e91f7ab9435947482f7d8/src/liballoc/boxed.rs:1022
   9: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at /rustc/5e1a799842ba6ed4a57e91f7ab9435947482f7d8/src/liballoc/boxed.rs:1022
      std::sys_common::thread::start_thread
             at src/libstd/sys_common/thread.rs:13
      std::sys::unix::thread::Thread::new::thread_start
             at src/libstd/sys/unix/thread.rs:80
guyskk commented 3 years ago

I meet the same issue, both python process and py-spy runs in host.

[root@a003 ~ ]$ export RUST_BACKTRACE=1
[root@a003 ~ ]$ export RUST_LOG=info
[root@a003 ~ ]$ ~/.local/bin/py-spy record -o profile.svg --pid 8847
[2021-01-16T17:27:08.255893438Z INFO  py_spy::config] Command line args: ArgMatches { args: {}, subcommand: Some(SubCommand { name: "record", matches: ArgMatches { args: {"output": MatchedArg { occurs: 1, indices: [2], vals: ["profile.svg"] }, "rate": MatchedArg { occurs: 0, indices: [7], vals: ["100"] }, "pid": MatchedArg { occurs: 1, indices: [4], vals: ["8847"] }, "format": MatchedArg { occurs: 0, indices: [5], vals: ["flamegraph"] }, "duration": MatchedArg { occurs: 0, indices: [6], vals: ["unlimited"] }}, subcommand: None, usage: Some("USAGE:\n    py-spy record [OPTIONS] --output <filename> --pid <pid> [python_program]...") } }), usage: Some("USAGE:\n    py-spy <SUBCOMMAND>") }
[2021-01-16T17:27:08.256185640Z INFO  py_spy::python_spy] Got virtual memory maps from pid 8847:
[2021-01-16T17:27:08.256705514Z INFO  py_spy::python_spy] Found libpython binary @ /usr/lib64/libpython3.6m.so.1.0
[2021-01-16T17:27:08.257792001Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2021-01-16T17:27:08.259313139Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Function not implemented (os error 38)
[2021-01-16T17:27:08.279575431Z INFO  py_spy::python_spy] Got virtual memory maps from pid 8847:
[2021-01-16T17:27:08.279730943Z INFO  py_spy::python_spy] Found libpython binary @ /usr/lib64/libpython3.6m.so.1.0
[2021-01-16T17:27:08.280721523Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2021-01-16T17:27:08.281320331Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Function not implemented (os error 38)
[2021-01-16T17:27:08.301571780Z INFO  py_spy::python_spy] Got virtual memory maps from pid 8847:
[2021-01-16T17:27:08.301731313Z INFO  py_spy::python_spy] Found libpython binary @ /usr/lib64/libpython3.6m.so.1.0
[2021-01-16T17:27:08.302760910Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2021-01-16T17:27:08.303286653Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Function not implemented (os error 38)
[2021-01-16T17:27:08.323543558Z INFO  py_spy::python_spy] Got virtual memory maps from pid 8847:
[2021-01-16T17:27:08.323687797Z INFO  py_spy::python_spy] Found libpython binary @ /usr/lib64/libpython3.6m.so.1.0
[2021-01-16T17:27:08.324732870Z INFO  py_spy::python_spy] Getting version from python binary BSS
[2021-01-16T17:27:08.325253409Z INFO  py_spy::python_spy] Failed to connect to process, retrying. Error: Function not implemented (os error 38)
[2021-01-16T17:27:08.345506432Z INFO  py_spy::python_spy] Got virtual memory maps from pid 8847:
[2021-01-16T17:27:08.345639126Z INFO  py_spy::python_spy] Found libpython binary @ /usr/lib64/libpython3.6m.so.1.0
[2021-01-16T17:27:08.346568463Z INFO  py_spy::python_spy] Getting version from python binary BSS
Error: Function not implemented (os error 38)
   0: failure::backtrace::internal::InternalBacktrace::new
   1: <failure::backtrace::Backtrace as core::default::Default>::default
   2: py_spy::python_spy::PythonSpy::new
   3: py_spy::python_spy::PythonSpy::retry_new
   4: std::sys_common::backtrace::__rust_begin_short_backtrace
   5: std::panicking::try::do_call
   6: __rust_maybe_catch_panic
             at src/libpanic_unwind/lib.rs:78
   7: core::ops::function::FnOnce::call_once{{vtable.shim}}
   8: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at /rustc/5e1a799842ba6ed4a57e91f7ab9435947482f7d8/src/liballoc/boxed.rs:1022
   9: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at /rustc/5e1a799842ba6ed4a57e91f7ab9435947482f7d8/src/liballoc/boxed.rs:1022
      std::sys_common::thread::start_thread
             at src/libstd/sys_common/thread.rs:13
      std::sys::unix::thread::Thread::new::thread_start
             at src/libstd/sys/unix/thread.rs:80

System Info:

[root@a003 ~ ]$ cat /etc/*release*
Aliyun Linux release 2.1903 LTS (Hunting Beagle)
Aliyun Linux release 2.1903 LTS (Hunting Beagle)
cat: /etc/lsb-release.d: 是一个目录
NAME="Aliyun Linux"
VERSION="2.1903 LTS (Hunting Beagle)"
ID="alinux"
ID_LIKE="rhel fedora centos"
VERSION_ID="2.1903"
PRETTY_NAME="Aliyun Linux 2.1903 LTS (Hunting Beagle)"
ANSI_COLOR="0;31"
HOME_URL="https://www.aliyun.com/"

Aliyun Linux release 2.1903 LTS (Hunting Beagle)
Aliyun Linux release 2.1903 LTS (Hunting Beagle)

[root@a003 ~ ]$ uname -a
Linux a003.localhost 4.19.91-19.1.al7.x86_64 #1 SMP Tue May 26 19:19:43 CST 2020 x86_64 x86_64 x86_64 GNU/Linux

py-spy version:

Python 3.6.8
py-spy 0.3.3
benfred commented 3 years ago

This should be fixed in v0.3.5 - https://pypi.org/project/py-spy/0.3.5/ .