Skip to content
This repository has been archived by the owner on Dec 3, 2019. It is now read-only.

Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA: Input/output error #129

Open
stevenkaras opened this issue Oct 26, 2017 · 8 comments
Open

Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA: Input/output error #129

stevenkaras opened this issue Oct 26, 2017 · 8 comments

Comments

@stevenkaras
Copy link
Contributor

I'm encountering this error after about 15 minutes of tracing a running python process.

Ubuntu 14.04, running 4.4.0-75-generic, tracing a long-lived python 2.7.6 process, built from source (e9c6b7a).
@eklitzke
Copy link
Contributor

eklitzke commented Oct 26, 2017 •
edited
Loading

What is the address printed (i.e. the complete exception message, including the hex string at the end)? Also, can you provide me the output of pyflame -v?

@stevenkaras
Copy link
Contributor Author

Here's the output of pyflame -v for the build that originally exited early:

Pyflame 1.5.7 (commit e9c6b7a) linux-gnu x86_64 (ABI list: 26 34)

I rebuilt it to only drop the current sample if a PTraceException is thrown, which gave me these exceptions over the last hour or so:

Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x6f6d5f5f00000051): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x6f6d5f5f00000051): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x7f5d126f5ffc): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x7f5d17fffffc): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x7f5d18e1fffc): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x7f5d18e1fffc): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x6f6d5f5f00000051): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x6f6d5f5f00000051): Input/output error
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 45512, addr 0x50): Input/output error

@stevenkaras
Copy link
Contributor Author

stevenkaras commented Oct 26, 2017 •
edited
Loading

looking at /proc/45512/maps, these are some of the relevant page allocations

7f5d126f4000-7f5d128f4000 ---p 00017000 08:01 262158                     /lib/x86_64-linux-gnu/libresolv-2.19.so
7f5d14049000-7f5d18000000 ---p 00000000 00:00 0
7f5d18e1f000-7f5d1901e000 ---p 0000a000 08:01 266284                     /lib/x86_64-linux-gnu/libnss_files-2.19.so

@eklitzke
Copy link
Contributor

The ones that say addr 0x50 are basically a null pointer dereference (I wrote about a related issue at https://eklitzke.org/an-unexpected-python-abi-change ), that's probably easier to debug. The other ones are hopefully fixed if we fix this case. If you want to help me debug this:

  • Make sure pyflame is built with debugging symbols (I believe it is by default)
  • Set a GDB breakpoint in the code path that throws the exception (i.e. at src/ptrace.cc:156)
  • Get the Pyflame backtrace (using bt in GDB) when you hit the breakpoint

That will help figure out where in the code the error is happening.

Also -- are you profiling a regular Python 2.7 process, or some kind of embedded Python build (e.g. a uwsgi worker process)?

@stevenkaras
Copy link
Contributor Author

This is a regular Python 2.7.6 process. Here's the backtrace:

#0  pyflame::PtracePeek (pid=pid@entry=45512, addr=addr@entry=80) at ptrace.cc:156
#1  0x000000000040d402 in pyflame::py26::FollowFrame (pid=pid@entry=45512, frame=140024926446528, stack=stack@entry=0x7fffffffe1d0) at ./frob.cc:229
#2  0x000000000040d4f3 in pyflame::py26::FollowFrame (pid=pid@entry=45512, frame=140037744176656, stack=stack@entry=0x7fffffffe1d0) at ./frob.cc:239
#3  0x000000000040d8a0 in pyflame::py26::GetThreads (pid=45512, addrs=..., enable_threads=false) at ./frob.cc:288
#4  0x000000000040ae10 in pyflame::PyFrob::GetThreads (this=this@entry=0x7fffffffe450) at pyfrob.cc:199
#5  0x0000000000405fa1 in pyflame::Prober::ProbeLoop (this=this@entry=0x7fffffffe410, frobber=...) at prober.cc:364
#6  0x0000000000403331 in main (argc=<optimized out>, argv=0x7fffffffe588) at pyflame.cc:37

@stevenkaras stevenkaras mentioned this issue Jan 17, 2018
Merged
@bk-equityzen
Copy link

I've also gotten this issue profiling a django uwsgi app:
Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA (pid 30398, addr 0x2f0000008e): Input/output error

Sometimes happens after a few seconds of clicking around, sometimes doesn't happen for a while, my current workaround is to profile in smaller bursts

@eklitzke
Copy link
Contributor

@stevenkaras That is interesting because that shows pointers well beyond where I would expect the stack to end. This differs from system to system, but here's what I see locally:

$ cat /proc/4006/maps
55c16bb0e000-55c16bb10000 r-xp 00000000 fd:01 139319                     /usr/bin/python3.6
55c16bd0f000-55c16bd10000 r--p 00001000 fd:01 139319                     /usr/bin/python3.6
55c16bd10000-55c16bd11000 rw-p 00002000 fd:01 139319                     /usr/bin/python3.6
55c16c16a000-55c16c2da000 rw-p 00000000 00:00 0                          [heap]
7fdbc5f02000-7fdbc5f42000 rw-p 00000000 00:00 0 
7fdbc5f42000-7fdbc5f46000 r-xp 00000000 fd:01 666378                     /usr/lib64/python3.6/lib-dynload/_random.cpython-36m-x86_64-linux-gnu.so
7fdbc5f46000-7fdbc6145000 ---p 00004000 fd:01 666378                     /usr/lib64/python3.6/lib-dynload/_random.cpython-36m-x86_64-linux-gnu.so
7fdbc6145000-7fdbc6146000 r--p 00003000 fd:01 666378                     /usr/lib64/python3.6/lib-dynload/_random.cpython-36m-x86_64-linux-gnu.so
7fdbc6146000-7fdbc6147000 rw-p 00004000 fd:01 666378                     /usr/lib64/python3.6/lib-dynload/_random.cpython-36m-x86_64-linux-gnu.so
7fdbc6147000-7fdbc6149000 r-xp 00000000 fd:01 663389                     /usr/lib64/python3.6/lib-dynload/_bisect.cpython-36m-x86_64-linux-gnu.so
7fdbc6149000-7fdbc6348000 ---p 00002000 fd:01 663389                     /usr/lib64/python3.6/lib-dynload/_bisect.cpython-36m-x86_64-linux-gnu.so
7fdbc6348000-7fdbc6349000 r--p 00001000 fd:01 663389                     /usr/lib64/python3.6/lib-dynload/_bisect.cpython-36m-x86_64-linux-gnu.so
7fdbc6349000-7fdbc634a000 rw-p 00002000 fd:01 663389                     /usr/lib64/python3.6/lib-dynload/_bisect.cpython-36m-x86_64-linux-gnu.so
7fdbc634a000-7fdbc6360000 r-xp 00000000 fd:01 666381                     /usr/lib64/python3.6/lib-dynload/_sha3.cpython-36m-x86_64-linux-gnu.so
7fdbc6360000-7fdbc655f000 ---p 00016000 fd:01 666381                     /usr/lib64/python3.6/lib-dynload/_sha3.cpython-36m-x86_64-linux-gnu.so
7fdbc655f000-7fdbc6560000 r--p 00015000 fd:01 666381                     /usr/lib64/python3.6/lib-dynload/_sha3.cpython-36m-x86_64-linux-gnu.so
7fdbc6560000-7fdbc6562000 rw-p 00016000 fd:01 666381                     /usr/lib64/python3.6/lib-dynload/_sha3.cpython-36m-x86_64-linux-gnu.so
7fdbc6562000-7fdbc656f000 r-xp 00000000 fd:01 666144                     /usr/lib64/python3.6/lib-dynload/_blake2.cpython-36m-x86_64-linux-gnu.so
7fdbc656f000-7fdbc676e000 ---p 0000d000 fd:01 666144                     /usr/lib64/python3.6/lib-dynload/_blake2.cpython-36m-x86_64-linux-gnu.so
7fdbc676e000-7fdbc676f000 r--p 0000c000 fd:01 666144                     /usr/lib64/python3.6/lib-dynload/_blake2.cpython-36m-x86_64-linux-gnu.so
7fdbc676f000-7fdbc6770000 rw-p 0000d000 fd:01 666144                     /usr/lib64/python3.6/lib-dynload/_blake2.cpython-36m-x86_64-linux-gnu.so
7fdbc6770000-7fdbc6786000 r-xp 00000000 fd:01 135588                     /usr/lib64/libz.so.1.2.11
7fdbc6786000-7fdbc6985000 ---p 00016000 fd:01 135588                     /usr/lib64/libz.so.1.2.11
7fdbc6985000-7fdbc6986000 r--p 00015000 fd:01 135588                     /usr/lib64/libz.so.1.2.11
7fdbc6986000-7fdbc6987000 rw-p 00000000 00:00 0 
7fdbc6987000-7fdbc6be3000 r-xp 00000000 fd:01 139043                     /usr/lib64/libcrypto.so.1.1.0g
7fdbc6be3000-7fdbc6de3000 ---p 0025c000 fd:01 139043                     /usr/lib64/libcrypto.so.1.1.0g
7fdbc6de3000-7fdbc6e00000 r--p 0025c000 fd:01 139043                     /usr/lib64/libcrypto.so.1.1.0g
7fdbc6e00000-7fdbc6e0c000 rw-p 00279000 fd:01 139043                     /usr/lib64/libcrypto.so.1.1.0g
7fdbc6e0c000-7fdbc6e0f000 rw-p 00000000 00:00 0 
7fdbc6e0f000-7fdbc6e71000 r-xp 00000000 fd:01 139045                     /usr/lib64/libssl.so.1.1.0g
7fdbc6e71000-7fdbc7071000 ---p 00062000 fd:01 139045                     /usr/lib64/libssl.so.1.1.0g
7fdbc7071000-7fdbc7075000 r--p 00062000 fd:01 139045                     /usr/lib64/libssl.so.1.1.0g
7fdbc7075000-7fdbc707b000 rw-p 00066000 fd:01 139045                     /usr/lib64/libssl.so.1.1.0g
7fdbc707b000-7fdbc7081000 r-xp 00000000 fd:01 666367                     /usr/lib64/python3.6/lib-dynload/_hashlib.cpython-36m-x86_64-linux-gnu.so
7fdbc7081000-7fdbc7280000 ---p 00006000 fd:01 666367                     /usr/lib64/python3.6/lib-dynload/_hashlib.cpython-36m-x86_64-linux-gnu.so
7fdbc7280000-7fdbc7281000 r--p 00005000 fd:01 666367                     /usr/lib64/python3.6/lib-dynload/_hashlib.cpython-36m-x86_64-linux-gnu.so
7fdbc7281000-7fdbc7282000 rw-p 00006000 fd:01 666367                     /usr/lib64/python3.6/lib-dynload/_hashlib.cpython-36m-x86_64-linux-gnu.so
7fdbc7282000-7fdbc728c000 r-xp 00000000 fd:01 666397                     /usr/lib64/python3.6/lib-dynload/math.cpython-36m-x86_64-linux-gnu.so
7fdbc728c000-7fdbc748b000 ---p 0000a000 fd:01 666397                     /usr/lib64/python3.6/lib-dynload/math.cpython-36m-x86_64-linux-gnu.so
7fdbc748b000-7fdbc748c000 r--p 00009000 fd:01 666397                     /usr/lib64/python3.6/lib-dynload/math.cpython-36m-x86_64-linux-gnu.so
7fdbc748c000-7fdbc748e000 rw-p 0000a000 fd:01 666397                     /usr/lib64/python3.6/lib-dynload/math.cpython-36m-x86_64-linux-gnu.so
7fdbc748e000-7fdbc750e000 rw-p 00000000 00:00 0 
7fdbc750e000-7fdbc7518000 r-xp 00000000 fd:01 666389                     /usr/lib64/python3.6/lib-dynload/_struct.cpython-36m-x86_64-linux-gnu.so
7fdbc7518000-7fdbc7718000 ---p 0000a000 fd:01 666389                     /usr/lib64/python3.6/lib-dynload/_struct.cpython-36m-x86_64-linux-gnu.so
7fdbc7718000-7fdbc7719000 r--p 0000a000 fd:01 666389                     /usr/lib64/python3.6/lib-dynload/_struct.cpython-36m-x86_64-linux-gnu.so
7fdbc7719000-7fdbc771b000 rw-p 0000b000 fd:01 666389                     /usr/lib64/python3.6/lib-dynload/_struct.cpython-36m-x86_64-linux-gnu.so
7fdbc771b000-7fdbc7824000 rw-p 00000000 00:00 0 
7fdbc7824000-7fdbc7827000 r-xp 00000000 fd:01 666368                     /usr/lib64/python3.6/lib-dynload/_heapq.cpython-36m-x86_64-linux-gnu.so
7fdbc7827000-7fdbc7a26000 ---p 00003000 fd:01 666368                     /usr/lib64/python3.6/lib-dynload/_heapq.cpython-36m-x86_64-linux-gnu.so
7fdbc7a26000-7fdbc7a27000 r--p 00002000 fd:01 666368                     /usr/lib64/python3.6/lib-dynload/_heapq.cpython-36m-x86_64-linux-gnu.so
7fdbc7a27000-7fdbc7a29000 rw-p 00003000 fd:01 666368                     /usr/lib64/python3.6/lib-dynload/_heapq.cpython-36m-x86_64-linux-gnu.so
7fdbc7a29000-7fdbc7aa9000 rw-p 00000000 00:00 0 
7fdbc7aa9000-7fdbce678000 r--p 00000000 fd:01 543636                     /usr/lib/locale/locale-archive
7fdbce678000-7fdbce824000 r-xp 00000000 fd:01 140221                     /usr/lib64/libc-2.26.so
7fdbce824000-7fdbcea24000 ---p 001ac000 fd:01 140221                     /usr/lib64/libc-2.26.so
7fdbcea24000-7fdbcea28000 r--p 001ac000 fd:01 140221                     /usr/lib64/libc-2.26.so
7fdbcea28000-7fdbcea2a000 rw-p 001b0000 fd:01 140221                     /usr/lib64/libc-2.26.so
7fdbcea2a000-7fdbcea2e000 rw-p 00000000 00:00 0 
7fdbcea2e000-7fdbceb78000 r-xp 00000000 fd:01 177305                     /usr/lib64/libm-2.26.so
7fdbceb78000-7fdbced77000 ---p 0014a000 fd:01 177305                     /usr/lib64/libm-2.26.so
7fdbced77000-7fdbced78000 r--p 00149000 fd:01 177305                     /usr/lib64/libm-2.26.so
7fdbced78000-7fdbced79000 rw-p 0014a000 fd:01 177305                     /usr/lib64/libm-2.26.so
7fdbced79000-7fdbced7b000 r-xp 00000000 fd:01 168001                     /usr/lib64/libutil-2.26.so
7fdbced7b000-7fdbcef7a000 ---p 00002000 fd:01 168001                     /usr/lib64/libutil-2.26.so
7fdbcef7a000-7fdbcef7b000 r--p 00001000 fd:01 168001                     /usr/lib64/libutil-2.26.so
7fdbcef7b000-7fdbcef7c000 rw-p 00002000 fd:01 168001                     /usr/lib64/libutil-2.26.so
7fdbcef7c000-7fdbcef7f000 r-xp 00000000 fd:01 155161                     /usr/lib64/libdl-2.26.so
7fdbcef7f000-7fdbcf17e000 ---p 00003000 fd:01 155161                     /usr/lib64/libdl-2.26.so
7fdbcf17e000-7fdbcf17f000 r--p 00002000 fd:01 155161                     /usr/lib64/libdl-2.26.so
7fdbcf17f000-7fdbcf180000 rw-p 00003000 fd:01 155161                     /usr/lib64/libdl-2.26.so
7fdbcf180000-7fdbcf199000 r-xp 00000000 fd:01 177313                     /usr/lib64/libpthread-2.26.so
7fdbcf199000-7fdbcf398000 ---p 00019000 fd:01 177313                     /usr/lib64/libpthread-2.26.so
7fdbcf398000-7fdbcf399000 r--p 00018000 fd:01 177313                     /usr/lib64/libpthread-2.26.so
7fdbcf399000-7fdbcf39a000 rw-p 00019000 fd:01 177313                     /usr/lib64/libpthread-2.26.so
7fdbcf39a000-7fdbcf39e000 rw-p 00000000 00:00 0 
7fdbcf39e000-7fdbcf664000 r-xp 00000000 fd:01 135367                     /usr/lib64/libpython3.6m.so.1.0
7fdbcf664000-7fdbcf863000 ---p 002c6000 fd:01 135367                     /usr/lib64/libpython3.6m.so.1.0
7fdbcf863000-7fdbcf869000 r--p 002c5000 fd:01 135367                     /usr/lib64/libpython3.6m.so.1.0
7fdbcf869000-7fdbcf8cc000 rw-p 002cb000 fd:01 135367                     /usr/lib64/libpython3.6m.so.1.0
7fdbcf8cc000-7fdbcf8fd000 rw-p 00000000 00:00 0 
7fdbcf8fd000-7fdbcf922000 r-xp 00000000 fd:01 135132                     /usr/lib64/ld-2.26.so
7fdbcf951000-7fdbcf991000 rw-p 00000000 00:00 0 
7fdbcf9b6000-7fdbcfafa000 rw-p 00000000 00:00 0 
7fdbcfb1a000-7fdbcfb21000 r--s 00000000 fd:01 135435                     /usr/lib64/gconv/gconv-modules.cache
7fdbcfb21000-7fdbcfb22000 r--p 00024000 fd:01 135132                     /usr/lib64/ld-2.26.so
7fdbcfb22000-7fdbcfb23000 rw-p 00025000 fd:01 135132                     /usr/lib64/ld-2.26.so
7fdbcfb23000-7fdbcfb24000 rw-p 00000000 00:00 0 
7ffd515b8000-7ffd515d9000 rw-p 00000000 00:00 0                          [stack]
7ffd515da000-7ffd515dd000 r--p 00000000 00:00 0                          [vvar]
7ffd515dd000-7ffd515df000 r-xp 00000000 00:00 0                          [vdso]
ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]

So on my system in this particular run the stack was in the range 7ffd515b8000-7ffd515d9000 which is typical (the exact numbers can vary). Normally it is some number like 0x7ff and then other digits after that, but before 0x7ffff...

You're seeing a stack entry well beyond that, i.e. from your trace:

#2  0x000000000040d4f3 in pyflame::py26::FollowFrame (pid=pid@entry=45512, frame=140037744176656, stack=stack@entry=0x7fffffffe1d0) at ./frob.cc:239

That address is 7728 bytes before where I expect userspace memory to end (0x7fffffffffff). Would need more data from gdb to debug further.

@bk-equityzen I would be interested to see what the memory map looks like in that situation as it appears not to be at the top of user memory. You can use /proc/PID/maps from the process as I did here to look at that.

@hackaugusto hackaugusto mentioned this issue Jan 24, 2019
Closed
@rousseldenis
Copy link

I rebuilt it to only drop the current sample if a PTraceException is thrown, which gave me these exceptions over the last hour or so:

I have the same errors on Ubuntu 18.10

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@eklitzke @stevenkaras @rousseldenis @bk-equityzen