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

refactor: use external crate for displaying tracing spans #4781

Merged
merged 3 commits into from
Sep 8, 2021

Conversation

matklad
Copy link
Contributor

@matklad matklad commented Sep 2, 2021

When debugging #4771, I had to copy-paste tracing_timings module to get
a useful profiling output, which isn't ideal. So I improved and
published that code to crates.io as tracing-span-tree.

In particular, this new implementation prints the trace in the correct
order, and it also has an .aggregate(true) mode for cases where you
run the profiled code in a loop and want a summary.

Example without aggregation:

  328.25ms         vm_script_smoke_test
    306.34ms         run_vm
      306.32ms         run_wasmer
        37.16µs          get_key
        301.50ms         compile_and_serialize_wasmer
        4.44ms           run_method
          2.53ms           run_method/instantiate
          128.17µs         run_method/call
          1.74ms           run_method/drop_instance
    4.50ms           run_vm
      4.49ms           run_wasmer
        31.81µs          get_key
        4.25ms           run_method
          2.45ms           run_method/instantiate
          45.46µs          run_method/call
          1.72ms           run_method/drop_instance
    4.43ms           run_vm
      4.42ms           run_wasmer
        22.43µs          get_key
        4.21ms           run_method
          2.41ms           run_method/instantiate
          42.84µs          run_method/call
          1.72ms           run_method/drop_instance
    4.81ms           run_vm
      4.80ms           run_wasmer
        22.09µs          get_key
        4.58ms           run_method
          2.40ms           run_method/instantiate
          419.57µs         run_method/call
          1.73ms           run_method/drop_instance

Example with aggregation (unit-less number is the number of aggregated calls):

  333.98ms         vm_script_smoke_test
    325.54ms  4      run_vm
      325.48ms  4      run_wasmer
        307.07ms         compile_and_serialize_wasmer
        129.19µs  4      get_key
        17.32ms   4      run_method
          612.46µs  4      run_method/call
          6.63ms    4      run_method/drop_instance
          9.94ms    4      run_method/instantiate

Test Plan

This is a debugging utility which is not enabled in production, so I just manually verified that the output makes sense.

When debugging near#4771, I had to copy-paste tracing_timings module to get
a useful profiling output, which isn't ideal. So I improved and
published that code to crates.io as `tracing-span-tree`.

In particular, this new implementation prints the trace in the correct
order, and it also has an `.aggregate(true)` mode for cases where you
run the profiled code in a loop and want a summary.
Copy link
Member

@ailisp ailisp left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good! Could you paste a sample output in PR description to demonstrate?

@matklad
Copy link
Contributor Author

matklad commented Sep 8, 2021

Good call!

@near-bulldozer near-bulldozer bot merged commit 4e761c5 into near:master Sep 8, 2021
@matklad matklad deleted the tracing-span-tree branch September 9, 2021 08:43
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

Successfully merging this pull request may close these issues.

2 participants