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

Python 3.6.1 support #69

Closed
qqueue opened this issue Jun 2, 2017 · 16 comments
Closed

Python 3.6.1 support #69

qqueue opened this issue Jun 2, 2017 · 16 comments

Comments

@qqueue
Copy link

qqueue commented Jun 2, 2017

Bleeding edge I know. Testing with Ubuntu 16.04 x64,

virtualenv -p python3.6 env
source env/bin/activate
pyflame -t python -c 'println(sum(i for i in range(0, 100000)))'

I only get (idle) 2 out of it. The same invocation works for python 3.5.2 and 2.7 on the same system. Attaching to a 3.6.1 process also only shows idle time. Sometimes, I instead get Failed to PTRACE_PEEKDATA at 0x10: Input/output error with different running processes, but I haven't figured out how to reproduce that.

@pwaller
Copy link

pwaller commented Jun 5, 2017

I get the same error, Ubuntu 17.04, x64, trying to attach I just see Failed to PTRACE_PEEKDATA at 0x10: Input/output error.

From the ptrace manpage, EIO is raised:

EIO request is invalid, or an attempt was made to read from or write to an invalid area in the tracer's or the tracee's memory, or there was a word-alignment violation, or an invalid signal was specified during a restart request.

@pwaller
Copy link

pwaller commented Jun 5, 2017

strace output indicates that it's all working nicely, looks like it follows a series of pointers before hitting a dead-end (expand details to see strace excerpt):

ptrace(PTRACE_POKEDATA, 13160, 0x7f2154c1518d, 0x50f) = 0                                                                                                                                                                              [179/531]
ptrace(PTRACE_SETREGS, 13160, NULL, 0x7ffd1be4f690) = 0                                                                                                                                                                                         
ptrace(PTRACE_SINGLESTEP, 13160, NULL, SIG_0) = 0                                                                                                                                                                                               
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_TRAPPED, si_pid=13160, si_uid=1000, si_status=SIGTRAP, si_utime=28249, si_stime=1546} ---                                                                                                            
wait4(13160, [{WIFSTOPPED(s) && WSTOPSIG(s) == SIGTRAP}], 0, NULL) = 13160                                                                                                                                                                      
ptrace(PTRACE_GETREGS, 13160, NULL, 0x7ffd1be4f950) = 0                                                                                                                                                                                         
ptrace(PTRACE_SETREGS, 13160, NULL, 0x7ffd1be4f690) = 0                                                                                                                                                                                         
ptrace(PTRACE_POKEDATA, 13160, 0x7f2154c1518d, 0xe8c28948243c8b48) = 0                                                                                                                                                                          
open("/proc/13160/task", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 4                                                                                                                                                                         
fstat(4, {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0                                                                                                                                                                                            
getdents(4, /* 35 entries */, 32768)    = 1104                                                                                                                                                                                                  
getdents(4, /* 0 entries */, 32768)     = 0                                                                                                                                                                                                     
ptrace(PTRACE_DETACH, 13167, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13168, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13169, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13170, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13171, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13172, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13173, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13174, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13191, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13192, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13193, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13194, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13195, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13196, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13197, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13198, NULL, SIG_0) = 0  
ptrace(PTRACE_DETACH, 13206, NULL, SIG_0) = 0                                                                                                                                                                                          [151/531]
ptrace(PTRACE_DETACH, 13684, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13685, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13686, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13687, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13688, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13689, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13690, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13691, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13692, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13693, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13694, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13695, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13696, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13697, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_DETACH, 13698, NULL, SIG_0) = 0                                                                                                                                                                                                   
ptrace(PTRACE_POKEDATA, 13160, 0x7f21549f9000, 0xccd0ff) = 0                                                                                                                                                                                    
ptrace(PTRACE_GETREGS, 13160, NULL, 0x7ffd1be4f870) = 0                                                                                                                                                                                         
ptrace(PTRACE_SETREGS, 13160, NULL, 0x7ffd1be4f690) = 0                                                                                                                                                                                         
ptrace(PTRACE_CONT, 13160, NULL, SIG_0) = 0                                                                                                                                                                                                     
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_TRAPPED, si_pid=13160, si_uid=1000, si_status=SIGTRAP, si_utime=28249, si_stime=1546} ---                                                                                                            
wait4(13160, [{WIFSTOPPED(s) && WSTOPSIG(s) == SIGTRAP}], 0, NULL) = 13160                                                                                                                                                                      
ptrace(PTRACE_GETREGS, 13160, NULL, 0x7ffd1be4f950) = 0                                                                                                                                                                                         
ptrace(PTRACE_SETREGS, 13160, NULL, 0x7ffd1be4f690) = 0                                                                                                                                                                                         
lstat("/proc/self/ns/mnt", {st_mode=S_IFLNK|0777, st_size=0, ...}) = 0                                                                                                                                                                          
readlink("/proc/self/ns/mnt", "mnt:[4026531840]", 4096) = 16                                                                                                                                                                                    
readlink("/proc/13160/ns/mnt", "mnt:[4026531840]", 4096) = 16                                                                                                                                                                                   
readlink("/proc/13160/exe", "/usr/bin/python3.6", 4096) = 18                                                                                                                                                                                    
open("/usr/bin/python3.6", O_RDONLY)    = 5                                                                                                                                                                                                     
lseek(5, 0, SEEK_END)                   = 4789488                                                                                                                                                                                               
mmap(NULL, 4789488, PROT_READ, MAP_SHARED, 5, 0) = 0x7ff9007be000                                                                                                                                                                               
close(5)                                = 0                                                                                                                                                                                                     
open("/proc/13160/maps", O_RDONLY)      = 5                                                                                                                                                                                                     
read(5, "55aaf333c000-55aaf3730000 r-xp 0"..., 8191) = 4080                                                                                                                                                                                     
close(5)                                = 0                                                                                                                                                                                                     
munmap(0x7ff9007be000, 4789488)         = 0                                                                                                                                                                                                     
ptrace(PTRACE_GETREGS, 13160, NULL, 0x7ffd1be4f650) = 0                                                                                                                                                                                         
ptrace(PTRACE_SETREGS, 13160, NULL, 0x7ffd1be4f470) = 0                                                                                                                                                                                         
ptrace(PTRACE_CONT, 13160, NULL, SIG_0) = 0                                                                                                                                                                                                     
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_TRAPPED, si_pid=13160, si_uid=1000, si_status=SIGTRAP, si_utime=28249, si_stime=1546} ---                                                                                                            
wait4(13160, [{WIFSTOPPED(s) && WSTOPSIG(s) == SIGTRAP}], 0, NULL) = 13160                                                                                                                                                                      
ptrace(PTRACE_GETREGS, 13160, NULL, 0x7ffd1be4f730) = 0                                                                                                                                                                                         
ptrace(PTRACE_SETREGS, 13160, NULL, 0x7ffd1be4f470) = 0                                                                                                                                                                                         
clock_gettime(CLOCK_REALTIME, {1496670627, 162034937}) = 0                                                                                                                                                                                      
clock_gettime(CLOCK_REALTIME, {1496670627, 162109762}) = 0                                                                                                                                                                                      
ptrace(PTRACE_PEEKDATA, 13160, 0x55aaf39d0e90, [0]) = 0                                                                                                                                                                                         
ptrace(PTRACE_PEEKDATA, 13160, 0x55aaf49b3568, [0x55aaf6158520]) = 0                                                                                                                                                                            
ptrace(PTRACE_PEEKDATA, 13160, 0x55aaf61585b8, [0x7f20fa41b700]) = 0                                                                                                                                                                            
ptrace(PTRACE_PEEKDATA, 13160, 0x55aaf6158538, [0x55aaf6881e58]) = 0                                                                                                                                                                            
ptrace(PTRACE_PEEKDATA, 13160, 0x55aaf6881e78, [0x7f21514d4930]) = 0                                                                                                                                                                            
ptrace(PTRACE_PEEKDATA, 13160, 0x7f21514d4990, [0x7f215151ce40]) = 0                                                                                                                                                                            
ptrace(PTRACE_PEEKDATA, 13160, 0x7f215151ce70, [0x77702f656d6f682f]) = 0                                                                                                                                                                        
ptrace(PTRACE_PEEKDATA, 13160, 0x7f215151ce78, [0x6c2e2f72656c6c61]) = 0                                                                                                                                                                        
ptrace(PTRACE_PEEKDATA, 13160, 0x7f215151ce80, [0x62696c2f6c61636f]) = 0                                                                                                                                                                        
ptrace(PTRACE_PEEKDATA, 13160, 0x7f215151ce88, [0x336e6f687479702f]) = 0                                                                                                                                                                        
ptrace(PTRACE_PEEKDATA, 13160, 0x7f215151ce90, [0x2d657469732f362e]) = 0                                                                                                                                                                        
ptrace(PTRACE_PEEKDATA, 13160, 0x7f215151ce98, [0x736567616b636170]) = 0                                                                                                                                                                        
ptrace(PTRACE_PEEKDATA, 13160, 0x7f215151cea0, [0x6775732f716d7a2f]) = 0                                                                                                                                                                        
ptrace(PTRACE_PEEKDATA, 13160, 0x7f215151cea8, [0x2e6c6c6f702f7261]) = 0                                                                                                                                                                        
ptrace(PTRACE_PEEKDATA, 13160, 0x7f215151ceb0, [0x6f732e33007970]) = 0                                                                                                                                                                          
ptrace(PTRACE_PEEKDATA, 13160, 0x7f21514d4998, [0x7f2154911880]) = 0                                                                                                                                                                            
ptrace(PTRACE_PEEKDATA, 13160, 0x7f21549118b0, [0x6c6c6f70]) = 0                                                                                                                                                                                
ptrace(PTRACE_PEEKDATA, 13160, 0x55aaf6881ea8, [0]) = 0                                                                                                                                                                                         
ptrace(PTRACE_PEEKDATA, 13160, 0x55aaf6881ed0, [0x4d00000032]) = 0                                                                                                                                                                              
ptrace(PTRACE_PEEKDATA, 13160, 0x7f21514d49a8, [0]) = 0                                                                                                                                                                                         
ptrace(PTRACE_PEEKDATA, 13160, 0x10, 0x7ffd1be4f668) = -1 EIO (Input/output error)

@pwaller
Copy link

pwaller commented Jun 5, 2017

Stack trace of pyflame (expand below). frob.cc:91 @ 36e9795 looks to be the culprit.

#0  pyflame::PtracePeek (pid=pid@entry=13160, addr=16) at ptrace.cc:86
#1  0x000055555556166f in pyflame::py3::GetLine (pid=13160, frame=94192768917080, f_code=139781074667824) at ./frob.cc:91
#2  0x00005555555617d6 in pyflame::py3::FollowFrame (pid=pid@entry=13160, frame=94192768917080, stack=stack@entry=0x7fffffffdd10) at ./frob.cc:122
#3  0x0000555555561b91 in pyflame::py3::GetThreads (pid=13160, addrs=..., enable_threads=true) at ./frob.cc:175
#4  0x000055555555e093 in pyflame::PyFrob::GetThreads (this=<optimized out>) at pyfrob.cc:165
#5  0x00005555555576b9 in main (argc=<optimized out>, argv=<optimized out>) at pyflame.cc:293

@pwaller
Copy link

pwaller commented Jun 5, 2017

Success! Made it work.

The problem was that configure was picking up pkg-config for the wrong version of python, so the PyCodeObject struct definition was different between what was compiled in to pyflame and what was running.

To fix this I edited configure.ac to read (changed [python3] to [python-3.6])...

PKG_CHECK_MODULES([PY3], [python-3.6], [enable_py3="yes"], [AC_MSG_WARN([Building without Python 3 support])])

Not sure of a good way of forcing this without editing the autoconf (e.g, via the ./configure options).

It would be useful if there was a sanity check comparing the compiled-in-to-pyflame python version vs the one which is running.

Thanks for a great tool :)

@jackvreeken
Copy link
Contributor

jackvreeken commented Jun 6, 2017

Just to add to pwaller's post, this is caused by this PEP which changes the PyCodeObject. Maybe it is possible to support both >=3.6 and <3.6 by some dynamic check for this field, if the user has multiple Python 3 versions installed. Note that the PEP adds functionality that may or may not be interesting for this project, to quote:

This ability to specify a frame evaluation function also allows for other use-cases beyond just opening CPython up to a JIT. For instance, it would not be difficult to implement a tracing or profiling function at the call level with this API.

@eklitzke
Copy link
Collaborator

eklitzke commented Jul 12, 2017

I looked into this a little bit this evening. Here's what I found:

On Debian/Ubuntu Pyflame is broken using Python 3.6 as described here. However, on my Fedora laptop (which is also running Python 3.6.1), Pyflame master works fine. So checking the Python version is not sufficient. The exact version of the package I have installed on Fedora is python3-3.6.1-8.fc26.src.rpm. Since I personally run Fedora, it is important to me that a fix for this issue doesn't break Fedora.

Currently the master test suite of Pyflame is failing, because somehow Travis changed and it's actually running Python 3.6 for the unit tests that are configured to run as Python 3.4 and Python 3.5, and thus tests are failing due to this bug. The fact that Travis is misconfigured is another issue I'm tracking at #76

It's possible that Fedora is applying a patch to Python 3 to undo PEP 523, but it doesn't seem likely. I haven't gone through the source RPM yet, but I see that my header files have the changes described in PEP 523, and my libpython has the new symbols:

$ nm -D /lib64/libpython3.6m.so.1.0 | grep _PyCode_[GS]etExtra
00000000000724e2 T _PyCode_GetExtra
00000000000723cd T _PyCode_SetExtra

I am going to have to dig deeper to figure out what the root cause is. Here are two possibilities that I can think of right now. Scenario A: Fedora patches the Python source in some incredibly strange way that disables the new Python frame API, but for some reason kept the new symbols (and headers). Scenario B: this is somehow caused by the fact that Debian embeds the Python symbols, whereas Fedora dynamically links the symbols from libpython, and somehow that affects the code object/frame API.

Both of these could be worked around, but both of them also seem very unlikely to me. I should have time to investigate further tomorrow.

@jmphilli
Copy link
Contributor

thanks for looking into this! i'd be happy to help! the pr i've got open definitely fixes it for my ubuntu 14.04 install, but yes 💯 don't want to break fedora. let me know what you turn up and i'd be happy to update my pr or be a guinea pig for changes

@eklitzke
Copy link
Collaborator

It looks like #70 works with Fedora, so nothing needs to change there. However, there are some other minor changes that need to be made, which I have noted on the PR. This is looking pretty good though -- I think we're close to being able to merge the branch.

@eklitzke
Copy link
Collaborator

It looks like the offset of co_firstlineno was changed In Python 3.6. Here's what I see in a diff of code.h from Python 3.4 and Python 3.6:

@@ -15,21 +25,29 @@
     int co_nlocals;		/* #local variables */
     int co_stacksize;		/* #entries needed for evaluation stack */
     int co_flags;		/* CO_..., see below */
+    int co_firstlineno;   /* first source line number */
     PyObject *co_code;		/* instruction opcodes */
     PyObject *co_consts;	/* list (constants used) */
     PyObject *co_names;		/* list of strings (names used) */
     PyObject *co_varnames;	/* tuple of strings (local variable names) */
     PyObject *co_freevars;	/* tuple of strings (free variable names) */
     PyObject *co_cellvars;      /* tuple of strings (cell variable names) */
-    /* The rest doesn't count for hash or comparisons */
+    /* The rest aren't used in either hash or comparisons, except for co_name,
+       used in both. This is done to preserve the name and line number
+       for tracebacks and debuggers; otherwise, constant de-duplication
+       would collapse identical functions/lambdas defined on different lines.
+    */
     unsigned char *co_cell2arg; /* Maps cell vars which are arguments. */
     PyObject *co_filename;	/* unicode (where it was loaded from) */
     PyObject *co_name;		/* unicode (name, for reference) */
-    int co_firstlineno;		/* first source line number */
     PyObject *co_lnotab;	/* string (encoding addr<->lineno mapping) See
 				   Objects/lnotab_notes.txt for details. */

This breaks things because now the offsetof() functions are using the offset for whatever python3.pc exports, which is wrong if there are multiple versions of Python 3 installed on a host. Pyflame master works for me because the only version of Python 3 I have installed is Python 3.6.

@jmphilli Is going to update his diff to change the configure.ac to never check against python3.pc, intead we'll explicitly check python-3.4.pc, python-3.5.pc, python-3.6.pc, etc.

@eklitzke
Copy link
Collaborator

This change is landed! Thanks to @jmphilli for the hard work!

To summarize the change:

  • If python-3.4.pc or python-3.5.pc files are on the system when Pyflame is compiled, it knows how to profile those Python versions
  • If python-3.6.pc is present, Pyflame will know how to profile Python 3.6

When new Python versions are released, assuming they don't break the ABI, the process should be just updating the configure.ac in this repo, and it should not require changes to the .cc or .h source files. If the configure.ac gets unwieldly in the future, I can look into writing some autoconf macros to clean up the Python version detection logic.

@eklitzke
Copy link
Collaborator

P.S. I tagged the release with this fix as 1.4.0, so that's the minimum version you need for the fix.

@jacg
Copy link

jacg commented Sep 9, 2017

If python-3.6.pc is present, Pyflame will know how to profile Python 3.6

I'm guessing that this applies to it being present in standard system locations. How can pyflame be made to work with Pythons installed with conda?

@nathantsoi
Copy link

w/ pyenv, for some reason, i had to

find ~/.pyenv/ -iname python-3.6.pc
export PKG_CONFIG_PATH=~/.pyenv/versions/3.6.3/lib/pkgconfig/
#rebuild

@darindf
Copy link

darindf commented May 14, 2018

For conda use similar approach

sudo find ~/anaconda3 -iname python-*.pc
export PKG_CONFIG_PATH=~/anaconda3/lib/pkgconfig

@ctrlbrett
Copy link

I am hitting trouble with miniconda on Python 3.6.7

python --version
Python 3.6.7 :: Anaconda, Inc.

I am utilizing the approach darindf recommended for conda:

sudo find ~/miniconda3 -iname python-*.pc # (find the pkgconfig directories)
export PKG_CONFIG_PATH=/home/brett/miniconda3/envs/far5/lib/pkgconfig/ # (far5 is the env I am using)
...build the normal way

(I am using the same conda environment to find the pkgconfig as the python program I am trying to trace), but I am getting

sudo ./pyflame -d --threads -p  15657                 
terminate called after throwing an instance of 'pyflame::PtraceException'
  what():  Failed to PTRACE_PEEKDATA (pid 15657, addr 0x55a8639c3508): Input/output error

For reference, i am trying to do this witha very minimal example:

import time

i = 0
while True:
    time.sleep(3)
    print('running', i)
    i += 1

@nitishgupta
Copy link

Bump! I'm having the same issue with miniconda. Followed the steps from @darindf but still get the Unexpected ptrace(2) exception: Failed to PTRACE_PEEKDATA error.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

10 participants