From a9544f5609d89fe3b3723cf55a8d42f646f7a417 Mon Sep 17 00:00:00 2001 From: Pay Giesselmann Date: Tue, 20 Jun 2023 15:47:38 +0200 Subject: [PATCH] lower log level for frequent messages --- cmd/cc-backend/main.go | 2 +- internal/api/rest.go | 2 +- internal/auth/auth.go | 6 +++--- internal/repository/hooks.go | 4 ++-- internal/repository/job.go | 26 +++++++++++++------------- internal/repository/query.go | 2 +- internal/repository/stats.go | 14 +++++++------- web/web.go | 2 +- 8 files changed, 29 insertions(+), 29 deletions(-) diff --git a/cmd/cc-backend/main.go b/cmd/cc-backend/main.go index f9868e6..ae2e044 100644 --- a/cmd/cc-backend/main.go +++ b/cmd/cc-backend/main.go @@ -338,7 +338,7 @@ func main() { handlers.AllowedOrigins([]string{"*"}))) handler := handlers.CustomLoggingHandler(io.Discard, r, func(_ io.Writer, params handlers.LogFormatterParams) { if strings.HasPrefix(params.Request.RequestURI, "/api/") { - log.Infof("%s %s (%d, %.02fkb, %dms)", + log.Debugf("%s %s (%d, %.02fkb, %dms)", params.Request.Method, params.URL.RequestURI(), params.StatusCode, float32(params.Size)/1024, time.Since(params.TimeStamp).Milliseconds()) diff --git a/internal/api/rest.go b/internal/api/rest.go index da37a25..c199bc2 100644 --- a/internal/api/rest.go +++ b/internal/api/rest.go @@ -523,7 +523,7 @@ func (api *RestApi) startJob(rw http.ResponseWriter, r *http.Request) { } else if err == nil { for _, job := range jobs { if (req.StartTime - job.StartTimeUnix) < 86400 { - handleError(fmt.Errorf("a job with that jobId, cluster and startTime already exists: dbid: %d", job.ID), http.StatusUnprocessableEntity, rw) + handleError(fmt.Errorf("a job with that jobId, cluster and startTime already exists: dbid: %d, jobid: %d", job.ID, job.JobID), http.StatusUnprocessableEntity, rw) return } } diff --git a/internal/auth/auth.go b/internal/auth/auth.go index 9234e9a..ea6c9f2 100644 --- a/internal/auth/auth.go +++ b/internal/auth/auth.go @@ -364,7 +364,7 @@ func (auth *Authentication) Login( return } - log.Warn("login failed: no authenticator applied") + log.Debugf("login failed: no authenticator applied") onfailure(rw, r, err) }) } @@ -380,7 +380,7 @@ func (auth *Authentication) Auth( for _, authenticator := range auth.authenticators { user, err := authenticator.Auth(rw, r) if err != nil { - log.Warnf("authentication failed: %s", err.Error()) + log.Infof("authentication failed: %s", err.Error()) http.Error(rw, err.Error(), http.StatusUnauthorized) return } @@ -393,7 +393,7 @@ func (auth *Authentication) Auth( return } - log.Warnf("authentication failed: %s", "no authenticator applied") + log.Debugf("authentication failed: %s", "no authenticator applied") // http.Error(rw, http.StatusText(http.StatusUnauthorized), http.StatusUnauthorized) onfailure(rw, r, errors.New("unauthorized (login first or use a token)")) }) diff --git a/internal/repository/hooks.go b/internal/repository/hooks.go index 57fac8a..2f40fd5 100644 --- a/internal/repository/hooks.go +++ b/internal/repository/hooks.go @@ -16,13 +16,13 @@ type Hooks struct{} // Before hook will print the query with it's args and return the context with the timestamp func (h *Hooks) Before(ctx context.Context, query string, args ...interface{}) (context.Context, error) { - log.Infof("SQL query %s %q", query, args) + log.Debugf("SQL query %s %q", query, args) return context.WithValue(ctx, "begin", time.Now()), nil } // After hook will get the timestamp registered on the Before hook and print the elapsed time func (h *Hooks) After(ctx context.Context, query string, args ...interface{}) (context.Context, error) { begin := ctx.Value("begin").(time.Time) - log.Infof("Took: %s\n", time.Since(begin)) + log.Debugf("Took: %s\n", time.Since(begin)) return ctx, nil } diff --git a/internal/repository/job.go b/internal/repository/job.go index 0f280cd..ff65989 100644 --- a/internal/repository/job.go +++ b/internal/repository/job.go @@ -55,7 +55,6 @@ func GetJobRepository() *JobRepository { // start archiving worker go jobRepoInstance.archivingWorker() }) - return jobRepoInstance } @@ -178,7 +177,7 @@ func (r *JobRepository) FetchMetadata(job *schema.Job) (map[string]string, error } r.cache.Put(cachekey, job.MetaData, len(job.RawMetaData), 24*time.Hour) - log.Infof("Timer FetchMetadata %s", time.Since(start)) + log.Debugf("Timer FetchMetadata %s", time.Since(start)) return job.MetaData, nil } @@ -238,7 +237,7 @@ func (r *JobRepository) Find( q = q.Where("job.start_time = ?", *startTime) } - log.Infof("Timer Find %s", time.Since(start)) + log.Debugf("Timer Find %s", time.Since(start)) return scanJob(q.RunWith(r.stmtCache).QueryRow()) } @@ -278,7 +277,7 @@ func (r *JobRepository) FindAll( } jobs = append(jobs, job) } - log.Infof("Timer FindAll %s", time.Since(start)) + log.Debugf("Timer FindAll %s", time.Since(start)) return jobs, nil } @@ -344,7 +343,7 @@ func (r *JobRepository) DeleteJobsBefore(startTime int64) (int, error) { if err != nil { log.Errorf(" DeleteJobsBefore(%d): error %#v", startTime, err) } else { - log.Infof("DeleteJobsBefore(%d): Deleted %d jobs", startTime, cnt) + log.Debugf("DeleteJobsBefore(%d): Deleted %d jobs", startTime, cnt) } return cnt, err } @@ -354,7 +353,7 @@ func (r *JobRepository) DeleteJobById(id int64) error { if err != nil { log.Errorf("DeleteJobById(%d): error %#v", id, err) } else { - log.Infof("DeleteJobById(%d): Success", id) + log.Debugf("DeleteJobById(%d): Success", id) } return err } @@ -383,7 +382,7 @@ func (r *JobRepository) CountGroupedJobs( count = fmt.Sprintf(`sum(job.num_nodes * (CASE WHEN job.job_state = "running" THEN %d - job.start_time ELSE job.duration END)) as count`, now) runner = r.DB default: - log.Infof("CountGroupedJobs() Weight %v unknown.", *weight) + log.Debugf("CountGroupedJobs() Weight %v unknown.", *weight) } } @@ -418,7 +417,7 @@ func (r *JobRepository) CountGroupedJobs( counts[group] = count } - log.Infof("Timer CountGroupedJobs %s", time.Since(start)) + log.Debugf("Timer CountGroupedJobs %s", time.Since(start)) return counts, nil } @@ -457,7 +456,7 @@ func (r *JobRepository) MarkArchived( case "file_bw": stmt = stmt.Set("file_bw_avg", stats.Avg) default: - log.Infof("MarkArchived() Metric '%v' unknown", metric) + log.Debugf("MarkArchived() Metric '%v' unknown", metric) } } @@ -476,6 +475,7 @@ func (r *JobRepository) archivingWorker() { if !ok { break } + start := time.Now() // not using meta data, called to load JobMeta into Cache? // will fail if job meta not in repository if _, err := r.FetchMetadata(job); err != nil { @@ -498,7 +498,7 @@ func (r *JobRepository) archivingWorker() { log.Errorf("archiving job (dbid: %d) failed: %s", job.ID, err.Error()) continue } - + log.Debugf("archiving job %d took %s", job.JobID, time.Since(start)) log.Printf("archiving job (dbid: %d) successful", job.ID) r.archivePending.Done() } @@ -635,7 +635,7 @@ func (r *JobRepository) Partitions(cluster string) ([]string, error) { if err != nil { return nil, err } - log.Infof("Timer Partitions %s", time.Since(start)) + log.Debugf("Timer Partitions %s", time.Since(start)) return partitions.([]string), nil } @@ -680,7 +680,7 @@ func (r *JobRepository) AllocatedNodes(cluster string) (map[string]map[string]in } } - log.Infof("Timer AllocatedNodes %s", time.Since(start)) + log.Debugf("Timer AllocatedNodes %s", time.Since(start)) return subclusters, nil } @@ -709,7 +709,7 @@ func (r *JobRepository) StopJobsExceedingWalltimeBy(seconds int) error { if rowsAffected > 0 { log.Infof("%d jobs have been marked as failed due to running too long", rowsAffected) } - log.Infof("Timer StopJobsExceedingWalltimeBy %s", time.Since(start)) + log.Debugf("Timer StopJobsExceedingWalltimeBy %s", time.Since(start)) return nil } diff --git a/internal/repository/query.go b/internal/repository/query.go index ba1d1d7..56ba173 100644 --- a/internal/repository/query.go +++ b/internal/repository/query.go @@ -211,7 +211,7 @@ func SecurityCheck(ctx context.Context, query sq.SelectBuilder) (sq.SelectBuilde if len(user.Projects) != 0 { return query.Where(sq.Or{sq.Eq{"job.project": user.Projects}, sq.Eq{"job.user": user.Username}}), nil } else { - log.Infof("Manager-User '%s' has no defined projects to lookup! Query only personal jobs ...", user.Username) + log.Debugf("Manager-User '%s' has no defined projects to lookup! Query only personal jobs ...", user.Username) return query.Where("job.user = ?", user.Username), nil } } else if user.HasRole(auth.RoleUser) { // User : Only personal jobs diff --git a/internal/repository/stats.go b/internal/repository/stats.go index d96c20a..158d34a 100644 --- a/internal/repository/stats.go +++ b/internal/repository/stats.go @@ -171,7 +171,7 @@ func (r *JobRepository) JobsStatsGrouped( } } - log.Infof("Timer JobsStatsGrouped %s", time.Since(start)) + log.Debugf("Timer JobsStatsGrouped %s", time.Since(start)) return stats, nil } @@ -212,7 +212,7 @@ func (r *JobRepository) JobsStats( TotalAccHours: totalAccHours}) } - log.Infof("Timer JobStats %s", time.Since(start)) + log.Debugf("Timer JobStats %s", time.Since(start)) return stats, nil } @@ -251,7 +251,7 @@ func (r *JobRepository) JobCountGrouped( } } - log.Infof("Timer JobCountGrouped %s", time.Since(start)) + log.Debugf("Timer JobCountGrouped %s", time.Since(start)) return stats, nil } @@ -300,7 +300,7 @@ func (r *JobRepository) AddJobCountGrouped( } } - log.Infof("Timer AddJobCountGrouped %s", time.Since(start)) + log.Debugf("Timer AddJobCountGrouped %s", time.Since(start)) return stats, nil } @@ -343,7 +343,7 @@ func (r *JobRepository) AddJobCount( } } - log.Infof("Timer JobJobCount %s", time.Since(start)) + log.Debugf("Timer JobJobCount %s", time.Since(start)) return stats, nil } @@ -368,7 +368,7 @@ func (r *JobRepository) AddHistograms( return nil, err } - log.Infof("Timer AddHistograms %s", time.Since(start)) + log.Debugf("Timer AddHistograms %s", time.Since(start)) return stat, nil } @@ -406,6 +406,6 @@ func (r *JobRepository) jobsStatisticsHistogram( points = append(points, &point) } - log.Infof("Timer jobsStatisticsHistogram %s", time.Since(start)) + log.Debugf("Timer jobsStatisticsHistogram %s", time.Since(start)) return points, nil } diff --git a/web/web.go b/web/web.go index 3547b85..6f31333 100644 --- a/web/web.go +++ b/web/web.go @@ -106,7 +106,7 @@ func RenderTemplate(rw http.ResponseWriter, r *http.Request, file string, page * } } - log.Infof("Page config : %v\n", page.Config) + log.Debugf("Page config : %v\n", page.Config) if err := t.Execute(rw, page); err != nil { log.Errorf("Template error: %s", err.Error()) }