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

Fix #7130: Contention scheduling actions in HashedWheelTimerScheduler #7144

Conversation

Arkatufus
Copy link
Contributor

Fixes #7130

Changes

Notes

Contention (deadlock) happened when HashedWheelTimerScheduler.Start() was called, causing extraneous timer start time or complete deadlock. Note that number is total milliseconds elapsed for each Timers.StartSingleTimer() call.

[INFO][04/09/2024 18:52:30.182Z][Thread 0027][akka://test/user/83] 5478
[INFO][04/09/2024 18:52:30.182Z][Thread 0023][akka://test/user/147] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0032][akka://test/user/149] 5478
[INFO][04/09/2024 18:52:30.182Z][Thread 0030][akka://test/user/8] 5478
[INFO][04/09/2024 18:52:30.182Z][Thread 0036][akka://test/user/60] 5470
[INFO][04/09/2024 18:52:30.182Z][Thread 0040][akka://test/user/223] 2042
[INFO][04/09/2024 18:52:30.182Z][Thread 0014][akka://test/user/61] 5375
[INFO][04/09/2024 18:52:30.182Z][Thread 0021][akka://test/user/5] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0019][akka://test/user/3] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0018][akka://test/user/2] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0025][akka://test/user/7] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0012][akka://test/user/56] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0022][akka://test/user/57] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0038][akka://test/user/9] 3067
[INFO][04/09/2024 18:52:30.182Z][Thread 0037][akka://test/user/4999] 4064
[INFO][04/09/2024 18:52:30.182Z][Thread 0013][akka://test/user/62] 4586
[INFO][04/09/2024 18:52:30.182Z][Thread 0020][akka://test/user/81] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0016][akka://test/user/0] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0007][akka://test/user/1] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0033][akka://test/user/150] 5478
[INFO][04/09/2024 18:52:30.189Z][Thread 0025][akka://test/user/216] 6
[INFO][04/09/2024 18:52:30.182Z][Thread 0039][akka://test/user/152] 2556
[INFO][04/09/2024 18:52:30.182Z][Thread 0026][akka://test/user/82] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0031][akka://test/user/148] 5478
[INFO][04/09/2024 18:52:30.182Z][Thread 0034][akka://test/user/151] 5477
[INFO][04/09/2024 18:52:30.182Z][Thread 0035][akka://test/user/59] 5477
[INFO][04/09/2024 18:52:30.182Z][Thread 0017][akka://test/user/4] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0024][akka://test/user/6] 5479
[INFO][04/09/2024 18:52:30.182Z][Thread 0028][akka://test/user/58] 5478
[INFO][04/09/2024 18:52:30.182Z][Thread 0029][akka://test/user/222] 5478
[INFO][04/09/2024 18:52:30.182Z][Thread 0041][akka://test/user/153] 1023
[INFO][04/09/2024 18:52:30.189Z][Thread 0012][akka://test/user/213] 6
[INFO][04/09/2024 18:52:30.210Z][Thread 0019][akka://test/user/3305] 1
[INFO][04/09/2024 18:52:30.210Z][Thread 0026][akka://test/user/3303] 1
[INFO][04/09/2024 18:52:30.210Z][Thread 0022][akka://test/user/3826] 1
[INFO][04/09/2024 18:52:30.210Z][Thread 0016][akka://test/user/3297] 1
[INFO][04/09/2024 18:52:30.210Z][Thread 0028][akka://test/user/3827] 1
[INFO][04/09/2024 18:52:30.210Z][Thread 0023][akka://test/user/3825] 1
[INFO][04/09/2024 18:52:30.210Z][Thread 0017][akka://test/user/3828] 1
[INFO][04/09/2024 18:52:30.210Z][Thread 0041][akka://test/user/3824] 1
[INFO][04/09/2024 18:52:30.226Z][Thread 0024][akka://test/user/4111] 16
[DEBUG][04/09/2024 18:52:33.353Z][Thread 0021][ActorSystem(test)] System shutdown initiated
[DEBUG][04/09/2024 18:52:33.356Z][Thread 0013][EventStream] Shutting down: StandardOutLogger started
[DEBUG][04/09/2024 18:52:33.356Z][Thread 0013][EventStream] All default loggers stopped

Copy link
Contributor Author

@Arkatufus Arkatufus left a comment

Choose a reason for hiding this comment

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

Self review

Comment on lines 168 to 172
if (start)
{
throw new SchedulerException("cannot enqueue after timer shutdown");
var timerDuration = TimeSpan.FromTicks(_tickDuration);
_timer ??= new PeriodicTimer(timerDuration);
Task.Run(() => RunAsync(_cts.Token)); // start the clock
Copy link
Contributor Author

Choose a reason for hiding this comment

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

Do not wait on _workerInitialized if we're the method call that started the timer, because a Wait() can deadlock the scheduler

private PeriodicTimer? _timer;
private readonly CancellationTokenSource _cts = new();

private void Start()
{
if (_workerState == WORKER_STATE_STARTED)
var start = false;
lock (_lock)
Copy link
Member

Choose a reason for hiding this comment

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

Remove lock

Copy link
Member

@Aaronontheweb Aaronontheweb left a comment

Choose a reason for hiding this comment

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

LGTM - left my data on #7130

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Contention scheduling actions in HashedWheelTimerScheduler
2 participants