flamegraph-rs / flamegraph

Easy flamegraphs for Rust projects and everything else, without Perl or pipes <3
Apache License 2.0
4.59k stars 142 forks source link

PERFILE binary contents spewed on stdout on Github Actions runners? #248

Open brainstorm opened 1 year ago

brainstorm commented 1 year ago

I'm running cargo flamegraph --deterministic --flamechart -o flamechart.svg --bench search-benchmarks -- --bench on Github Actions and I'm seeing the binary contents of perf files being dumped on stdout (perhaps stderr?):

Screenshot 2023-01-17 at 10 44 51 am

The same command on OSX (DTrace) does not seem to have that issue.

djc commented 1 year ago

Seems surprising -- I don't have an idea off the top of my head why it might be.

brainstorm commented 1 year ago

I just tested it under Windows 11 WSL2 (with some SO perf binary workarounds) instead of GHA and the output both surprised me and gave some clues... 3.6GB of perf.data are being generated at the end of the command!!:

brainstorm@braingate:~/htsget-rs$ cargo flamegraph --deterministic --flamechart -o flamechart.svg --bench search-benchmarks -- --bench
    Finished bench [optimized + debuginfo] target(s) in 0.50s
Queries/[LIGHT] Bam query all
                        time:   [601.06 ns 607.58 ns 615.31 ns]
Found 5 outliers among 50 measurements (10.00%)
  1 (2.00%) low mild
  2 (4.00%) high mild
  2 (4.00%) high severe
Queries/[LIGHT] Bam query specific
                        time:   [606.72 ns 620.28 ns 636.32 ns]
Found 7 outliers among 50 measurements (14.00%)
  1 (2.00%) high mild
  6 (12.00%) high severe
Queries/[LIGHT] Bam query header
                        time:   [597.83 ns 600.43 ns 603.43 ns]
Found 7 outliers among 50 measurements (14.00%)
  2 (4.00%) low mild
  3 (6.00%) high mild
  2 (4.00%) high severe
Queries/[LIGHT] Cram query all
                        time:   [594.48 ns 596.35 ns 598.44 ns]
Found 5 outliers among 50 measurements (10.00%)
  2 (4.00%) low severe
  1 (2.00%) low mild
  1 (2.00%) high mild
  1 (2.00%) high severe
Queries/[LIGHT] Cram query specific
                        time:   [598.58 ns 603.78 ns 609.88 ns]
Found 4 outliers among 50 measurements (8.00%)
  2 (4.00%) high mild
  2 (4.00%) high severe
Queries/[LIGHT] Cram query header
                        time:   [594.58 ns 595.79 ns 596.68 ns]
Found 5 outliers among 50 measurements (10.00%)
  1 (2.00%) low severe
  2 (4.00%) high mild
  2 (4.00%) high severe
Queries/[LIGHT] Vcf query all
                        time:   [595.42 ns 596.08 ns 596.95 ns]
Found 7 outliers among 50 measurements (14.00%)
  3 (6.00%) high mild
  4 (8.00%) high severe
Queries/[LIGHT] Vcf query specific
                        time:   [595.15 ns 596.86 ns 598.91 ns]
Found 4 outliers among 50 measurements (8.00%)
  2 (4.00%) high mild
  2 (4.00%) high severe
Queries/[LIGHT] Vcf query header
                        time:   [596.16 ns 599.26 ns 602.53 ns]
Found 1 outliers among 50 measurements (2.00%)
  1 (2.00%) high mild
Queries/[LIGHT] Bcf query all
                        time:   [594.19 ns 599.49 ns 608.89 ns]
Found 4 outliers among 50 measurements (8.00%)
  1 (2.00%) high mild
  3 (6.00%) high severe
Queries/[LIGHT] Bcf query specific
                        time:   [591.72 ns 592.48 ns 593.38 ns]
Found 5 outliers among 50 measurements (10.00%)
  3 (6.00%) high mild
  2 (4.00%) high severe
Queries/[LIGHT] Bcf query header
                        time:   [591.55 ns 592.22 ns 593.08 ns]
Found 6 outliers among 50 measurements (12.00%)
  1 (2.00%) high mild
  5 (10.00%) high severe
 
[ perf record: Woken up 14410 times to write data ]
[ perf record: Captured and wrote 3661.574 MB perf.data (230547 samples) ]
 
brainstorm@braingate:~/htsget-rs$ ls -alh
(...)
-rw-------  1 brainstorm brainstorm 3.6G Jan 18 15:35 perf.data

Perhaps I need to consider https://github.com/koute/not-perf or somehow downsize the current benchmarks suite... still it doesn't explain why perf.data ends up in stdout/stderr for GHA runner, but anyway, the data size collected is not practical for CI.

Also, the command never ends on WSL2 either (need to Ctrl+C)... and a flamechart.svg is actually generated after interrupting the process :/

/cc @mmalenic

larseggert commented 6 months ago

I see the same issue. I'm working around it by giving -c "record -o perf.data -F997 --call-graph dwarf,16384 -g", i.e., by setting the output file name explicitly, but it's not a very satisfying solution.