diff -r 99ef4501205b .hgignore --- a/.hgignore Thu May 10 16:11:12 2012 +0100 +++ b/.hgignore Thu May 10 16:53:13 2012 -0400 @@ -19,6 +19,7 @@ python.exe$ reflog.txt$ tags$ +Include/pysystemtap.h Lib/plat-mac/errors.rsrc.df.rsrc Doc/tools/sphinx/ Doc/tools/docutils/ diff -r 99ef4501205b Doc/using/index.rst --- a/Doc/using/index.rst Thu May 10 16:11:12 2012 +0100 +++ b/Doc/using/index.rst Thu May 10 16:53:13 2012 -0400 @@ -17,4 +17,5 @@ unix.rst windows.rst mac.rst + systemtap.rst diff -r 99ef4501205b Doc/using/systemtap.rst --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/Doc/using/systemtap.rst Thu May 10 16:53:13 2012 -0400 @@ -0,0 +1,168 @@ +Debugging and Instrumentation +============================= + +DTrace and SystemTap are monitoring tools, each providing a way to inspect +what the processes on a computer system are doing. They both use +domain-specific languages to express + + - filtering which processes are to be observed + - gathering data from the processes of interest + - generating reports on the data + +As of Python 3.3, CPython can be built with embedded "markers" that can be +observed by a SystemTap script, making it easier to monitor what the CPython +processes on a system are doing. + +.. impl-detail:: + + This is an implementation detail of the CPython implementation of Python. + Other implementations may or may not offer similar functionality. See + :ref:`implementations` for further resources. + +Enabling the static markers +--------------------------- + +In order to build CPython with the embedded markers for SystemTap, the +SystemTap development tools must be installed. + +On a Fedora or Red Hat Enterprise Linux machine, this can be done via:: + + yum install systemtap-sdt-devel + +CPython must then be configured `--with-systemtap`:: + + checking for --with-systemtap... yes + +You can verify if the SystemTap static markers are present in the built +binary by seeing if it contains a ".note.stapsdt" section. + +.. code-block:: bash + + $ eu-readelf -S ./python | grep .note.stapsdt + [29] .note.stapsdt NOTE 0000000000000000 00308d78 000000b8 0 0 0 4 + +If you've built python as a shared library (with --enable-shared), you need +to look instead within the shared library. For example: + +.. code-block:: bash + + $ eu-readelf -S libpython3.3dm.so.1.0 | grep .note.stapsdt + [28] .note.stapsdt NOTE 0000000000000000 00365b68 000000b8 0 0 0 4 + +Earlier versions of SystemTap stored the markers in a ".probes" section. + +For the curious, you can see the metadata for the static markers using this +invocation. + +.. code-block:: bash + + $ eu-readelf -x .note.stapsdt ./python + + Hex dump of section [29] '.note.stapsdt', 184 bytes at offset 0x308d78: + 0x00000000 08000000 45000000 03000000 73746170 ....E.......stap + 0x00000010 73647400 d4664b00 00000000 4fc36600 sdt..fK.....O.f. + 0x00000020 00000000 488d9000 00000000 70797468 ....H.......pyth + 0x00000030 6f6e0066 756e6374 696f6e5f 5f656e74 on.function__ent + 0x00000040 72790038 40257261 78203840 25726478 ry.8@%rax 8@%rdx + 0x00000050 202d3440 25656378 00000000 08000000 -4@%ecx........ + 0x00000060 46000000 03000000 73746170 73647400 F.......stapsdt. + 0x00000070 0d674b00 00000000 4fc36600 00000000 .gK.....O.f..... + 0x00000080 4a8d9000 00000000 70797468 6f6e0066 J.......python.f + 0x00000090 756e6374 696f6e5f 5f726574 75726e00 unction__return. + 0x000000a0 38402572 61782038 40257264 78202d34 8@%rax 8@%rdx -4 + 0x000000b0 40256563 78000000 @%ecx... + +The above metadata contains information for SystemTap describing how it can +patch strategically-placed machine code "nop" instructions to enable the +tracing hooks used by a SystemTap script. + + +Static markers +-------------- + +The low-level way to use the SystemTap integration is to use the static +markers directly. This requires you to explicitly state the binary file +containing them. + +For example, this script can be used to show the call/return hierarchy of a +Python script:: + + probe process('python').mark("function__entry") { + filename = user_string($arg1); + funcname = user_string($arg2); + lineno = $arg3; + + printf("%s => %s in %s:%d\\n", thread_indent(1), funcname, filename, lineno); + } + + probe process('python').mark("function__return") { + filename = user_string($arg1); + funcname = user_string($arg2); + lineno = $arg3; + + printf("%s <= %s in %s:%d\\n", thread_indent(-1), funcname, filename, lineno); + } + +It can be invoked like this: + +.. code-block:: bash + + $ stap \ + show-call-hierarchy.stp \ + -c ./python test.py + +The output looks like this:: + + 11408 python(8274): => __contains__ in Lib/_abcoll.py:362 + 11414 python(8274): => __getitem__ in Lib/os.py:425 + 11418 python(8274): => encode in Lib/os.py:490 + 11424 python(8274): <= encode in Lib/os.py:493 + 11428 python(8274): <= __getitem__ in Lib/os.py:426 + 11433 python(8274): <= __contains__ in Lib/_abcoll.py:366 + +where the columns are: + + - time in microseconds since start of script + + - name of executable + + - PID of process + +and the remainder indicates the call/return hierarchy as the script executes. + +For a `--enable-shared` build of CPython, the markers are contained within the +libpython shared library, and the probe's dotted path needs to reflect this. For +example, this line from the above example:: + + probe process('python').mark("function__entry") { + +should instead read:: + + probe process('python').library("libpython3.3dm.so.1.0").mark("function__entry") { + +(assuming a debug build of CPython 3.3) + +.. I'm reusing the "c:function" type for markers + +.. c:function:: function__entry(str filename, str funcname, int lineno) + + This marker indicates that execution of a Python function has begun. It is + only triggered for pure-python (bytecode) functions. + + The filename, function name, and line number are provided back to the + tracing script as positional arguments, which must be accessed using $arg1, $arg2 + + Example: probing all python files visited as a program implemented in Python + runs: + + .. code-block:: bash + + $ stap \ + -e'probe process("./python").function.entry {log(filename);}' \ + -c ./python test.py + +.. c:function:: function__return(str filename, str funcname, int lineno) + + This marker is the converse of `function__entry`, and indicates that + execution of a Python function has ended (either via ``return``, or via an + exception). It is only triggered for pure-python (bytecode) functions. diff -r 99ef4501205b Include/pysystemtap.d --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/Include/pysystemtap.d Thu May 10 16:53:13 2012 -0400 @@ -0,0 +1,10 @@ +provider python { + probe function__entry(const char *, const char *, int); + probe function__return(const char *, const char *, int); +}; + +#pragma D attributes Evolving/Evolving/Common provider python provider +#pragma D attributes Private/Private/Common provider python module +#pragma D attributes Private/Private/Common provider python function +#pragma D attributes Evolving/Evolving/Common provider python name +#pragma D attributes Evolving/Evolving/Common provider python args diff -r 99ef4501205b Lib/test/test_systemtap.py --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/Lib/test/test_systemtap.py Thu May 10 16:53:13 2012 -0400 @@ -0,0 +1,194 @@ +# Verify that systemtap static probes work +# +import subprocess +import sys +import sysconfig +import os +import unittest + +from test.support import run_unittest, TESTFN, unlink + +try: + _, stap_version = subprocess.Popen(["stap", "-V"], + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + ).communicate() +except OSError: + # This is what "no stap" looks like. There may, however, be other + # errors that manifest this way too. + raise unittest.SkipTest("Couldn't find stap on the path") + +def invoke_systemtap_script(script, pythoncode="pass", pythonfile=None): + # Start a child python process, probing with the given systemtap script + # (passed as stdin to the "stap" tool) + # The script should be a bytes instance + # Return (stdout, stderr) pair + + if pythonfile: + pythoncmd = '%s %s' % (sys.executable, pythonfile) + else: + pythoncmd = '%s -c %r' % (sys.executable, pythoncode) + + # The process tree of a stap invocation of a command goes through + # something like this: + # stap ->fork/exec(staprun; exec stapio ->f/e(-c cmd); exec staprun -r) + # and this trip trhough setuid leads to LD_LIBRARY_PATH being dropped, + # which would lead to an --enable-shared build of python failing to be + # find its libpython, with an error like: + # error while loading shared libraries: libpython3.3dm.so.1.0: cannot + # open shared object file: No such file or directory + # Hence we need to jump through some hoops to expose LD_LIBRARY_PATH to + # the invoked python process: + LD_LIBRARY_PATH = os.environ.get('LD_LIBRARY_PATH', '') + if LD_LIBRARY_PATH: + pythoncmd = 'env LD_LIBRARY_PATH=%s ' % LD_LIBRARY_PATH + pythoncmd + + p = subprocess.Popen(["stap", "-", '-v', '-c', pythoncmd], + stdin=subprocess.PIPE, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE) + out, err = p.communicate(input=script) + return out, err + +# Verify that stap can run a simple "hello world"-style script +# This can fail for various reasons: +# - missing kernel headers +# - permissions (a non-root user needs to be in the "stapdev" group) +TRIVIAL_STAP_SCRIPT = b'probe begin { println("hello world") exit () }' + +out, err = invoke_systemtap_script(TRIVIAL_STAP_SCRIPT) + +if out != b'hello world\n': + raise unittest.SkipTest("Test systemtap script did not run; stderr was: %s" % err) + +# We don't expect stderr to be empty, since we're invoking stap with "-v": stap +# will (we hope) generate debugging output on stderr. + +# The following script ought to generate lots of lines showing recursive +# function entry and return, of the form: +# 11408 python(8274): => __contains__ in Lib/_abcoll.py:362 +# 11414 python(8274): => __getitem__ in Lib/os.py:425 +# 11418 python(8274): => encode in Lib/os.py:490 +# 11424 python(8274): <= encode in Lib/os.py:493 +# 11428 python(8274): <= __getitem__ in Lib/os.py:426 +# 11433 python(8274): <= __contains__ in Lib/_abcoll.py:366 +# where the column are: +# - time in microseconds since start of script +# - name of executable +# - PID of process +# and the remainder indicates the call/return hierarchy + +# We need to supply the prefix of a systemtap dotted probe point that +# contains the static marker. +# See http://sourceware.org/systemtap/langref/Probe_points.html +# +# We need to determine if this is a shared-library build +# +# Note that sysconfig can get this wrong; see: +# http://bugs.python.org/issue14774 +# +if '--enable-shared' in sysconfig.get_config_var('CONFIG_ARGS'): + # For a shared-library build, the markers are in library(INSTSONAME): + INSTSONAME = sysconfig.get_config_var('INSTSONAME') + probe_prefix = 'process("%s").library("%s")' % (sys.executable, INSTSONAME) +else: + # For a non-shared-library build, we can simply use sys.executable: + probe_prefix = 'process("%s")' % sys.executable + +hierarchy_script = (''' +probe %s.mark("function__entry") { + filename = user_string($arg1); + funcname = user_string($arg2); + lineno = $arg3; + + printf("%%s => %%s in %%s:%%d\\n", thread_indent(1), funcname, filename, lineno); +} + +probe %s.mark("function__return") { + filename = user_string($arg1); + funcname = user_string($arg2); + lineno = $arg3; + + printf("%%s <= %%s in %%s:%%d\\n", thread_indent(-1), funcname, filename, lineno); +} +''' % (probe_prefix, probe_prefix)).encode('utf-8') + + +class ErrorDumper: + # A context manager that dumps extra information if an exception is raised, + # to help track down why the problem occurred + def __init__(self, out, err): + self.out = out + self.err = err + + def __enter__(self): + pass + + def __exit__(self, type_, value, traceback): + if type_: + # an exception is being raised: + print('stdout: %s' % out.decode()) + print('stderr: %s' % err.decode()) + +class SystemtapTests(unittest.TestCase): + + def test_invoking_python(self): + # Ensure that we can invoke python under stap, with a trivial stap + # script: + out, err = invoke_systemtap_script(b'probe begin { println("hello from stap") exit () }', + pythoncode="print('hello from python')") + with ErrorDumper(out, err): + self.assertIn(b'hello from stap', out) + self.assertIn(b'hello from python', out) + + def test_function_entry(self): + # Ensure that the function_entry static marker works + out, err = invoke_systemtap_script(hierarchy_script) + # stdout ought to contain various lines showing recursive function + # entry and return (see above) + + # Uncomment this for debugging purposes: + # print(out.decode('utf-8')) + + # Executing the cmdline-supplied "pass": + # 0 python(8274): => in :1 + # 5 python(8274): <= in :1 + with ErrorDumper(out, err): + self.assertIn(b'=> in :1', out, + msg="stdout: %s\nstderr: %s\n" % (out, err)) + + def test_encoding(self): + # Ensure that scripts and function names containing non-Latin 1 code + # points are handled: + pythonfile = TESTFN + '_☠.py' + try: + unlink(pythonfile) + f = open(pythonfile, "wb") + f.write(""" +# Sample script with non-ASCII filename, for use by test_systemtap.py +# Implicitly UTF-8 + +def 文字化け(): + '''Function with non-ASCII identifier; I believe this reads "mojibake"''' + print("hello world!") + +文字化け() +""".encode('utf-8')) + f.close() + + out, err = invoke_systemtap_script(hierarchy_script, + pythonfile=pythonfile) + out_utf8 = out.decode('utf-8') + with ErrorDumper(out, err): + self.assertIn('=> in %s:5' % pythonfile, out_utf8) + self.assertIn(' => 文字化け in %s:5' % pythonfile, out_utf8) + self.assertIn(' <= 文字化け in %s:7' % pythonfile, out_utf8) + self.assertIn('<= in %s:9' % pythonfile, out_utf8) + finally: + unlink(pythonfile) + +def test_main(): + run_unittest(SystemtapTests) + +if __name__ == "__main__": + test_main() diff -r 99ef4501205b Makefile.pre.in --- a/Makefile.pre.in Thu May 10 16:11:12 2012 +0100 +++ b/Makefile.pre.in Thu May 10 16:53:13 2012 -0400 @@ -359,6 +359,7 @@ Python/formatter_unicode.o \ Python/fileutils.o \ Python/$(DYNLOADFILE) \ + @SYSTEMTAPOBJS@ \ $(LIBOBJS) \ $(MACHDEP_OBJS) \ $(THREADOBJ) @@ -708,7 +709,7 @@ $(OPCODETARGETS_H): $(OPCODETARGETGEN_FILES) $(OPCODETARGETGEN) $(OPCODETARGETS_H) -Python/ceval.o: $(OPCODETARGETS_H) $(srcdir)/Python/ceval_gil.h +Python/ceval.o: $(OPCODETARGETS_H) $(srcdir)/Python/ceval_gil.h $(srcdir)/Include/pysystemtap.h Python/formatter_unicode.o: $(srcdir)/Python/formatter_unicode.c \ $(BYTESTR_DEPS) @@ -719,6 +720,13 @@ $(srcdir)/Objects/typeslots.inc: $(srcdir)/Include/typeslots.h $(srcdir)/Objects/typeslots.py $(PYTHON) $(srcdir)/Objects/typeslots.py < $(srcdir)/Include/typeslots.h > $(srcdir)/Objects/typeslots.inc +# Only needed with --with-systemtap +$(srcdir)/Include/pysystemtap.h: $(srcdir)/Include/pysystemtap.d + dtrace -o $@ $(DFLAGS) -C -h -s $(srcdir)/Include/pysystemtap.d + +Python/pysystemtap.o: $(srcdir)/Include/pysystemtap.d Python/ceval.o + dtrace -o $@ $(DFLAGS) -C -G -s $(srcdir)/Include/pysystemtap.d Python/ceval.o + ############################################################################ # Header files diff -r 99ef4501205b Python/ceval.c --- a/Python/ceval.c Thu May 10 16:11:12 2012 +0100 +++ b/Python/ceval.c Thu May 10 16:53:13 2012 -0400 @@ -18,6 +18,10 @@ #include +#ifdef WITH_SYSTEMTAP +#include "pysystemtap.h" +#endif + #ifndef WITH_TSC #define READ_TIMESTAMP(var) @@ -777,6 +781,76 @@ } +#ifdef WITH_SYSTEMTAP +struct frame_marker_info +{ + PyObject *filename_obj; + PyObject *funcname_obj; + const char *filename; + const char *funcname; + int lineno; +}; + +static void +get_frame_marker_info(PyFrameObject *f, struct frame_marker_info *fmi) +{ + PyObject *ptype; + PyObject *pvalue; + PyObject *ptraceback; + + PyErr_Fetch(&ptype, &pvalue, &ptraceback); + + fmi->filename_obj = PyUnicode_EncodeFSDefault(f->f_code->co_filename); + if (fmi->filename_obj) { + fmi->filename = PyBytes_AsString(fmi->filename_obj); + } else { + fmi->filename = NULL; + } + + fmi->funcname_obj = PyUnicode_AsUTF8String(f->f_code->co_name); + if (fmi->funcname_obj) { + fmi->funcname = PyBytes_AsString(fmi->funcname_obj); + } else { + fmi->funcname = NULL; + } + + fmi->lineno = PyCode_Addr2Line(f->f_code, f->f_lasti); + + PyErr_Restore(ptype, pvalue, ptraceback); + +} + +static void +release_frame_marker_info(struct frame_marker_info *fmi) +{ + Py_XDECREF(fmi->filename_obj); + Py_XDECREF(fmi->funcname_obj); +} + +static void +systemtap_function_entry(PyFrameObject *f) +{ + struct frame_marker_info fmi; + get_frame_marker_info(f, &fmi); + PYTHON_FUNCTION_ENTRY(fmi.filename, fmi.funcname, fmi.lineno); + release_frame_marker_info(&fmi); +} + +static void +systemtap_function_return(PyFrameObject *f) +{ + struct frame_marker_info fmi; + get_frame_marker_info(f, &fmi); + PYTHON_FUNCTION_RETURN(fmi.filename, fmi.funcname, fmi.lineno); + release_frame_marker_info(&fmi); +} +#else +#define PYTHON_FUNCTION_ENTRY_ENABLED() 0 +#define PYTHON_FUNCTION_RETURN_ENABLED() 0 +#define systemtap_function_entry(f) +#define systemtap_function_return(f) +#endif + /* Interpreter main loop */ PyObject * @@ -1160,6 +1234,10 @@ } } + if (PYTHON_FUNCTION_ENTRY_ENABLED()) { + systemtap_function_entry(f); + } + co = f->f_code; names = co->co_names; consts = co->co_consts; @@ -3077,6 +3155,9 @@ /* pop frame */ exit_eval_frame: + if (PYTHON_FUNCTION_RETURN_ENABLED()) { + systemtap_function_return(f); + } Py_LeaveRecursiveCall(); tstate->frame = f->f_back; diff -r 99ef4501205b configure --- a/configure Thu May 10 16:11:12 2012 +0100 +++ b/configure Thu May 10 16:53:13 2012 -0400 @@ -618,6 +618,7 @@ MACHDEP_OBJS DYNLOADFILE DLINCLDIR +SYSTEMTAPOBJS THREADOBJ LDLAST USE_THREAD_MODULE @@ -773,6 +774,7 @@ with_tsc with_pymalloc with_valgrind +with_systemtap with_fpectl with_libm with_libc @@ -1450,6 +1452,7 @@ --with(out)-tsc enable/disable timestamp counter profile --with(out)-pymalloc disable/enable specialized mallocs --with-valgrind Enable Valgrind support + --with(out)-systemtap disable/enable SystemTap support --with-fpectl enable SIGFPE catching --with-libm=STRING math library --with-libc=STRING C library @@ -9492,6 +9495,37 @@ OPT="-DDYNAMIC_ANNOTATIONS_ENABLED=1 $OPT" fi +# Check for systemtap support +# On Linux, /usr/bin/dtrace is in fact a shim to SystemTap +{ $as_echo "$as_me:${as_lineno-$LINENO}: checking for --with-systemtap" >&5 +$as_echo_n "checking for --with-systemtap... " >&6; } + +# Check whether --with-systemtap was given. +if test "${with_systemtap+set}" = set; then : + withval=$with_systemtap; +else + with_systemtap=no +fi + +{ $as_echo "$as_me:${as_lineno-$LINENO}: result: $with_systemtap" >&5 +$as_echo "$with_systemtap" >&6; } +if test ! -z "$with_systemtap" +then + if dtrace -G -o /dev/null -s $srcdir/Include/pysystemtap.d 2>/dev/null + then + +$as_echo "#define WITH_SYSTEMTAP 1" >>confdefs.h + + SYSTEMTAPOBJS="Python/pysystemtap.o" + else + with_systemtap="no" + fi +else + with_systemtap="no" +fi + + + # -I${DLINCLDIR} is added to the compile rule for importdl.o DLINCLDIR=. diff -r 99ef4501205b configure.ac --- a/configure.ac Thu May 10 16:11:12 2012 +0100 +++ b/configure.ac Thu May 10 16:53:13 2012 -0400 @@ -2537,6 +2537,29 @@ OPT="-DDYNAMIC_ANNOTATIONS_ENABLED=1 $OPT" fi +# Check for systemtap support +# On Linux, /usr/bin/dtrace is in fact a shim to SystemTap +AC_MSG_CHECKING([for --with-systemtap]) +AC_ARG_WITH([systemtap], + AC_HELP_STRING([--with(out)-systemtap], [disable/enable SystemTap support]),, + with_systemtap=no) +AC_MSG_RESULT([$with_systemtap]) +if test ! -z "$with_systemtap" +then + if dtrace -G -o /dev/null -s $srcdir/Include/pysystemtap.d 2>/dev/null + then + AC_DEFINE(WITH_SYSTEMTAP, 1, + [Define if you want to compile in SystemTap support]) + SYSTEMTAPOBJS="Python/pysystemtap.o" + else + with_systemtap="no" + fi +else + with_systemtap="no" +fi + +AC_SUBST(SYSTEMTAPOBJS) + # -I${DLINCLDIR} is added to the compile rule for importdl.o AC_SUBST(DLINCLDIR) DLINCLDIR=. diff -r 99ef4501205b pyconfig.h.in --- a/pyconfig.h.in Thu May 10 16:11:12 2012 +0100 +++ b/pyconfig.h.in Thu May 10 16:53:13 2012 -0400 @@ -1306,6 +1306,9 @@ /* Define if you want to compile in Python-specific mallocs */ #undef WITH_PYMALLOC +/* Define if you want to compile in SystemTap support */ +#undef WITH_SYSTEMTAP + /* Define if you want to compile in rudimentary thread support */ #undef WITH_THREAD