vmprof / vmprof-python

vmprof - a statistical program profiler
https://vmprof.readthedocs.io
Other
433 stars 55 forks source link

unknown marker 0x0 #135

Open rappdw opened 7 years ago

rappdw commented 7 years ago

With v0.4.4, running python -m vmprof -o output.log ... results in:

unknown marker 0x0

Running vmprofshow against output.log results in:

Fatal: could not read vmprof profile file 'output.log': (313125, "b'\\x00'")
Traceback (most recent call last):
  File "/usr/local/bin/vmprofshow", line 11, in <module>
    sys.exit(main())
  File "/usr/local/lib/python3.6/site-packages/vmprof/show.py", line 262, in main
    pp.show(args.profile)
  File "/usr/local/lib/python3.6/site-packages/vmprof/show.py", line 39, in show
    if stats.get_runtime_in_microseconds() < 1000000:
UnboundLocalError: local variable 'stats' referenced before assignment

(This is running in a debian docker container.)

When running on OSX, there is no unknown marker message, rather the following message occurs when running vmprofshow:

WARNING: The profiling completed in less than 1 seconds. Please run your programs longer!
No stack trace has been recorded (profile is empty)! Did your program not run long enough?

And this despite the program running for 70 seconds or so.

planrich commented 7 years ago

Could I get my hands on the profile? You can send it privately to planrichi [at] gmail [dot] com if you are not allowed to share it in public.

rappdw commented 7 years ago

Sent privately... (the profile was for the docker environment)

planrich commented 7 years ago

Can you try to do pip install --pre vmprof to install 0.4.5.dev0 and try again? The profile is broken though, you need to rerun the docker container...

rappdw commented 7 years ago

This fixes the issue when running in the Debian docker container.

On OSX, however, I still see: No stack trace has been recorded (profile is empty)! Did your program not run long enough?

planrich commented 7 years ago

As a quick test you could try to run python -m vmprof --no-native ... and see if it works. I'm investigating.

rappdw commented 7 years ago

adding the --no-native option did produce a profile usable by vmprofshow on OSX

planrich commented 7 years ago

I suspect that there is some libunwind issue. I have added a check that turns off native profiling if libunwind reports that it cannot initialize the library. (a warning is printed in this case).

Can you try 0.4.5.dev2? Does your osx have the developer command line tools?

rappdw commented 7 years ago

I do have developer command line tools installed.

I installed: git+git://github.com/vmprof/vmprof-python@334bc18a0713364e8611f71863afe5540f6b3021

I don't see any warning message printed.

I still see

vmprofshow profile.osx.log
No stack trace has been recorded (profile is empty)!
planrich commented 7 years ago

uh, I'm a bit clue less. I have one or two theories, but that would be too much to ask... Is there a way so that I can reproduce the issue on my osx machine?

rappdw commented 7 years ago

Hmm... I can't think of a way to easily reproduce this (running a mix of proprietary and opensource code against sensitive data).

planrich commented 7 years ago

Ok, I have scattered some warnings in the commit 8569d4b. Could I pester you to try that commit and report the warnings that are printed? Thanks.

rappdw commented 7 years ago

I installed 8569d4b and it now works (without any warnings being displayed).

I rolled back to 334bc18 and verified that it does not work.

planrich commented 7 years ago

That can have two reasons:

1) If libunwind cannot walk back the stack (there needs to be just one stack entry that is not well formed), no stack was recorded in 334bc18 2) The matching between C frame <-> Python level did not succeed, and previously no stack was returned either...

rappdw commented 7 years ago

I'm seeing the following in multiple executions:

8569d4b consistently succeeds (without any warnings) 334bc18 consistently fails