Some DTrace probes are broken in 3.11 #98894

Elias-elastisys · 2022-10-31T09:50:10Z

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.

The text was updated successfully, but these errors were encountered:

brandtbucher · 2022-11-18T21:02:43Z

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

citrus-it · 2022-11-19T23:34:13Z

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

lukaszachy · 2023-03-09T20:06:13Z

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.

encukou · 2023-04-19T12:13:18Z

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

brandtbucher · 2023-04-19T14:05:23Z

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

Elias-elastisys added the type-crash A hard crash of the interpreter, possibly with a core dump label Oct 31, 2022

kumaraditya303 added interpreter-core (Objects, Python, Grammar, and Parser dirs) 3.11 bug and security fixes labels Oct 31, 2022

brandtbucher self-assigned this Nov 18, 2022

citrus-it mentioned this issue Nov 27, 2022

Add python 3.11 omniosorg/omnios-build#3013

Merged

brandtbucher removed their assignment Apr 19, 2023

This was referenced May 10, 2023

Missing DTrace probes #104280

Open

Generator finalization is slower in 3.11 vs 3.10 #100762

Open

Some DTrace probes are broken in 3.11 #98894

Some DTrace probes are broken in 3.11 #98894

Elias-elastisys commented Oct 31, 2022

brandtbucher commented Nov 18, 2022

citrus-it commented Nov 19, 2022 •

edited

lukaszachy commented Mar 9, 2023

encukou commented Apr 19, 2023

brandtbucher commented Apr 19, 2023

Some DTrace probes are broken in 3.11 #98894

Some DTrace probes are broken in 3.11 #98894

Comments

Elias-elastisys commented Oct 31, 2022

Crash report

Error messages

Expected result

Your environment

brandtbucher commented Nov 18, 2022

citrus-it commented Nov 19, 2022 • edited

lukaszachy commented Mar 9, 2023

encukou commented Apr 19, 2023

brandtbucher commented Apr 19, 2023

citrus-it commented Nov 19, 2022 •

edited