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.

Sign up for GitHub

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

Improve log output for too-many-scheduled-tasks #5322

Merged
merged 3 commits into from
Jul 25, 2022
Merged

Improve log output for too-many-scheduled-tasks #5322

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
d958bfc
Improve log output for too-many-scheduled-tasks
peppy Jul 25, 2022
32cef65
Apply nullability to `Scheduler` and delegate classes
peppy Jul 25, 2022
d2c85f9
Move display logic to individual `ScheduledDelegate` implementations
peppy Jul 25, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 9 additions & 5 deletions osu.Framework/Threading/ScheduledDelegate.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,8 +1,6 @@
// Copyright (c) ppy Pty Ltd <contact@ppy.sh>. Licensed under the MIT Licence.
// See the LICENCE file in the repository root for full licence text.

#nullable disable

using System;
using System.Diagnostics;

Expand Down Expand Up @@ -42,7 +40,7 @@ public class ScheduledDelegate : IComparable<ScheduledDelegate>
/// <summary>
/// The work task.
/// </summary>
internal Action Task;
internal Action? Task;

public ScheduledDelegate(Action task, double executionTime = 0, double repeatInterval = -1)
: this(executionTime, repeatInterval)
Expand Down Expand Up @@ -102,7 +100,11 @@ internal void RunTaskInternal()
}
}

protected virtual void InvokeTask() => Task();
protected virtual void InvokeTask()
{
Debug.Assert(Task != null);
Task();
}

/// <summary>
/// Cancel a task.
Expand All @@ -118,7 +120,7 @@ public void Cancel()
}
}

public int CompareTo(ScheduledDelegate other) => ExecutionTime == other.ExecutionTime ? -1 : ExecutionTime.CompareTo(other.ExecutionTime);
public int CompareTo(ScheduledDelegate? other) => ExecutionTime == other?.ExecutionTime ? -1 : ExecutionTime.CompareTo(other?.ExecutionTime);

internal void SetNextExecution(double? currentTime)
{
Expand All @@ -139,6 +141,8 @@ internal void SetNextExecution(double? currentTime)
}
}

public override string ToString() => $"method \"{Task?.Method}\" targeting \"{Task?.Target}\" executing at {ExecutionTime:N0} with repeat {RepeatInterval}";

/// <summary>
/// The current state of a scheduled delegate.
/// </summary>
Expand Down
4 changes: 2 additions & 2 deletions osu.Framework/Threading/ScheduledDelegateWithData.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,8 +1,6 @@
// Copyright (c) ppy Pty Ltd <contact@ppy.sh>. Licensed under the MIT Licence.
// See the LICENCE file in the repository root for full licence text.

#nullable disable

using System;

namespace osu.Framework.Threading
Expand All @@ -21,5 +19,7 @@ public ScheduledDelegateWithData(Action<T> task, T data, double executionTime =
}

protected override void InvokeTask() => Task(Data);

public override string ToString() => $"method \"{Task.Method}\" targeting \"{Task.Target}\" with data \"{Data}\" executing at {ExecutionTime:N0} with repeat {RepeatInterval}";
}
}
37 changes: 19 additions & 18 deletions osu.Framework/Threading/Scheduler.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,13 +1,11 @@
// Copyright (c) ppy Pty Ltd <contact@ppy.sh>. Licensed under the MIT Licence.
// See the LICENCE file in the repository root for full licence text.

#nullable disable

using System;
using System.Collections.Generic;
using System.Diagnostics.CodeAnalysis;
using System.Linq;
using System.Threading;
using JetBrains.Annotations;
using osu.Framework.Extensions;
using osu.Framework.Logging;
using osu.Framework.Timing;
Expand All @@ -23,9 +21,10 @@ public class Scheduler
private readonly List<ScheduledDelegate> timedTasks = new List<ScheduledDelegate>();
private readonly List<ScheduledDelegate> perUpdateTasks = new List<ScheduledDelegate>();

private readonly Func<bool> isCurrentThread;
private readonly Func<bool>? isCurrentThread;

private IClock? clock;

private IClock clock;
private double currentTime => clock?.CurrentTime ?? 0;

private readonly object queueLock = new object();
Expand Down Expand Up @@ -60,7 +59,7 @@ public Scheduler()
/// <summary>
/// The base thread is assumed to be the thread on which the constructor is run.
/// </summary>
public Scheduler(Func<bool> isCurrentThread, IClock clock)
public Scheduler(Func<bool>? isCurrentThread, IClock clock)
{
this.isCurrentThread = isCurrentThread;
this.clock = clock;
Expand Down Expand Up @@ -121,7 +120,7 @@ public int Update()

int countRun = 0;

while (getNextTask(out ScheduledDelegate sd))
while (getNextTask(out ScheduledDelegate? sd))
{
sd.RunTaskInternal();

Expand Down Expand Up @@ -204,7 +203,7 @@ private void queuePerUpdateTasks()
}
}

private bool getNextTask(out ScheduledDelegate task)
private bool getNextTask([NotNullWhen(true)] out ScheduledDelegate? task)
{
lock (queueLock)
{
Expand Down Expand Up @@ -240,8 +239,7 @@ public void CancelDelayedTasks()
/// <param name="data">The data to be passed to the task.</param>
/// <param name="forceScheduled">If set to false, the task will be executed immediately if we are on the main thread.</param>
/// <returns>The scheduled task, or <c>null</c> if the task was executed immediately.</returns>
[CanBeNull]
public ScheduledDelegate Add<T>([NotNull] Action<T> task, T data, bool forceScheduled = true)
public ScheduledDelegate? Add<T>(Action<T> task, T data, bool forceScheduled = true)
{
if (!forceScheduled && IsMainThread)
{
Expand All @@ -264,8 +262,7 @@ public ScheduledDelegate Add<T>([NotNull] Action<T> task, T data, bool forceSche
/// <param name="task">The work to be done.</param>
/// <param name="forceScheduled">If set to false, the task will be executed immediately if we are on the main thread.</param>
/// <returns>The scheduled task, or <c>null</c> if the task was executed immediately.</returns>
[CanBeNull]
public ScheduledDelegate Add([NotNull] Action task, bool forceScheduled = true)
public ScheduledDelegate? Add(Action task, bool forceScheduled = true)
{
if (!forceScheduled && IsMainThread)
{
Expand All @@ -287,16 +284,21 @@ public ScheduledDelegate Add([NotNull] Action task, bool forceScheduled = true)
/// <remarks>The task will be run on the next <see cref="Update"/> independent of the current clock time.</remarks>
/// <param name="task">The scheduled delegate to add.</param>
/// <exception cref="InvalidOperationException">Thrown when attempting to add a scheduled delegate that has been already completed.</exception>
public void Add([NotNull] ScheduledDelegate task)
public void Add(ScheduledDelegate task)
{
if (task.Completed)
throw new InvalidOperationException($"Can not add a {nameof(ScheduledDelegate)} that has been already {nameof(ScheduledDelegate.Completed)}");

lock (queueLock)
{
timedTasks.AddInPlace(task);

if (timedTasks.Count % LOG_EXCESSSIVE_QUEUE_LENGTH_INTERVAL == 0)
{
Logger.Log($"{this} has {timedTasks.Count} timed tasks pending", LoggingTarget.Performance);
Logger.Log($"- First task: {timedTasks.First()}", LoggingTarget.Performance);
Logger.Log($"- Last task: {timedTasks.Last()}", LoggingTarget.Performance);
}
}
}

Expand All @@ -308,7 +310,7 @@ public void Add([NotNull] ScheduledDelegate task)
/// <param name="timeUntilRun">Milliseconds until run.</param>
/// <param name="repeat">Whether this task should repeat.</param>
/// <returns>Whether this is the first queue attempt of this work.</returns>
public ScheduledDelegate AddDelayed<T>([NotNull] Action<T> task, T data, double timeUntilRun, bool repeat = false)
public ScheduledDelegate AddDelayed<T>(Action<T> task, T data, double timeUntilRun, bool repeat = false)
{
// We are locking here already to make sure we have no concurrent access to currentTime
lock (queueLock)
Expand All @@ -326,8 +328,7 @@ public ScheduledDelegate AddDelayed<T>([NotNull] Action<T> task, T data, double
/// <param name="timeUntilRun">Milliseconds until run.</param>
/// <param name="repeat">Whether this task should repeat.</param>
/// <returns>The scheduled task.</returns>
[NotNull]
public ScheduledDelegate AddDelayed([NotNull] Action task, double timeUntilRun, bool repeat = false)
public ScheduledDelegate AddDelayed(Action task, double timeUntilRun, bool repeat = false)
{
// We are locking here already to make sure we have no concurrent access to currentTime
lock (queueLock)
Expand All @@ -345,7 +346,7 @@ public ScheduledDelegate AddDelayed([NotNull] Action task, double timeUntilRun,
/// <param name="task">The work to be done.</param>
/// <param name="data">The data to be passed to the task. Note that duplicate schedules may result in previous data never being run.</param>
/// <returns>Whether this is the first queue attempt of this work.</returns>
public bool AddOnce<T>([NotNull] Action<T> task, T data)
public bool AddOnce<T>(Action<T> task, T data)
{
lock (queueLock)
{
Expand All @@ -370,7 +371,7 @@ public bool AddOnce<T>([NotNull] Action<T> task, T data)
/// <remarks>The task will be run on the next <see cref="Update"/> independent of the current clock time.</remarks>
/// <param name="task">The work to be done.</param>
/// <returns>Whether this is the first queue attempt of this work.</returns>
public bool AddOnce([NotNull] Action task)
public bool AddOnce(Action task)
{
lock (queueLock)
{
Expand Down