Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
brainstorm opened this issue Jan 16, 2023 · 3 comments
Open

Comments

@brainstorm
Copy link

brainstorm commented Jan 16, 2023

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.

brainstorm added a commit to umccr/htsget-rs that referenced this issue Jan 16, 2023
…happen in DTrace under OSX? See: flamegraph-rs/flamegraph#248

Also check contents of restricted GHA kernel memory map.
@djc
Copy link
Contributor

djc commented Jan 17, 2023

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

@brainstorm
Copy link
Author

brainstorm commented Jan 18, 2023

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

@brainstorm brainstorm changed the title PERFILE binary contents spewed on stdout? PERFILE binary contents spewed on stdout on Github Actions runners? Jan 18, 2023
@larseggert
Copy link

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants