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

feat: measure fuel usage and timing stats #465

Draft
wants to merge 19 commits into
base: master
Choose a base branch
from

Conversation

Kubuxu
Copy link

@Kubuxu Kubuxu commented Apr 6, 2022

No description provided.

@raulk
Copy link
Member

raulk commented Apr 7, 2022

Rude to remove me as an author @Kubuxu 🙃🤣

@Kubuxu
Copy link
Author

Kubuxu commented Apr 7, 2022

It wasn't on purpose 🙃 no idea why it picked up steb instead of you as the author.

raulk and others added 3 commits April 7, 2022 14:05
Signed-off-by: Jakub Sztandera <kubuxu@protocol.ai>

feat: expose machine from executor via deref
Signed-off-by: Jakub Sztandera <kubuxu@protocol.ai>

fvm: more stats
Signed-off-by: Jakub Sztandera <kubuxu@protocol.ai>

feat: track "real" compute gas

feat: time module compile/link/instantiate time

detailed gas and fuel tracing: initial implementation.

Introduces a new Cargo feature `tracing` that enables detailed gas tracing.

Traces are accumulated in the GasTracer, owned by the CallManager.

Gas traces specify the context, point of tracing, consumption stats, and timing stats.

We currently support these tracing points:

- {Pre,Post}Syscall
- {Pre,Post}Extern
- {Enter,Exit}Call
- Start (of the call stack)
- Finish (of the call stack)

Traces are currently serialized to JSON and printed directly on stdout.

There's a bit of duplication the syscall binding macros that I'm not happy about, and
perhaps we could make the tracepoints in the CallManager a bit DRYer.

fix build.

Trace to file

Signed-off-by: Jakub Sztandera <kubuxu@protocol.ai>
Signed-off-by: Jakub Sztandera <kubuxu@protocol.ai>
Signed-off-by: Jakub Sztandera <kubuxu@protocol.ai>
@Kubuxu
Copy link
Author

Kubuxu commented Apr 7, 2022

Fixed

Copy link
Member

@raulk raulk left a comment

Choose a reason for hiding this comment

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

This tracing framework is useful to inspect running logic in detail, how it interacts with the environment, debugging execution flow, understand the instruction complexity of ranges, and get a relative sense of where time is spent.

However, this should come with a massive warning sign: the timing numbers are considerably skewed by several factors:

  1. Non-negligible overhead of getting time from the system.
    • According to minstant benchmarks, std::time::Instant::now() can have an overhead of as much as 30ns on the specified platform.
    • Using the TSC is a solution, but even with minstant there's an overhead of 10ns which needs to be accounted for.
    • Potential solution: correct for overhead by benchmarking getting time, and applying a negative offset to all duration readings.
  2. Additional instructions + cache thrashing due to the tracing logic, which is not observed in real executions.

@raulk raulk force-pushed the kub/detailed-gas-tracing branch 2 times, most recently from d953e55 to 22edabc Compare April 25, 2022 19:25
@raulk raulk force-pushed the kub/detailed-gas-tracing branch 2 times, most recently from f9d5ea2 to 8ea11f0 Compare April 26, 2022 20:20
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.

None yet

2 participants