diff --git a/internal/manager/api_impl/jobs_query.go b/internal/manager/api_impl/jobs_query.go index bafe39bf..bfc18779 100644 --- a/internal/manager/api_impl/jobs_query.go +++ b/internal/manager/api_impl/jobs_query.go @@ -70,9 +70,13 @@ func (f *Flamenco) QueryJobs(e echo.Context) error { ctx := e.Request().Context() dbJobs, err := f.persist.QueryJobs(ctx, api.JobsQuery(jobsQuery)) - if err != nil { + switch { + case errors.Is(err, context.Canceled): + logger.Debug().AnErr("cause", err).Msg("could not query for jobs, remote end probably closed the connection") + return sendAPIError(e, http.StatusInternalServerError, "error querying for jobs: %v", err) + case err != nil: logger.Warn().Err(err).Msg("error querying for jobs") - return sendAPIError(e, http.StatusInternalServerError, "error querying for jobs") + return sendAPIError(e, http.StatusInternalServerError, "error querying for jobs: %v", err) } apiJobs := make([]api.Job, len(dbJobs)) @@ -97,9 +101,13 @@ func (f *Flamenco) FetchJobTasks(e echo.Context, jobID string) error { } tasks, err := f.persist.QueryJobTaskSummaries(ctx, jobID) - if err != nil { - logger.Warn().Err(err).Msg("error querying for jobs") - return sendAPIError(e, http.StatusInternalServerError, "error querying for jobs") + switch { + case errors.Is(err, context.Canceled): + logger.Debug().AnErr("cause", err).Msg("could not fetch job tasks, remote end probably closed connection") + return sendAPIError(e, http.StatusInternalServerError, "error fetching job tasks: %v", err) + case err != nil: + logger.Warn().Err(err).Msg("error fetching job tasks") + return sendAPIError(e, http.StatusInternalServerError, "error fetching job tasks: %v", err) } summaries := make([]api.TaskSummary, len(tasks)) diff --git a/internal/manager/persistence/logger.go b/internal/manager/persistence/logger.go index 3e346ef8..a5db0b8f 100644 --- a/internal/manager/persistence/logger.go +++ b/internal/manager/persistence/logger.go @@ -85,7 +85,7 @@ func (l *dbLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql st // Function to lazily get the SQL, affected rows, and logger. buildLogger := func() (loggerPtr *zerolog.Logger, sql string) { sql, rows := fc() - logCtx = logCtx.Err(err) + logCtx = logCtx.AnErr("cause", err) if rows >= 0 { logCtx = logCtx.Int64("rowsAffected", rows) } @@ -94,9 +94,13 @@ func (l *dbLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql st } switch { - case err != nil && zlogLevel <= zerolog.ErrorLevel && (!errors.Is(err, gorm.ErrRecordNotFound) || !l.IgnoreRecordNotFoundError): + case err != nil && zlogLevel <= zerolog.ErrorLevel: logger, sql := buildLogger() - logger.Error().Msg(sql) + if l.silenceLoggingError(err) { + logger.Debug().Msg(sql) + } else { + logger.Error().Msg(sql) + } case elapsed > l.SlowThreshold && l.SlowThreshold != 0 && zlogLevel <= zerolog.WarnLevel: logger, sql := buildLogger() @@ -112,13 +116,27 @@ func (l *dbLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql st } } +func (l dbLogger) silenceLoggingError(err error) bool { + switch { + case l.IgnoreRecordNotFoundError && errors.Is(err, gorm.ErrRecordNotFound): + return true + case errors.Is(err, context.Canceled): + // These are usually caused by the HTTP client connection closing. Stopping + // a database query is normal behaviour in such a case, so this shouldn't be + // logged as an error. + return true + default: + return false + } +} + // logEvent logs an even at the given level. func (l dbLogger) logEvent(level zerolog.Level, msg string, args ...interface{}) { if l.zlog.GetLevel() > level { return } logger := l.logger(args) - logger.WithLevel(level).Msg(msg) + logger.WithLevel(level).Msg("logEvent: " + msg) } // logger constructs a zerolog logger. The given arguments are added via reflection.