blender/flamenco
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Job deleter: improve logging

Browse Source 
Various improvements to the logging of the job deletion:

- Reduce the log level of the "removing logs" and "removing job from
  database" lines from INFO to DEBUG, so that only one line of INFO is
  logged per deleted job
- Show size of the queue and the check interval in the "job deletion
  queue is full" log message.
This commit is contained in:
Sybren A. Stüvel 2023-03-21 12:16:04 +01:00
parent 0fb252083b
commit 0ac64719e7
1 changed files with 12 additions and 4 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

16
internal/manager/job_deleter/job_deleter.go
View File

@ -28,7 +28,13 @@ import (
// memory at a time. This is variable to allow unit testing with lower limits. // memory at a time. This is variable to allow unit testing with lower limits.
var jobDeletionQueueSize = defaultJobDeletionQueueSize var jobDeletionQueueSize = defaultJobDeletionQueueSize
const defaultJobDeletionQueueSize = 100 const (
defaultJobDeletionQueueSize = 100
// jobDeletionCheckInterval determines how often the database is checked for
// jobs that have been requested to be deleted.
jobDeletionCheckInterval = 1 * time.Minute
)
// Service can mark jobs as "deletion requested", as well as delete those jobs // Service can mark jobs as "deletion requested", as well as delete those jobs
// in a background goroutine. // in a background goroutine.
@ -106,7 +112,7 @@ func (s *Service) Run(ctx context.Context) {
return return
case jobUUID := <-s.queue: case jobUUID := <-s.queue:
s.deleteJob(ctx, jobUUID) s.deleteJob(ctx, jobUUID)
case <-time.After(1 * time.Minute): case <-time.After(jobDeletionCheckInterval):
// Inspect the database to see if there was anything marked for deletion // Inspect the database to see if there was anything marked for deletion
// without getting into our queue. This can happen when lots of jobs are // without getting into our queue. This can happen when lots of jobs are
// queued in quick succession, as then the queue channel gets full. // queued in quick succession, as then the queue channel gets full.
@ -135,7 +141,9 @@ queueLoop:
case <-time.After(100 * time.Millisecond): case <-time.After(100 * time.Millisecond):
numRemaining := numDeletionsQueued - index numRemaining := numDeletionsQueued - index
log.Info(). log.Info().
Int("deletionsQueued", len(s.queue)).
Int("deletionsRemaining", numRemaining). Int("deletionsRemaining", numRemaining).
Stringer("checkInterval", jobDeletionCheckInterval).
Msg("job deleter: job deletion queue is full, remaining deletions will be picked up later") Msg("job deleter: job deletion queue is full, remaining deletions will be picked up later")
break queueLoop break queueLoop
} }
@ -150,13 +158,13 @@ func (s *Service) deleteJob(ctx context.Context, jobUUID string) error {
return err return err
} }
logger.Info().Msg("job deleter: removing logs, last-rendered images, etc.") logger.Debug().Msg("job deleter: removing logs, last-rendered images, etc.")
if err := s.storage.RemoveJobStorage(ctx, jobUUID); err != nil { if err := s.storage.RemoveJobStorage(ctx, jobUUID); err != nil {
logger.Error().Err(err).Msg("job deleter: error removing job logs, job deletion aborted") logger.Error().Err(err).Msg("job deleter: error removing job logs, job deletion aborted")
return err return err
} }
logger.Info().Msg("job deleter: removing job from database") logger.Debug().Msg("job deleter: removing job from database")
if err := s.persist.DeleteJob(ctx, jobUUID); err != nil { if err := s.persist.DeleteJob(ctx, jobUUID); err != nil {
logger.Error().Err(err).Msg("job deleter: unable to remove job from database") logger.Error().Err(err).Msg("job deleter: unable to remove job from database")
return err return err