From d69fd6af22751974364e35cc697f9eaaaef160d3 Mon Sep 17 00:00:00 2001 From: Phil Taprogge Date: Mon, 10 Aug 2020 11:44:08 +0100 Subject: [PATCH] Allow Logging to stdout with separate Error Log Channel (#718) * Add dedicated error logging writer * Document new errors to stdout flag * Update changelog * Thread-safe the log buffer * Address feedback * Remove duplication by adding log level * Clean up error formatting * Apply suggestions from code review Co-authored-by: Joel Speed --- CHANGELOG.md | 1 + docs/configuration/configuration.md | 1 + http.go | 2 +- main.go | 6 +- oauthproxy.go | 26 +++---- pkg/apis/options/legacy_options.go | 2 +- pkg/apis/options/logging.go | 3 + pkg/authentication/basic/htpasswd.go | 2 +- pkg/cookies/cookies.go | 4 +- pkg/logger/logger.go | 109 +++++++++++++++++++++------ pkg/middleware/basic_session.go | 2 +- pkg/middleware/jwt_session.go | 2 +- pkg/middleware/stored_session.go | 4 +- pkg/sessions/cookie/session_store.go | 2 +- pkg/sessions/redis/redis_store.go | 4 +- pkg/upstream/proxy.go | 2 +- pkg/validation/logging.go | 3 +- pkg/validation/options.go | 2 +- providers/azure.go | 4 +- providers/bitbucket.go | 10 +-- providers/google.go | 6 +- providers/internal_util.go | 10 +-- providers/keycloak.go | 2 +- providers/provider_data.go | 2 +- validator.go | 2 +- watcher.go | 2 +- watcher_unsupported.go | 2 +- 27 files changed, 144 insertions(+), 73 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 23c6e9a2..da1b7731 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -11,6 +11,7 @@ ## Changes since v6.0.0 +- [#718](https://github.com/oauth2-proxy/oauth2-proxy/pull/718) Allow Logging to stdout with separate Error Log Channel - [#690](https://github.com/oauth2-proxy/oauth2-proxy/pull/690) Address GoSec security findings & remediate (@NickMeves) - [#689](https://github.com/oauth2-proxy/oauth2-proxy/pull/689) Fix finicky logging_handler_test from time drift (@NickMeves) - [#699](https://github.com/oauth2-proxy/oauth2-proxy/pull/699) Align persistence ginkgo tests with conventions (@NickMeves) diff --git a/docs/configuration/configuration.md b/docs/configuration/configuration.md index 21ae2ef8..92bc9cd6 100644 --- a/docs/configuration/configuration.md +++ b/docs/configuration/configuration.md @@ -45,6 +45,7 @@ An example [oauth2-proxy.cfg]({{ site.gitweb }}/contrib/oauth2-proxy.cfg.example | `--custom-templates-dir` | string | path to custom html templates | | | `--display-htpasswd-form` | bool | display username / password login form if an htpasswd file is provided | true | | `--email-domain` | string \| list | authenticate emails with the specified domain (may be given multiple times). Use `*` to authenticate any email | | +| `--errors-to-info-log` | bool | redirects error-level logging to default log channel instead of stderr | | | `--extra-jwt-issuers` | string | if `--skip-jwt-bearer-tokens` is set, a list of extra JWT `issuer=audience` pairs (where the issuer URL has a `.well-known/openid-configuration` or a `.well-known/jwks.json`) | | | `--exclude-logging-paths` | string | comma separated list of paths to exclude from logging, e.g. `"/ping,/path2"` |`""` (no paths excluded) | | `--flush-interval` | duration | period between flushing response buffers when streaming responses | `"1s"` | diff --git a/http.go b/http.go index 41198de4..fd0d6b76 100644 --- a/http.go +++ b/http.go @@ -106,7 +106,7 @@ func (s *Server) serve(listener net.Listener) { err := srv.Serve(listener) if err != nil && !errors.Is(err, http.ErrServerClosed) { - logger.Printf("ERROR: http.Serve() - %s", err) + logger.Errorf("ERROR: http.Serve() - %s", err) } <-idleConnsClosed } diff --git a/main.go b/main.go index ef9ac44e..527d55ad 100644 --- a/main.go +++ b/main.go @@ -38,13 +38,13 @@ func main() { legacyOpts := options.NewLegacyOptions() err = options.Load(*config, flagSet, legacyOpts) if err != nil { - logger.Printf("ERROR: Failed to load config: %v", err) + logger.Errorf("ERROR: Failed to load config: %v", err) os.Exit(1) } opts, err := legacyOpts.ToOptions() if err != nil { - logger.Printf("ERROR: Failed to convert config: %v", err) + logger.Errorf("ERROR: Failed to convert config: %v", err) os.Exit(1) } @@ -57,7 +57,7 @@ func main() { validator := NewValidator(opts.EmailDomains, opts.AuthenticatedEmailsFile) oauthproxy, err := NewOAuthProxy(opts, validator) if err != nil { - logger.Printf("ERROR: Failed to initialise OAuth2 Proxy: %v", err) + logger.Errorf("ERROR: Failed to initialise OAuth2 Proxy: %v", err) os.Exit(1) } diff --git a/oauthproxy.go b/oauthproxy.go index ac9e0565..5bfb7631 100644 --- a/oauthproxy.go +++ b/oauthproxy.go @@ -337,7 +337,7 @@ func (p *OAuthProxy) makeCookie(req *http.Request, name string, value string, ex domain = h } if !strings.HasSuffix(domain, cookieDomain) { - logger.Printf("Warning: request host is %q but using configured cookie domain of %q", domain, cookieDomain) + logger.Errorf("Warning: request host is %q but using configured cookie domain of %q", domain, cookieDomain) } } @@ -423,7 +423,7 @@ func (p *OAuthProxy) SignInPage(rw http.ResponseWriter, req *http.Request, code redirectURL, err := p.GetRedirect(req) if err != nil { - logger.Printf("Error obtaining redirect: %v", err) + logger.Errorf("Error obtaining redirect: %v", err) p.ErrorPage(rw, http.StatusInternalServerError, "Internal Server Error", err.Error()) return } @@ -623,7 +623,7 @@ func (p *OAuthProxy) IsTrustedIP(req *http.Request) bool { remoteAddr, err := ip.GetClientIP(p.realClientIPParser, req) if err != nil { - logger.Printf("Error obtaining real IP for trusted IP list: %v", err) + logger.Errorf("Error obtaining real IP for trusted IP list: %v", err) // Possibly spoofed X-Real-IP header return false } @@ -666,7 +666,7 @@ func (p *OAuthProxy) ServeHTTP(rw http.ResponseWriter, req *http.Request) { func (p *OAuthProxy) SignIn(rw http.ResponseWriter, req *http.Request) { redirect, err := p.GetRedirect(req) if err != nil { - logger.Printf("Error obtaining redirect: %v", err) + logger.Errorf("Error obtaining redirect: %v", err) p.ErrorPage(rw, http.StatusInternalServerError, "Internal Server Error", err.Error()) return } @@ -718,13 +718,13 @@ func (p *OAuthProxy) UserInfo(rw http.ResponseWriter, req *http.Request) { func (p *OAuthProxy) SignOut(rw http.ResponseWriter, req *http.Request) { redirect, err := p.GetRedirect(req) if err != nil { - logger.Printf("Error obtaining redirect: %v", err) + logger.Errorf("Error obtaining redirect: %v", err) p.ErrorPage(rw, http.StatusInternalServerError, "Internal Server Error", err.Error()) return } err = p.ClearSessionCookie(rw, req) if err != nil { - logger.Printf("Error clearing session cookie: %v", err) + logger.Errorf("Error clearing session cookie: %v", err) p.ErrorPage(rw, http.StatusInternalServerError, "Internal Server Error", err.Error()) return } @@ -736,14 +736,14 @@ func (p *OAuthProxy) OAuthStart(rw http.ResponseWriter, req *http.Request) { prepareNoCache(rw) nonce, err := encryption.Nonce() if err != nil { - logger.Printf("Error obtaining nonce: %v", err) + logger.Errorf("Error obtaining nonce: %v", err) p.ErrorPage(rw, http.StatusInternalServerError, "Internal Server Error", err.Error()) return } p.SetCSRFCookie(rw, req, nonce) redirect, err := p.GetRedirect(req) if err != nil { - logger.Printf("Error obtaining redirect: %v", err) + logger.Errorf("Error obtaining redirect: %v", err) p.ErrorPage(rw, http.StatusInternalServerError, "Internal Server Error", err.Error()) return } @@ -759,27 +759,27 @@ func (p *OAuthProxy) OAuthCallback(rw http.ResponseWriter, req *http.Request) { // finish the oauth cycle err := req.ParseForm() if err != nil { - logger.Printf("Error while parsing OAuth2 callback: %v", err) + logger.Errorf("Error while parsing OAuth2 callback: %v", err) p.ErrorPage(rw, http.StatusInternalServerError, "Internal Server Error", err.Error()) return } errorString := req.Form.Get("error") if errorString != "" { - logger.Printf("Error while parsing OAuth2 callback: %s", errorString) + logger.Errorf("Error while parsing OAuth2 callback: %s", errorString) p.ErrorPage(rw, http.StatusForbidden, "Permission Denied", errorString) return } session, err := p.redeemCode(req.Context(), req.Host, req.Form.Get("code")) if err != nil { - logger.Printf("Error redeeming code during OAuth2 callback: %v", err) + logger.Errorf("Error redeeming code during OAuth2 callback: %v", err) p.ErrorPage(rw, http.StatusInternalServerError, "Internal Server Error", "Internal Error") return } s := strings.SplitN(req.Form.Get("state"), ":", 2) if len(s) != 2 { - logger.Printf("Error while parsing OAuth2 state: invalid length") + logger.Error("Error while parsing OAuth2 state: invalid length") p.ErrorPage(rw, http.StatusInternalServerError, "Internal Server Error", "Invalid State") return } @@ -865,7 +865,7 @@ func (p *OAuthProxy) Proxy(rw http.ResponseWriter, req *http.Request) { default: // unknown error - logger.Printf("Unexpected internal error: %s", err) + logger.Errorf("Unexpected internal error: %v", err) p.ErrorPage(rw, http.StatusInternalServerError, "Internal Error", "Internal Error") } diff --git a/pkg/apis/options/legacy_options.go b/pkg/apis/options/legacy_options.go index 762eba07..d7f13e59 100644 --- a/pkg/apis/options/legacy_options.go +++ b/pkg/apis/options/legacy_options.go @@ -91,7 +91,7 @@ func (l *LegacyUpstreams) convert() (Upstreams, error) { case "static": responseCode, err := strconv.Atoi(u.Host) if err != nil { - logger.Printf("unable to convert %q to int, use default \"200\"", u.Host) + logger.Errorf("unable to convert %q to int, use default \"200\"", u.Host) responseCode = 200 } upstream.Static = true diff --git a/pkg/apis/options/logging.go b/pkg/apis/options/logging.go index d7407678..b133825e 100644 --- a/pkg/apis/options/logging.go +++ b/pkg/apis/options/logging.go @@ -13,6 +13,7 @@ type Logging struct { RequestFormat string `flag:"request-logging-format" cfg:"request_logging_format"` StandardEnabled bool `flag:"standard-logging" cfg:"standard_logging"` StandardFormat string `flag:"standard-logging-format" cfg:"standard_logging_format"` + ErrToInfo bool `flag:"errors-to-info-log" cfg:"errors_to_info_log"` ExcludePaths []string `flag:"exclude-logging-path" cfg:"exclude_logging_paths"` LocalTime bool `flag:"logging-local-time" cfg:"logging_local_time"` SilencePing bool `flag:"silence-ping-logging" cfg:"silence_ping_logging"` @@ -37,6 +38,7 @@ func loggingFlagSet() *pflag.FlagSet { flagSet.String("standard-logging-format", logger.DefaultStandardLoggingFormat, "Template for standard log lines") flagSet.Bool("request-logging", true, "Log HTTP requests") flagSet.String("request-logging-format", logger.DefaultRequestLoggingFormat, "Template for HTTP request log lines") + flagSet.Bool("errors-to-info-log", false, "Log errors to the standard logging channel instead of stderr") flagSet.StringSlice("exclude-logging-path", []string{}, "Exclude logging requests to paths (eg: '/path1,/path2,/path3')") flagSet.Bool("logging-local-time", true, "If the time in log files and backup filenames are local or UTC time") @@ -63,6 +65,7 @@ func loggingDefaults() Logging { RequestFormat: logger.DefaultRequestLoggingFormat, StandardEnabled: true, StandardFormat: logger.DefaultStandardLoggingFormat, + ErrToInfo: false, File: LogFileOptions{ Filename: "", MaxSize: 100, diff --git a/pkg/authentication/basic/htpasswd.go b/pkg/authentication/basic/htpasswd.go index 321b7bae..a0ec9c22 100644 --- a/pkg/authentication/basic/htpasswd.go +++ b/pkg/authentication/basic/htpasswd.go @@ -78,7 +78,7 @@ func createHtpasswdMap(records [][]string) (*htpasswdMap, error) { // Password is neither sha1 or bcrypt // TODO(JoelSpeed): In the next breaking release, make this return an error. - logger.Printf("Invalid htpasswd entry for %s. Must be a SHA or bcrypt entry.", user) + logger.Errorf("Invalid htpasswd entry for %s. Must be a SHA or bcrypt entry.", user) } return h, nil } diff --git a/pkg/cookies/cookies.go b/pkg/cookies/cookies.go index f3879587..01186108 100644 --- a/pkg/cookies/cookies.go +++ b/pkg/cookies/cookies.go @@ -20,7 +20,7 @@ func MakeCookie(req *http.Request, name string, value string, path string, domai host = h } if !strings.HasSuffix(host, domain) { - logger.Printf("Warning: request host is %q but using configured cookie domain of %q", host, domain) + logger.Errorf("Warning: request host is %q but using configured cookie domain of %q", host, domain) } } @@ -45,7 +45,7 @@ func MakeCookieFromOptions(req *http.Request, name string, value string, cookieO return MakeCookie(req, name, value, cookieOpts.Path, domain, cookieOpts.HTTPOnly, cookieOpts.Secure, expiration, now, ParseSameSite(cookieOpts.SameSite)) } // If nothing matches, create the cookie with the shortest domain - logger.Printf("Warning: request host %q did not match any of the specific cookie domains of %q", GetRequestHost(req), strings.Join(cookieOpts.Domains, ",")) + logger.Errorf("Warning: request host %q did not match any of the specific cookie domains of %q", GetRequestHost(req), strings.Join(cookieOpts.Domains, ",")) defaultDomain := "" if len(cookieOpts.Domains) > 0 { defaultDomain = cookieOpts.Domains[len(cookieOpts.Domains)-1] diff --git a/pkg/logger/logger.go b/pkg/logger/logger.go index e0ce61dd..6bc0ae82 100644 --- a/pkg/logger/logger.go +++ b/pkg/logger/logger.go @@ -1,6 +1,7 @@ package logger import ( + "bytes" "fmt" "io" "net/http" @@ -15,6 +16,9 @@ import ( // AuthStatus defines the different types of auth logging that occur type AuthStatus string +// Level indicates the log level for log messages +type Level int + const ( // DefaultStandardLoggingFormat defines the default standard log format DefaultStandardLoggingFormat = "[{{.Timestamp}}] [{{.File}}] {{.Message}}" @@ -38,6 +42,11 @@ const ( LUTC // LstdFlags flag for initial values for the logger LstdFlags = Lshortfile + + // DEFAULT is the default log level (effectively INFO) + DEFAULT Level = iota + // ERROR is for error-level logging + ERROR ) // These are the containers for all values that are available as variables in the logging formats. @@ -87,6 +96,7 @@ type Logger struct { mu sync.Mutex flag int writer io.Writer + errWriter io.Writer stdEnabled bool authEnabled bool reqEnabled bool @@ -100,7 +110,8 @@ type Logger struct { // New creates a new Standarderr Logger. func New(flag int) *Logger { return &Logger{ - writer: os.Stderr, + writer: os.Stdout, + errWriter: os.Stderr, flag: flag, stdEnabled: true, authEnabled: true, @@ -115,13 +126,7 @@ func New(flag int) *Logger { var std = New(LstdFlags) -// Output a standard log template with a simple message. -// Write a final newline at the end of every message. -func (l *Logger) Output(calldepth int, message string) { - if !l.stdEnabled { - return - } - +func (l *Logger) formatLogMessage(calldepth int, message string) []byte { now := time.Now() file := "???:0" @@ -129,10 +134,8 @@ func (l *Logger) Output(calldepth int, message string) { file = l.GetFileLineString(calldepth + 1) } - l.mu.Lock() - defer l.mu.Unlock() - - err := l.stdLogTemplate.Execute(l.writer, stdLogMessageData{ + var logBuff = new(bytes.Buffer) + err := l.stdLogTemplate.Execute(logBuff, stdLogMessageData{ Timestamp: FormatTimestamp(now), File: file, Message: message, @@ -145,6 +148,26 @@ func (l *Logger) Output(calldepth int, message string) { if err != nil { panic(err) } + logBuff.Write([]byte("\n")) + + return logBuff.Bytes() +} + +// Output a standard log template with a simple message to default output channel. +// Write a final newline at the end of every message. +func (l *Logger) Output(lvl Level, calldepth int, message string) { + l.mu.Lock() + defer l.mu.Unlock() + if !l.stdEnabled { + return + } + msg := l.formatLogMessage(calldepth, message) + switch lvl { + case ERROR: + l.errWriter.Write(msg) + default: + l.writer.Write(msg) + } } // PrintAuthf writes auth info to the logger. Requires an http.Request to @@ -302,6 +325,17 @@ func (l *Logger) SetStandardEnabled(e bool) { l.stdEnabled = e } +// SetErrToInfo enables or disables error logging to error writer instead of the default. +func (l *Logger) SetErrToInfo(e bool) { + l.mu.Lock() + defer l.mu.Unlock() + if e { + l.errWriter = l.writer + } else { + l.errWriter = os.Stderr + } +} + // SetAuthEnabled enables or disables auth logging. func (l *Logger) SetAuthEnabled(e bool) { l.mu.Lock() @@ -371,19 +405,32 @@ func SetFlags(flag int) { std.SetFlags(flag) } -// SetOutput sets the output destination for the standard logger. +// SetOutput sets the output destination for the standard logger's default channel. func SetOutput(w io.Writer) { std.mu.Lock() defer std.mu.Unlock() std.writer = w } +// SetErrOutput sets the output destination for the standard logger's error channel. +func SetErrOutput(w io.Writer) { + std.mu.Lock() + defer std.mu.Unlock() + std.errWriter = w +} + // SetStandardEnabled enables or disables standard logging for the // standard logger. func SetStandardEnabled(e bool) { std.SetStandardEnabled(e) } +// SetErrToInfo enables or disables error logging to output writer instead of +// error writer. +func SetErrToInfo(e bool) { + std.SetErrToInfo(e) +} + // SetAuthEnabled enables or disables auth logging for the standard // logger. func SetAuthEnabled(e bool) { @@ -428,57 +475,75 @@ func SetReqTemplate(t string) { // Print calls Output to print to the standard logger. // Arguments are handled in the manner of fmt.Print. func Print(v ...interface{}) { - std.Output(2, fmt.Sprint(v...)) + std.Output(DEFAULT, 2, fmt.Sprint(v...)) } // Printf calls Output to print to the standard logger. // Arguments are handled in the manner of fmt.Printf. func Printf(format string, v ...interface{}) { - std.Output(2, fmt.Sprintf(format, v...)) + std.Output(DEFAULT, 2, fmt.Sprintf(format, v...)) } // Println calls Output to print to the standard logger. // Arguments are handled in the manner of fmt.Println. func Println(v ...interface{}) { - std.Output(2, fmt.Sprintln(v...)) + std.Output(DEFAULT, 2, fmt.Sprintln(v...)) +} + +// Error calls OutputErr to print to the standard logger's error channel. +// Arguments are handled in the manner of fmt.Print. +func Error(v ...interface{}) { + std.Output(ERROR, 2, fmt.Sprint(v...)) +} + +// Errorf calls OutputErr to print to the standard logger's error channel. +// Arguments are handled in the manner of fmt.Printf. +func Errorf(format string, v ...interface{}) { + std.Output(ERROR, 2, fmt.Sprintf(format, v...)) +} + +// Errorln calls OutputErr to print to the standard logger's error channel. +// Arguments are handled in the manner of fmt.Println. +func Errorln(v ...interface{}) { + std.Output(ERROR, 2, fmt.Sprintln(v...)) } // Fatal is equivalent to Print() followed by a call to os.Exit(1). func Fatal(v ...interface{}) { - std.Output(2, fmt.Sprint(v...)) + std.Output(ERROR, 2, fmt.Sprint(v...)) os.Exit(1) } // Fatalf is equivalent to Printf() followed by a call to os.Exit(1). func Fatalf(format string, v ...interface{}) { - std.Output(2, fmt.Sprintf(format, v...)) + std.Output(ERROR, 2, fmt.Sprintf(format, v...)) os.Exit(1) } // Fatalln is equivalent to Println() followed by a call to os.Exit(1). func Fatalln(v ...interface{}) { - std.Output(2, fmt.Sprintln(v...)) + std.Output(ERROR, 2, fmt.Sprintln(v...)) os.Exit(1) } // Panic is equivalent to Print() followed by a call to panic(). func Panic(v ...interface{}) { s := fmt.Sprint(v...) - std.Output(2, s) + std.Output(ERROR, 2, s) panic(s) } // Panicf is equivalent to Printf() followed by a call to panic(). func Panicf(format string, v ...interface{}) { s := fmt.Sprintf(format, v...) - std.Output(2, s) + std.Output(ERROR, 2, s) panic(s) } // Panicln is equivalent to Println() followed by a call to panic(). func Panicln(v ...interface{}) { s := fmt.Sprintln(v...) - std.Output(2, s) + std.Output(ERROR, 2, s) panic(s) } diff --git a/pkg/middleware/basic_session.go b/pkg/middleware/basic_session.go index 734f4d83..02264155 100644 --- a/pkg/middleware/basic_session.go +++ b/pkg/middleware/basic_session.go @@ -34,7 +34,7 @@ func loadBasicAuthSession(validator basic.Validator, next http.Handler) http.Han session, err := getBasicSession(validator, req) if err != nil { - logger.Printf("Error retrieving session from token in Authorization header: %v", err) + logger.Errorf("Error retrieving session from token in Authorization header: %v", err) } // Add the session to the scope if it was found diff --git a/pkg/middleware/jwt_session.go b/pkg/middleware/jwt_session.go index 3a0b65fc..f3dc85ab 100644 --- a/pkg/middleware/jwt_session.go +++ b/pkg/middleware/jwt_session.go @@ -57,7 +57,7 @@ func (j *jwtSessionLoader) loadSession(next http.Handler) http.Handler { session, err := j.getJwtSession(req) if err != nil { - logger.Printf("Error retrieving session from token in Authorization header: %v", err) + logger.Errorf("Error retrieving session from token in Authorization header: %v", err) } // Add the session to the scope if it was found diff --git a/pkg/middleware/stored_session.go b/pkg/middleware/stored_session.go index d299fdf8..da6de96d 100644 --- a/pkg/middleware/stored_session.go +++ b/pkg/middleware/stored_session.go @@ -72,10 +72,10 @@ func (s *storedSessionLoader) loadSession(next http.Handler) http.Handler { if err != nil { // In the case when there was an error loading the session, // we should clear the session - logger.Printf("Error loading cookied session: %v, removing session", err) + logger.Errorf("Error loading cookied session: %v, removing session", err) err = s.store.Clear(rw, req) if err != nil { - logger.Printf("Error removing session: %v", err) + logger.Errorf("Error removing session: %v", err) } } diff --git a/pkg/sessions/cookie/session_store.go b/pkg/sessions/cookie/session_store.go index 87d16863..08419334 100644 --- a/pkg/sessions/cookie/session_store.go +++ b/pkg/sessions/cookie/session_store.go @@ -176,7 +176,7 @@ func splitCookie(c *http.Cookie) []*http.Cookie { return []*http.Cookie{c} } - logger.Printf("WARNING: Multiple cookies are required for this session as it exceeds the 4kb cookie limit. Please use server side session storage (eg. Redis) instead.") + logger.Errorf("WARNING: Multiple cookies are required for this session as it exceeds the 4kb cookie limit. Please use server side session storage (eg. Redis) instead.") cookies := []*http.Cookie{} valueBytes := []byte(c.Value) diff --git a/pkg/sessions/redis/redis_store.go b/pkg/sessions/redis/redis_store.go index 38fe3caa..4a2ceb2f 100644 --- a/pkg/sessions/redis/redis_store.go +++ b/pkg/sessions/redis/redis_store.go @@ -121,7 +121,7 @@ func buildStandaloneClient(opts options.RedisStoreOptions) (Client, error) { if opts.CAPath != "" { rootCAs, err := x509.SystemCertPool() if err != nil { - logger.Printf("failed to load system cert pool for redis connection, falling back to empty cert pool") + logger.Errorf("failed to load system cert pool for redis connection, falling back to empty cert pool") } if rootCAs == nil { rootCAs = x509.NewCertPool() @@ -133,7 +133,7 @@ func buildStandaloneClient(opts options.RedisStoreOptions) (Client, error) { // Append our cert to the system pool if ok := rootCAs.AppendCertsFromPEM(certs); !ok { - logger.Printf("no certs appended, using system certs only") + logger.Errorf("no certs appended, using system certs only") } opt.TLSConfig.RootCAs = rootCAs diff --git a/pkg/upstream/proxy.go b/pkg/upstream/proxy.go index 403b9b91..a6abc305 100644 --- a/pkg/upstream/proxy.go +++ b/pkg/upstream/proxy.go @@ -74,7 +74,7 @@ func (m *multiUpstreamProxy) registerHTTPUpstreamProxy(upstream options.Upstream // NewProxyErrorHandler creates a ProxyErrorHandler using the template given. func NewProxyErrorHandler(errorTemplate *template.Template, proxyPrefix string) ProxyErrorHandler { return func(rw http.ResponseWriter, req *http.Request, proxyErr error) { - logger.Printf("Error proxying to upstream server: %v", proxyErr) + logger.Errorf("Error proxying to upstream server: %v", proxyErr) rw.WriteHeader(http.StatusBadGateway) data := struct { Title string diff --git a/pkg/validation/logging.go b/pkg/validation/logging.go index 83b965ce..2ad7aba3 100644 --- a/pkg/validation/logging.go +++ b/pkg/validation/logging.go @@ -40,11 +40,12 @@ func configureLogger(o options.Logging, msgs []string) []string { // Supply a sanity warning to the logger if all logging is disabled if !o.StandardEnabled && !o.AuthEnabled && !o.RequestEnabled { - logger.Print("Warning: Logging disabled. No further logs will be shown.") + logger.Error("Warning: Logging disabled. No further logs will be shown.") } // Pass configuration values to the standard logger logger.SetStandardEnabled(o.StandardEnabled) + logger.SetErrToInfo(o.ErrToInfo) logger.SetAuthEnabled(o.AuthEnabled) logger.SetReqEnabled(o.RequestEnabled) logger.SetStandardTemplate(o.StandardFormat) diff --git a/pkg/validation/options.go b/pkg/validation/options.go index 86197c06..f9325cf0 100644 --- a/pkg/validation/options.go +++ b/pkg/validation/options.go @@ -92,7 +92,7 @@ func Validate(o *options.Options) error { Do(). UnmarshalJSON() if err != nil { - logger.Printf("error: failed to discover OIDC configuration: %v", err) + logger.Errorf("error: failed to discover OIDC configuration: %v", err) } else { // Prefer manually configured URLs. It's a bit unclear // why you'd be doing discovery and also providing the URLs diff --git a/providers/azure.go b/providers/azure.go index c713854c..12ef13d0 100644 --- a/providers/azure.go +++ b/providers/azure.go @@ -202,12 +202,12 @@ func (p *AzureProvider) GetEmailAddress(ctx context.Context, s *sessions.Session email, err = json.Get("userPrincipalName").String() if err != nil { - logger.Printf("failed making request %s", err) + logger.Errorf("failed making request %s", err) return "", err } if email == "" { - logger.Printf("failed to get email address") + logger.Errorf("failed to get email address") return "", err } diff --git a/providers/bitbucket.go b/providers/bitbucket.go index 8b6b71db..56f2aa24 100644 --- a/providers/bitbucket.go +++ b/providers/bitbucket.go @@ -107,7 +107,7 @@ func (p *BitbucketProvider) GetEmailAddress(ctx context.Context, s *sessions.Ses Do(). UnmarshalInto(&emails) if err != nil { - logger.Printf("failed making request: %v", err) + logger.Errorf("failed making request: %v", err) return "", err } @@ -123,7 +123,7 @@ func (p *BitbucketProvider) GetEmailAddress(ctx context.Context, s *sessions.Ses Do(). UnmarshalInto(&teams) if err != nil { - logger.Printf("failed requesting teams membership: %v", err) + logger.Errorf("failed requesting teams membership: %v", err) return "", err } var found = false @@ -134,7 +134,7 @@ func (p *BitbucketProvider) GetEmailAddress(ctx context.Context, s *sessions.Ses } } if !found { - logger.Print("team membership test failed, access denied") + logger.Error("team membership test failed, access denied") return "", nil } } @@ -153,7 +153,7 @@ func (p *BitbucketProvider) GetEmailAddress(ctx context.Context, s *sessions.Ses Do(). UnmarshalInto(&repositories) if err != nil { - logger.Printf("failed checking repository access: %v", err) + logger.Errorf("failed checking repository access: %v", err) return "", err } @@ -165,7 +165,7 @@ func (p *BitbucketProvider) GetEmailAddress(ctx context.Context, s *sessions.Ses } } if !found { - logger.Print("repository access test failed, access denied") + logger.Error("repository access test failed, access denied") return "", nil } } diff --git a/providers/google.go b/providers/google.go index 85c064db..d69a09d3 100644 --- a/providers/google.go +++ b/providers/google.go @@ -212,7 +212,7 @@ func userInGroup(service *admin.Service, groups []string, email string) bool { gerr, ok := err.(*googleapi.Error) switch { case ok && gerr.Code == 404: - logger.Printf("error checking membership in group %s: group does not exist", group) + logger.Errorf("error checking membership in group %s: group does not exist", group) case ok && gerr.Code == 400: // It is possible for Members.HasMember to return false even if the email is a group member. // One case that can cause this is if the user email is from a different domain than the group, @@ -222,7 +222,7 @@ func userInGroup(service *admin.Service, groups []string, email string) bool { r, err := req.Do() if err != nil { - logger.Printf("error using get API to check member %s of google group %s: user not in the group", email, group) + logger.Errorf("error using get API to check member %s of google group %s: user not in the group", email, group) continue } @@ -232,7 +232,7 @@ func userInGroup(service *admin.Service, groups []string, email string) bool { return true } default: - logger.Printf("error checking group membership: %v", err) + logger.Errorf("error checking group membership: %v", err) } continue } diff --git a/providers/internal_util.go b/providers/internal_util.go index 42948408..b5c2b284 100644 --- a/providers/internal_util.go +++ b/providers/internal_util.go @@ -24,14 +24,14 @@ func stripToken(endpoint string) string { func stripParam(param, endpoint string) string { u, err := url.Parse(endpoint) if err != nil { - logger.Printf("error attempting to strip %s: %s", param, err) + logger.Errorf("error attempting to strip %s: %s", param, err) return endpoint } if u.RawQuery != "" { values, err := url.ParseQuery(u.RawQuery) if err != nil { - logger.Printf("error attempting to strip %s: %s", param, err) + logger.Errorf("error attempting to strip %s: %s", param, err) return u.String() } @@ -61,8 +61,8 @@ func validateToken(ctx context.Context, p Provider, accessToken string, header h WithHeaders(header). Do() if result.Error() != nil { - logger.Printf("GET %s", stripToken(endpoint)) - logger.Printf("token validation request failed: %s", result.Error()) + logger.Errorf("GET %s", stripToken(endpoint)) + logger.Errorf("token validation request failed: %s", result.Error()) return false } @@ -71,6 +71,6 @@ func validateToken(ctx context.Context, p Provider, accessToken string, header h if result.StatusCode() == 200 { return true } - logger.Printf("token validation request failed: status %d - %s", result.StatusCode(), result.Body()) + logger.Errorf("token validation request failed: status %d - %s", result.StatusCode(), result.Body()) return false } diff --git a/providers/keycloak.go b/providers/keycloak.go index cb795fe2..95f90720 100644 --- a/providers/keycloak.go +++ b/providers/keycloak.go @@ -70,7 +70,7 @@ func (p *KeycloakProvider) GetEmailAddress(ctx context.Context, s *sessions.Sess Do(). UnmarshalJSON() if err != nil { - logger.Printf("failed making request %s", err) + logger.Errorf("failed making request %s", err) return "", err } diff --git a/providers/provider_data.go b/providers/provider_data.go index 1371dd39..78aee687 100644 --- a/providers/provider_data.go +++ b/providers/provider_data.go @@ -39,7 +39,7 @@ func (p *ProviderData) GetClientSecret() (clientSecret string, err error) { // Getting ClientSecret can fail in runtime so we need to report it without returning the file name to the user fileClientSecret, err := ioutil.ReadFile(p.ClientSecretFile) if err != nil { - logger.Printf("error reading client secret file %s: %s", p.ClientSecretFile, err) + logger.Errorf("error reading client secret file %s: %s", p.ClientSecretFile, err) return "", errors.New("could not read client secret file") } return string(fileClientSecret), nil diff --git a/validator.go b/validator.go index 9db34a27..e02a2536 100644 --- a/validator.go +++ b/validator.go @@ -62,7 +62,7 @@ func (um *UserMap) LoadAuthenticatedEmailsFile() { csvReader.TrimLeadingSpace = true records, err := csvReader.ReadAll() if err != nil { - logger.Printf("error reading authenticated-emails-file=%q, %s", um.usersFile, err) + logger.Errorf("error reading authenticated-emails-file=%q, %s", um.usersFile, err) return } updated := make(map[string]bool) diff --git a/watcher.go b/watcher.go index b71b8035..642cb36d 100644 --- a/watcher.go +++ b/watcher.go @@ -69,7 +69,7 @@ func WatchForUpdates(filename string, done <-chan bool, action func()) { logger.Printf("reloading after event: %s", event) action() case err = <-watcher.Errors: - logger.Printf("error watching %s: %s", filename, err) + logger.Errorf("error watching %s: %s", filename, err) } } }() diff --git a/watcher_unsupported.go b/watcher_unsupported.go index 09c56468..986cc462 100644 --- a/watcher_unsupported.go +++ b/watcher_unsupported.go @@ -5,6 +5,6 @@ package main import "github.com/oauth2-proxy/oauth2-proxy/pkg/logger" func WatchForUpdates(filename string, done <-chan bool, action func()) { - logger.Printf("file watching not implemented on this platform") + logger.Errorf("file watching not implemented on this platform") go func() { <-done }() }