Empty Flamegraph - Githubissues

jphalimi-intel commented 8 years ago

I am using the following command:

0x app.js

The profiling starts, unfortunately the Flamegraph generated keeps being empty. I followed the steps presented in the tutorial.

0x version 2.2.8 Ubuntu 16.04 (perf v4.4.16)

Attachment: output of the command: DEBUG=* 0x app.js > /dev/null output.txt

Attachment: stacks file, that is empty (zipped): stacks.zip

Is there something obvious I am missing? :-)

Thanks,

Jp

davidmarkclements commented 8 years ago

Hey @jphalimi-intel

did it generate the actual flamegraph successfully though?
if on linux do you have perf installed
have you tried the --stacks-only flag (if all you want is stacks - https://github.com/davidmarkclements/0x#production-servers)
https://github.com/davidmarkclements/0x/issues/34 and https://github.com/davidmarkclements/0x/issues/33 may provide clues to help you figure out the issue

jphalimi-intel commented 8 years ago

@davidmarkclements Yes, the flamegraph.html was generated successfully, the file is here: flamegraph.zip

As mentioned previously, perf is installed (version 4.4.16).

If I try --stacks-only, the stacks.out is the only file generated, and it is empty.

I had a look at #34 and #33 but I could not find anything that helped me with the issue. I don't have any errors generated, even with DEBUG=*

davidmarkclements commented 8 years ago

what I'm guessing is happening, there's something getting in the way of https://github.com/davidmarkclements/0x/blob/master/soft-exit.js

That file is injected into your process - we need it there to successfully generate stacks

If another library is preventing that from happening (#33 / #34 related to this scenario) then you wont get stack output - it's a quirk of the interaction between node and perf.

@mcollina - anything to add?

mcollina commented 8 years ago

I agree that this looks like #33 or #34.

Were you able to replicate this issue using a test script, or just your application?

davidmarkclements commented 8 years ago

closing for now as we can't know more without looking at code, @jphalimi-intel feel free to contact me personally

jphalimi-intel commented 8 years ago

I will try to look closer at #33 and #34. If I can t solve my problem after that, I will contact you. Thanks for your prompt answers.

david-martin commented 8 years ago

@davidmarkclements @mcollina Can we re-open this issue?

I'm seeing this on Fedora 24 (using the slow-rest-api app) Some additional info that may be relevant.

EDIT Updated the output below to include the caught exception when trying to kill the perf record process. Looks permissions related...

DEBUG=0x,0x:stack-convert 0x --trace-info index.js 
0x captures stacks using perf, which requires sudo access
[sudo] password for dmartin: 
Profiling^C[ perf record: Woken up 9 times to write data ]
  0x Caught SIGINT, generating flamegraph +0ms
Caught SIGINT, generating flamegraph SIGINT Exception { Error: kill EPERM
    at exports._errnoException (util.js:1026:11)
    at process.kill (internal/process.js:172:13)
    at process.analyze (/home/dmartin/.nvm/versions/node/v6.8.0/lib/node_modules/0x/index.js:230:19)
    at process.g (events.js:291:16)
    at emitNone (events.js:86:13)
    at process.emit (events.js:185:7)
    at Signal.wrap.onsignal (internal/process.js:199:44) code: 'EPERM', errno: 'EPERM', syscall: 'kill' }
WARNING: The /tmp/perf-ez26sg.data file's data size field is 0 which is unexpected.
Was the 'perf record' command properly terminated?
  0x begin rendering +44ms
  0x:stack-convert serializing samples +2ms
  0x:stack-convert samples serialized +1ms
  0x converted stacks to intermediate format +0ms
[ perf record: Captured and wrote 2.113 MB /tmp/perf-ez26sg.data (5417 samples) ]
  0x flamegraph generated +280ms
  0x tidying up +1ms
file:///home/dmartin/nodeconfeu2016/slow-rest-api/profile-13728/flamegraph.html

  0x exiting +0ms
  0x done rendering +0ms

autocannon -d 5 -c 100 -l http://localhost:3000/a 
Running 5s test @ http://localhost:3000/a
100 connections

Stat         Avg       Stdev    Max      
Latency (ms) 165.65    11.32    243      
Req/Sec      592.8     33.2     614      
Bytes/Sec    756.94 kB 44.45 kB 819.2 kB 

Percentile      Latency (ms)      
50              163               
75              166               
90              176               
99              195               
99.9            238               
99.99           243               
99.999          243               

3k requests in 5s, 3.81 MB read

I'm looking into this error specifically, which hints at a timing issue around the perf script cmd being executed

Caught SIGINT generating flamegraph WARNING: The /tmp/perf-3ns4rp.data file's data size field is 0 which is unexpected.
Was the 'perf record' command properly terminated?

Note the perf file is actually greater than 0 in size, but might not have it's contents written or flushed at the time it's being read by 0x

ls -l /tmp/perf-3ns4rp.data
-rw-------. 1 root root 2226512 Oct 17 21:29 /tmp/perf-3ns4rp.data

davidmarkclements / 0x

Empty Flamegraph #41