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

Add turmoil::sim_elapsed for retrieving total simulation virtual time #164

Merged
merged 2 commits into from
Jan 10, 2024

Conversation

zakvdm
Copy link
Collaborator

@zakvdm zakvdm commented Jan 8, 2024

Previously, we only exposed turmoil::elapsed which returned the elapsed virtual time for the currently executing host. If you step your simulation for some duration before registering a host then the host's elapsed time will be less than the overall sim elapsed time.

We didn't want to make a breaking API change for this, so opted to add a new function (turmoil::sim_elapsed). This function returns an Option so that the caller can gracefully handle failure (turmoil::elapsed will crash if called outside of an executing host, for example). This makes it easier to use sim_elapsed for things like logging elapsed time via the std tracing subscriber (there's an example of how to do this in the grpc example).

One sharp edge I ran into is that we sometimes do tracing in this crate itself (e.g. in Tcp::bind) which happens while we're holding a mutable borrow of the thread-local RefCell<World>. Since the tracing event causes us to call tracing::sim_elapsed, we have an attempted double mutable borrow. In these cases I just made sim_elapsed return None. It's a bit of a wart but I think it's okay. We also return None when sim_elapsed is called when there's no executing host, so I think the API returning Option feels right. We can internally fix the double borrow issue in future without a breaking change.

Copy link
Contributor

@mcches mcches left a comment

Choose a reason for hiding this comment

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

Nice change!

fn format_time(&self, w: &mut tracing_subscriber::fmt::format::Writer<'_>) -> std::fmt::Result {
// The debug implementation of Duration gives reasonably formatted
// durations (e.g. `610ms`, `2.62s`).
write!(w, "{:?}", turmoil::sim_elapsed().unwrap_or_default())
Copy link
Contributor

Choose a reason for hiding this comment

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

I think it is valuable to see real and sim time in the trace. Up to you on whether you think that is useful in the example.

/// virtual time.
///
/// Must be called from within a Turmoil simulation.
pub fn elapsed() -> Duration {
Copy link
Contributor

Choose a reason for hiding this comment

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

While the docs are the same, this is definitely more readable in the source code.

@zakvdm zakvdm closed this Jan 10, 2024
@zakvdm zakvdm deleted the sim_elapsed branch January 10, 2024 16:56
@zakvdm zakvdm reopened this Jan 10, 2024
Zak van der Merwe added 2 commits January 10, 2024 09:33
Previously, we only exposed `turmoil::elapsed` which returned the
elapsed virtual time for the currently executing host. If you step your
simulation for some duration before registering a host then the host's
elapsed time will be less than the overall sim elapsed time.

We didn't want to make a breaking API change for this, so opted to add a
new function (`turmoil::sim_elapsed`). This function returns an `Option`
so that the caller can gracefully handle failure (`turmoil::elapsed`
will crash if called outside of an executing host, for example). This
makes it easier to use `sim_elapsed` for things like logging elapsed
time via the std tracing subscriber (there's an example of how to do
this in the `grpc` example).

One sharp edge I ran into is that we sometimes do tracing in this crate
itself (e.g. in `Tcp::bind`) which happens while we're holding a mutable
borrow of the thread-local `RefCell<World>`. Since the tracing event
causes us to call `tracing::sim_elapsed`, we have an attempted double
mutable borrow. In these cases I just made `sim_elapsed` return `None`.
It's a bit of a wart but I think it's okay. We also return `None` when
`sim_elapsed` is called when there's no executing host, so I think the
API returning `Option` feels right. We can internally fix the double
borrow issue in future without a breaking change.
@zakvdm zakvdm merged commit 9277434 into tokio-rs:main Jan 10, 2024
3 checks passed
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