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 tokio taskname registration for use in tokio-console #89

Merged
merged 19 commits into from
Nov 24, 2024

Conversation

hirschenberger
Copy link
Contributor

@hirschenberger hirschenberger commented Oct 29, 2024

This uses the tokio-unstable feature that has to be enabled and also the runtime variable RUSTFLAGS="--cfg tokio_unstable" must be set to enable tokio taskname registration.

See example program tokio-console.rs for usage.

fixes #87

src/runner.rs Fixed Show fixed Hide fixed
src/runner.rs Outdated Show resolved Hide resolved
src/runner.rs Outdated Show resolved Hide resolved
@Finomnis
Copy link
Owner

We might have to think about how to update the CI. Should we test twice, once with and once without the feature?

@hirschenberger
Copy link
Contributor Author

We might have to think about how to update the CI. Should we test twice, once with and once without the feature?

Yes, I think that makes sense to avoid code-rot.

This uses the `tokio-unstable` feature that has to be enabled and also
the runtime variable `RUSTFLAGS="--cfg tokio_unstable"` must be set to
enable tokio taskname registration.

See example program `tokio-console.rs` for usage.
@Finomnis
Copy link
Owner

Will you look into that or do you need help?

@hirschenberger
Copy link
Contributor Author

Will you look into that or do you need help?

The CI? I'm not so familliar with Github CI, so help would be great.

@github-advanced-security
Copy link

This pull request sets up GitHub code scanning for this repository. Once the scans have completed and the checks have passed, the analysis results for this pull request branch will appear on this overview. Once you merge this pull request, the 'Security' tab will show more code scanning analysis results (for example, for the default branch). Depending on your configuration and choice of analysis tool, future pull requests will be annotated with code scanning analysis results. For more information about GitHub code scanning, check out the documentation.

Copy link

codecov bot commented Nov 1, 2024

Codecov Report

Attention: Patch coverage is 96.07843% with 2 lines in your changes missing coverage. Please review.

Project coverage is 97.46%. Comparing base (8b2d7f1) to head (bc5b151).
Report is 1 commits behind head on main.

Files with missing lines Patch % Lines
src/runner.rs 94.11% 1 Missing and 1 partial ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main      #89      +/-   ##
==========================================
+ Coverage   97.40%   97.46%   +0.05%     
==========================================
  Files          14       15       +1     
  Lines         656      670      +14     
  Branches      656      670      +14     
==========================================
+ Hits          639      653      +14     
- Misses          0        1       +1     
+ Partials       17       16       -1     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.


🚨 Try these New Features:

@Finomnis
Copy link
Owner

Finomnis commented Nov 1, 2024

Activating RUSTFLAGS="--cfg tokio_unstable" seems to print really long and convoluted log messages. What's up with that?

How does the output of examples/tokio-console.rs look for you? Because for me it's quite a mess.

examples/tokio_console.rs Fixed Show fixed Hide fixed
examples/tokio_console.rs Fixed Show fixed Hide fixed
@Finomnis
Copy link
Owner

Finomnis commented Nov 2, 2024

@hirschenberger I did some refactoring; what's your opinion on the current state?

(p.s. don't worry about the amount of commits, I'll squash anyway)

@hirschenberger
Copy link
Contributor Author

hirschenberger commented Nov 2, 2024

@Finomnis Sorry for the late reply, I was busy the last days. You've been pretty productive. Looks good, I also thought about also naming the internal tasks (wait for signal and subsystem spawner).

One little nitpick, it is a bit misleading that the spawn functions for the tokio-unstable and not(tokio-unstable) case are both in a file named tokio-unstable.

And I'm also not sure if my feature name tokio-unstable is a good choice. Maybe we should rename it so that it expresses "What" that thing enables.

@Finomnis
Copy link
Owner

Finomnis commented Nov 2, 2024

@Finomnis Sorry for the late reply, I was busy the last days. You've been pretty productive. Looks good, I also thought about also naming the internal tasks (wait for signal and subsystem spawner).

You also named the wrong task :)
Every subsystem contains two tasks, one that is the actual subsystem code, and one that checks the error status and propagates it after the task is done. That was necessary because there was no other way to process subsystem panics (that I found).

One little nitpick, it is a bit misleading that the spawn functions for the tokio-unstable and not(tokio-unstable) case are both in a file named tokio-unstable.

Propose something better :) my first guess was "spawn", but that collided with the function "spawn". Maybe "task", so you can do crate::task::spawn()?

And I'm also not sure if my feature name tokio-unstable is a good choice. Maybe we should rename it so that it expresses "What" that thing enables.

Yah, maybe "tracing"?

@hirschenberger
Copy link
Contributor Author

task::spawn() sounds good and we'll known.

For the feature name how about named-tasks

@Finomnis
Copy link
Owner

Finomnis commented Nov 2, 2024

For the feature name how about named-tasks

It does more though; it enables tokio/tracing which globally changes some tokio behavior (like, it makes logging much more verbose). So I would like to include that behavior in the flag name as well.

Are you ok with simply tracing?

@hirschenberger
Copy link
Contributor Author

hirschenberger commented Nov 2, 2024

For the feature name how about named-tasks

It does more though; it enables tokio/tracing which globally changes some tokio behavior (like, it makes logging much more verbose). So I would like to include that behavior in the flag name as well.

I'm not really sure if it changes the tacing behaviour. I think this hurricane of logs comes from the tracing configuration in the example program. Maybe I did something wrong there and logged the messages that are meant for the tokio-console CLI to stdout.

Unfortunately I have no time today to look into this. But I believe that's the reason. I have used tokio-console before without that amount of logs to stdout.

Are you ok with simply tracing?

@Finomnis
Copy link
Owner

Finomnis commented Nov 2, 2024

I'm not really sure if it changes the tacing behaviour. I think this hurricane of logs comes from the tracing configuration in the example program. Maybe I did something wrong there and logged the messages that are meant for the tokio-console CLI to stdout.

It seems to be the --cfg tokio_unstable that creates this amount of logs.

$ cargo run --example 01_normal_shutdown
2024-11-02T14:10:50.230417Z  INFO 01_normal_shutdown: Subsystem2 started.
2024-11-02T14:10:50.230417Z  INFO 01_normal_shutdown: Subsystem1 started.
2024-11-02T14:13:01.829802Z DEBUG tokio_graceful_shutdown::signal_handling: Received CTRL_C.
2024-11-02T14:13:01.830451Z  INFO 01_normal_shutdown: Shutting down Subsystem1 ...
2024-11-02T14:13:01.830529Z  INFO 01_normal_shutdown: Shutting down Subsystem2 ...
2024-11-02T14:13:01.830543Z  INFO tokio_graceful_shutdown::toplevel: Shutting down ...
2024-11-02T14:13:02.243128Z  INFO 01_normal_shutdown: Subsystem1 stopped.
2024-11-02T14:13:02.344850Z  INFO 01_normal_shutdown: Subsystem2 stopped.
2024-11-02T14:13:02.345369Z  INFO tokio_graceful_shutdown::toplevel: Shutdown finished.
$ RUSTFLAGS="--cfg tokio_unstable" cargo run --example 01_normal_shutdown
2024-11-02T12:35:23.187997Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: tx_dropped=false tx_dropped.op="override"
2024-11-02T12:35:23.188843Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: rx_dropped=false rx_dropped.op="override"
2024-11-02T12:35:23.190484Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_sent=false value_sent.op="override"
2024-11-02T12:35:23.191902Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_received=false value_received.op="override"
2024-11-02T12:35:23.188238Z TRACE runtime.spawn{kind=task task.name= task.id=7 size.bytes=272 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=2
2024-11-02T12:35:23.194233Z TRACE runtime.spawn{kind=task task.name= task.id=7 size.bytes=272 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=2
2024-11-02T12:35:23.193188Z TRACE runtime.spawn{kind=task task.name= task.id=6 size.bytes=768 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=1
2024-11-02T12:35:23.196063Z TRACE runtime.spawn{kind=task task.name= task.id=7 size.bytes=272 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=2
2024-11-02T12:35:23.197616Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_sent=true value_sent.op="override"
2024-11-02T12:35:23.197777Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: tx_dropped=false tx_dropped.op="override"
2024-11-02T12:35:23.202642Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: rx_dropped=false rx_dropped.op="override"
2024-11-02T12:35:23.204418Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_sent=false value_sent.op="override"
2024-11-02T12:35:23.199624Z TRACE runtime.spawn{kind=task task.name= task.id=7 size.bytes=272 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=2
2024-11-02T12:35:23.201402Z TRACE tokio::task::waker: op="waker.wake_by_ref" task.id=1
2024-11-02T12:35:23.209296Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_received=true value_received.op="override"
2024-11-02T12:35:23.210809Z TRACE runtime.spawn{kind=task task.name= task.id=6 size.bytes=768 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=1
2024-11-02T12:35:23.209438Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: tx_dropped=false tx_dropped.op="override"
2024-11-02T12:35:23.213492Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: rx_dropped=false rx_dropped.op="override"
2024-11-02T12:35:23.206832Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_received=false value_received.op="override"
2024-11-02T12:35:23.215041Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_sent=false value_sent.op="override"
2024-11-02T12:35:23.217892Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_received=false value_received.op="override"
2024-11-02T12:35:23.222648Z TRACE runtime.spawn{kind=task task.name= task.id=10 size.bytes=768 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=274877906950
2024-11-02T12:35:23.225614Z  INFO runtime.spawn{kind=task task.name= task.id=12 size.bytes=544 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: 01_normal_shutdown: Subsystem2 started.
2024-11-02T12:35:23.216488Z TRACE runtime.spawn{kind=task task.name= task.id=9 size.bytes=768 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=274877906949
2024-11-02T12:35:23.230171Z TRACE runtime.spawn{kind=task task.name= task.id=12 size.bytes=544 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=824633720836
2024-11-02T12:35:23.231641Z  INFO runtime.spawn{kind=task task.name= task.id=11 size.bytes=544 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: 01_normal_shutdown: Subsystem1 started.
2024-11-02T12:35:23.234362Z TRACE runtime.spawn{kind=task task.name= task.id=11 size.bytes=544 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=549755813892
2024-11-02T12:35:27.980901Z TRACE tokio::task::waker: op="waker.wake" task.id=2
2024-11-02T12:35:27.981758Z DEBUG runtime.spawn{kind=task task.name= task.id=7 size.bytes=272 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio_graceful_shutdown::signal_handling: Received CTRL_C.
2024-11-02T12:35:27.983118Z TRACE runtime.spawn{kind=task task.name= task.id=7 size.bytes=272 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.drop" task.id=2
2024-11-02T12:35:27.984708Z TRACE runtime.spawn{kind=task task.name= task.id=7 size.bytes=272 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.drop" task.id=2
2024-11-02T12:35:27.986070Z TRACE runtime.spawn{kind=task task.name= task.id=7 size.bytes=272 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.drop" task.id=2
2024-11-02T12:35:27.987683Z TRACE runtime.spawn{kind=task task.name= task.id=7 size.bytes=272 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.wake" task.id=824633720836
2024-11-02T12:35:27.989488Z TRACE runtime.spawn{kind=task task.name= task.id=7 size.bytes=272 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.wake" task.id=549755813892
2024-11-02T12:35:27.991022Z  INFO runtime.spawn{kind=task task.name= task.id=12 size.bytes=544 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: 01_normal_shutdown: Shutting down Subsystem2 ...
2024-11-02T12:35:27.992614Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=27 loc.col=5}: runtime::resource::state_update: duration=500 duration.unit="ms" duration.op="override"
2024-11-02T12:35:27.991422Z  INFO runtime.spawn{kind=task task.name= task.id=11 size.bytes=544 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: 01_normal_shutdown: Shutting down Subsystem1 ...
2024-11-02T12:35:27.991083Z  INFO tokio_graceful_shutdown::toplevel: Shutting down ...
2024-11-02T12:35:27.994373Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=27 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=true   
2024-11-02T12:35:27.995328Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=18 loc.col=5}: runtime::resource::state_update: duration=401 duration.unit="ms" duration.op="override"
2024-11-02T12:35:27.998178Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=18 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=true   
2024-11-02T12:35:27.999514Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=18 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: tokio::task::waker: op="waker.clone" task.id=549755813892
2024-11-02T12:35:28.000906Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=18 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=false  
2024-11-02T12:35:27.997137Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=27 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: tokio::task::waker: op="waker.clone" task.id=824633720836
2024-11-02T12:35:27.995663Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\toplevel.rs" loc.line=189 loc.col=15}: runtime::resource::state_update: duration=1001 duration.unit="ms" duration.op="override"
2024-11-02T12:35:28.009875Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\toplevel.rs" loc.line=189 loc.col=15}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=true
2024-11-02T12:35:28.007136Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=27 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=false  
2024-11-02T12:35:28.013293Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\toplevel.rs" loc.line=189 loc.col=15}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=false
2024-11-02T12:35:28.404890Z TRACE tokio::task::waker: op="waker.wake" task.id=549755813892
2024-11-02T12:35:28.405376Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=18 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=true   
2024-11-02T12:35:28.406551Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=18 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: tokio::task::waker: op="waker.clone" task.id=549755813892
2024-11-02T12:35:28.407565Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=18 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=true   
2024-11-02T12:35:28.408582Z TRACE runtime.spawn{kind=task task.name= task.id=11 size.bytes=544 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.drop" task.id=549755813892
2024-11-02T12:35:28.409509Z  INFO runtime.spawn{kind=task task.name= task.id=11 size.bytes=544 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: 01_normal_shutdown: Subsystem1 stopped.
2024-11-02T12:35:28.410507Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_sent=true value_sent.op="override"
2024-11-02T12:35:28.411882Z TRACE tokio::task::waker: op="waker.wake_by_ref" task.id=274877906949     
2024-11-02T12:35:28.412603Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_received=true value_received.op="override"
2024-11-02T12:35:28.413848Z TRACE runtime.spawn{kind=task task.name= task.id=9 size.bytes=768 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.wake" task.id=1
2024-11-02T12:35:28.415510Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\toplevel.rs" loc.line=189 loc.col=15}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=true
2024-11-02T12:35:28.415921Z TRACE runtime.spawn{kind=task task.name= task.id=9 size.bytes=768 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.drop" task.id=274877906949
2024-11-02T12:35:28.418232Z TRACE runtime.spawn{kind=task task.name= task.id=6 size.bytes=768 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.clone" task.id=1
2024-11-02T12:35:28.417125Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\toplevel.rs" loc.line=189 loc.col=15}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=false
2024-11-02T12:35:28.500620Z TRACE tokio::task::waker: op="waker.wake" task.id=824633720836
2024-11-02T12:35:28.501106Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=27 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=true   
2024-11-02T12:35:28.502688Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=27 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: tokio::task::waker: op="waker.clone" task.id=824633720836
2024-11-02T12:35:28.503691Z TRACE runtime.resource{concrete_type="Sleep" kind="timer" loc.file="examples\\01_normal_shutdown.rs" loc.line=27 loc.col=5}:runtime.resource.async_op{source="Sleep::new_timeout"}:runtime.resource.async_op.poll: runtime::resource::poll_op: op_name="poll_elapsed" is_ready=true   
2024-11-02T12:35:28.504709Z TRACE runtime.spawn{kind=task task.name= task.id=12 size.bytes=544 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.drop" task.id=824633720836
2024-11-02T12:35:28.505666Z  INFO runtime.spawn{kind=task task.name= task.id=12 size.bytes=544 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: 01_normal_shutdown: Subsystem2 stopped.
2024-11-02T12:35:28.507014Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_sent=true value_sent.op="override"
2024-11-02T12:35:28.508169Z TRACE tokio::task::waker: op="waker.wake_by_ref" task.id=274877906950     
2024-11-02T12:35:28.508548Z TRACE runtime.resource{concrete_type="Sender|Receiver" kind="Sync" loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\subsystem\\subsystem_handle.rs" loc.line=181 loc.col=34}: runtime::resource::state_update: value_received=true value_received.op="override"
2024-11-02T12:35:28.509530Z TRACE runtime.spawn{kind=task task.name= task.id=10 size.bytes=768 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.wake" task.id=1
2024-11-02T12:35:28.509587Z  INFO tokio_graceful_shutdown::toplevel: Shutdown finished.
2024-11-02T12:35:28.510986Z TRACE runtime::resource::poll_op: op_name="poll_recv" is_ready=false      
2024-11-02T12:35:28.510624Z TRACE runtime.spawn{kind=task task.name= task.id=10 size.bytes=768 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.drop" task.id=274877906950
2024-11-02T12:35:28.511038Z TRACE runtime.spawn{kind=task task.name= task.id=6 size.bytes=768 loc.file="D:\\Projects\\tokio-graceful-shutdown\\src\\tokio_task.rs" loc.line=9 loc.col=5}: tokio::task::waker: op="waker.drop" task.id=1
2024-11-02T12:35:28.514301Z TRACE runtime::resource::state_update: tx_dropped=true tx_dropped.op="override"
2024-11-02T12:35:28.514322Z TRACE runtime::resource::poll_op: op_name="poll_recv" is_ready=true       
2024-11-02T12:35:28.515362Z TRACE runtime::resource::state_update: rx_dropped=true rx_dropped.op="override"

@Finomnis
Copy link
Owner

Finomnis commented Nov 2, 2024

@hirschenberger Added some #[track_caller] tags and a small rework, so the tokio console now shows the user code as the task location

@Finomnis
Copy link
Owner

Finomnis commented Nov 2, 2024

@hirschenberger Yah, I think I'm satisfied now.

Would you mind reviewing it again as well?

@hirschenberger
Copy link
Contributor Author

@hirschenberger Added some #[track_caller] tags and a small rework, so the tokio console now shows the user code as the task location

NICE

@hirschenberger
Copy link
Contributor Author

@hirschenberger Yah, I think I'm satisfied now.

Would you mind reviewing it again as well?

Sure, but tomorrow.

@hirschenberger
Copy link
Contributor Author

@Finomnis This looks pretty good. You put a lot of effort into my PR, nice work. I like the track_caller functionality, didn't know that.

Looks fine for me

@Finomnis Finomnis merged commit e3cee38 into Finomnis:main Nov 24, 2024
18 of 19 checks passed
@Finomnis
Copy link
Owner

Released as 0.15.2.

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.

Spawn subsystems with the tokio::Task::Builder API to name the subsystems.
2 participants