Skip to content

Commit 8a413d2

Browse files
committed
Add some logging to TaskScheduler again
Turns out that some of logging from task scheduler would have been useful to debug a recent test failure. This adds some logging into `TaskScheduler` again and, most importantly, adds log messages to `ClosureTaskDescription` in `TaskSchedulerTests`.
1 parent a671e5a commit 8a413d2

File tree

2 files changed

+39
-11
lines changed

2 files changed

+39
-11
lines changed

Sources/SKCore/TaskScheduler.swift

Lines changed: 36 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,8 @@ public enum TaskDependencyAction<TaskDescription: TaskDescriptionProtocol> {
2020
case cancelAndRescheduleDependency(TaskDescription)
2121
}
2222

23+
private let taskSchedulerSubsystem = "org.swift.sourcekit-lsp.task-scheduler"
24+
2325
public protocol TaskDescriptionProtocol: Identifiable, Sendable, CustomLogStringConvertible {
2426
/// Execute the task.
2527
///
@@ -208,7 +210,14 @@ public actor QueuedTask<TaskDescription: TaskDescriptionProtocol> {
208210
await withTaskGroup(of: Void.self) { taskGroup in
209211
taskGroup.addTask {
210212
for await _ in updatePriorityStream {
211-
self.priority = Task.currentPriority
213+
if Task.currentPriority != self.priority {
214+
withLoggingSubsystemAndScope(subsystem: taskSchedulerSubsystem, scope: nil) {
215+
logger.debug(
216+
"Updating priority of \(self.description.forLogging) from \(self.priority.rawValue) to \(Task.currentPriority.rawValue)"
217+
)
218+
}
219+
self.priority = Task.currentPriority
220+
}
212221
}
213222
}
214223
taskGroup.addTask {
@@ -296,6 +305,11 @@ public actor QueuedTask<TaskDescription: TaskDescriptionProtocol> {
296305
/// a new task that depends on it. Otherwise a no-op.
297306
nonisolated func elevatePriority(to targetPriority: TaskPriority) {
298307
if priority < targetPriority {
308+
withLoggingSubsystemAndScope(subsystem: taskSchedulerSubsystem, scope: nil) {
309+
logger.debug(
310+
"Elevating priority of \(self.description.forLogging) from \(self.priority.rawValue) to \(targetPriority.rawValue)"
311+
)
312+
}
299313
Task(priority: targetPriority) {
300314
await self.resultTask.value
301315
}
@@ -428,13 +442,17 @@ public actor TaskScheduler<TaskDescription: TaskDescriptionProtocol> {
428442
case .cancelAndRescheduleDependency(let taskDescription):
429443
guard let dependency = self.currentlyExecutingTasks.first(where: { $0.description.id == taskDescription.id })
430444
else {
431-
logger.fault(
432-
"Cannot find task to wait for \(taskDescription.forLogging) in list of currently executing tasks"
433-
)
445+
withLoggingSubsystemAndScope(subsystem: taskSchedulerSubsystem, scope: nil) {
446+
logger.fault(
447+
"Cannot find task to wait for \(taskDescription.forLogging) in list of currently executing tasks"
448+
)
449+
}
434450
return nil
435451
}
436452
if !taskDescription.isIdempotent {
437-
logger.fault("Cannot reschedule task '\(taskDescription.forLogging)' since it is not idempotent")
453+
withLoggingSubsystemAndScope(subsystem: taskSchedulerSubsystem, scope: nil) {
454+
logger.fault("Cannot reschedule task '\(taskDescription.forLogging)' since it is not idempotent")
455+
}
438456
return dependency
439457
}
440458
if dependency.priority > task.priority {
@@ -445,9 +463,11 @@ public actor TaskScheduler<TaskDescription: TaskDescriptionProtocol> {
445463
case .waitAndElevatePriorityOfDependency(let taskDescription):
446464
guard let dependency = self.currentlyExecutingTasks.first(where: { $0.description.id == taskDescription.id })
447465
else {
448-
logger.fault(
449-
"Cannot find task to wait for '\(taskDescription.forLogging)' in list of currently executing tasks"
450-
)
466+
withLoggingSubsystemAndScope(subsystem: taskSchedulerSubsystem, scope: nil) {
467+
logger.fault(
468+
"Cannot find task to wait for '\(taskDescription.forLogging)' in list of currently executing tasks"
469+
)
470+
}
451471
return nil
452472
}
453473
return dependency
@@ -465,9 +485,11 @@ public actor TaskScheduler<TaskDescription: TaskDescriptionProtocol> {
465485
switch taskDependency {
466486
case .cancelAndRescheduleDependency(let taskDescription):
467487
guard let task = self.currentlyExecutingTasks.first(where: { $0.description.id == taskDescription.id }) else {
468-
logger.fault(
469-
"Cannot find task to reschedule \(taskDescription.forLogging) in list of currently executing tasks"
470-
)
488+
withLoggingSubsystemAndScope(subsystem: taskSchedulerSubsystem, scope: nil) {
489+
logger.fault(
490+
"Cannot find task to reschedule \(taskDescription.forLogging) in list of currently executing tasks"
491+
)
492+
}
471493
return nil
472494
}
473495
return task
@@ -478,6 +500,9 @@ public actor TaskScheduler<TaskDescription: TaskDescriptionProtocol> {
478500
if !rescheduleTasks.isEmpty {
479501
Task.detached(priority: task.priority) {
480502
for task in rescheduleTasks {
503+
withLoggingSubsystemAndScope(subsystem: taskSchedulerSubsystem, scope: nil) {
504+
logger.debug("Suspending \(task.description.forLogging)")
505+
}
481506
await task.cancelToBeRescheduled()
482507
}
483508
}

Tests/SKCoreTests/TaskSchedulerTests.swift

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@
1010
//
1111
//===----------------------------------------------------------------------===//
1212

13+
import LSPLogging
1314
import SKCore
1415
import SKTestSupport
1516
import XCTest
@@ -262,7 +263,9 @@ fileprivate final class ClosureTaskDescription: TaskDescriptionProtocol {
262263
}
263264

264265
func execute() async {
266+
logger.debug("Starting execution of \(self) with priority \(Task.currentPriority.rawValue)")
265267
await closure()
268+
logger.debug("Finished executing \(self) with priority \(Task.currentPriority.rawValue)")
266269
}
267270

268271
func dependencies(

0 commit comments

Comments
 (0)