[Python-Dev] Internal counter to debug leaking file descriptors

[David Malcolm]

On Tue, 2010-08-31 at 17:40 +0000, exarkun at twistedmatrix.com wrote:
> On 05:22 pm, glyph at twistedmatrix.com wrote:
> >
> >On Aug 31, 2010, at 10:03 AM, Guido van Rossum wrote:
> >>On Linux you can look somewhere in /proc, but I don't know that it
> >>would help you find where a file was opened.
> >
> >"/dev/fd" is actually a somewhat portable way of getting this 
> >information.  I don't think it's part of a standard, but on Linux it's 
> >usually a symlink to "/proc/self/fd", and it's available on MacOS and 
> >most BSDs (based on a hasty and completely-not-comprehensive 
> >investigation).  But it won't help you find out when the FDs were 
> >originally opened, no.
> >_______________________________________________
> 
> On OS X and Solaris, dtrace and ustack will tell you exactly when and 
> where the FDs were originally opened, though.  On Linux, SystemTap might 
> give you the same information (but I know much less about SystemTap). 
> If http://bugs.python.org/issue4111 is resolved, then this may even be 
> possible without using a patched version of Python.

I believe you can do something like this:
$ cat /tmp/trace-all-syscalls.stp 
/*
  Watch all syscalls in a specified process, dumping a user-space
  backtrace 
*/
probe syscall.* {
  if (pid() == target()) {
      printf("%s(%s)\n", probefunc(), argstr)
      print_ubacktrace();
  }
}

$ sudo stap --ldd -d /usr/bin/python /tmp/trace-all-syscalls.stp -c "python -c 'print 42'"

This generates a torrent of debug data like this:
sys_mmap_pgoff(0x0, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0)
 0x38f44e17aa : mmap64+0xa/0x30 [libc-2.11.90.so]
 0x38f44673fc : _IO_file_doallocate+0x7c/0x110 [libc-2.11.90.so]
 0x38f447498c : _IO_doallocbuf+0x2c/0x50 [libc-2.11.90.so]
 0x38f4472ef4 : _IO_file_underflow@@GLIBC_2.2.5+0x1b4/0x230 [libc-2.11.90.so]
 0x38f44749ce : _IO_default_uflow+0xe/0x30 [libc-2.11.90.so]
 0x38f446fdcb : getc+0xab/0xf0 [libc-2.11.90.so]
 0x39054f3e13 : r_long+0x23/0x120 [libpython2.6.so.1.0]
 0x39054f3f3b : PyMarshal_ReadLongFromFile+0x2b/0x30 [libpython2.6.so.1.0]
 0x39054f0661 : load_source_module+0x271/0x640 [libpython2.6.so.1.0]
 0x39054f1cc5 : import_submodule+0x155/0x300 [libpython2.6.so.1.0]
 0x39054f1f85 : load_next+0x115/0x2a0 [libpython2.6.so.1.0]
 0x39054f2592 : import_module_level+0x212/0x730 [libpython2.6.so.1.0]
 0x39054f3314 : PyImport_ImportModuleLevel+0x44/0xb0 [libpython2.6.so.1.0]
 0x39054d843f : builtin___import__+0x8f/0xa0 [libpython2.6.so.1.0]
 0x3905443f43 : PyObject_Call+0x53/0x100 [libpython2.6.so.1.0]
 0x39054d89b3 : PyEval_CallObjectWithKeywords+0x43/0xf0 [libpython2.6.so.1.0]
 0x39054db674 : PyEval_EvalFrameEx+0x21b4/0x65b0 [libpython2.6.so.1.0]
 0x39054e03a8 : PyEval_EvalCodeEx+0x938/0x9e0 [libpython2.6.so.1.0]
 0x39054e0482 : PyEval_EvalCode+0x32/0x40 [libpython2.6.so.1.0]
 0x39054f02c2 : PyImport_ExecCodeModuleEx+0xc2/0x1f0 [libpython2.6.so.1.0]
 0x39054f07a6 : load_source_module+0x3b6/0x640 [libpython2.6.so.1.0]


You may want to specify specific syscalls in the above to narrow the
scope.

Issue 4111 patches cpython to statically mark Python frame entry/exit so
that systemtap can directly instrument that; in Fedora 13 onwards I've
built Python with systemtap hooks so that you can add:

probe python.function.entry {
    printf("%s:%s:%d\n", filename, funcname, lineno);
}


(Arguably this is wrong, it's frame entry/exit, rather than function
entry/exit).

Potentially systemtap could be taught how to decipher/prettyprint Python
backtraces in a similar way to how gdb does it (by hooking into
PyEval_EvalFrameEx)


Hope this is helpful
Dave