From 22f151df685018f487b555bfd9392330712e0493 Mon Sep 17 00:00:00 2001 From: Diaa Sami Date: Fri, 1 Oct 2021 10:48:33 +0200 Subject: [PATCH] worker: Improve logging Use logrus library for logging Use appropriate log-level for different log statements --- cmd/osbuild-composer/composer.go | 5 ++-- cmd/osbuild-composer/main.go | 8 +++---- cmd/osbuild-worker/main.go | 40 ++++++++++++++++---------------- internal/worker/server.go | 9 +++---- 4 files changed, 30 insertions(+), 32 deletions(-) diff --git a/cmd/osbuild-composer/composer.go b/cmd/osbuild-composer/composer.go index 2c07a5d8e..396898c01 100644 --- a/cmd/osbuild-composer/composer.go +++ b/cmd/osbuild-composer/composer.go @@ -44,12 +44,11 @@ type Composer struct { weldrListener, localWorkerListener, workerListener, apiListener net.Listener } -func NewComposer(config *ComposerConfigFile, stateDir, cacheDir string, logger *log.Logger) (*Composer, error) { +func NewComposer(config *ComposerConfigFile, stateDir, cacheDir string) (*Composer, error) { c := Composer{ config: config, stateDir: stateDir, cacheDir: cacheDir, - logger: logger, } queueDir, err := c.ensureStateDirectory("jobs", 0700) @@ -63,7 +62,7 @@ func NewComposer(config *ComposerConfigFile, stateDir, cacheDir string, logger * } c.distros = distroregistry.NewDefault() - logrus.Info(fmt.Sprintf("Loaded %d distros", len(c.distros.List()))) + logrus.Infof("Loaded %d distros", len(c.distros.List())) c.rpm = rpmmd.NewRPMMD(path.Join(c.cacheDir, "rpmmd"), "/usr/libexec/osbuild-composer/dnf-json") diff --git a/cmd/osbuild-composer/main.go b/cmd/osbuild-composer/main.go index 3a73024fd..69c34bdfa 100644 --- a/cmd/osbuild-composer/main.go +++ b/cmd/osbuild-composer/main.go @@ -2,7 +2,6 @@ package main import ( "flag" - "log" "os" "github.com/coreos/go-systemd/activation" @@ -25,9 +24,8 @@ func main() { flag.BoolVar(&verbose, "verbose", false, "Print access log") flag.Parse() - var logger *log.Logger - if verbose { - logger = log.New(os.Stdout, "", 0) + if !verbose { + logrus.Print("verbose flag is provided for backward compatibility only, current behavior is always printing the access log") } config, err := LoadConfig(configFile) @@ -60,7 +58,7 @@ func main() { logrus.Fatal("CACHE_DIRECTORY is not set. Is the service file missing CacheDirectory=?") } - composer, err := NewComposer(config, stateDir, cacheDir, logger) + composer, err := NewComposer(config, stateDir, cacheDir) if err != nil { logrus.Fatalf("%v", err) } diff --git a/cmd/osbuild-worker/main.go b/cmd/osbuild-worker/main.go index f79e4ac10..72ebed475 100644 --- a/cmd/osbuild-worker/main.go +++ b/cmd/osbuild-worker/main.go @@ -8,7 +8,6 @@ import ( "flag" "fmt" "io/ioutil" - "log" "os" "os/exec" "path" @@ -16,6 +15,7 @@ import ( "time" "github.com/BurntSushi/toml" + "github.com/sirupsen/logrus" "github.com/osbuild/osbuild-composer/internal/common" "github.com/osbuild/osbuild-composer/internal/upload/azure" @@ -70,7 +70,7 @@ func WatchJob(ctx context.Context, job worker.Job) { case <-time.After(15 * time.Second): canceled, err := job.Canceled() if err == nil && canceled { - log.Println("Job was canceled. Exiting.") + logrus.Info("Job was canceled. Exiting.") os.Exit(0) } case <-ctx.Done(): @@ -116,19 +116,19 @@ func main() { _, err := toml.DecodeFile(configFile, &config) if err == nil { - log.Println("Composer configuration:") - encoder := toml.NewEncoder(log.Writer()) + logrus.Info("Composer configuration:") + encoder := toml.NewEncoder(logrus.StandardLogger().WriterLevel(logrus.InfoLevel)) err := encoder.Encode(&config) if err != nil { - log.Fatalf("Could not print config: %v", err) + logrus.Fatalf("Could not print config: %v", err) } } else if !os.IsNotExist(err) { - log.Fatalf("Could not load config file '%s': %v", configFile, err) + logrus.Fatalf("Could not load config file '%s': %v", configFile, err) } cacheDirectory, ok := os.LookupEnv("CACHE_DIRECTORY") if !ok { - log.Fatal("CACHE_DIRECTORY is not set. Is the service file missing CacheDirectory=?") + logrus.Fatal("CACHE_DIRECTORY is not set. Is the service file missing CacheDirectory=?") } store := path.Join(cacheDirectory, "osbuild-store") output := path.Join(cacheDirectory, "output") @@ -155,20 +155,20 @@ func main() { if config.Authentication != nil && config.Authentication.OfflineTokenPath != "" { t, err := ioutil.ReadFile(config.Authentication.OfflineTokenPath) if err != nil { - log.Fatalf("Could not read offline token: %v", err) + logrus.Fatalf("Could not read offline token: %v", err) } t2 := strings.TrimSpace(string(t)) token = &t2 if config.Authentication.OAuthURL == "" { - log.Fatal("OAuth URL should be specified together with the offline token") + logrus.Fatal("OAuth URL should be specified together with the offline token") } oAuthURL = &config.Authentication.OAuthURL if strings.HasPrefix(address, "http") { out, err := exec.Command("systemd-escape", "-u", address).Output() if err != nil { - log.Fatalf("Could not escape remote worker address: %v", err) + logrus.Fatalf("Could not escape remote worker address: %v", err) } address = strings.TrimSpace(string(out)) } else { @@ -185,13 +185,13 @@ func main() { if _, err = os.Stat(conConf.CACertFile); err == nil { conf, err = createTLSConfig(conConf) if err != nil { - log.Fatalf("Error creating TLS config: %v", err) + logrus.Fatalf("Error creating TLS config: %v", err) } } client, err = worker.NewClient(address, conf, token, oAuthURL) if err != nil { - log.Fatalf("Error creating worker client: %v", err) + logrus.Fatalf("Error creating worker client: %v", err) } } @@ -202,7 +202,7 @@ func main() { if config.Azure != nil { azureCredentials, err = azure.ParseAzureCredentialsFile(config.Azure.Credentials) if err != nil { - log.Fatalf("cannot load azure credentials: %v", err) + logrus.Fatalf("cannot load azure credentials: %v", err) } } @@ -214,7 +214,7 @@ func main() { if config.GCP != nil { gcpCredentials, err = ioutil.ReadFile(config.GCP.Credentials) if err != nil { - log.Fatalf("cannot load GCP credentials: %v", err) + logrus.Fatalf("cannot load GCP credentials: %v", err) } } @@ -245,19 +245,19 @@ func main() { } for { - fmt.Println("Waiting for a new job...") + logrus.Info("Waiting for a new job...") job, err := client.RequestJob(acceptedJobTypes, common.CurrentArch()) if err != nil { - log.Fatal(err) + logrus.Fatal(err) } impl, exists := jobImpls[job.Type()] if !exists { - log.Printf("Ignoring job with unknown type %s", job.Type()) + logrus.Warnf("Ignoring job with unknown type %s", job.Type()) continue } - fmt.Printf("Running '%s' job %v\n", job.Type(), job.Id()) + logrus.Infof("Running '%s' job %v\n", job.Type(), job.Id()) ctx, cancelWatcher := context.WithCancel(context.Background()) go WatchJob(ctx, job) @@ -265,10 +265,10 @@ func main() { err = impl.Run(job) cancelWatcher() if err != nil { - log.Printf("Job %s failed: %v", job.Id(), err) + logrus.Warnf("Job %s failed: %v", job.Id(), err) continue } - log.Printf("Job %s finished", job.Id()) + logrus.Infof("Job %s finished", job.Id()) } } diff --git a/internal/worker/server.go b/internal/worker/server.go index 9ab72c61d..81bbb2548 100644 --- a/internal/worker/server.go +++ b/internal/worker/server.go @@ -16,6 +16,7 @@ import ( "github.com/google/uuid" "github.com/labstack/echo/v4" + "github.com/sirupsen/logrus" "github.com/osbuild/osbuild-composer/internal/common" "github.com/osbuild/osbuild-composer/internal/jobqueue" @@ -52,7 +53,7 @@ func NewServer(logger *log.Logger, jobs jobqueue.JobQueue, artifactsDir string) func (s *Server) Handler() http.Handler { e := echo.New() e.Binder = binder{} - e.StdLogger = s.logger + e.Logger = common.Logger() // log errors returned from handlers e.HTTPErrorHandler = api.HTTPErrorHandler @@ -73,10 +74,10 @@ func (s *Server) WatchHeartbeats() { for range time.Tick(time.Second * 30) { for _, token := range s.jobs.Heartbeats(time.Second * 120) { id, _ := s.jobs.IdFromToken(token) - log.Printf("Removing unresponsive job: %s\n", id) + logrus.Infof("Removing unresponsive job: %s\n", id) err := s.FinishJob(token, nil) if err != nil { - log.Printf("Error finishing unresponsive job: %v", err) + logrus.Errorf("Error finishing unresponsive job: %v", err) } } } @@ -271,7 +272,7 @@ func (s *Server) FinishJob(token uuid.UUID, result json.RawMessage) error { if s.artifactsDir != "" { err := os.Rename(path.Join(s.artifactsDir, "tmp", token.String()), path.Join(s.artifactsDir, jobId.String())) if err != nil { - log.Printf("Error moving artifacts for job%s: %v", jobId, err) + logrus.Errorf("Error moving artifacts for job %s: %v", jobId, err) } }