From 87bce6be368ea0f45fb20cc7480b8e46675bb278 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Sybren=20A=2E=20St=C3=BCvel?= Date: Thu, 9 Jun 2022 11:30:46 +0200 Subject: [PATCH] Manager: unify logging of task assignment and requeue-on-signoff The requeue-task-on-worker-signoff operation also needs to log a timestamp. The code for this, and the recently added code for timestamping the "task assigned to worker" message, are now unified. --- internal/manager/api_impl/jobs.go | 9 --------- internal/manager/api_impl/workers.go | 15 +++++++++------ internal/manager/api_impl/workers_test.go | 5 +++-- 3 files changed, 12 insertions(+), 17 deletions(-) diff --git a/internal/manager/api_impl/jobs.go b/internal/manager/api_impl/jobs.go index 945495e4..bfbc06c3 100644 --- a/internal/manager/api_impl/jobs.go +++ b/internal/manager/api_impl/jobs.go @@ -7,10 +7,8 @@ import ( "fmt" "net/http" "os" - "time" "github.com/labstack/echo/v4" - "github.com/rs/zerolog" "git.blender.org/flamenco/internal/manager/job_compilers" "git.blender.org/flamenco/internal/manager/persistence" @@ -221,13 +219,6 @@ func (f *Flamenco) FetchTaskLogTail(e echo.Context, taskID string) error { return e.String(http.StatusOK, tail) } -// taskLogAppendTimestamped writes the given log text, prefixed with the current -// date & time, to the task's log. -func (f *Flamenco) taskLogAppendTimestamped(logger zerolog.Logger, jobID, taskID string, logText string) error { - now := f.clock.Now().Format(time.RFC3339) - return f.logStorage.Write(logger, jobID, taskID, now+" "+logText) -} - func jobDBtoAPI(dbJob *persistence.Job) api.Job { apiJob := api.Job{ SubmittedJob: api.SubmittedJob{ diff --git a/internal/manager/api_impl/workers.go b/internal/manager/api_impl/workers.go index 4fa6af78..bffb68bc 100644 --- a/internal/manager/api_impl/workers.go +++ b/internal/manager/api_impl/workers.go @@ -211,7 +211,7 @@ func (f *Flamenco) workerRequeueActiveTasks(ctx context.Context, logger zerolog. lastErr = err } - f.taskLogAppend(logger, task, "Task was requeued by Manager because the worker assigned to it signed off.\n") + f.taskLogAppendTimestamped(logger, task, "Task was requeued by Manager because the worker assigned to it signed off.\n") } return lastErr @@ -319,11 +319,8 @@ func (f *Flamenco) ScheduleTask(e echo.Context) error { } // Add a note to the task log about the worker assignment. - err = f.taskLogAppendTimestamped(logger, dbTask.Job.UUID, dbTask.UUID, - fmt.Sprintf("Task assigned to worker %s (%s)", worker.Name, worker.UUID)) - if err != nil { - logger.Error().Err(err).Msg("error writing to task log") - } + f.taskLogAppendTimestamped(logger, dbTask, + fmt.Sprintf("Task assigned to worker %s (%s)\n", worker.Name, worker.UUID)) // Convert database objects to API objects: apiCommands := []api.Command{} @@ -478,6 +475,12 @@ func (f *Flamenco) taskLogAppend(logger zerolog.Logger, dbTask *persistence.Task f.broadcaster.BroadcastTaskLogUpdate(taskUpdate) } +// taskLogAppendTimestamped writes the given log text, prefixed with the current date & time, to the task's log. +func (f *Flamenco) taskLogAppendTimestamped(logger zerolog.Logger, dbTask *persistence.Task, logText string) { + now := f.clock.Now().Format(time.RFC3339) + f.taskLogAppend(logger, dbTask, now+" "+logText) +} + func (f *Flamenco) MayWorkerRun(e echo.Context, taskID string) error { logger := requestLogger(e) worker := requestWorkerOrPanic(e) diff --git a/internal/manager/api_impl/workers_test.go b/internal/manager/api_impl/workers_test.go index be034e93..2cc16dbd 100644 --- a/internal/manager/api_impl/workers_test.go +++ b/internal/manager/api_impl/workers_test.go @@ -36,7 +36,8 @@ func TestTaskScheduleHappy(t *testing.T) { mf.persistence.EXPECT().ScheduleTask(echo.Request().Context(), &worker).Return(&task, nil) mf.logStorage.EXPECT().Write(gomock.Any(), job.UUID, task.UUID, - "2022-06-09T11:14:41+02:00 Task assigned to worker дрон (e7632d62-c3b8-4af0-9e78-01752928952c)") + "2022-06-09T11:14:41+02:00 Task assigned to worker дрон (e7632d62-c3b8-4af0-9e78-01752928952c)\n") + mf.broadcaster.EXPECT().BroadcastTaskLogUpdate(gomock.Any()) // The task log should be updated; this test assumes the contents are ok. err := mf.flamenco.ScheduleTask(echo) assert.NoError(t, err) @@ -166,7 +167,7 @@ func TestWorkerSignoffTaskRequeue(t *testing.T) { // Expect this re-queueing to end up in the task's log and activity. mf.persistence.EXPECT().SaveTaskActivity(expectCtx, &task1) // TODO: test saved activity value mf.persistence.EXPECT().SaveTaskActivity(expectCtx, &task2) // TODO: test saved activity value - logMsg := "Task was requeued by Manager because the worker assigned to it signed off.\n" + logMsg := "2022-06-09T11:14:41+02:00 Task was requeued by Manager because the worker assigned to it signed off.\n" mf.logStorage.EXPECT().Write(gomock.Any(), job.UUID, task1.UUID, logMsg) mf.logStorage.EXPECT().Write(gomock.Any(), job.UUID, task2.UUID, logMsg) mf.broadcaster.EXPECT().BroadcastTaskLogUpdate(api.SocketIOTaskLogUpdate{TaskId: task1.UUID, Log: logMsg})