Improve logging

- switch to structured logging
- use JSON formatter
- support log level and formatter configuration

changelog.md

@@ -14,6 +14,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 - separate server name and bind address to allow binding to a local address
   but publish a different public name
 - move default configuration to internal/services/configuration.go
+- use structured logging
+- support JSON logging and make it the default
+- support log level configuration
 
 ## [0.1.3] - 2023-07-24
 ### Fixed

cmd/idp/main.go

@@ -22,6 +22,7 @@ import (
 	"crypto/tls"
 	"crypto/x509"
 	"encoding/base64"
+	"errors"
 	"fmt"
 	"net/http"
 	"net/url"
@@ -43,9 +44,14 @@ import (
 )
 
 const (
-	TimeoutThirty     = 30 * time.Second
-	TimeoutTwenty     = 20 * time.Second
+	IdleTimeout     = 30 * time.Second
+	ShutdownTimeout = 30 * time.Second
+	ReadTimeOut     = 20 * time.Second
+	WriteTimeOut    = 20 * time.Second
+
 	DefaultCSRFMaxAge = 600
+
+	httpsDefaultPort = 443
 )
 
 var (
@@ -62,6 +68,19 @@ func main() {
 		log.Fatalf("error loading configuration: %v", err)
 	}
 
+	if level := config.String("log.level"); level != "" {
+		logLevel, err := log.ParseLevel(level)
+		if err != nil {
+			logger.WithError(err).Fatal("could not parse log level")
+		}
+
+		logger.SetLevel(logLevel)
+	}
+
+	if config.Bool("log.json") {
+		logger.SetFormatter(&log.JSONFormatter{})
+	}
+
 	logger.WithFields(log.Fields{
 		"version": version, "commit": commit, "date": date,
 	}).Info("Starting CAcert OpenID Connect Identity Provider")
@@ -69,12 +88,12 @@ func main() {
 	bundle, catalog := services.InitI18n(logger, config.Strings("i18n.languages"))
 
 	if err = services.AddMessages(catalog); err != nil {
-		logger.Fatalf("could not add messages for i18n: %v", err)
+		logger.WithError(err).Fatal("could not add messages for i18n")
 	}
 
 	adminURL, err := url.Parse(config.MustString("admin.url"))
 	if err != nil {
-		logger.Fatalf("error parsing admin URL: %v", err)
+		logger.WithError(err).Fatal("error parsing admin URL")
 	}
 
 	tlsClientConfig := &tls.Config{MinVersion: tls.VersionTLS12}
@@ -121,13 +140,9 @@ func main() {
 	router.Handle("/css/", staticFiles)
 	router.Handle("/js/", staticFiles)
 
-	if err != nil {
-		logger.Fatal(err)
-	}
-
 	csrfKey, err := base64.StdEncoding.DecodeString(config.MustString("security.csrf.key"))
 	if err != nil {
-		logger.Fatalf("could not parse CSRF key bytes: %v", err)
+		logger.WithError(err).Fatal("could not parse CSRF key bytes")
 	}
 
 	nextRequestID := func() string {
@@ -143,14 +158,9 @@ func main() {
 		csrf.SameSite(csrf.SameSiteStrictMode),
 		csrf.MaxAge(DefaultCSRFMaxAge))
 
-	errorMiddleware, err := handlers.ErrorHandling(
-		logger,
-		ui.Templates,
-		bundle,
-		catalog,
-	)
+	errorMiddleware, err := handlers.ErrorHandling(logger, ui.Templates, bundle, catalog)
 	if err != nil {
-		logger.Fatalf("could not initialize request error handling: %v", err)
+		logger.WithError(err).Fatal("could not initialize request error handling")
 	}
 
 	handlerChain := tracing(logging(hsts(errorMiddleware(csrfProtect(router)))))
@@ -168,7 +178,7 @@ func startServer(ctx context.Context, handlerChain http.Handler, logger *log.Log
 
 	pemBytes, err := os.ReadFile(clientCertificateCAFile)
 	if err != nil {
-		logger.Fatalf("could not load client CA certificates: %v", err)
+		logger.WithError(err).Fatal("could not load client CA certificates")
 	}
 
 	clientCertPool.AppendCertsFromPEM(pemBytes)
@@ -182,9 +192,9 @@ func startServer(ctx context.Context, handlerChain http.Handler, logger *log.Log
 	server := &http.Server{
 		Addr:         fmt.Sprintf("%s:%d", serverBindAddress, serverPort),
 		Handler:      handlerChain,
-		ReadTimeout:  TimeoutTwenty,
-		WriteTimeout: TimeoutTwenty,
-		IdleTimeout:  TimeoutThirty,
+		ReadTimeout:  ReadTimeOut,
+		WriteTimeout: WriteTimeOut,
+		IdleTimeout:  IdleTimeout,
 		TLSConfig:    tlsConfig,
 	}
 
@@ -197,30 +207,39 @@ func startServer(ctx context.Context, handlerChain http.Handler, logger *log.Log
 		logger.Infoln("Server is shutting down...")
 		atomic.StoreInt32(&handlers.Healthy, 0)
 
-		ctx, cancel := context.WithTimeout(ctx, TimeoutThirty)
+		ctx, cancel := context.WithTimeout(ctx, ShutdownTimeout)
 		defer cancel()
 
 		server.SetKeepAlivesEnabled(false)
 
 		if err := server.Shutdown(ctx); err != nil {
-			logger.Fatalf("Could not gracefully shutdown the server: %v\n", err)
+			logger.WithError(err).Fatal("Could not gracefully shutdown the server")
 		}
 
 		close(done)
 	}()
 
 	logger.WithFields(log.Fields{
-		"address": server.Addr,
-		"url":     fmt.Sprintf("https://%s:%d/", serverName, serverPort),
+		"address": server.Addr, "url": publicAddress(serverName, serverPort),
 	}).Info("Server is ready to handle requests")
 	atomic.StoreInt32(&handlers.Healthy, 1)
 
 	if err := server.ListenAndServeTLS(
 		config.String("server.certificate"), config.String("server.key"),
-	); err != nil && err != http.ErrServerClosed {
-		logger.Fatalf("Could not listen on %s: %v\n", server.Addr, err)
+	); err != nil && !errors.Is(err, http.ErrServerClosed) {
+		logger.WithError(err).WithField(
+			"server_addr", server.Addr,
+		).Fatal("Could not listen on configured server address")
 	}
 
 	<-done
 	logger.Infoln("Server stopped")
 }
+
+func publicAddress(serverName string, serverPort int) string {
+	if serverPort != httpsDefaultPort {
+		return fmt.Sprintf("https://%s:%d/", serverName, serverPort)
+	}
+
+	return fmt.Sprintf("https://%s/", serverName)
+}

internal/handlers/consent.go

@@ -113,7 +113,7 @@ func (i *UserInfo) GetFullName() string {
 func (h *ConsentHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	challenge := r.URL.Query().Get("consent_challenge")
 
-	h.logger.Debugf("received consent challenge %s", challenge)
+	h.logger.WithField("consent_challenge", challenge).Debug("received consent challenge")
 
 	accept := r.Header.Get("Accept-Language")
 	localizer := i18n.NewLocalizer(h.bundle, accept)
@@ -128,7 +128,7 @@ func (h *ConsentHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	switch r.Method {
 	case http.MethodGet:
 		if err := h.renderConsentForm(w, r, consentData, requestedClaims, localizer); err != nil {
-			h.logger.Error(err)
+			h.logger.WithError(err).Error("could not render consent form")
 			http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
 
 			return
@@ -139,7 +139,7 @@ func (h *ConsentHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 		// validate input
 		decoder := form.NewDecoder()
 		if err := decoder.Decode(&consentInfo, r.Form); err != nil {
-			h.logger.Error(err)
+			h.logger.WithError(err).Error("could not decode consent form")
 			http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
 
 			return
@@ -148,7 +148,7 @@ func (h *ConsentHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 		if consentInfo.ConsentChecked {
 			sessionData, err := h.getSessionData(r, consentInfo, requestedClaims, consentData.Payload)
 			if err != nil {
-				h.logger.Errorf("could not get session data: %v", err)
+				h.logger.WithError(err).Error("could not get session data")
 				http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
 
 				return
@@ -165,7 +165,7 @@ func (h *ConsentHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 						Session:                  sessionData,
 					}).WithTimeout(TimeoutTen))
 			if err != nil {
-				h.logger.Error(err)
+				h.logger.WithError(err).Error("accept consent request failed")
 				http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
 
 				return
@@ -181,7 +181,7 @@ func (h *ConsentHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 			admin.NewRejectConsentRequestParams().WithConsentChallenge(challenge).WithBody(
 				&models.RejectRequest{}))
 		if err != nil {
-			h.logger.Error(err)
+			h.logger.WithError(err).Error("reject consent request failed")
 			http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
 
 			return
@@ -200,7 +200,7 @@ func (h *ConsentHandler) getRequestedConsentInformation(challenge string, r *htt
 	consentData, err := h.adminClient.GetConsentRequest(
 		admin.NewGetConsentRequestParams().WithConsentChallenge(challenge))
 	if err != nil {
-		h.logger.Errorf("error getting consent information: %v", err)
+		h.logger.WithError(err).Error("error getting consent information")
 
 		if errorBucket := GetErrorBucket(r); errorBucket != nil {
 			errorDetails := &ErrorDetails{
@@ -218,18 +218,18 @@ func (h *ConsentHandler) getRequestedConsentInformation(challenge string, r *htt
 
 	requestURL, err := url.Parse(consentData.Payload.RequestURL)
 	if err != nil {
-		h.logger.Warnf("could not parse original request URL %s: %v", consentData.Payload.RequestURL, err)
+		h.logger.WithError(err).WithField(
+			"request_url", consentData.Payload.RequestURL,
+		).Warn("could not parse original request URL")
 	} else {
 		claimsParameter := requestURL.Query().Get("claims")
 		if claimsParameter != "" {
 			decoder := json.NewDecoder(strings.NewReader(claimsParameter))
 			err := decoder.Decode(&requestedClaims)
 			if err != nil {
-				h.logger.Warnf(
-					"ignoring claims request parameter %s that could not be decoded: %v",
-					claimsParameter,
-					err,
-				)
+				h.logger.WithError(err).WithField(
+					"claims_parameter", claimsParameter,
+				).Warn("ignoring claims request parameter that could not be decoded")
 			}
 		}
 	}
@@ -296,7 +296,7 @@ func (h *ConsentHandler) mapRequestedScope(
 
 	for _, scopeName := range scope {
 		if _, ok := supportedScopes[scopeName]; !ok {
-			h.logger.Warnf("unsupported scope %s ignored", scopeName)
+			h.logger.WithField("scope", scopeName).Warn("ignoring unsupported scope")
 
 			continue
 		}
@@ -305,7 +305,7 @@ func (h *ConsentHandler) mapRequestedScope(
 			DefaultMessage: supportedScopes[scopeName],
 		})
 		if err != nil {
-			h.logger.Warnf("could not localize label for scope %s: %v", scopeName, err)
+			h.logger.WithError(err).WithField("scope", scopeName).Warn("could not localize scope label")
 			label = scopeName
 		}
 
@@ -332,7 +332,7 @@ func (h *ConsentHandler) mapRequestedClaims(
 		if claimElement != nil {
 			for k, v := range *claimElement {
 				if _, ok := supportedClaims[k]; !ok {
-					h.logger.Warnf("unsupported claim %s ignored", k)
+					h.logger.WithField("claim", k).Warn("ignoring unsupported claim")
 
 					continue
 				}
@@ -341,7 +341,7 @@ func (h *ConsentHandler) mapRequestedClaims(
 					DefaultMessage: supportedClaims[k],
 				})
 				if err != nil {
-					h.logger.Warnf("could not localize label for claim %s: %v", k, err)
+					h.logger.WithError(err).WithField("claim", k).Warn("could not localize claim label")
 					label = k
 				}
 
@@ -469,15 +469,9 @@ func (h *ConsentHandler) parseUserInfoClaims(
 		}
 
 		if claim.IsEssential() {
-			h.logger.Warnf(
-				"handling for essential claim name %s not implemented",
-				claimName,
-			)
+			h.logger.WithField("claim", claimName).Warn("handling for essential claim not implemented")
 		} else {
-			h.logger.Warnf(
-				"handling for claim name %s not implemented",
-				claimName,
-			)
+			h.logger.WithField("claim", claimName).Warn("handling for claim not implemented")
 		}
 	}
 
@@ -491,7 +485,9 @@ func (h *ConsentHandler) GetUserInfoFromClientCertificate(r *http.Request, subje
 		var verified bool
 
 		for _, email := range firstCert.EmailAddresses {
-			h.logger.Infof("authenticated with a client certificate for email address %s", email)
+			h.logger.WithField(
+				"email", email,
+			).Info("authenticated with client certificate for email address")
 
 			if subject == email {
 				verified = true
@@ -499,10 +495,9 @@ func (h *ConsentHandler) GetUserInfoFromClientCertificate(r *http.Request, subje
 		}
 
 		if !verified {
-			h.logger.Warnf(
-				"authentication attempt with a wrong certificate that did not contain the requested address %s",
-				subject,
-			)
+			h.logger.WithField(
+				"subject", subject,
+			).Warn("authentication attempt with a wrong certificate that did not contain the requested address")
 
 			return nil
 		}

internal/handlers/login.go

@@ -82,7 +82,7 @@ func (h *LoginHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	h.logger.Debugf("received login challenge %s\n", challenge)
+	h.logger.WithField("challenge", challenge).Debug("received login challenge")
 
 	certEmails := h.getEmailAddressesFromClientCertificate(r)
 
@@ -153,7 +153,7 @@ func (h *LoginHandler) handlePost(
 	}
 
 	// perform certificate auth
-	h.logger.Infof("would perform certificate authentication with: %+v", certEmails)
+	h.logger.WithField("emails", certEmails).Info("will perform certificate authentication")
 
 	userID, err := h.performCertificateLogin(certEmails, r)
 	if err != nil {
@@ -172,7 +172,7 @@ func (h *LoginHandler) handlePost(
 				Subject:     &userID,
 			}).WithTimeout(TimeoutTen))
 	if err != nil {
-		h.logger.Errorf("error getting login request: %#v", err)
+		h.logger.WithError(err).Error("error getting login request")
 
 		h.fillAcceptLoginRequestErrorBucket(r, err)
 
@@ -223,7 +223,7 @@ func (h *LoginHandler) rejectLogin(w http.ResponseWriter, challenge string, loca
 			},
 		).WithTimeout(Ten))
 	if err != nil {
-		h.logger.Errorf("error getting reject login request: %#v", err)
+		h.logger.WithError(err).Error("error getting reject login request")
 		http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
 
 		return
@@ -242,7 +242,9 @@ func (h *LoginHandler) getEmailAddressesFromClientCertificate(r *http.Request) [
 		}
 
 		for _, email := range firstCert.EmailAddresses {
-			h.logger.Infof("authenticated with a client certificate for email address %s", email)
+			h.logger.WithField(
+				"email", email,
+			).Info("authenticated with a client certificate for email address")
 		}
 
 		return firstCert.EmailAddresses
@@ -268,28 +270,28 @@ func (h *LoginHandler) renderRequestForClientCert(
 	localizer *i18n.Localizer,
 	loginRequest *admin.GetLoginRequestOK,
 ) {
-	trans := func(label string) string {
-		return h.messageCatalog.LookupMessage(label, nil, localizer)
-	}
+	msg := h.messageCatalog.LookupMessage
+	msgPlural := h.messageCatalog.LookupMessagePlural
+	msgMarkdown := h.messageCatalog.LookupMarkdownMessage
 
 	rendered := bytes.NewBuffer(make([]byte, 0))
+
 	err := h.templates[CertificateLogin].Lookup("base").Execute(rendered, map[string]interface{}{
-		"Title":          trans("LoginTitle"),
+		"Title":          msg("LoginTitle", nil, localizer),
 		csrf.TemplateTag: csrf.TemplateField(r),
-		"IntroText": template.HTML(h.messageCatalog.LookupMessage( //nolint:gosec
+		"IntroText": template.HTML(msgMarkdown( //nolint:gosec
 			"CertLoginIntroText",
 			map[string]interface{}{"ClientName": loginRequest.GetPayload().Client.ClientName},
 			localizer,
 		)),
-		"EmailChoiceText": h.messageCatalog.LookupMessagePlural("EmailChoiceText", nil, localizer, len(emails)),
+		"EmailChoiceText": msgPlural("EmailChoiceText", nil, localizer, len(emails)),
 		"emails":          emails,
-		"RequestText":     trans("CertLoginRequestText"),
-		"AcceptLabel":     trans("LabelAcceptCertLogin"),
-		"RejectLabel":     trans("LabelRejectCertLogin"),
+		"RequestText":     msg("CertLoginRequestText", nil, localizer),
+		"AcceptLabel":     msg("LabelAcceptCertLogin", nil, localizer),
+		"RejectLabel":     msg("LabelRejectCertLogin", nil, localizer),
 	})
-
 	if err != nil {
-		h.logger.Error(err)
+		h.logger.WithError(err).Error("template rendering failed")
 		http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
 
 		return
@@ -312,13 +314,11 @@ func (h *LoginHandler) performCertificateLogin(emails []string, r *http.Request)
 }
 
 func (h *LoginHandler) renderNoEmailsInClientCertificate(w http.ResponseWriter, localizer *i18n.Localizer) {
-	trans := func(label string) string {
-		return h.messageCatalog.LookupMessage(label, nil, localizer)
-	}
+	msg := h.messageCatalog.LookupMessage
 
 	err := h.templates[NoEmailsInClientCertificate].Lookup("base").Execute(w, map[string]interface{}{
-		"Title":       trans("NoEmailsInClientCertificateTitle"),
-		"Explanation": trans("NoEmailsInClientCertificateExplanation"),
+		"Title":       msg("NoEmailsInClientCertificateTitle", nil, localizer),
+		"Explanation": msg("NoEmailsInClientCertificateExplanation", nil, localizer),
 	})
 	if err != nil {
 		h.logger.WithError(err).Error("template rendering failed")

internal/handlers/logout.go

@@ -40,23 +40,23 @@ func (h *LogoutHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	const Ten = 10 * time.Second
 
 	challenge := r.URL.Query().Get("logout_challenge")
-	h.logger.Debugf("received challenge %s\n", challenge)
+	h.logger.WithField("challenge", challenge).Debug("received logout challenge")
 
 	logoutRequest, err := h.adminClient.GetLogoutRequest(
 		admin.NewGetLogoutRequestParams().WithLogoutChallenge(challenge).WithTimeout(Ten))
 	if err != nil {
-		h.logger.Errorf("error getting logout requests: %v", err)
+		h.logger.WithError(err).Error("error getting logout requests")
 		http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
 
 		return
 	}
 
-	h.logger.Debugf("received logout request: %#v", logoutRequest.Payload)
+	h.logger.WithField("logout_request", logoutRequest.Payload).Debug("received logout request")
 
 	acceptLogoutRequest, err := h.adminClient.AcceptLogoutRequest(
 		admin.NewAcceptLogoutRequestParams().WithLogoutChallenge(challenge))
 	if err != nil {
-		h.logger.Errorf("error accepting logout: %v", err)
+		h.logger.WithError(err).Error("accept logout request failed")
 		http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
 	}
 

internal/handlers/observability.go

@@ -64,7 +64,7 @@ func Logging(logger *log.Logger) func(http.Handler) http.Handler {
 					requestID = "unknown"
 				}
 				logger.Infof(
-					"%s %s \"%s %s\" %d %d \"%s\"",
+					"[%s] %s \"%s %s\" %d %d \"%s\"",
 					requestID,
 					r.RemoteAddr,
 					r.Method,

internal/services/configuration.go

@@ -43,6 +43,8 @@ var DefaultConfig = map[string]interface{}{
 	"security.client.ca-file": "client_ca.pem",
 	"admin.url":               "https://hydra.cacert.localhost:4445/",
 	"i18n.languages":          []string{"en", "de"},
+	"log.level":               "info",
+	"log.json":                true,
 }
 
 func ConfigureApplication(
@@ -52,18 +54,20 @@ func ConfigureApplication(
 ) (*koanf.Koanf, error) {
 	f := pflag.NewFlagSet("config", pflag.ContinueOnError)
 	f.Usage = func() {
-		fmt.Println(f.FlagUsages()) //nolint:forbidigo
+		logger.Info(f.FlagUsages())
+
 		os.Exit(0)
 	}
-
 	f.StringSlice(
 		"conf",
 		[]string{fmt.Sprintf("%s.toml", strings.ToLower(appName))},
 		"path to one or more .toml files",
 	)
 
-	if err := f.Parse(os.Args[1:]); err != nil {
-		logger.Fatal(err)
+	var err error
+
+	if err = f.Parse(os.Args[1:]); err != nil {
+		logger.WithError(err).Fatal("could not parse command line arguments")
 	}
 
 	config := koanf.New(".")
@@ -72,27 +76,28 @@ func ConfigureApplication(
 
 	cFiles, _ := f.GetStringSlice("conf")
 	for _, c := range cFiles {
-		if err := config.Load(file.Provider(c), toml.Parser()); err != nil {
-			logger.Fatalf("error loading config file: %s", err)
+		if err = config.Load(file.Provider(c), toml.Parser()); err != nil {
+			logger.WithError(err).WithField("file", c).Fatal("error loading configuration from file")
 		}
 	}
 
-	if err := config.Load(posflag.Provider(f, ".", config), nil); err != nil {
-		logger.Fatalf("error loading configuration: %s", err)
+	if err = config.Load(posflag.Provider(f, ".", config), nil); err != nil {
+		logger.WithError(err).Fatal("error loading configuration from command line")
 	}
 
-	if err := config.Load(
-		file.Provider("resource_app.toml"),
+	if err = config.Load(
+		file.Provider("idp.toml"),
 		toml.Parser(),
 	); err != nil && !os.IsNotExist(err) {
-		logger.Fatalf("error loading config: %v", err)
+		logrus.WithError(err).Fatal("error loading configuration from resource_app.toml")
 	}
 
 	prefix := fmt.Sprintf("%s_", strings.ToUpper(appName))
-	if err := config.Load(env.Provider(prefix, ".", func(s string) string {
+
+	if err = config.Load(env.Provider(prefix, ".", func(s string) string {
 		return strings.ReplaceAll(strings.ToLower(strings.TrimPrefix(s, prefix)), "_", ".")
 	}), nil); err != nil {
-		logger.Fatalf("error loading config: %v", err)
+		logrus.WithError(err).Fatal("error loading configuration from environment")
 	}
 
 	return config, nil

internal/services/i18n.go

@@ -148,18 +148,24 @@ func (m *MessageCatalog) AddMessages(messages map[string]*i18n.Message) {
 	}
 }
 
-func (m *MessageCatalog) LookupErrorMessage(tag, field string, value interface{}, localizer *i18n.Localizer) string {
-	message, ok := m.messages[fmt.Sprintf("%s-%s", field, tag)]
+func (m *MessageCatalog) LookupErrorMessage(
+	tag string,
+	field string,
+	value interface{},
+	localizer *i18n.Localizer,
+) string {
+	fieldTag := fmt.Sprintf("%s-%s", field, tag)
+	message, ok := m.messages[fieldTag]
 	if !ok {
-		m.logger.Infof("no specific error message %s-%s", field, tag)
+		m.logger.WithField("field_tag", fieldTag).Info("no specific error message for field and tag")
 
 		message, ok = m.messages[tag]
 		if !ok {
-			m.logger.Infof("no specific error message %s", tag)
+			m.logger.WithField("tag", tag).Info("no specific error message for tag")
 
 			message, ok = m.messages["unknown"]
 			if !ok {
-				m.logger.Warnf("no default translation found")
+				m.logger.Warn("no default translation found")
 
 				return tag
 			}
@@ -173,7 +179,7 @@ func (m *MessageCatalog) LookupErrorMessage(tag, field string, value interface{}
 		},
 	})
 	if err != nil {
-		m.logger.Error(err)
+		m.logger.WithError(err).Error("localization failed")
 
 		return tag
 	}
@@ -227,7 +233,7 @@ func (m *MessageCatalog) LookupMarkdownMessage(
 		return buf.String()
 	}
 
-	m.logger.Warnf("no translation found for %s", id)
+	m.logger.WithField("id", id).Warn("no translation found for id")
 
 	return id
 }
@@ -251,7 +257,7 @@ func (m *MessageCatalog) LookupMessagePlural(
 		return translation
 	}
 
-	m.logger.Warnf("no translation found for %s", id)
+	m.logger.WithField("id", id).Warn("no translation found for id")
 
 	return id
 }
@@ -281,7 +287,7 @@ func InitI18n(logger *log.Logger, languages []string) (*i18n.Bundle, *MessageCat
 
 		bundleBytes, err := translations.Bundles.ReadFile(bundleName)
 		if err != nil {
-			logger.Warnf("message bundle %s not found", bundleName)
+			logger.WithField("bundle", bundleName).Warn("message bundle not found")
 
 			continue
 		}