Some DTrace probes are broken in 3.11

Crash report

I've been using eBPF with the static markers in Python 3.10 and wanted to try out 3.11 now that it is released.

But it seems that the function__entry and line markers are broken in 3.11.

The function__entry probe simply does not fire into the eBPF program.
The line probe crashes the interpreter.

I'm using BCC to load the eBPF program like this:

#!/usr/bin/python3

import argparse
from bcc import BPF, USDT

parser = argparse.ArgumentParser()
parser.add_argument("pid", type=int)
args = parser.parse_args()

program = """
int trace_entry(struct pt_regs *ctx) {
    bpf_trace_printk("Entry:");

    return 0;
}

int trace_return(struct pt_regs *ctx) {
    bpf_trace_printk("Return:");

    return 0;
}

int trace_line(struct pt_regs *ctx) {
    bpf_trace_printk("Line:");

    return 0;
}
"""

usdt = USDT(pid=args.pid)
usdt.enable_probe_or_bail("python:function__entry", 'trace_entry')
usdt.enable_probe_or_bail("python:function__return", 'trace_return')
usdt.enable_probe_or_bail("python:line", 'trace_line')

bpf = BPF(text=program, usdt_contexts=[usdt] if usdt else [], debug=0)

try:
    bpf.trace_print()
except KeyboardInterrupt:
    exit()

If I don't enable the line probe this is the output:

❯ sudo ./ebpf-test.py 80715
b'          python-80715   [001] d...1  6539.145626: bpf_trace_printk: Return:'

The entry message is never printed.

Error messages

With the line probe enabled, this is the crash error:

❯ ./python
Python 3.11.0+ (heads/3.11:57dd11038f, Oct 31 2022, 10:30:28) [GCC 11.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> print("Hello world!")
python: Python/ceval.c:5620: _PyEval_EvalFrameDefault: Assertion `cframe.use_tracing' failed.
[1]    80398 IOT instruction (core dumped)  ./python

Expected result

Running the same test in 3.10.6 I get this result, as expected:

❯ python3                      
Python 3.10.6 (main, Aug 10 2022, 11:40:04) [GCC 11.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> print("Hello world!")
Hello world!

❯ sudo ./ebpf-test.py 81962
b'         python3-81962   [003] d...1  6907.857690: bpf_trace_printk: Entry:'
b'         python3-81962   [003] d...1  6907.857710: bpf_trace_printk: Line:'
b'         python3-81962   [003] d...1  6907.857765: bpf_trace_printk: Return:'

Your environment

I used the head of the 3.11 branch with ./configure --with-dtrace --with-pydebug
On Ubuntu 22.04.

Linked PRs

Thanks, I'll take a look at this soon.

I am seeing the same behaviour on illumos with the function-entry dtrace probe - it's firing but not for much, and not for functions defined in the test program. The dtrace tests fail.

build:cpython:heads/v3.11.0% uname -a
SunOS build 5.11 omnios-r151044-d3b715b9d1 i86pc i386 i86pc

build:cpython:heads/v3.11.0% LD_LIBRARY_PATH=. \
>     dtrace -s Lib/test/dtracedata/call_stack.d \
>     -c './python Lib/test/dtracedata/call_stack.py'
dtrace: script 'Lib/test/dtracedata/call_stack.d' matched 10 probes
dtrace: pid 11421 has exited

build:cpython:heads/v3.11.0% LD_LIBRARY_PATH=. \
    dtrace -n 'python$target:::function-entry{trace(copyinstr(arg1))}' \
    -c './python Lib/test/dtracedata/call_stack.py'
dtrace: description 'python$target:::function-entry' matched 2 probes
dtrace: pid 13756 has exited
CPU     ID                    FUNCTION:NAME
 12  99130 dtrace_function_entry:function-entry   <genexpr>
 12  99130 dtrace_function_entry:function-entry   <lambda>
 12  99130 dtrace_function_entry:function-entry   _coro
 12  99130 dtrace_function_entry:function-entry   _ag

build:cpython:heads/v3.11.0% LD_LIBRARY_PATH=. \
    dtrace -ln 'python$target:::' \
    -c './python Lib/test/dtracedata/call_stack.py'
   ID   PROVIDER            MODULE                          FUNCTION NAME
99126 python15257 libpython3.11.so.1.0                  sys_audit_tstate audit
99127 python15257 libpython3.11.so.1.0             sys_audit_tstate.cold audit
99128 python15257 libpython3.11.so.1.0                         sys_audit audit
99129 python15257 libpython3.11.so.1.0          _PyEval_EvalFrameDefault function-entry
99130 python15257 libpython3.11.so.1.0             dtrace_function_entry function-entry
99131 python15257 libpython3.11.so.1.0          _PyEval_EvalFrameDefault function-return
99132 python15257 libpython3.11.so.1.0            dtrace_function_return function-return
99133 python15257 libpython3.11.so.1.0     _PyEval_EvalFrameDefault.cold function-return
99134 python15257 libpython3.11.so.1.0              gc_collect_main.cold gc-done
99135 python15257 libpython3.11.so.1.0                   gc_collect_main gc-done
99136 python15257 libpython3.11.so.1.0              gc_collect_main.cold gc-start
99137 python15257 libpython3.11.so.1.0                   gc_collect_main gc-start
99138 python15257 libpython3.11.so.1.0 PyImport_ImportModuleLevelObject.cold import-find-load-done
99139 python15257 libpython3.11.so.1.0 PyImport_ImportModuleLevelObject.cold import-find-load-start
99140 python15257 libpython3.11.so.1.0          _PyEval_EvalFrameDefault line
99141 python15257 libpython3.11.so.1.0     _PyEval_EvalFrameDefault.cold line

Edit: the line probe seems fine:

build:cpython:heads/v3.11.0% LD_LIBRARY_PATH=. \
    dtrace -n 'python$target:::line{printf("%s:%d", copyinstr(arg1), arg2)}' \
    -c './python Lib/test/dtracedata/call_stack.py' | sed -n '/start/,$p'
dtrace: description 'python$target:::line' matched 2 probes
dtrace: pid 20479 has exited
 27  99141 _PyEval_EvalFrameDefault.cold:line start:24
 27  99141 _PyEval_EvalFrameDefault.cold:line function_1:2
 27  99141 _PyEval_EvalFrameDefault.cold:line function_3:10
 27  99141 _PyEval_EvalFrameDefault.cold:line start:25
 27  99141 _PyEval_EvalFrameDefault.cold:line function_2:6
 27  99141 _PyEval_EvalFrameDefault.cold:line function_1:2
 27  99141 _PyEval_EvalFrameDefault.cold:line function_3:10
 27  99141 _PyEval_EvalFrameDefault.cold:line start:26
 27  99141 _PyEval_EvalFrameDefault.cold:line function_3:10
 27  99141 _PyEval_EvalFrameDefault.cold:line start:27
 27  99141 _PyEval_EvalFrameDefault.cold:line function_4:14
 27  99141 _PyEval_EvalFrameDefault.cold:line start:28
 27  99141 _PyEval_EvalFrameDefault.cold:line function_5:19
 27  99141 _PyEval_EvalFrameDefault.cold:line function_5:21

Hi, could this issue be also the reason why following systemtap probe is not printing anything for python3.11?

Probe:

#!/usr/bin/stap -v
probe python.function.entry
{
 if ( filename =~ "random" )
  printf("%s => %s in %s:%d\n", thread_indent(1), funcname, filename, lineno);
}

Simple python script

import random, time
print(random.random())
time.sleep(3)

To reproduce run stap probe.stp -v -c "python3.11 script.py". I've tried python3.11 available in Fedora 37 or centos-stream-9.

@brandtbucher

@brandtbucher, do you still intend to look at this?

Probably not… this stuff seems to have changed quite a bit recently, and I was never too familiar with it in the first place.

I took a look at this yesterday in 3.12 as part of my current effort to package 3.12 for OpenIndiana (illumos) and I got the function entry/exit probes restored and working well enough to pass the test_dtrace.py test.

I'll share when I get a chance - I'm doing this with original dtrace on illumos (the open-source continuation of opensolaris) but it would likely also work for those who want to use these probes via systemtap.

As I mentioned in #104280 I have the function-entry and function-return probes restored in https://github.com/Bill-Sommerfeld/cpython/tree/dtrace-3.12

I'd appreciate it if others could give it a look.

pythongh-98894: Update DTrace Docs in instrumentation.rst

pythongh-98894: Restore function entry/exit DTrace probes

fixup! pythongh-98894: Restore function entry/exit DTrace probes

pythongh-98894: Quote test_dtrace tracer subcommands

[3.15] gh-98894: Check tracer exit status in test_dtrace (GH-152893) (#…

gh-98894: Quote test_dtrace tracer subcommands (#152901)

[3.15] gh-98894: Quote test_dtrace tracer subcommands (GH-152901) (#1…

pythongh-98894: Fix dtrace tests in shared builds

gh-98894: Fix dtrace tests in shared builds (#153372)

pythongh-98894: Fix dtrace tests in shared builds (python#153372)

[3.15] gh-98894: Fix dtrace tests in shared builds (GH-153372) (#155803)

[3.14] gh-156701: Backport test_dtrace from main (#159596)

test_dtrace has been patched by multiple issues:

Some DTrace probes are broken in 3.11 #98894
test_dtrace can hang indefinitely when bpftrace usability check times out #151496
test_dtrace leaks temporary files on "PPC64LE CentOS9 LTO + PGO 3.x" buildbot #156701
test_dtrace fails on aarch64 Fedora Stable 3.15: "libpython3.15d.so.1.0: cannot open shared object file" #156703
test_dtrace should try to terminate SystemTap gracefully before SIGKILL #156722

I tried to reproduce the initial reproducer #98894 (comment) on the main branch, but I got this error:

Failed to enable USDT probe 'python:line':
the specified pid might not contain the given language's runtime,
or the runtime was not built with the required USDT probes. Look
for a configure flag similar to --with-dtrace or --enable-dtrace.
To check which probes are present in the process, use the tplist tool.

I cannot find the "line" probe in readelf output:

$ readelf -n ./python
(...)

Displaying notes found in: .note.stapsdt
  Owner                Data size 	Description
  stapsdt              0x00000046	NT_STAPSDT (SystemTap probe descriptors)
    Provider: python
    Name: function__return
    Location: 0x00000000005ad35f, Base: 0x00000000008f1655, Semaphore: 0x0000000000a30ed2
    Arguments: 8@%r14 8@%r12 -4@%eax
  stapsdt              0x00000045	NT_STAPSDT (SystemTap probe descriptors)
    Provider: python
    Name: function__entry
    Location: 0x00000000005ad3a4, Base: 0x00000000008f1655, Semaphore: 0x0000000000a30ed0
    Arguments: 8@%r14 8@%r12 -4@%eax
  stapsdt              0x00000032	NT_STAPSDT (SystemTap probe descriptors)
    Provider: python
    Name: gc__start
    Location: 0x000000000060796c, Base: 0x00000000008f1655, Semaphore: 0x0000000000a30ede
    Arguments: -4@%r12d
  stapsdt              0x00000030	NT_STAPSDT (SystemTap probe descriptors)
    Provider: python
    Name: gc__done
    Location: 0x0000000000607d41, Base: 0x00000000008f1655, Semaphore: 0x0000000000a30ee0
    Arguments: -8@%rax
  stapsdt              0x00000040	NT_STAPSDT (SystemTap probe descriptors)
    Provider: python
    Name: import__find__load__start
    Location: 0x0000000000617481, Base: 0x00000000008f1655, Semaphore: 0x0000000000a30ee2
    Arguments: 8@%rax
  stapsdt              0x00000048	NT_STAPSDT (SystemTap probe descriptors)
    Provider: python
    Name: import__find__load__done
    Location: 0x00000000006174a7, Base: 0x00000000008f1655, Semaphore: 0x0000000000a30ee4
    Arguments: 8@%rax -4@%r15d
  stapsdt              0x00000033	NT_STAPSDT (SystemTap probe descriptors)
    Provider: python
    Name: audit
    Location: 0x000000000065ce26, Base: 0x00000000008f1655, Semaphore: 0x0000000000a30ee6
    Arguments: 8@%r12 8@%r13

In Python 3.11, I see that OR_DTRACE_LINE macro is used by Python/ceval.c. But the macro is no longer used in Python 3.12 and newer. It seems like OR_DTRACE_LINE is broken on 3.12 and newer.

gh-98894: Fix test_dtrace on Solaris (#154803)

[3.15] gh-98894: Fix test_dtrace on Solaris (GH-154803) (#159602)

pythongh-98894: Fix test_dtrace on Solaris (python#154803)

[3.14] gh-98894: Fix test_dtrace on Solaris (#154803) (#159605)

Navigation Menu

Repository navigation

Some DTrace probes are broken in 3.11 #98894

Crash report

Error messages

Expected result

Your environment

Linked PRs

21 remaining items

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Some DTrace probes are broken in 3.11 #98894

Description

Crash report

Error messages

Expected result

Your environment

Linked PRs

Activity

brandtbucher commented on Nov 18, 2022

citrus-it commented on Nov 19, 2022

lukaszachy commented on Mar 9, 2023

encukou commented on Apr 19, 2023

brandtbucher commented on Apr 19, 2023

Bill-Sommerfeld commented on Feb 9, 2024

Bill-Sommerfeld commented on Feb 9, 2024

21 remaining items

vstinner commented on Oct 16, 2026

vstinner commented on Oct 16, 2026

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions