diff --git a/Doc/howto/instrumentation.rst b/Doc/howto/instrumentation.rst index 4ce15c69dac90b..e8e18dabbb2b05 100644 --- a/Doc/howto/instrumentation.rst +++ b/Doc/howto/instrumentation.rst @@ -274,14 +274,14 @@ should instead read: Available static markers ------------------------ -.. object:: function__entry(str filename, str funcname, int lineno) +.. object:: function__entry(str filename, str funcname, int lineno, str modulename) 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``, ``$arg3``: + The filename, function name, line number, and module name are provided back + to the tracing script as positional arguments, which must be accessed using + ``$arg1``, ``$arg2``, ``$arg3``, ``$arg4``: * ``$arg1`` : ``(const char *)`` filename, accessible using ``user_string($arg1)`` @@ -290,7 +290,9 @@ Available static markers * ``$arg3`` : ``int`` line number -.. object:: function__return(str filename, str funcname, int lineno) + * ``$arg4`` : ``(const char *)`` module name + +.. object:: function__return(str filename, str funcname, int lineno, str modulename) This marker is the converse of :c:func:`function__entry`, and indicates that execution of a Python function has ended (either via ``return``, or via an @@ -298,13 +300,28 @@ Available static markers The arguments are the same as for :c:func:`function__entry` +.. object:: cfunction__entry(str filename, str funcname, int lineno, str modulename) + + This marker indicates that execution of a built-in or extension function has + begun. The filename and line number refer to the Python call site, while the + module name and function name identify the C callable. The module name may + be empty when the function is not associated with a particular module. + +.. object:: cfunction__return(str filename, str funcname, int lineno, str modulename) + + This marker is the converse of :c:func:`cfunction__entry`, and indicates that + execution of a built-in or extension function has ended. The arguments are + the same as for :c:func:`cfunction__entry`. + .. object:: line(str filename, str funcname, int lineno) This marker indicates a Python line is about to be executed. It is the equivalent of line-by-line tracing with a Python profiler. It is not triggered within C functions. - The arguments are the same as for :c:func:`function__entry`. + The arguments are the filename, function name, and line number for the + executing frame (the same as the first three arguments to + :c:func:`function__entry`). .. object:: gc__start(int generation) diff --git a/Include/pydtrace.d b/Include/pydtrace.d index 5e6a626b01b82f..7ce1b7931f5181 100644 --- a/Include/pydtrace.d +++ b/Include/pydtrace.d @@ -1,8 +1,10 @@ /* Python DTrace provider */ provider python { - probe function__entry(const char *, const char *, int); - probe function__return(const char *, const char *, int); + probe function__entry(const char *, const char *, int, const char *); + probe function__return(const char *, const char *, int, const char *); + probe cfunction__entry(const char *, const char *, int, const char *); + probe cfunction__return(const char *, const char *, int, const char *); probe instance__new__start(const char *, const char *); probe instance__new__done(const char *, const char *); probe instance__delete__start(const char *, const char *); diff --git a/Include/pydtrace.h b/Include/pydtrace.h index 75f8e7f70979c5..7c4a4a27d5ba4d 100644 --- a/Include/pydtrace.h +++ b/Include/pydtrace.h @@ -18,7 +18,7 @@ extern "C" { check to minimize performance impact when probing is off. For example: if (PyDTrace_FUNCTION_ENTRY_ENABLED()) - PyDTrace_FUNCTION_ENTRY(f); + PyDTrace_FUNCTION_ENTRY(filename, funcname, lineno, modulename); */ #else @@ -26,14 +26,16 @@ extern "C" { /* Without DTrace, compile to nothing. */ static inline void PyDTrace_LINE(const char *arg0, const char *arg1, int arg2) {} -static inline void PyDTrace_FUNCTION_ENTRY(const char *arg0, const char *arg1, int arg2) {} -static inline void PyDTrace_FUNCTION_RETURN(const char *arg0, const char *arg1, int arg2) {} +static inline void PyDTrace_FUNCTION_ENTRY(const char *arg0, const char *arg1, int arg2, const char *arg3) {} +static inline void PyDTrace_FUNCTION_RETURN(const char *arg0, const char *arg1, int arg2, const char *arg3) {} +static inline void PyDTrace_CFUNCTION_ENTRY(const char *arg0, const char *arg1, int arg2, const char *arg3) {} +static inline void PyDTrace_CFUNCTION_RETURN(const char *arg0, const char *arg1, int arg2, const char *arg3) {} static inline void PyDTrace_GC_START(int arg0) {} static inline void PyDTrace_GC_DONE(Py_ssize_t arg0) {} -static inline void PyDTrace_INSTANCE_NEW_START(int arg0) {} -static inline void PyDTrace_INSTANCE_NEW_DONE(int arg0) {} -static inline void PyDTrace_INSTANCE_DELETE_START(int arg0) {} -static inline void PyDTrace_INSTANCE_DELETE_DONE(int arg0) {} +static inline void PyDTrace_INSTANCE_NEW_START(const char *arg0, const char *arg1) {} +static inline void PyDTrace_INSTANCE_NEW_DONE(const char *arg0, const char *arg1) {} +static inline void PyDTrace_INSTANCE_DELETE_START(const char *arg0, const char *arg1) {} +static inline void PyDTrace_INSTANCE_DELETE_DONE(const char *arg0, const char *arg1) {} static inline void PyDTrace_IMPORT_FIND_LOAD_START(const char *arg0) {} static inline void PyDTrace_IMPORT_FIND_LOAD_DONE(const char *arg0, int arg1) {} static inline void PyDTrace_AUDIT(const char *arg0, void *arg1) {} @@ -41,6 +43,8 @@ static inline void PyDTrace_AUDIT(const char *arg0, void *arg1) {} static inline int PyDTrace_LINE_ENABLED(void) { return 0; } static inline int PyDTrace_FUNCTION_ENTRY_ENABLED(void) { return 0; } static inline int PyDTrace_FUNCTION_RETURN_ENABLED(void) { return 0; } +static inline int PyDTrace_CFUNCTION_ENTRY_ENABLED(void) { return 0; } +static inline int PyDTrace_CFUNCTION_RETURN_ENABLED(void) { return 0; } static inline int PyDTrace_GC_START_ENABLED(void) { return 0; } static inline int PyDTrace_GC_DONE_ENABLED(void) { return 0; } static inline int PyDTrace_INSTANCE_NEW_START_ENABLED(void) { return 0; } diff --git a/Lib/test/dtracedata/assert_usable.bt b/Lib/test/dtracedata/assert_usable.bt new file mode 100644 index 00000000000000..adade7b29267cb --- /dev/null +++ b/Lib/test/dtracedata/assert_usable.bt @@ -0,0 +1 @@ +BEGIN { printf("probe: success\n"); exit(); } diff --git a/Lib/test/dtracedata/call_stack.bt b/Lib/test/dtracedata/call_stack.bt new file mode 100644 index 00000000000000..461d48a9bc51f5 --- /dev/null +++ b/Lib/test/dtracedata/call_stack.bt @@ -0,0 +1,29 @@ +@seq = 0; + +usdt:@TARGET@:python:function__entry /str(args->arg1) == "start"/ { + @trace[tid] = 1; + @indent[tid] = 0; +} + +usdt:@TARGET@:python:function__entry /@trace[tid]/ { + @seq += 1; + printf("%d\t%15s:", (int)@seq, "function-entry"); + printf("%*s", @indent[tid], ""); + printf("%s:%s:%d:%s\n", str(args->arg0), str(args->arg1), args->arg2, + str(args->arg3)); + @indent[tid] = @indent[tid] + 1; +} + +usdt:@TARGET@:python:function__return /@trace[tid]/ { + @indent[tid] = @indent[tid] - 1; + @seq += 1; + printf("%d\t%15s:", (int)@seq, "function-return"); + printf("%*s", @indent[tid], ""); + printf("%s:%s:%d:%s\n", str(args->arg0), str(args->arg1), args->arg2, + str(args->arg3)); +} + +usdt:@TARGET@:python:function__return /str(args->arg1) == "start"/ { + @trace[tid] = 0; + @indent[tid] = 0; +} diff --git a/Lib/test/dtracedata/call_stack.bt.expected b/Lib/test/dtracedata/call_stack.bt.expected new file mode 100644 index 00000000000000..139af108bf5160 --- /dev/null +++ b/Lib/test/dtracedata/call_stack.bt.expected @@ -0,0 +1,18 @@ + function-entry:call_stack.py:start:23 + function-entry: call_stack.py:function_1:1:__main__ + function-entry: call_stack.py:function_3:9:__main__ +function-return: call_stack.py:function_3:10:__main__ +function-return: call_stack.py:function_1:2:__main__ + function-entry: call_stack.py:function_2:5:__main__ + function-entry: call_stack.py:function_1:1:__main__ + function-entry: call_stack.py:function_3:9:__main__ +function-return: call_stack.py:function_3:10:__main__ +function-return: call_stack.py:function_1:2:__main__ +function-return: call_stack.py:function_2:6:__main__ + function-entry: call_stack.py:function_3:9:__main__ +function-return: call_stack.py:function_3:10:__main__ + function-entry: call_stack.py:function_4:13:__main__ +function-return: call_stack.py:function_4:14:__main__ + function-entry: call_stack.py:function_5:18:__main__ +function-return: call_stack.py:function_5:21:__main__ +function-return:call_stack.py:start:28:__main__ diff --git a/Lib/test/dtracedata/call_stack.d b/Lib/test/dtracedata/call_stack.d index 761d30fd55967b..bd64bf870e88d6 100644 --- a/Lib/test/dtracedata/call_stack.d +++ b/Lib/test/dtracedata/call_stack.d @@ -11,7 +11,8 @@ python$target:::function-entry { printf("%d\t%*s:", timestamp, 15, probename); printf("%*s", self->indent, ""); - printf("%s:%s:%d\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2); + printf("%s:%s:%d:%s\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2, + copyinstr(arg3)); self->indent++; } @@ -21,7 +22,8 @@ python$target:::function-return self->indent--; printf("%d\t%*s:", timestamp, 15, probename); printf("%*s", self->indent, ""); - printf("%s:%s:%d\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2); + printf("%s:%s:%d:%s\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2, + copyinstr(arg3)); } python$target:::function-return diff --git a/Lib/test/dtracedata/call_stack.d.expected b/Lib/test/dtracedata/call_stack.d.expected index 27849d154954bf..3cbe42c4b20677 100644 --- a/Lib/test/dtracedata/call_stack.d.expected +++ b/Lib/test/dtracedata/call_stack.d.expected @@ -1,18 +1,18 @@ - function-entry:call_stack.py:start:23 - function-entry: call_stack.py:function_1:1 - function-entry: call_stack.py:function_3:9 -function-return: call_stack.py:function_3:10 -function-return: call_stack.py:function_1:2 - function-entry: call_stack.py:function_2:5 - function-entry: call_stack.py:function_1:1 - function-entry: call_stack.py:function_3:9 -function-return: call_stack.py:function_3:10 -function-return: call_stack.py:function_1:2 -function-return: call_stack.py:function_2:6 - function-entry: call_stack.py:function_3:9 -function-return: call_stack.py:function_3:10 - function-entry: call_stack.py:function_4:13 -function-return: call_stack.py:function_4:14 - function-entry: call_stack.py:function_5:18 -function-return: call_stack.py:function_5:21 -function-return:call_stack.py:start:28 + function-entry:call_stack.py:start:23:__main__ + function-entry: call_stack.py:function_1:1:__main__ + function-entry: call_stack.py:function_3:9:__main__ +function-return: call_stack.py:function_3:10:__main__ +function-return: call_stack.py:function_1:2:__main__ + function-entry: call_stack.py:function_2:5:__main__ + function-entry: call_stack.py:function_1:1:__main__ + function-entry: call_stack.py:function_3:9:__main__ +function-return: call_stack.py:function_3:10:__main__ +function-return: call_stack.py:function_1:2:__main__ +function-return: call_stack.py:function_2:6:__main__ + function-entry: call_stack.py:function_3:9:__main__ +function-return: call_stack.py:function_3:10:__main__ + function-entry: call_stack.py:function_4:13:__main__ +function-return: call_stack.py:function_4:14:__main__ + function-entry: call_stack.py:function_5:18:__main__ +function-return: call_stack.py:function_5:21:__main__ +function-return:call_stack.py:start:28:__main__ diff --git a/Lib/test/dtracedata/call_stack.stp b/Lib/test/dtracedata/call_stack.stp index 54082c202f66aa..32efdf4a5fc6c7 100644 --- a/Lib/test/dtracedata/call_stack.stp +++ b/Lib/test/dtracedata/call_stack.stp @@ -24,10 +24,11 @@ probe process.mark("function__entry"), process.mark("function__return") filename = user_string($arg1); funcname = user_string($arg2); lineno = $arg3; + modulename = user_string($arg4); if (tracing) { - printf("%d\t%s:%s:%s:%d\n", gettimeofday_us(), $$name, - basename(filename), funcname, lineno); + printf("%d\t%s:%s:%s:%d:%s\n", gettimeofday_us(), $$name, + basename(filename), funcname, lineno, modulename); } } diff --git a/Lib/test/dtracedata/call_stack.stp.expected b/Lib/test/dtracedata/call_stack.stp.expected index 32cf396f820629..f81a3855d2f106 100644 --- a/Lib/test/dtracedata/call_stack.stp.expected +++ b/Lib/test/dtracedata/call_stack.stp.expected @@ -1,14 +1,14 @@ -function__entry:call_stack.py:start:23 -function__entry:call_stack.py:function_1:1 -function__return:call_stack.py:function_1:2 -function__entry:call_stack.py:function_2:5 -function__entry:call_stack.py:function_1:1 -function__return:call_stack.py:function_1:2 -function__return:call_stack.py:function_2:6 -function__entry:call_stack.py:function_3:9 -function__return:call_stack.py:function_3:10 -function__entry:call_stack.py:function_4:13 -function__return:call_stack.py:function_4:14 -function__entry:call_stack.py:function_5:18 -function__return:call_stack.py:function_5:21 -function__return:call_stack.py:start:28 +function__entry:call_stack.py:start:23:__main__ +function__entry:call_stack.py:function_1:1:__main__ +function__return:call_stack.py:function_1:2:__main__ +function__entry:call_stack.py:function_2:5:__main__ +function__entry:call_stack.py:function_1:1:__main__ +function__return:call_stack.py:function_1:2:__main__ +function__return:call_stack.py:function_2:6:__main__ +function__entry:call_stack.py:function_3:9:__main__ +function__return:call_stack.py:function_3:10:__main__ +function__entry:call_stack.py:function_4:13:__main__ +function__return:call_stack.py:function_4:14:__main__ +function__entry:call_stack.py:function_5:18:__main__ +function__return:call_stack.py:function_5:21:__main__ +function__return:call_stack.py:start:28:__main__ diff --git a/Lib/test/dtracedata/cfunction.bt b/Lib/test/dtracedata/cfunction.bt new file mode 100644 index 00000000000000..1743a6ea1665a1 --- /dev/null +++ b/Lib/test/dtracedata/cfunction.bt @@ -0,0 +1,19 @@ +@seq = 0; + +usdt:@TARGET@:python:function__entry /str(args->arg1) == "start"/ { @trace[tid] = 1; } + +usdt:@TARGET@:python:cfunction__entry /@trace[tid]/ { + @seq += 1; + const char *module = args->arg3 ? str(args->arg3) : ""; + printf("%d\tcfunction-entry:%s:%s:%d:%s\n", (int)@seq, + str(args->arg0), str(args->arg1), args->arg2, module); +} + +usdt:@TARGET@:python:cfunction__return /@trace[tid]/ { + @seq += 1; + const char *module = args->arg3 ? str(args->arg3) : ""; + printf("%d\tcfunction-return:%s:%s:%d:%s\n", (int)@seq, + str(args->arg0), str(args->arg1), args->arg2, module); +} + +usdt:@TARGET@:python:function__return /str(args->arg1) == "start"/ { @trace[tid] = 0; } diff --git a/Lib/test/dtracedata/cfunction.bt.expected b/Lib/test/dtracedata/cfunction.bt.expected new file mode 100644 index 00000000000000..5e80c00a3e9bfd --- /dev/null +++ b/Lib/test/dtracedata/cfunction.bt.expected @@ -0,0 +1,6 @@ +cfunction-entry:cfunction.py:5:builtins:len +cfunction-return:cfunction.py:5:builtins:len +cfunction-entry:cfunction.py:6:math:sqrt +cfunction-return:cfunction.py:6:math:sqrt +cfunction-entry:cfunction.py:7:builtins:sum +cfunction-return:cfunction.py:7:builtins:sum diff --git a/Lib/test/dtracedata/cfunction.d b/Lib/test/dtracedata/cfunction.d new file mode 100644 index 00000000000000..9545e0749b3b25 --- /dev/null +++ b/Lib/test/dtracedata/cfunction.d @@ -0,0 +1,22 @@ +self int tracing; + +python$target:::function-entry +/copyinstr(arg1) == "start"/ +{ + self->tracing = 1; +} + +python$target:::cfunction-entry, +python$target:::cfunction-return +/self->tracing/ +{ + this->module = arg3 ? copyinstr(arg3) : ""; + printf("%d\t%s:%s:%d:%s:%s\n", timestamp, probename, + copyinstr(arg0), arg2, this->module, copyinstr(arg1)); +} + +python$target:::function-return +/copyinstr(arg1) == "start"/ +{ + self->tracing = 0; +} diff --git a/Lib/test/dtracedata/cfunction.d.expected b/Lib/test/dtracedata/cfunction.d.expected new file mode 100644 index 00000000000000..5e80c00a3e9bfd --- /dev/null +++ b/Lib/test/dtracedata/cfunction.d.expected @@ -0,0 +1,6 @@ +cfunction-entry:cfunction.py:5:builtins:len +cfunction-return:cfunction.py:5:builtins:len +cfunction-entry:cfunction.py:6:math:sqrt +cfunction-return:cfunction.py:6:math:sqrt +cfunction-entry:cfunction.py:7:builtins:sum +cfunction-return:cfunction.py:7:builtins:sum diff --git a/Lib/test/dtracedata/cfunction.py b/Lib/test/dtracedata/cfunction.py new file mode 100644 index 00000000000000..1beace25982f06 --- /dev/null +++ b/Lib/test/dtracedata/cfunction.py @@ -0,0 +1,15 @@ +import math + + +def start(): + len([1, 2, 3]) + math.sqrt(16.0) + sum([1, 2, 3]) + + +def main(): + start() + + +if __name__ == "__main__": + main() diff --git a/Lib/test/dtracedata/cfunction.stp b/Lib/test/dtracedata/cfunction.stp new file mode 100644 index 00000000000000..2154421abe3a94 --- /dev/null +++ b/Lib/test/dtracedata/cfunction.stp @@ -0,0 +1,24 @@ +global tracing + +probe process.mark("function__entry") +{ + if (user_string($arg2) == "start") { + tracing = 1; + } +} + +probe process.mark("cfunction__entry"), process.mark("cfunction__return") +{ + if (tracing) { + modulename = $arg4 ? user_string($arg4) : ""; + printf("%d\t%s:%s:%d:%s:%s\n", gettimeofday_us(), $$name, + user_string($arg1), $arg3, modulename, user_string($arg2)); + } +} + +probe process.mark("function__return") +{ + if (user_string($arg2) == "start") { + tracing = 0; + } +} diff --git a/Lib/test/dtracedata/cfunction.stp.expected b/Lib/test/dtracedata/cfunction.stp.expected new file mode 100644 index 00000000000000..a1b0c408d45fa2 --- /dev/null +++ b/Lib/test/dtracedata/cfunction.stp.expected @@ -0,0 +1,6 @@ +cfunction__entry:cfunction.py:5:builtins:len +cfunction__return:cfunction.py:5:builtins:len +cfunction__entry:cfunction.py:6:math:sqrt +cfunction__return:cfunction.py:6:math:sqrt +cfunction__entry:cfunction.py:7:builtins:sum +cfunction__return:cfunction.py:7:builtins:sum diff --git a/Lib/test/dtracedata/gc.bt b/Lib/test/dtracedata/gc.bt new file mode 100644 index 00000000000000..20bc48ad59f8f9 --- /dev/null +++ b/Lib/test/dtracedata/gc.bt @@ -0,0 +1,15 @@ +@seq = 0; + +usdt:@TARGET@:python:function__entry /str(args->arg1) == "start"/ { @trace[tid] = 1; } + +usdt:@TARGET@:python:gc__start /@trace[tid]/ { + @seq += 1; + printf("%d\tgc-start:%ld\n", (int)@seq, args->arg0); +} + +usdt:@TARGET@:python:gc__done /@trace[tid]/ { + @seq += 1; + printf("%d\tgc-done:%ld\n", (int)@seq, args->arg0); +} + +usdt:@TARGET@:python:function__return /str(args->arg1) == "start"/ { @trace[tid] = 0; } diff --git a/Lib/test/dtracedata/gc.bt.expected b/Lib/test/dtracedata/gc.bt.expected new file mode 100644 index 00000000000000..8e5ac2a6d568de --- /dev/null +++ b/Lib/test/dtracedata/gc.bt.expected @@ -0,0 +1,8 @@ +gc-start:0 +gc-done:0 +gc-start:1 +gc-done:0 +gc-start:2 +gc-done:0 +gc-start:2 +gc-done:1 diff --git a/Lib/test/dtracedata/line.bt b/Lib/test/dtracedata/line.bt new file mode 100644 index 00000000000000..6539edb0c87cc8 --- /dev/null +++ b/Lib/test/dtracedata/line.bt @@ -0,0 +1,6 @@ +@seq = 0; + +usdt:@TARGET@:python:line /str(args->arg1) == "test_line"/ { + @seq += 1; + printf("%d\tline:%s:%s:%d\n", (int)@seq, str(args->arg0), str(args->arg1), args->arg2); +} diff --git a/Lib/test/dtracedata/line.bt.expected b/Lib/test/dtracedata/line.bt.expected new file mode 100644 index 00000000000000..9b16ce76ee60a4 --- /dev/null +++ b/Lib/test/dtracedata/line.bt.expected @@ -0,0 +1,20 @@ +line:line.py:test_line:2 +line:line.py:test_line:3 +line:line.py:test_line:4 +line:line.py:test_line:5 +line:line.py:test_line:6 +line:line.py:test_line:7 +line:line.py:test_line:8 +line:line.py:test_line:9 +line:line.py:test_line:10 +line:line.py:test_line:11 +line:line.py:test_line:4 +line:line.py:test_line:5 +line:line.py:test_line:6 +line:line.py:test_line:7 +line:line.py:test_line:8 +line:line.py:test_line:10 +line:line.py:test_line:11 +line:line.py:test_line:4 +line:line.py:test_line:12 +line:line.py:test_line:13 diff --git a/Lib/test/test_dtrace.py b/Lib/test/test_dtrace.py index 8a436ad123b80f..52b8a3df91e3cd 100644 --- a/Lib/test/test_dtrace.py +++ b/Lib/test/test_dtrace.py @@ -1,10 +1,17 @@ import dis +import os import os.path import re import subprocess +import shlex +import os +import re +import subprocess import sys +import tempfile import types import unittest +import dis from test.support import findfile @@ -97,6 +104,37 @@ class SystemTapBackend(TraceBackend): COMMAND = ["stap", "-g"] +class BpftraceBackend(TraceBackend): + EXTENSION = ".bt" + COMMAND = ["bpftrace"] + + def __init__(self): + self._temps = [] + + def generate_trace_command(self, script_file, subcommand=None): + with open(script_file) as f: + source = f.read().replace("@TARGET@", sys.executable) + + temp = tempfile.NamedTemporaryFile("w", suffix=self.EXTENSION, delete=False) + temp.write(source) + temp.flush() + temp.close() + self._temps.append(temp.name) + + quoted_script = shlex.quote(temp.name) + quoted_cmd = f"ulimit -l unlimited; exec bpftrace {quoted_script}" + if subcommand: + quoted_cmd += " -c " + shlex.quote(subcommand) + return ["bash", "-c", quoted_cmd] + + def __del__(self): + for name in self._temps: + try: + os.unlink(name) + except FileNotFoundError: + pass + + class TraceTests: # unittest.TestCase options maxDiff = None @@ -148,6 +186,9 @@ def test_gc(self): def test_line(self): self.run_case("line") + def test_cfunction_entry_return(self): + self.run_case("cfunction") + class DTraceNormalTests(TraceTests, unittest.TestCase): backend = DTraceBackend() @@ -169,5 +210,15 @@ class SystemTapOptimizedTests(TraceTests, unittest.TestCase): optimize_python = 2 +class BpftraceNormalTests(TraceTests, unittest.TestCase): + backend = BpftraceBackend() + optimize_python = 0 + + +class BpftraceOptimizedTests(TraceTests, unittest.TestCase): + backend = BpftraceBackend() + optimize_python = 2 + + if __name__ == '__main__': unittest.main() diff --git a/Python/ceval.c b/Python/ceval.c index 9f4ef6be0e1f2a..633bc42a205dc4 100644 --- a/Python/ceval.c +++ b/Python/ceval.c @@ -81,6 +81,8 @@ static int maybe_call_line_trace(Py_tracefunc, PyObject *, static void maybe_dtrace_line(PyFrameObject *, PyTraceInfo *, int); static void dtrace_function_entry(PyFrameObject *); static void dtrace_function_return(PyFrameObject *); +static void dtrace_cfunction_entry(PyThreadState *, PyObject *); +static void dtrace_cfunction_return(PyThreadState *, PyObject *); static PyObject * import_name(PyThreadState *, PyFrameObject *, PyObject *, PyObject *, PyObject *); @@ -5845,7 +5847,13 @@ trace_call_function(PyThreadState *tstate, { PyObject *x; if (PyCFunction_CheckExact(func) || PyCMethod_CheckExact(func)) { + if (PyDTrace_CFUNCTION_ENTRY_ENABLED()) { + dtrace_cfunction_entry(tstate, func); + } C_TRACE(x, PyObject_Vectorcall(func, args, nargs, kwnames)); + if (PyDTrace_CFUNCTION_RETURN_ENABLED()) { + dtrace_cfunction_return(tstate, func); + } return x; } else if (Py_IS_TYPE(func, &PyMethodDescr_Type) && nargs > 0) { @@ -5889,6 +5897,15 @@ call_function(PyThreadState *tstate, if (trace_info->cframe.use_tracing) { x = trace_call_function(tstate, trace_info, func, stack, nargs, kwnames); } + else if (PyCFunction_Check(func)) { + if (PyDTrace_CFUNCTION_ENTRY_ENABLED()) { + dtrace_cfunction_entry(tstate, func); + } + x = PyObject_Vectorcall(func, stack, nargs | PY_VECTORCALL_ARGUMENTS_OFFSET, kwnames); + if (PyDTrace_CFUNCTION_RETURN_ENABLED()) { + dtrace_cfunction_return(tstate, func); + } + } else { x = PyObject_Vectorcall(func, stack, nargs | PY_VECTORCALL_ARGUMENTS_OFFSET, kwnames); } @@ -5914,7 +5931,13 @@ do_call_core(PyThreadState *tstate, PyObject *result; if (PyCFunction_CheckExact(func) || PyCMethod_CheckExact(func)) { + if (PyDTrace_CFUNCTION_ENTRY_ENABLED()) { + dtrace_cfunction_entry(tstate, func); + } C_TRACE(result, PyObject_Call(func, callargs, kwdict)); + if (PyDTrace_CFUNCTION_RETURN_ENABLED()) { + dtrace_cfunction_return(tstate, func); + } return result; } else if (Py_IS_TYPE(func, &PyMethodDescr_Type)) { @@ -6453,19 +6476,66 @@ _PyEval_RequestCodeExtraIndex(freefunc free) return new_index; } +static const char * +dtrace_frame_module_name(PyFrameObject *frame, PyObject **keepalive) +{ + const char *modulename = "?"; + PyObject *globals = frame->f_globals; + if (globals == NULL) { + return modulename; + } + + PyObject *old_type, *old_value, *old_traceback; + PyErr_Fetch(&old_type, &old_value, &old_traceback); + + PyObject *nameobj = PyDict_GetItemString(globals, "__name__"); + if (nameobj != NULL && PyUnicode_Check(nameobj)) { + modulename = PyUnicode_AsUTF8(nameobj); + if (modulename == NULL) { + modulename = "?"; + } + else if (keepalive != NULL) { + Py_INCREF(nameobj); + *keepalive = nameobj; + } + } + + PyErr_Restore(old_type, old_value, old_traceback); + if (modulename == NULL) { + modulename = "?"; + Py_XDECREF(keepalive ? *keepalive : NULL); + if (keepalive) { + *keepalive = NULL; + } + } + return modulename; +} + static void dtrace_function_entry(PyFrameObject *f) { const char *filename; const char *funcname; int lineno; + PyObject *modname_obj = NULL; + const char *modulename = "?"; PyCodeObject *code = f->f_code; filename = PyUnicode_AsUTF8(code->co_filename); + if (filename == NULL) { + PyErr_Clear(); + filename = "?"; + } funcname = PyUnicode_AsUTF8(code->co_name); + if (funcname == NULL) { + PyErr_Clear(); + funcname = "?"; + } lineno = PyFrame_GetLineNumber(f); + modulename = dtrace_frame_module_name(f, &modname_obj); - PyDTrace_FUNCTION_ENTRY(filename, funcname, lineno); + PyDTrace_FUNCTION_ENTRY(filename, funcname, lineno, modulename); + Py_XDECREF(modname_obj); } static void @@ -6474,13 +6544,125 @@ dtrace_function_return(PyFrameObject *f) const char *filename; const char *funcname; int lineno; + PyObject *modname_obj = NULL; + const char *modulename = "?"; PyCodeObject *code = f->f_code; filename = PyUnicode_AsUTF8(code->co_filename); + if (filename == NULL) { + PyErr_Clear(); + filename = "?"; + } funcname = PyUnicode_AsUTF8(code->co_name); + if (funcname == NULL) { + PyErr_Clear(); + funcname = "?"; + } lineno = PyFrame_GetLineNumber(f); + modulename = dtrace_frame_module_name(f, &modname_obj); + + PyDTrace_FUNCTION_RETURN(filename, funcname, lineno, modulename); + Py_XDECREF(modname_obj); +} + +static const char * +dtrace_cfunction_module_name(PyCFunctionObject *func, PyObject **keepalive) +{ + PyObject *module = func->m_module; + if (module == NULL) { + return "?"; + } - PyDTrace_FUNCTION_RETURN(filename, funcname, lineno); + PyObject *old_type, *old_value, *old_traceback; + PyErr_Fetch(&old_type, &old_value, &old_traceback); + + const char *name = NULL; + if (PyUnicode_Check(module)) { + name = PyUnicode_AsUTF8(module); + } + else if (PyModule_Check(module)) { + PyObject *nameobj = PyModule_GetNameObject(module); + if (nameobj != NULL) { + name = PyUnicode_AsUTF8(nameobj); + if (keepalive != NULL) { + *keepalive = nameobj; + } + else { + Py_DECREF(nameobj); + } + } + } + else { + name = Py_TYPE(module)->tp_name; + } + + PyErr_Restore(old_type, old_value, old_traceback); + if (name == NULL) { + name = "?"; + Py_XDECREF(keepalive ? *keepalive : NULL); + if (keepalive) { + *keepalive = NULL; + } + } + return name; +} + +static void +dtrace_cfunction_entry(PyThreadState *tstate, PyObject *func) +{ + assert(PyCFunction_Check(func)); + + PyCFunctionObject *cfunc = (PyCFunctionObject *)func; + PyObject *keepalive = NULL; + const char *module = dtrace_cfunction_module_name(cfunc, &keepalive); + const char *name = cfunc->m_ml->ml_name; + const char *filename = "?"; + int lineno = 0; + + PyFrameObject *frame = tstate->frame; + if (frame != NULL) { + filename = PyUnicode_AsUTF8(frame->f_code->co_filename); + if (filename == NULL) { + PyErr_Clear(); + filename = "?"; + } + lineno = PyFrame_GetLineNumber(frame); + } + + if (module == NULL) { + module = "?"; + } + PyDTrace_CFUNCTION_ENTRY(filename, name, lineno, module); + Py_XDECREF(keepalive); +} + +static void +dtrace_cfunction_return(PyThreadState *tstate, PyObject *func) +{ + assert(PyCFunction_Check(func)); + + PyCFunctionObject *cfunc = (PyCFunctionObject *)func; + PyObject *keepalive = NULL; + const char *module = dtrace_cfunction_module_name(cfunc, &keepalive); + const char *name = cfunc->m_ml->ml_name; + const char *filename = "?"; + int lineno = 0; + + PyFrameObject *frame = tstate->frame; + if (frame != NULL) { + filename = PyUnicode_AsUTF8(frame->f_code->co_filename); + if (filename == NULL) { + PyErr_Clear(); + filename = "?"; + } + lineno = PyFrame_GetLineNumber(frame); + } + + if (module == NULL) { + module = "?"; + } + PyDTrace_CFUNCTION_RETURN(filename, name, lineno, module); + Py_XDECREF(keepalive); } /* DTrace equivalent of maybe_call_line_trace. */