Skip to content

[shim] Adjust log levels and messages #4217

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

Merged
un-def merged 1 commit into from
Aug 26, 2026
Merged

[shim] Adjust log levels and messages #4217

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
2 changes: 1 addition & 1 deletion runner/internal/shim/backends/aws.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -55,7 +55,7 @@ func (e *AWSBackend) GetRealDeviceName(ctx context.Context, volumeID, deviceName
if time.Now().After(deadline) {
return "", fmt.Errorf("volume %s not found among block devices after %s", volumeID, deviceResolveTimeout)
}
log.Debug(ctx, "volume not yet visible among block devices, retrying", "volume", volumeID)
log.Trace(ctx, "volume not yet visible among block devices, retrying", "volume", volumeID)
time.Sleep(deviceResolveInterval)
}

Expand Down
11 changes: 6 additions & 5 deletions runner/internal/shim/docker.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -463,7 +463,7 @@ func (d *DockerRunner) Start(ctx context.Context, taskID string) (err error) {
if err != nil {
return fmt.Errorf("make runner dir: %w", err)
}
log.Debug(ctx, "runner dir", "task", task.ID, "path", runnerDir)
log.Trace(ctx, "runner dir", "task", task.ID, "path", runnerDir)
// Resources are committed as soon as they are acquired, so that they are not
// lost if the task is updated by another goroutine, e.g., terminated by the server
if err := d.commit(&task, func(t *Task) { t.runnerDir = runnerDir }); err != nil {
Expand Down Expand Up @@ -496,7 +496,6 @@ func (d *DockerRunner) Start(ctx context.Context, taskID string) (err error) {
}
}

log.Debug(ctx, "Preparing volumes")
// Volumes mounted by a failed prepareVolumes() call are unmounted by cleanupLocked()
err = prepareVolumes(ctx, cfg)
if err != nil {
Expand Down Expand Up @@ -540,7 +539,7 @@ func (d *DockerRunner) Start(ctx context.Context, taskID string) (err error) {
return fmt.Errorf("create container: %w", err)
}

log.Debug(ctx, "Running container", "task", task.ID, "name", task.containerName)
log.Debug(ctx, "Starting container", "task", task.ID, "name", task.containerName)
err = d.startContainer(ctx, &task)
if len(task.config.GPUDevices) == 0 &&
shouldRetryWithoutNvidiaDisplayCapability(d.gpuVendor, err) {
Expand Down Expand Up @@ -582,7 +581,7 @@ func (d *DockerRunner) Start(ctx context.Context, taskID string) (err error) {
}
started = true

log.Debug(ctx, "Container is running", "task", task.ID, "name", task.containerName)
log.Debug(ctx, "Task started", "task", task.ID, "name", task.containerName)

return nil
}
Expand Down Expand Up @@ -677,7 +676,9 @@ func (d *DockerRunner) terminate(ctx context.Context, task *Task, timeout uint,
d.cleanupLocked(ctx, task)
}
task.SetStatusTerminated(reason, message)
log.Debug(ctx, "terminated", "task", task.ID)
// Logged a level below the spontaneous termination reported by ProcessTasks():
// this one is requested by the caller, which reports it on its own
log.Debug(ctx, "terminated", "task", task.ID, "reason", reason)
return nil
}

Expand Down
2 changes: 1 addition & 1 deletion runner/internal/shim/process.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -88,7 +88,7 @@ func (d *DockerRunner) processTask(ctx context.Context, taskID string, container
// the same lock
if !task.TryLock(ctx) {
// The task is busy, e.g., being terminated or removed. Try again on the next call
log.Debug(ctx, "skip processing: task is busy", "task", taskID)
log.Trace(ctx, "skip processing: task is busy", "task", taskID)
return
}
defer func() { task.Release(ctx) }()
Expand Down
10 changes: 6 additions & 4 deletions runner/internal/shim/resources.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -94,7 +94,8 @@ func (gl *GpuLock) Acquire(ctx context.Context, count int) ([]string, error) {
}

// Lock marks passed Resource IDs as locked (busy)
// This method never fails, it's safe to lock already locked resource or try to lock unknown resource
// This method never fails: an already locked or unknown resource is skipped and
// reported as a warning, as neither is expected during normal operation
// The returned slice contains only actually locked resource IDs
func (gl *GpuLock) Lock(ctx context.Context, ids []string) []string {
gl.mu.Lock()
Expand All @@ -104,7 +105,7 @@ func (gl *GpuLock) Lock(ctx context.Context, ids []string) []string {
if locked, ok := gl.lock[id]; !ok {
log.Warning(ctx, "skip locking: unknown GPU resource", "id", id)
} else if locked {
log.Info(ctx, "skip locking: GPU already locked", "id", id)
log.Warning(ctx, "skip locking: GPU already locked", "id", id)
} else {
gl.lock[id] = true
lockedIDs = append(lockedIDs, id)
Expand All @@ -114,7 +115,8 @@ func (gl *GpuLock) Lock(ctx context.Context, ids []string) []string {
}

// Release marks passed Resource IDs as idle
// This method never fails, it's safe to release already idle resource or try to release unknown resource
// This method never fails: an already idle or unknown resource is skipped and
// reported as a warning, as neither is expected during normal operation
// The returned slice contains only actually released resource IDs
func (gl *GpuLock) Release(ctx context.Context, ids []string) []string {
gl.mu.Lock()
Expand All @@ -124,7 +126,7 @@ func (gl *GpuLock) Release(ctx context.Context, ids []string) []string {
if locked, ok := gl.lock[id]; !ok {
log.Warning(ctx, "skip releasing: unknown GPU resource", "id", id)
} else if !locked {
log.Info(ctx, "skip releasing: GPU not locked", "id", id)
log.Warning(ctx, "skip releasing: GPU not locked", "id", id)
} else {
gl.lock[id] = false
releasedIDs = append(releasedIDs, id)
Expand Down
8 changes: 4 additions & 4 deletions runner/internal/shim/task.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -61,17 +61,17 @@ type Task struct {
// being processed in the background.
func (t *Task) Lock(ctx context.Context) {
t.mu.Lock()
log.Debug(ctx, "locked", "task", t.ID)
log.Trace(ctx, "locked", "task", t.ID)
}

// TryLock is a non-blocking version of Lock. It reports whether the lock has
// been acquired, so that the caller can retry later instead of waiting.
func (t *Task) TryLock(ctx context.Context) bool {
if !t.mu.TryLock() {
log.Debug(ctx, "already locked", "task", t.ID)
log.Trace(ctx, "already locked", "task", t.ID)
return false
}
log.Debug(ctx, "locked", "task", t.ID)
log.Trace(ctx, "locked", "task", t.ID)
return true
}

Expand All @@ -80,7 +80,7 @@ func (t *Task) TryLock(ctx context.Context) bool {
// looks like lock: https://github.com/golang/go/issues/18451
func (t *Task) Release(ctx context.Context) {
t.mu.Unlock()
log.Debug(ctx, "unlocked", "task", t.ID)
log.Trace(ctx, "unlocked", "task", t.ID)
}

func (t *Task) IsTransitionAllowed(toStatus TaskStatus) bool {
Expand Down
4 changes: 4 additions & 0 deletions runner/internal/shim/volumes.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,10 @@ import (
)

func prepareVolumes(ctx context.Context, taskConfig TaskConfig) error {
if len(taskConfig.Volumes) == 0 {
return nil
}
log.Debug(ctx, "Preparing volumes...")
for _, volume := range taskConfig.Volumes {
err := formatAndMountVolume(ctx, volume)
if err != nil {
Expand Down
Loading