feat(console): add warning for tasks that never yield

[jefftt]

This PR only addresses the never yielding part of #203 wasn't sure if the hasn't yielded in a long time part should be in the same warning or not.

[hds]

Thanks for your PR!

I agree with the approach to splitting #203 into 2 separate lints. One for tasks that have never yielded (this PR) and another for tasks that have long poll times (but have yielded at least once). That's a good idea!

I've got a few suggestions for changes here. Would you be able to have a look at them?

[jefftt]

Thanks for the helpful review! Changes have been applied

[hds]

Thanks for the changes!

I tested this locally and found an issue. The lint isn't always being run at the right time to catch the "never yielded" state. This is because lints only get run when a task receives an update.

See this video of my test:

Screen.Recording.2023-07-12.at.16.56.21.mov

The first time you start tokio-console (using the app example), the lint will be run (because all tasks are received and this counts as an update). Since 1 second has probably already passed,check() will return true and we see the warning.

However, when the greedy task gets spawned again (which is what would happen if a task gets spawned after tokio-console has already started running), it only gets checked on a state transition. So you would see a check when it transitions to Running and another when it transitions to state Completed. Since there are no further updates for this task, the lint will never be run again. And since it doesn't yield, there won't be further updates - that is of course the whole point of the lint! (-;

Have a look at the tracing events I produced from within the NeverYielded::check method:

2023-07-12T14:45:02.401182Z  INFO tokio_console::warnings: checking for NeverYielded: 'Some("greedy")' state: Running, total_polls: 1, busy: 9.778227771s
2023-07-12T14:45:02.626523Z  INFO tokio_console::warnings: checking for NeverYielded: 'Some("greedy")' state: Running, total_polls: 1, busy: 10.003567771s
2023-07-12T14:45:13.625785Z  INFO tokio_console::warnings: checking for NeverYielded: 'Some("greedy")' state: Running, total_polls: 1, busy: 998.316004ms
2023-07-12T14:45:13.626350Z  INFO tokio_console::warnings: checking for NeverYielded: 'Some("greedy")' state: Completed, total_polls: 1, busy: 20.003362491s
2023-07-12T14:45:33.625470Z  INFO tokio_console::warnings: checking for NeverYielded: 'Some("greedy")' state: Running, total_polls: 1, busy: 995.971509ms
2023-07-12T14:45:33.625605Z  INFO tokio_console::warnings: checking for NeverYielded: 'Some("greedy")' state: Completed, total_polls: 1, busy: 20.001640062s
2023-07-12T14:45:53.625837Z  INFO tokio_console::warnings: checking for NeverYielded: 'Some("greedy")' state: Running, total_polls: 1, busy: 991.334708ms
2023-07-12T14:45:53.626094Z  INFO tokio_console::warnings: checking for NeverYielded: 'Some("greedy")' state: Completed, total_polls: 1, busy: 20.004502567s

See how the first check happens when the task has already been running for 9 seconds. Then the subsequent checks (when the task is in state Running) occur when the task has been running for just under a second, so the warning check returns false.

If we got a bit luckier, that check might have happened 10 milliseconds later and it would have returned true. However, we probably need to find a better solution than being lucky.

It may be necessary for a lint to indicate that it should be checked again after some interval. This would allow the NeverYielded lint to ask to be checked again, for a specific task, at some time after the 1 second would have passed (or a different period if we make that default value configurable).

The TasksState::update_tasks() would then need a way to keep track of which lints need to be rechecked and then recheck them during the next cycle, even if the task itself hasn't been updated.

Sorry for the big dump of information. If you're still interested in working on this topic and need some help, let me know. You can comment here in the PR, or if you're on Discord, you can find me in the Tokio server as haydenstainsby (just post in the #console channel, I'll see it).

[jefftt]

ah i see yeah that makes sense thank you for the detailed explaination. would still be interested in working on this - just need to find the time :) happy to pass this off if someone else gets to it before me but will take a stab otherwise

[jefftt]

@hds finally got around to this and found an easy change to make to fix this issue which is to lint every task on each update. not sure if the performance hit that it takes is worth it though. thoughts?

[hds]

@jefftt thanks for looking into this further! I just wanted to let you know that it will be a few days before I look at this PR as I'm on holiday at the moment. I should get to it in the middle of next week.

[hds]

Thanks for your work on this PR!

I think we need to find a more light weight solution. This approach will potentially add a lot of unnecessary computational overhead in every update cycle.

Would you like to discuss some different options?

[jefftt]

Thanks for your help, as discussed offline, I updated the PR with the suggestions

[hds]

Great work! I think that the logic here is almost completely fine (one case where I believe we may lint some tasks twice). I've also got some style suggestions which I think will help us reason about the flow more easily in the future.

[hds]

@jefftt Thanks for your changes! I was hoping to get to this review today, but it might be tomorrow. Just wanted to let you know that it will be soon!

[hds]

Thanks for your changes, we're almost there!

The debug assert in Linter<T>::format is currently causing tokio-console to panic when viewing the details for a task with a warning. Looks like it's just a logic flip.

I've also got some last style nits.

[hds]

This looks all set now. Thanks for all the work that you put into this PR, we really appreciate it!

Congratulations on your first tokio-console contribution!