vmprof / vmprof-python

vmprof - a statistical program profiler
http://vmprof.com
Other
433 stars 54 forks source link

Embedded Python seems not possible to resolve "native" functions #236

Open kayhayen opened 3 years ago

kayhayen commented 3 years ago

Hello,

this is Linux with Python2 and Python3 both.

git clone --branch factory https://github.com/Nuitka/Nuitka.git
python2 ./bin/nuitka-run --profile tests/benchmarks/pystone.py 500000 && python -m vmprof.show nuitka-performance.dat
#or if you prefer:
python3 ./bin/nuitka-run --profile tests/benchmarks/pystone3.py 500000 && python3 -m vmprof.show nuitka-performance.dat

I am getting purely native symbols with plausible time distribution. Nuitka is embedding Python here. I am doing this on Debian Linux with both installed Python2 and Python3 with same results. This used to work years ago. When you look at pystone.bin you will find it's not stripped, has debug symbols, and objdump disassambles it just fine with symbols. It writes "nuitka-performance.dat" hard coded.

The way I am implementing it is here: https://github.com/Nuitka/Nuitka/blob/factory/nuitka/build/static_src/HelpersProfiling.c

Basically I am just calling enable with a file number and default arguments. My checking of vmprof code says that on Linux "native" resolution is automatically enabled by default.

Can you tell me what I am doing wrong, or give me a pointer, to where it's attempted to resolve, so I might debug this? My current best guess is that it might be using sys.exectable, which would not be the binary, something like this. Is embedding of Python supported at all anymore? Was it ever, maybe I always used extension modules, not sure now.

Yours, Kay

kayhayen commented 3 years ago

I managed to verify that libbacktrace in fact claims to have found "dwarf" information. This is the case with CCLFAGS="-gdwarf" LDFLAGS="-gdwarf and without, not sure if it really read anything successful. I cannot find a place to dump what it read. Also I don't yet figure out how vmp_walk_and_record_stack does the resolution.

kayhayen commented 3 years ago

Ok, I think this got removed, the only instance of a call to unw_get_proc_name has been commented out. This has been done in commit 4ce5fd2 or on closer inspection, a commented out use, probably for tracing, was added.

Does it mean, that I cannot expect the C function names of Nuitka C functions in the binary to be listed? Makes me wonder, what libbacktrace is used for? Something must be wrong in my analysis.

Should the log reader be able to resolve this addresses later? That may be a problem with hardening defaults of some sorts. The addresses are randomized and cannot be resolved anymore.

kayhayen commented 3 years ago

Activating the traces, I am getting what I want, traced:

  impl___main__$$$function__8_Proc2 0x5575bbcff150
  CALL_FUNCTION_WITH_SINGLE_ARG 0x5575bbd41800
  impl___main__$$$function__6_Proc0 0x5575bbd01d60
  CALL_FUNCTION_WITH_SINGLE_ARG 0x5575bbd41800
  impl___main__$$$function__4_pystones 0x5575bbcfbff0
  CALL_FUNCTION_WITH_SINGLE_ARG 0x5575bbd41800
  impl___main__$$$function__3_main 0x5575bbd050c0
  CALL_FUNCTION_WITH_SINGLE_ARG 0x5575bbd41800
  modulecode___main__ 0x5575bbd06b50
  _EXECUTE_EMBEDDED_MODULE 0x5575bbd8e760
  IMPORT_EMBEDDED_MODULE 0x5575bbd8e5c0
  main 0x5575bbcf8bb0

Now I guess, I am going to extend my copy of vmprof such that it supports including a mapping of names for native functions, and be able to read that.

kayhayen commented 3 years ago

It seems it writes a table of code object identifiers at the end, probably something similar would be needed for native function names too.

kayhayen commented 3 years ago

Ok, when I did that, I found it never recorded what I was having on the stack. It seems to have some severe regressions for mixing C code and Python stacks. At the end, after recording the all C stack, it would unconditionally record the Python stack only, unless in the middle, it encounter a frame evaluation, when it does that sooner.

Still no idea why these came out as native functions. Probably because I barely have any Python stacks, and there are functions on the stack before entering main. When I find the time, I am goingto make a PR out of this.