Skip to content

Commit 19f3abd

Browse files
Delta-in-hubDelta-in-hub
committed
Expand DTrace probe arguments with module context
1 parent 6c2ecc1 commit 19f3abd

16 files changed

+217
-116
lines changed

‎Doc/howto/instrumentation.rst‎

Lines changed: 15 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -274,14 +274,14 @@ should instead read:
274274
Available static markers
275275
------------------------
276276

277-
.. object:: function__entry(str filename, str funcname, int lineno)
277+
.. object:: function__entry(str filename, str funcname, int lineno, str modulename)
278278

279279
This marker indicates that execution of a Python function has begun.
280280
It is only triggered for pure-Python (bytecode) functions.
281281

282-
The filename, function name, and line number are provided back to the
283-
tracing script as positional arguments, which must be accessed using
284-
``$arg1``, ``$arg2``, ``$arg3``:
282+
The filename, function name, line number, and module name are provided back
283+
to the tracing script as positional arguments, which must be accessed using
284+
``$arg1``, ``$arg2``, ``$arg3``, ``$arg4``:
285285

286286
* ``$arg1`` : ``(const char *)`` filename, accessible using ``user_string($arg1)``
287287

@@ -290,22 +290,24 @@ Available static markers
290290

291291
* ``$arg3`` : ``int`` line number
292292

293-
.. object:: function__return(str filename, str funcname, int lineno)
293+
* ``$arg4`` : ``(const char *)`` module name
294+
295+
.. object:: function__return(str filename, str funcname, int lineno, str modulename)
294296

295297
This marker is the converse of :c:func:`function__entry`, and indicates that
296298
execution of a Python function has ended (either via ``return``, or via an
297299
exception). It is only triggered for pure-Python (bytecode) functions.
298300

299301
The arguments are the same as for :c:func:`function__entry`
300302

301-
.. object:: cfunction__entry(str modulename, str funcname)
303+
.. object:: cfunction__entry(str filename, str funcname, int lineno, str modulename)
302304

303305
This marker indicates that execution of a built-in or extension function has
304-
begun. The module name and function name are provided as C strings. The
305-
module name may be empty when the function is not associated with a
306-
particular module.
306+
begun. The filename and line number refer to the Python call site, while the
307+
module name and function name identify the C callable. The module name may
308+
be empty when the function is not associated with a particular module.
307309

308-
.. object:: cfunction__return(str modulename, str funcname)
310+
.. object:: cfunction__return(str filename, str funcname, int lineno, str modulename)
309311

310312
This marker is the converse of :c:func:`cfunction__entry`, and indicates that
311313
execution of a built-in or extension function has ended. The arguments are
@@ -317,7 +319,9 @@ Available static markers
317319
the equivalent of line-by-line tracing with a Python profiler. It is
318320
not triggered within C functions.
319321

320-
The arguments are the same as for :c:func:`function__entry`.
322+
The arguments are the filename, function name, and line number for the
323+
executing frame (the same as the first three arguments to
324+
:c:func:`function__entry`).
321325

322326
.. object:: gc__start(int generation)
323327

‎Include/pydtrace.d‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1,10 +1,10 @@
11
/* Python DTrace provider */
22

33
provider python {
4-
probe function__entry(const char *, const char *, int);
5-
probe function__return(const char *, const char *, int);
6-
probe cfunction__entry(const char *, const char *);
7-
probe cfunction__return(const char *, const char *);
4+
probe function__entry(const char *, const char *, int, const char *);
5+
probe function__return(const char *, const char *, int, const char *);
6+
probe cfunction__entry(const char *, const char *, int, const char *);
7+
probe cfunction__return(const char *, const char *, int, const char *);
88
probe instance__new__start(const char *, const char *);
99
probe instance__new__done(const char *, const char *);
1010
probe instance__delete__start(const char *, const char *);

‎Include/pydtrace.h‎

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -18,18 +18,18 @@ extern "C" {
1818
check to minimize performance impact when probing is off. For example:
1919
2020
if (PyDTrace_FUNCTION_ENTRY_ENABLED())
21-
PyDTrace_FUNCTION_ENTRY(f);
21+
PyDTrace_FUNCTION_ENTRY(filename, funcname, lineno, modulename);
2222
*/
2323

2424
#else
2525

2626
/* Without DTrace, compile to nothing. */
2727

2828
static inline void PyDTrace_LINE(const char *arg0, const char *arg1, int arg2) {}
29-
static inline void PyDTrace_FUNCTION_ENTRY(const char *arg0, const char *arg1, int arg2) {}
30-
static inline void PyDTrace_FUNCTION_RETURN(const char *arg0, const char *arg1, int arg2) {}
31-
static inline void PyDTrace_CFUNCTION_ENTRY(const char *arg0, const char *arg1) {}
32-
static inline void PyDTrace_CFUNCTION_RETURN(const char *arg0, const char *arg1) {}
29+
static inline void PyDTrace_FUNCTION_ENTRY(const char *arg0, const char *arg1, int arg2, const char *arg3) {}
30+
static inline void PyDTrace_FUNCTION_RETURN(const char *arg0, const char *arg1, int arg2, const char *arg3) {}
31+
static inline void PyDTrace_CFUNCTION_ENTRY(const char *arg0, const char *arg1, int arg2, const char *arg3) {}
32+
static inline void PyDTrace_CFUNCTION_RETURN(const char *arg0, const char *arg1, int arg2, const char *arg3) {}
3333
static inline void PyDTrace_GC_START(int arg0) {}
3434
static inline void PyDTrace_GC_DONE(Py_ssize_t arg0) {}
3535
static inline void PyDTrace_INSTANCE_NEW_START(const char *arg0, const char *arg1) {}

‎Lib/test/dtracedata/call_stack.bt‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,8 @@ usdt:@TARGET@:python:function__entry /@trace[tid]/ {
99
@seq += 1;
1010
printf("%d\t%15s:", (int)@seq, "function-entry");
1111
printf("%*s", @indent[tid], "");
12-
printf("%s:%s:%d\n", str(args->arg0), str(args->arg1), args->arg2);
12+
printf("%s:%s:%d:%s\n", str(args->arg0), str(args->arg1), args->arg2,
13+
str(args->arg3));
1314
@indent[tid] = @indent[tid] + 1;
1415
}
1516

@@ -18,7 +19,8 @@ usdt:@TARGET@:python:function__return /@trace[tid]/ {
1819
@seq += 1;
1920
printf("%d\t%15s:", (int)@seq, "function-return");
2021
printf("%*s", @indent[tid], "");
21-
printf("%s:%s:%d\n", str(args->arg0), str(args->arg1), args->arg2);
22+
printf("%s:%s:%d:%s\n", str(args->arg0), str(args->arg1), args->arg2,
23+
str(args->arg3));
2224
}
2325

2426
usdt:@TARGET@:python:function__return /str(args->arg1) == "start"/ {

‎Lib/test/dtracedata/call_stack.bt.expected‎

Lines changed: 17 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -1,18 +1,18 @@
11
function-entry:call_stack.py:start:23
2-
function-entry: call_stack.py:function_1:1
3-
function-entry: call_stack.py:function_3:9
4-
function-return: call_stack.py:function_3:10
5-
function-return: call_stack.py:function_1:2
6-
function-entry: call_stack.py:function_2:5
7-
function-entry: call_stack.py:function_1:1
8-
function-entry: call_stack.py:function_3:9
9-
function-return: call_stack.py:function_3:10
10-
function-return: call_stack.py:function_1:2
11-
function-return: call_stack.py:function_2:6
12-
function-entry: call_stack.py:function_3:9
13-
function-return: call_stack.py:function_3:10
14-
function-entry: call_stack.py:function_4:13
15-
function-return: call_stack.py:function_4:14
16-
function-entry: call_stack.py:function_5:18
17-
function-return: call_stack.py:function_5:21
18-
function-return:call_stack.py:start:28
2+
function-entry: call_stack.py:function_1:1:__main__
3+
function-entry: call_stack.py:function_3:9:__main__
4+
function-return: call_stack.py:function_3:10:__main__
5+
function-return: call_stack.py:function_1:2:__main__
6+
function-entry: call_stack.py:function_2:5:__main__
7+
function-entry: call_stack.py:function_1:1:__main__
8+
function-entry: call_stack.py:function_3:9:__main__
9+
function-return: call_stack.py:function_3:10:__main__
10+
function-return: call_stack.py:function_1:2:__main__
11+
function-return: call_stack.py:function_2:6:__main__
12+
function-entry: call_stack.py:function_3:9:__main__
13+
function-return: call_stack.py:function_3:10:__main__
14+
function-entry: call_stack.py:function_4:13:__main__
15+
function-return: call_stack.py:function_4:14:__main__
16+
function-entry: call_stack.py:function_5:18:__main__
17+
function-return: call_stack.py:function_5:21:__main__
18+
function-return:call_stack.py:start:28:__main__

‎Lib/test/dtracedata/call_stack.d‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,8 @@ python$target:::function-entry
1111
{
1212
printf("%d\t%*s:", timestamp, 15, probename);
1313
printf("%*s", self->indent, "");
14-
printf("%s:%s:%d\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2);
14+
printf("%s:%s:%d:%s\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2,
15+
copyinstr(arg3));
1516
self->indent++;
1617
}
1718

@@ -21,7 +22,8 @@ python$target:::function-return
2122
self->indent--;
2223
printf("%d\t%*s:", timestamp, 15, probename);
2324
printf("%*s", self->indent, "");
24-
printf("%s:%s:%d\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2);
25+
printf("%s:%s:%d:%s\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2,
26+
copyinstr(arg3));
2527
}
2628

2729
python$target:::function-return

‎Lib/test/dtracedata/call_stack.d.expected‎

Lines changed: 18 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -1,18 +1,18 @@
1-
function-entry:call_stack.py:start:23
2-
function-entry: call_stack.py:function_1:1
3-
function-entry: call_stack.py:function_3:9
4-
function-return: call_stack.py:function_3:10
5-
function-return: call_stack.py:function_1:2
6-
function-entry: call_stack.py:function_2:5
7-
function-entry: call_stack.py:function_1:1
8-
function-entry: call_stack.py:function_3:9
9-
function-return: call_stack.py:function_3:10
10-
function-return: call_stack.py:function_1:2
11-
function-return: call_stack.py:function_2:6
12-
function-entry: call_stack.py:function_3:9
13-
function-return: call_stack.py:function_3:10
14-
function-entry: call_stack.py:function_4:13
15-
function-return: call_stack.py:function_4:14
16-
function-entry: call_stack.py:function_5:18
17-
function-return: call_stack.py:function_5:21
18-
function-return:call_stack.py:start:28
1+
function-entry:call_stack.py:start:23:__main__
2+
function-entry: call_stack.py:function_1:1:__main__
3+
function-entry: call_stack.py:function_3:9:__main__
4+
function-return: call_stack.py:function_3:10:__main__
5+
function-return: call_stack.py:function_1:2:__main__
6+
function-entry: call_stack.py:function_2:5:__main__
7+
function-entry: call_stack.py:function_1:1:__main__
8+
function-entry: call_stack.py:function_3:9:__main__
9+
function-return: call_stack.py:function_3:10:__main__
10+
function-return: call_stack.py:function_1:2:__main__
11+
function-return: call_stack.py:function_2:6:__main__
12+
function-entry: call_stack.py:function_3:9:__main__
13+
function-return: call_stack.py:function_3:10:__main__
14+
function-entry: call_stack.py:function_4:13:__main__
15+
function-return: call_stack.py:function_4:14:__main__
16+
function-entry: call_stack.py:function_5:18:__main__
17+
function-return: call_stack.py:function_5:21:__main__
18+
function-return:call_stack.py:start:28:__main__

‎Lib/test/dtracedata/call_stack.stp‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -24,10 +24,11 @@ probe process.mark("function__entry"), process.mark("function__return")
2424
filename = user_string($arg1);
2525
funcname = user_string($arg2);
2626
lineno = $arg3;
27+
modulename = user_string($arg4);
2728

2829
if (tracing) {
29-
printf("%d\t%s:%s:%s:%d\n", gettimeofday_us(), $$name,
30-
basename(filename), funcname, lineno);
30+
printf("%d\t%s:%s:%s:%d:%s\n", gettimeofday_us(), $$name,
31+
basename(filename), funcname, lineno, modulename);
3132
}
3233
}
3334

‎Lib/test/dtracedata/call_stack.stp.expected‎

Lines changed: 14 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -1,14 +1,14 @@
1-
function__entry:call_stack.py:start:23
2-
function__entry:call_stack.py:function_1:1
3-
function__return:call_stack.py:function_1:2
4-
function__entry:call_stack.py:function_2:5
5-
function__entry:call_stack.py:function_1:1
6-
function__return:call_stack.py:function_1:2
7-
function__return:call_stack.py:function_2:6
8-
function__entry:call_stack.py:function_3:9
9-
function__return:call_stack.py:function_3:10
10-
function__entry:call_stack.py:function_4:13
11-
function__return:call_stack.py:function_4:14
12-
function__entry:call_stack.py:function_5:18
13-
function__return:call_stack.py:function_5:21
14-
function__return:call_stack.py:start:28
1+
function__entry:call_stack.py:start:23:__main__
2+
function__entry:call_stack.py:function_1:1:__main__
3+
function__return:call_stack.py:function_1:2:__main__
4+
function__entry:call_stack.py:function_2:5:__main__
5+
function__entry:call_stack.py:function_1:1:__main__
6+
function__return:call_stack.py:function_1:2:__main__
7+
function__return:call_stack.py:function_2:6:__main__
8+
function__entry:call_stack.py:function_3:9:__main__
9+
function__return:call_stack.py:function_3:10:__main__
10+
function__entry:call_stack.py:function_4:13:__main__
11+
function__return:call_stack.py:function_4:14:__main__
12+
function__entry:call_stack.py:function_5:18:__main__
13+
function__return:call_stack.py:function_5:21:__main__
14+
function__return:call_stack.py:start:28:__main__

‎Lib/test/dtracedata/cfunction.bt‎

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -4,14 +4,16 @@ usdt:@TARGET@:python:function__entry /str(args->arg1) == "start"/ { @trace[tid]
44

55
usdt:@TARGET@:python:cfunction__entry /@trace[tid]/ {
66
@seq += 1;
7-
const char *module = args->arg0 ? str(args->arg0) : "";
8-
printf("%d\tcfunction-entry:%s:%s\n", (int)@seq, module, str(args->arg1));
7+
const char *module = args->arg3 ? str(args->arg3) : "";
8+
printf("%d\tcfunction-entry:%s:%s:%d:%s\n", (int)@seq,
9+
str(args->arg0), str(args->arg1), args->arg2, module);
910
}
1011

1112
usdt:@TARGET@:python:cfunction__return /@trace[tid]/ {
1213
@seq += 1;
13-
const char *module = args->arg0 ? str(args->arg0) : "";
14-
printf("%d\tcfunction-return:%s:%s\n", (int)@seq, module, str(args->arg1));
14+
const char *module = args->arg3 ? str(args->arg3) : "";
15+
printf("%d\tcfunction-return:%s:%s:%d:%s\n", (int)@seq,
16+
str(args->arg0), str(args->arg1), args->arg2, module);
1517
}
1618

1719
usdt:@TARGET@:python:function__return /str(args->arg1) == "start"/ { @trace[tid] = 0; }

0 commit comments

Comments
 (0)