From 24e6807939c23b40c68fc7b3fd85e7f3df6e71bc Mon Sep 17 00:00:00 2001
From: Rohith <gambol99@gmail.com>
Date: Sun, 11 Jun 2017 19:02:13 +0100
Subject: [PATCH] Zap Logging
- removing the github.com/Sirupsen/logrus logger and replacing zap
---
doc.go | 3 +
forwarding.go | 91 +++++++---------
handlers.go | 84 +++++++--------
middleware.go | 158 +++++++++++++--------------
middleware_test.go | 6 +-
misc.go | 11 +-
rotation.go | 27 ++---
rotation_test.go | 7 +-
server.go | 259 ++++++++++++++++++++++++++++-----------------
server_test.go | 6 +-
session.go | 13 ++-
store_boltdb.go | 17 ---
store_redis.go | 17 ---
stores.go | 6 +-
utils.go | 64 -----------
utils_test.go | 9 --
16 files changed, 353 insertions(+), 425 deletions(-)
diff --git a/doc.go b/doc.go
index f6abfcc..d7c9d90 100644
--- a/doc.go
+++ b/doc.go
@@ -236,6 +236,9 @@ type Config struct {
ForwardingPassword string `json:"forwarding-password" yaml:"forwarding-password" usage:"password to use when logging into the openid provider"`
// ForwardingDomains is a collection of domains to signs
ForwardingDomains []string `json:"forwarding-domains" yaml:"forwarding-domains" usage:"list of domains which should be signed; everything else is relayed unsigned"`
+
+ // DisableAllLogging indicates no logging at all
+ DisableAllLogging bool `json:"disable-all-logging" yaml:"disable-all-logging" usage:"disables all logging to stdout and stderr"`
}
// getVersion returns the proxy version
diff --git a/forwarding.go b/forwarding.go
index 296d900..43f1741 100644
--- a/forwarding.go
+++ b/forwarding.go
@@ -20,10 +20,10 @@ import (
"net/http"
"time"
- log "github.com/Sirupsen/logrus"
"github.com/gambol99/go-oidc/jose"
"github.com/gambol99/go-oidc/oidc"
"github.com/labstack/echo"
+ "go.uber.org/zap"
)
// proxyMiddleware is responsible for handles reverse proxy request to the upstream endpoint
@@ -39,9 +39,9 @@ func (r *oauthProxy) proxyMiddleware() echo.MiddlewareFunc {
// step: is this connection upgrading?
if isUpgradedConnection(cx.Request()) {
- log.Debugf("upgrading the connnection to %s", cx.Request().Header.Get(headerUpgrade))
+ r.log.Debug("upgrading the connnection", zap.String("client_ip", cx.RealIP()))
if err := tryUpdateConnection(cx.Request(), cx.Response().Writer, r.endpoint); err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("failed to upgrade the connection")
+ r.log.Error("failed to upgrade connection", zap.Error(err))
cx.NoContent(http.StatusInternalServerError)
return nil
}
@@ -73,9 +73,7 @@ func (r *oauthProxy) forwardProxyHandler() func(*http.Request, *http.Response) {
// step: create oauth client
client, err := r.client.OAuthClient()
if err != nil {
- log.WithFields(log.Fields{
- "error": err.Error(),
- }).Fatal("failed to create an oauth client")
+ r.log.Fatal("failed to create oauth client", zap.Error(err))
}
// step: the loop state
@@ -102,17 +100,13 @@ func (r *oauthProxy) forwardProxyHandler() func(*http.Request, *http.Response) {
// step: do we have a access token
if state.login {
- log.WithFields(log.Fields{
- "username": r.config.ForwardingUsername,
- }).Infof("requesting access token for user")
+ r.log.Info("requesting access token for user",
+ zap.String("username", r.config.ForwardingUsername))
// step: login into the service
resp, err := client.UserCredsToken(r.config.ForwardingUsername, r.config.ForwardingPassword)
if err != nil {
- log.WithFields(log.Fields{
- "error": err.Error(),
- }).Error("failed to login to authentication service")
-
+ r.log.Error("failed to login to authentication service", zap.Error(err))
// step: back-off and reschedule
<-time.After(time.Duration(5) * time.Second)
continue
@@ -121,10 +115,7 @@ func (r *oauthProxy) forwardProxyHandler() func(*http.Request, *http.Response) {
// step: parse the token
token, identity, err := parseToken(resp.AccessToken)
if err != nil {
- log.WithFields(log.Fields{
- "error": err.Error(),
- }).Errorf("failed to parse the access token")
-
+ r.log.Error("failed to parse the access token", zap.Error(err))
// step: we should probably hope and reschedule here
<-time.After(time.Duration(5) * time.Second)
continue
@@ -138,25 +129,22 @@ func (r *oauthProxy) forwardProxyHandler() func(*http.Request, *http.Response) {
state.login = false
state.refresh = resp.RefreshToken
- log.WithFields(log.Fields{
- "subject": state.identity.ID,
- "email": state.identity.Email,
- "expires": state.expiration.Format(time.RFC3339),
- }).Infof("successfully retrieved access token for subject")
+ r.log.Info("successfully retrieved access token for subject",
+ zap.String("subject", state.identity.ID),
+ zap.String("email", state.identity.Email),
+ zap.String("expires", state.expiration.Format(time.RFC3339)))
} else {
- log.WithFields(log.Fields{
- "subject": state.identity.ID,
- "email": state.identity.Email,
- }).Infof("access token is about to expiry")
+ r.log.Info("access token is about to expiry",
+ zap.String("subject", state.identity.ID),
+ zap.String("email", state.identity.Email))
// step: if we a have a refresh token, we need to login again
if state.refresh != "" {
- log.WithFields(log.Fields{
- "subject": state.identity.ID,
- "email": state.identity.Email,
- "expires": state.expiration.Format(time.RFC3339),
- }).Infof("attempting to refresh the access token")
+ r.log.Info("attempting to refresh the access token",
+ zap.String("subject", state.identity.ID),
+ zap.String("email", state.identity.Email),
+ zap.String("expires", state.expiration.Format(time.RFC3339)))
// step: attempt to refresh the access
token, expiration, err := getRefreshedToken(r.client, state.refresh)
@@ -164,14 +152,11 @@ func (r *oauthProxy) forwardProxyHandler() func(*http.Request, *http.Response) {
state.login = true
switch err {
case ErrRefreshTokenExpired:
- log.WithFields(log.Fields{
- "subject": state.identity.ID,
- "email": state.identity.Email,
- }).Warningf("the refresh token has expired, need to login again")
+ r.log.Warn("the refresh token has expired, need to login again",
+ zap.String("subject", state.identity.ID),
+ zap.String("email", state.identity.Email))
default:
- log.WithFields(log.Fields{
- "error": err.Error(),
- }).Errorf("failed to refresh the access token")
+ r.log.Error("failed to refresh the access token", zap.Error(err))
}
continue
}
@@ -183,33 +168,29 @@ func (r *oauthProxy) forwardProxyHandler() func(*http.Request, *http.Response) {
state.login = false
// step: add some debugging
- log.WithFields(log.Fields{
- "subject": state.identity.ID,
- "email": state.identity.Email,
- "expires": state.expiration.Format(time.RFC3339),
- }).Infof("successfully refreshed the access token")
+ r.log.Info("successfully refreshed the access token",
+ zap.String("subject", state.identity.ID),
+ zap.String("email", state.identity.Email),
+ zap.String("expires", state.expiration.Format(time.RFC3339)))
} else {
- log.WithFields(log.Fields{
- "subject": state.identity.ID,
- "email": state.identity.Email,
- }).Infof("session does not support refresh token, acquiring new token")
+ r.log.Info("session does not support refresh token, acquiring new token",
+ zap.String("subject", state.identity.ID),
+ zap.String("email", state.identity.Email))
- // step: we don't have a refresh token, we must perform a login again
+ // we don't have a refresh token, we must perform a login again
state.wait = false
state.login = true
}
}
- // step: wait for an expiration to come close
+ // wait for an expiration to come close
if state.wait {
- // step: set the expiration of the access token within a random 85% of actual expiration
+ // set the expiration of the access token within a random 85% of actual expiration
duration := getWithin(state.expiration, 0.85)
-
- log.WithFields(log.Fields{
- "token_expiration": state.expiration.Format(time.RFC3339),
- "renewel_duration": duration.String(),
- }).Infof("waiting for expiration of access token")
+ r.log.Info("waiting for expiration of access token",
+ zap.String("token_expiration", state.expiration.Format(time.RFC3339)),
+ zap.String("renewel_duration", duration.String()))
<-time.After(duration)
}
diff --git a/handlers.go b/handlers.go
index 9a5ef1e..297920c 100644
--- a/handlers.go
+++ b/handlers.go
@@ -29,9 +29,9 @@ import (
"strings"
"time"
- log "github.com/Sirupsen/logrus"
"github.com/gambol99/go-oidc/oauth2"
"github.com/labstack/echo"
+ "go.uber.org/zap"
)
// getRedirectionURL returns the redirectionURL for the oauth flow
@@ -78,7 +78,7 @@ func (r *oauthProxy) oauthHandler(cx echo.Context) error {
return r.tokenHandler(cx)
case metricsURL:
if r.config.EnableMetrics {
- return r.metricsHandler(cx)
+ return r.proxyMetricsHandler(cx)
}
default:
return cx.NoContent(http.StatusNotFound)
@@ -104,10 +104,7 @@ func (r *oauthProxy) oauthAuthorizationHandler(cx echo.Context) error {
}
client, err := r.getOAuthClient(r.getRedirectionURL(cx))
if err != nil {
- log.WithFields(log.Fields{
- "error": err.Error(),
- }).Errorf("failed to retrieve the oauth client for authorization")
-
+ r.log.Error("failed to retrieve the oauth client for authorization", zap.String("error", err.Error()))
return cx.NoContent(http.StatusInternalServerError)
}
@@ -118,11 +115,10 @@ func (r *oauthProxy) oauthAuthorizationHandler(cx echo.Context) error {
}
authURL := client.AuthCodeURL(cx.QueryParam("state"), accessType, "")
- log.WithFields(log.Fields{
- "access_type": accessType,
- "auth-url": authURL,
- "client_ip": cx.RealIP(),
- }).Debugf("incoming authorization request from client address: %s", cx.RealIP())
+ r.log.Debug("incoming authorization request from client address",
+ zap.String("access_type", accessType),
+ zap.String("auth_url", authURL),
+ zap.String("client_ip", cx.RealIP()))
// step: if we have a custom sign in page, lets display that
if r.config.hasCustomSignInPage() {
@@ -148,13 +144,13 @@ func (r *oauthProxy) oauthCallbackHandler(cx echo.Context) error {
client, err := r.getOAuthClient(r.getRedirectionURL(cx))
if err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("unable to create a oauth2 client")
+ r.log.Error("unable to create a oauth2 client", zap.String("error", err.Error()))
return cx.NoContent(http.StatusInternalServerError)
}
resp, err := exchangeAuthenticationCode(client, code)
if err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("unable to exchange code for access token")
+ r.log.Error("unable to exchange code for access token", zap.String("error", err.Error()))
return r.accessForbidden(cx)
}
@@ -163,7 +159,7 @@ func (r *oauthProxy) oauthCallbackHandler(cx echo.Context) error {
// to the ID Token.
token, identity, err := parseToken(resp.IDToken)
if err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("unable to parse id token for identity")
+ r.log.Error("unable to parse id token for identity", zap.String("error", err.Error()))
return r.accessForbidden(cx)
}
access, id, err := parseToken(resp.AccessToken)
@@ -171,12 +167,12 @@ func (r *oauthProxy) oauthCallbackHandler(cx echo.Context) error {
token = access
identity = id
} else {
- log.WithFields(log.Fields{"error": err.Error()}).Warn("unable to parse the access token, using id token only")
+ r.log.Warn("unable to parse the access token, using id token only", zap.String("error", err.Error()))
}
// step: check the access token is valid
if err = verifyToken(r.client, token); err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("unable to verify the id token")
+ r.log.Error("unable to verify the id token", zap.String("error", err.Error()))
return r.accessForbidden(cx)
}
accessToken := token.Encode()
@@ -184,23 +180,22 @@ func (r *oauthProxy) oauthCallbackHandler(cx echo.Context) error {
// step: are we encrypting the access token?
if r.config.EnableEncryptedToken {
if accessToken, err = encodeText(accessToken, r.config.EncryptionKey); err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Error("unable to encode the access token")
+ r.log.Error("unable to encode the access token", zap.String("error", err.Error()))
return cx.NoContent(http.StatusInternalServerError)
}
}
- log.WithFields(log.Fields{
- "email": identity.Email,
- "expires": identity.ExpiresAt.Format(time.RFC3339),
- "duration": time.Until(identity.ExpiresAt).String(),
- }).Info("issuing access token for user")
+ r.log.Info("issuing access token for user",
+ zap.String("email", identity.Email),
+ zap.String("expires", identity.ExpiresAt.Format(time.RFC3339)),
+ zap.String("duration", time.Until(identity.ExpiresAt).String()))
// step: does the response has a refresh token and we are NOT ignore refresh tokens?
if r.config.EnableRefreshTokens && resp.RefreshToken != "" {
var encrypted string
encrypted, err = encodeText(resp.RefreshToken, r.config.EncryptionKey)
if err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("failed to encrypt the refresh token")
+ r.log.Error("failed to encrypt the refresh token", zap.String("error", err.Error()))
return cx.NoContent(http.StatusInternalServerError)
}
// drop in the access token - cookie expiration = access token
@@ -209,7 +204,7 @@ func (r *oauthProxy) oauthCallbackHandler(cx echo.Context) error {
switch r.useStore() {
case true:
if err = r.StoreRefreshToken(token, encrypted); err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Warnf("failed to save the refresh token in the store")
+ r.log.Warn("failed to save the refresh token in the store", zap.String("error", err.Error()))
}
default:
// notes: not all idp refresh tokens are readable, google for example, so we attempt to decode into
@@ -229,10 +224,9 @@ func (r *oauthProxy) oauthCallbackHandler(cx echo.Context) error {
if cx.QueryParam("state") != "" {
decoded, err := base64.StdEncoding.DecodeString(cx.QueryParam("state"))
if err != nil {
- log.WithFields(log.Fields{
- "state": cx.QueryParam("state"),
- "error": err.Error(),
- }).Warnf("unable to decode the state parameter")
+ r.log.Warn("unable to decode the state parameter",
+ zap.String("state", cx.QueryParam("state")),
+ zap.String("error", err.Error()))
} else {
state = string(decoded)
}
@@ -284,10 +278,9 @@ func (r *oauthProxy) loginHandler(cx echo.Context) error {
return "", http.StatusOK, nil
}()
if err != nil {
- log.WithFields(log.Fields{
- "client_ip": cx.RealIP(),
- "error": err.Error,
- }).Errorf(errorMsg)
+ r.log.Error(errorMsg,
+ zap.String("client_ip", cx.RealIP()),
+ zap.String("error", err.Error()))
return cx.NoContent(code)
}
@@ -324,9 +317,7 @@ func (r *oauthProxy) logoutHandler(cx echo.Context) error {
if r.useStore() {
go func() {
if err := r.DeleteRefreshToken(user.token); err != nil {
- log.WithFields(log.Fields{
- "error": err.Error(),
- }).Errorf("unable to remove the refresh token from store")
+ r.log.Error("unable to remove the refresh token from store", zap.String("error", err.Error()))
}
}()
}
@@ -336,7 +327,7 @@ func (r *oauthProxy) logoutHandler(cx echo.Context) error {
if revocationURL != "" {
client, err := r.client.OAuthClient()
if err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("unable to retrieve the openid client")
+ r.log.Error("unable to retrieve the openid client", zap.String("error", err.Error()))
return cx.NoContent(http.StatusInternalServerError)
}
@@ -349,7 +340,7 @@ func (r *oauthProxy) logoutHandler(cx echo.Context) error {
request, err := http.NewRequest(http.MethodPost, revocationURL,
bytes.NewBufferString(fmt.Sprintf("refresh_token=%s", identityToken)))
if err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("unable to construct the revocation request")
+ r.log.Error("unable to construct the revocation request", zap.String("error", err.Error()))
return cx.NoContent(http.StatusInternalServerError)
}
// step: add the authentication headers and content-type
@@ -358,22 +349,19 @@ func (r *oauthProxy) logoutHandler(cx echo.Context) error {
response, err := client.HttpClient().Do(request)
if err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("unable to post to revocation endpoint")
+ r.log.Error("unable to post to revocation endpoint", zap.String("error", err.Error()))
return nil
}
// step: check the response
switch response.StatusCode {
case http.StatusNoContent:
- log.WithFields(log.Fields{
- "user": user.email,
- }).Infof("successfully logged out of the endpoint")
+ r.log.Info("successfully logged out of the endpoint", zap.String("email", user.email))
default:
content, _ := ioutil.ReadAll(response.Body)
- log.WithFields(log.Fields{
- "status": response.StatusCode,
- "response": fmt.Sprintf("%s", content),
- }).Errorf("invalid response from revocation endpoint")
+ r.log.Error("invalid response from revocation endpoint",
+ zap.Int("status", response.StatusCode),
+ zap.String("response", fmt.Sprintf("%s", content)))
}
}
// step: should we redirect the user
@@ -452,14 +440,14 @@ func (r *oauthProxy) debugHandler(cx echo.Context) error {
return nil
}
-// metricsHandler forwards the request into the prometheus handler
-func (r *oauthProxy) metricsHandler(cx echo.Context) error {
+// proxyMetricsHandler forwards the request into the prometheus handler
+func (r *oauthProxy) proxyMetricsHandler(cx echo.Context) error {
if r.config.LocalhostMetrics {
if !net.ParseIP(cx.RealIP()).IsLoopback() {
return r.accessForbidden(cx)
}
}
- r.prometheusHandler.ServeHTTP(cx.Response().Writer, cx.Request())
+ r.metricsHandler.ServeHTTP(cx.Response().Writer, cx.Request())
return nil
}
diff --git a/middleware.go b/middleware.go
index 309ab6a..3299c0c 100644
--- a/middleware.go
+++ b/middleware.go
@@ -23,11 +23,11 @@ import (
"time"
"github.com/PuerkitoBio/purell"
- log "github.com/Sirupsen/logrus"
"github.com/gambol99/go-oidc/jose"
"github.com/labstack/echo"
"github.com/prometheus/client_golang/prometheus"
"github.com/unrolled/secure"
+ "go.uber.org/zap"
)
const normalizeFlags purell.NormalizationFlags = purell.FlagRemoveDotSegments | purell.FlagRemoveDuplicateSlashes
@@ -76,14 +76,16 @@ func (r *oauthProxy) loggingMiddleware() echo.MiddlewareFunc {
next(cx)
latency := time.Since(start)
addr := cx.RealIP()
- log.WithFields(log.Fields{
- "client_ip": addr,
- "method": cx.Request().Method,
- "status": cx.Response().Status,
- "bytes": cx.Response().Size,
- "path": cx.Request().URL.Path,
- "latency": latency.String(),
- }).Infof("[%d] |%s| |%10v| %-5s %s", cx.Response().Status, addr, latency, cx.Request().Method, cx.Request().URL.Path)
+ //msg := .Infof("[%d] |%s| |%10v| %-5s %s", cx.Response().Status, addr, latency, cx.Request().Method, cx.Request().URL.Path)
+ r.log.Info("client request",
+ zap.Int("response", cx.Response().Status),
+ zap.String("path", cx.Request().URL.Path),
+ zap.String("client_ip", addr),
+ zap.String("method", cx.Request().Method),
+ zap.Int("status", cx.Response().Status),
+ zap.Int64("bytes", cx.Response().Size),
+ zap.String("path", cx.Request().URL.Path),
+ zap.String("latency", latency.String()))
return nil
}
@@ -92,7 +94,8 @@ func (r *oauthProxy) loggingMiddleware() echo.MiddlewareFunc {
// metricsMiddleware is responsible for collecting metrics
func (r *oauthProxy) metricsMiddleware() echo.MiddlewareFunc {
- log.Infof("enabled the service metrics middleware, available on %s%s", oauthURL, metricsURL)
+ r.log.Info("enabled the service metrics middleware, available on",
+ zap.String("path", fmt.Sprintf("%s%s", oauthURL, metricsURL)))
statusMetrics := prometheus.NewCounterVec(
prometheus.CounterOpts{
@@ -120,20 +123,19 @@ func (r *oauthProxy) authenticationMiddleware(resource *Resource) echo.Middlewar
// step: grab the user identity from the request
user, err := r.getIdentity(cx.Request())
if err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("no session found in request, redirecting for authorization")
+ r.log.Error("no session found in request, redirecting for authorization", zap.Error(err))
return r.redirectToAuthorization(cx)
}
cx.Set(userContextName, user)
// step: skip if we are running skip-token-verification
if r.config.SkipTokenVerification {
- log.Warnf("skip token verification enabled, skipping verification - TESTING ONLY")
+ r.log.Warn("skip token verification enabled, skipping verification - TESTING ONLY")
if user.isExpired() {
- log.WithFields(log.Fields{
- "client_ip": clientIP,
- "username": user.name,
- "expired_on": user.expiresAt.String(),
- }).Errorf("the session has expired and verification switch off")
+ r.log.Error("the session has expired and verification switch off",
+ zap.String("client_ip", clientIP),
+ zap.String("username", user.name),
+ zap.String("expired_on", user.expiresAt.String()))
return r.redirectToAuthorization(cx)
}
} else {
@@ -142,36 +144,32 @@ func (r *oauthProxy) authenticationMiddleware(resource *Resource) echo.Middlewar
// expired error we immediately throw an access forbidden - as there is
// something messed up in the token
if err != ErrAccessTokenExpired {
- log.WithFields(log.Fields{
- "client_ip": clientIP,
- "error": err.Error(),
- }).Errorf("access token failed verification")
+ r.log.Error("access token failed verification",
+ zap.String("client_ip", clientIP),
+ zap.Error(err))
return r.accessForbidden(cx)
}
// step: check if we are refreshing the access tokens and if not re-auth
if !r.config.EnableRefreshTokens {
- log.WithFields(log.Fields{
- "client_ip": clientIP,
- "email": user.name,
- "expired_on": user.expiresAt.String(),
- }).Errorf("session expired and access token refreshing is disabled")
+ r.log.Error("session expired and access token refreshing is disabled",
+ zap.String("client_ip", clientIP),
+ zap.String("email", user.name),
+ zap.String("expired_on", user.expiresAt.String()))
return r.redirectToAuthorization(cx)
}
- log.WithFields(log.Fields{
- "client_ip": clientIP,
- "email": user.email,
- }).Infof("accces token for user has expired, attemping to refresh the token")
+ r.log.Info("accces token for user has expired, attemping to refresh the token",
+ zap.String("client_ip", clientIP),
+ zap.String("email", user.email))
// step: check if the user has refresh token
refresh, encrypted, err := r.retrieveRefreshToken(cx.Request(), user)
if err != nil {
- log.WithFields(log.Fields{
- "client_ip": clientIP,
- "email": user.email,
- "error": err.Error(),
- }).Errorf("unable to find a refresh token for user")
+ r.log.Error("unable to find a refresh token for user",
+ zap.String("client_ip", clientIP),
+ zap.String("email", user.email),
+ zap.Error(err))
return r.redirectToAuthorization(cx)
}
@@ -180,31 +178,29 @@ func (r *oauthProxy) authenticationMiddleware(resource *Resource) echo.Middlewar
if err != nil {
switch err {
case ErrRefreshTokenExpired:
- log.WithFields(log.Fields{
- "client_ip": clientIP,
- "email": user.email,
- }).Warningf("refresh token has expired, cannot retrieve access token")
+ r.log.Warn("refresh token has expired, cannot retrieve access token",
+ zap.String("client_ip", clientIP),
+ zap.String("email", user.email))
r.clearAllCookies(cx.Request(), cx.Response().Writer)
default:
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("failed to refresh the access token")
+ r.log.Error("failed to refresh the access token", zap.Error(err))
}
return r.redirectToAuthorization(cx)
}
// get the expiration of the new access token
expiresIn := r.getAccessCookieExpiration(token, refresh)
- log.WithFields(log.Fields{
- "client_ip": clientIP,
- "cookie_name": r.config.CookieAccessName,
- "email": user.email,
- "expires_in": time.Until(exp),
- }).Infof("injecting the refreshed access token cookie")
+ r.log.Info("injecting the refreshed access token cookie",
+ zap.String("client_ip", clientIP),
+ zap.String("cookie_name", r.config.CookieAccessName),
+ zap.String("email", user.email),
+ zap.Duration("expires_in", time.Until(exp)))
accessToken := token.Encode()
if r.config.EnableEncryptedToken {
if accessToken, err = encodeText(accessToken, r.config.EncryptionKey); err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Error("unable to encode the access token")
+ r.log.Error("unable to encode the access token", zap.Error(err))
return cx.NoContent(http.StatusInternalServerError)
}
}
@@ -214,10 +210,10 @@ func (r *oauthProxy) authenticationMiddleware(resource *Resource) echo.Middlewar
if r.useStore() {
go func(old, new jose.JWT, encrypted string) {
if err := r.DeleteRefreshToken(old); err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("failed to remove old token")
+ r.log.Error("failed to remove old token", zap.Error(err))
}
if err := r.StoreRefreshToken(new, encrypted); err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("failed to store refresh token")
+ r.log.Error("failed to store refresh token", zap.Error(err))
return
}
}(user.token, token, encrypted)
@@ -249,12 +245,11 @@ func (r *oauthProxy) admissionMiddleware(resource *Resource) echo.MiddlewareFunc
// step: we need to check the roles
if roles := len(resource.Roles); roles > 0 {
if !hasRoles(resource.Roles, user.roles) {
- log.WithFields(log.Fields{
- "access": "denied",
- "email": user.email,
- "resource": resource.URL,
- "required": resource.getRoles(),
- }).Warnf("access denied, invalid roles")
+ r.log.Warn("access denied, invalid roles",
+ zap.String("access", "denied"),
+ zap.String("email", user.email),
+ zap.String("resource", resource.URL),
+ zap.String("required", resource.getRoles()))
return r.accessForbidden(cx)
}
@@ -265,49 +260,44 @@ func (r *oauthProxy) admissionMiddleware(resource *Resource) echo.MiddlewareFunc
// step: if the claim is NOT in the token, we access deny
value, found, err := user.claims.StringClaim(claimName)
if err != nil {
- log.WithFields(log.Fields{
- "access": "denied",
- "email": user.email,
- "resource": resource.URL,
- "error": err.Error(),
- }).Errorf("unable to extract the claim from token")
+ r.log.Error("unable to extract the claim from token",
+ zap.String("access", "denied"),
+ zap.String("email", user.email),
+ zap.String("resource", resource.URL),
+ zap.Error(err))
return r.accessForbidden(cx)
}
if !found {
- log.WithFields(log.Fields{
- "access": "denied",
- "claim": claimName,
- "email": user.email,
- "resource": resource.URL,
- }).Warnf("the token does not have the claim")
+ r.log.Warn("the token does not have the claim",
+ zap.String("access", "denied"),
+ zap.String("claim", claimName),
+ zap.String("email", user.email),
+ zap.String("resource", resource.URL))
return r.accessForbidden(cx)
}
// step: check the claim is the same
if !match.MatchString(value) {
- log.WithFields(log.Fields{
- "access": "denied",
- "claim": claimName,
- "email": user.email,
- "issued": value,
- "required": match,
- "resource": resource.URL,
- }).Warnf("the token claims does not match claim requirement")
+ r.log.Warn("the token claims does not match claim requirement",
+ zap.String("access", "denied"),
+ zap.String("claim", claimName),
+ zap.String("email", user.email),
+ zap.String("issued", value),
+ zap.String("required", match.String()),
+ zap.String("resource", resource.URL))
return r.accessForbidden(cx)
}
}
- log.WithFields(log.Fields{
- "access": "permitted",
- "client": user.audience,
- "email": user.email,
- "expires": time.Until(user.expiresAt).String(),
- "resource": resource.URL,
- }).Debugf("access permitted to resource")
+ r.log.Debug("access permitted to resource",
+ zap.String("access", "permitted"),
+ zap.String("email", user.email),
+ zap.Duration("expires", time.Until(user.expiresAt)),
+ zap.String("resource", resource.URL))
return next(cx)
}
@@ -351,7 +341,7 @@ func (r *oauthProxy) headersMiddleware(custom []string) echo.MiddlewareFunc {
// securityMiddleware performs numerous security checks on the request
func (r *oauthProxy) securityMiddleware() echo.MiddlewareFunc {
- log.Info("enabling the security filter middleware")
+ r.log.Info("enabling the security filter middleware")
secure := secure.New(secure.Options{
AllowedHosts: r.config.Hostnames,
BrowserXssFilter: r.config.EnableBrowserXSSFilter,
@@ -364,7 +354,7 @@ func (r *oauthProxy) securityMiddleware() echo.MiddlewareFunc {
return func(next echo.HandlerFunc) echo.HandlerFunc {
return func(cx echo.Context) error {
if err := secure.Process(cx.Response().Writer, cx.Request()); err != nil {
- log.WithFields(log.Fields{"error": err.Error()}).Errorf("failed security middleware")
+ r.log.Error("failed security middleware", zap.Error(err))
return r.accessForbidden(cx)
}
return next(cx)
diff --git a/middleware_test.go b/middleware_test.go
index 553c87a..2c1012f 100644
--- a/middleware_test.go
+++ b/middleware_test.go
@@ -18,17 +18,18 @@ package main
import (
"fmt"
"io/ioutil"
+ "log"
"net"
"net/http"
"strings"
"testing"
"time"
- log "github.com/Sirupsen/logrus"
"github.com/gambol99/go-oidc/jose"
"github.com/go-resty/resty"
"github.com/labstack/echo/middleware"
"github.com/stretchr/testify/assert"
+ "go.uber.org/zap"
)
type fakeRequest struct {
@@ -83,13 +84,14 @@ func newFakeProxy(c *Config) *fakeProxy {
if err != nil {
panic("failed to create fake proxy service, error: " + err.Error())
}
+ proxy.log = zap.NewNop()
proxy.upstream = &fakeUpstreamService{}
if err = proxy.Run(); err != nil {
panic("failed to create the proxy service, error: " + err.Error())
}
c.RedirectionURL = fmt.Sprintf("http://%s", proxy.listener.Addr().String())
// step: we need to update the client configs
- if proxy.client, proxy.idp, proxy.idpClient, err = newOpenIDClient(c); err != nil {
+ if proxy.client, proxy.idp, proxy.idpClient, err = proxy.newOpenIDClient(); err != nil {
panic("failed to recreate the openid client, error: " + err.Error())
}
diff --git a/misc.go b/misc.go
index 82d9c06..b0541fa 100644
--- a/misc.go
+++ b/misc.go
@@ -22,9 +22,9 @@ import (
"path"
"time"
- log "github.com/Sirupsen/logrus"
"github.com/gambol99/go-oidc/jose"
"github.com/labstack/echo"
+ "go.uber.org/zap"
)
// revokeProxy is responsible to stopping the middleware from proxying the request
@@ -40,10 +40,9 @@ func (r *oauthProxy) accessForbidden(cx echo.Context) error {
tplName := path.Base(r.config.ForbiddenPage)
err := cx.Render(http.StatusForbidden, tplName, r.config.Tags)
if err != nil {
- log.WithFields(log.Fields{
- "error": err,
- "template": tplName,
- }).Error("unable to render the template")
+ r.log.Error("unable to render the template",
+ zap.Error(err),
+ zap.String("template", tplName))
}
return err
@@ -71,7 +70,7 @@ func (r *oauthProxy) redirectToAuthorization(cx echo.Context) error {
// step: if verification is switched off, we can't authorization
if r.config.SkipTokenVerification {
- log.Errorf("refusing to redirection to authorization endpoint, skip token verification switched on")
+ r.log.Error("refusing to redirection to authorization endpoint, skip token verification switched on")
return cx.NoContent(http.StatusForbidden)
}
diff --git a/rotation.go b/rotation.go
index 1c623f4..3d8479e 100644
--- a/rotation.go
+++ b/rotation.go
@@ -21,8 +21,8 @@ import (
"path"
"sync"
- log "github.com/Sirupsen/logrus"
"github.com/fsnotify/fsnotify"
+ "go.uber.org/zap"
)
type certificationRotation struct {
@@ -33,10 +33,12 @@ type certificationRotation struct {
certificateFile string
// the privateKeyFile is the path of the private key
privateKeyFile string
+ // the logger for this service
+ log *zap.Logger
}
// newCertificateRotator creates a new certificate
-func newCertificateRotator(cert, key string) (*certificationRotation, error) {
+func newCertificateRotator(cert, key string, log *zap.Logger) (*certificationRotation, error) {
// step: attempt to load the certificate
certificate, err := tls.LoadX509KeyPair(cert, key)
if err != nil {
@@ -46,13 +48,17 @@ func newCertificateRotator(cert, key string) (*certificationRotation, error) {
return &certificationRotation{
certificate: certificate,
certificateFile: cert,
+ log: log,
privateKeyFile: key,
}, nil
}
// watch is responsible for adding a file notification and watch on the files for changes
func (c *certificationRotation) watch() error {
- log.Infof("adding a file watch on the certificates, certificate: %s, key: %s", c.certificateFile, c.privateKeyFile)
+ c.log.Info("adding a file watch on the certificates, certificate",
+ zap.String("certificate", c.certificateFile),
+ zap.String("private_key", c.privateKeyFile))
+
watcher, err := fsnotify.NewWatcher()
if err != nil {
return err
@@ -67,7 +73,7 @@ func (c *certificationRotation) watch() error {
// step: watching for events
filewatchPaths := []string{c.certificateFile, c.privateKeyFile}
go func() {
- log.Info("starting to watch changes to the tls certificate files")
+ c.log.Info("starting to watch changes to the tls certificate files")
for {
select {
case event := <-watcher.Events:
@@ -79,20 +85,17 @@ func (c *certificationRotation) watch() error {
// step: reload the certificate
certificate, err := tls.LoadX509KeyPair(c.certificateFile, c.privateKeyFile)
if err != nil {
- log.WithFields(log.Fields{
- "filename": event.Name,
- "error": err.Error(),
- }).Error("unable to load the updated certificate")
+ c.log.Error("unable to load the updated certificate",
+ zap.String("filename", event.Name),
+ zap.Error(err))
}
// step: load the new certificate
c.storeCertificate(certificate)
// step: print a debug message for us
- log.Infof("replacing the server certifacte with updated version")
+ c.log.Info("replacing the server certifacte with updated version")
}
case err := <-watcher.Errors:
- log.WithFields(log.Fields{
- "error": err.Error(),
- }).Error("recieved an error from the file watcher")
+ c.log.Error("recieved an error from the file watcher", zap.Error(err))
}
}
}()
diff --git a/rotation_test.go b/rotation_test.go
index b67515a..01f96af 100644
--- a/rotation_test.go
+++ b/rotation_test.go
@@ -20,6 +20,7 @@ import (
"testing"
"github.com/stretchr/testify/assert"
+ "go.uber.org/zap"
)
const (
@@ -28,7 +29,7 @@ const (
)
func newTestCertificateRotator(t *testing.T) *certificationRotation {
- c, err := newCertificateRotator(testCertificateFile, testPrivateKeyFile)
+ c, err := newCertificateRotator(testCertificateFile, testPrivateKeyFile, zap.NewNop())
assert.NotNil(t, c)
assert.Equal(t, testCertificateFile, c.certificateFile)
assert.Equal(t, testPrivateKeyFile, c.privateKeyFile)
@@ -40,13 +41,13 @@ func newTestCertificateRotator(t *testing.T) *certificationRotation {
}
func TestNewCeritifacteRotator(t *testing.T) {
- c, err := newCertificateRotator(testCertificateFile, testPrivateKeyFile)
+ c, err := newCertificateRotator(testCertificateFile, testPrivateKeyFile, zap.NewNop())
assert.NotNil(t, c)
assert.NoError(t, err)
}
func TestNewCeritifacteRotatorFailure(t *testing.T) {
- c, err := newCertificateRotator("./tests/does_not_exist", testPrivateKeyFile)
+ c, err := newCertificateRotator("./tests/does_not_exist", testPrivateKeyFile, zap.NewNop())
assert.Nil(t, c)
assert.Error(t, err)
}
diff --git a/server.go b/server.go
index 2c1892d..b8e5a57 100644
--- a/server.go
+++ b/server.go
@@ -18,6 +18,7 @@ package main
import (
"crypto/tls"
"crypto/x509"
+ "errors"
"fmt"
"html/template"
"io"
@@ -32,101 +33,82 @@ import (
httplog "log"
- log "github.com/Sirupsen/logrus"
"github.com/armon/go-proxyproto"
"github.com/gambol99/go-oidc/oidc"
"github.com/gambol99/goproxy"
"github.com/labstack/echo"
"github.com/labstack/echo/middleware"
"github.com/prometheus/client_golang/prometheus"
+ "go.uber.org/zap"
)
type oauthProxy struct {
- // the proxy configuration
- config *Config
- // the http service
- router http.Handler
- // the opened client
- client *oidc.Client
- // the openid provider configuration
- idp oidc.ProviderConfig
- // the provider http client
- idpClient *http.Client
- // the proxy client
- upstream reverseProxy
- // the upstream endpoint url
- endpoint *url.URL
- // the templates for the custom pages
- templates *template.Template
- // the store interface
- store storage
- // the prometheus handler
- prometheusHandler http.Handler
- // the default server
- server *http.Server
- // the default listener
- listener net.Listener
+ client *oidc.Client
+ config *Config
+ endpoint *url.URL
+ idp oidc.ProviderConfig
+ idpClient *http.Client
+ listener net.Listener
+ log *zap.Logger
+ metricsHandler http.Handler
+ router http.Handler
+ server *http.Server
+ store storage
+ templates *template.Template
+ upstream reverseProxy
}
func init() {
- // step: ensure all time is in UTC
- time.LoadLocation("UTC")
- // step: set the core
- runtime.GOMAXPROCS(runtime.NumCPU())
+ time.LoadLocation("UTC") // ensure all time is in UTC
+ runtime.GOMAXPROCS(runtime.NumCPU()) // set the core
}
// newProxy create's a new proxy from configuration
func newProxy(config *Config) (*oauthProxy, error) {
- var err error
- // step: set the logging
- httplog.SetOutput(ioutil.Discard)
- if config.EnableJSONLogging {
- log.SetFormatter(&log.JSONFormatter{})
- }
- if config.Verbose {
- log.SetLevel(log.DebugLevel)
- httplog.SetOutput(os.Stderr)
+ // create the service logger
+ log, err := createLogger(config)
+ if err != nil {
+ return nil, err
}
- log.Infof("starting %s, author: %s, version: %s, ", prog, author, version)
-
+ log.Info("starting the service", zap.String("prog", prog), zap.String("author", author), zap.String("version", version))
svc := &oauthProxy{
- config: config,
- prometheusHandler: prometheus.Handler(),
+ config: config,
+ log: log,
+ metricsHandler: prometheus.Handler(),
}
- // step: parse the upstream endpoint
+ // parse the upstream endpoint
if svc.endpoint, err = url.Parse(config.Upstream); err != nil {
return nil, err
}
- // step: initialize the store if any
+ // initialize the store if any
if config.StoreURL != "" {
if svc.store, err = createStorage(config.StoreURL); err != nil {
return nil, err
}
}
- // step: initialize the openid client
+ // initialize the openid client
if !config.SkipTokenVerification {
- if svc.client, svc.idp, svc.idpClient, err = newOpenIDClient(config); err != nil {
+ if svc.client, svc.idp, svc.idpClient, err = svc.newOpenIDClient(); err != nil {
return nil, err
}
} else {
- log.Warnf("TESTING ONLY CONFIG - the verification of the token have been disabled")
+ log.Warn("TESTING ONLY CONFIG - the verification of the token have been disabled")
}
if config.ClientID == "" && config.ClientSecret == "" {
- log.Warnf("client credentials are not set, depending on provider (confidential|public) you might be unable to auth")
+ log.Warn("client credentials are not set, depending on provider (confidential|public) you might be unable to auth")
}
- // step: are we running in forwarding more?
- switch config.EnableForwarding {
- case true:
+ // are we running in forwarding mode?
+ if config.EnableForwarding {
if err := svc.createForwardingProxy(); err != nil {
return nil, err
}
- default:
+ } else {
if err := svc.createReverseProxy(); err != nil {
return nil, err
}
@@ -135,9 +117,34 @@ func newProxy(config *Config) (*oauthProxy, error) {
return svc, nil
}
+// createLogger is responsible for creating the service logger
+func createLogger(config *Config) (*zap.Logger, error) {
+ httplog.SetOutput(ioutil.Discard) // disable the http logger
+ if config.DisableAllLogging {
+ return zap.NewNop(), nil
+ }
+
+ c := zap.NewProductionConfig()
+ c.DisableStacktrace = true
+ c.DisableCaller = true
+ // are we enabling json logging?
+ if !config.EnableJSONLogging {
+ c.Encoding = "console"
+ }
+ // are we running verbose mode?
+ if config.Verbose {
+ httplog.SetOutput(os.Stderr)
+ c.DisableCaller = false
+ c.Development = true
+ c.Level = zap.NewAtomicLevelAt(zap.DebugLevel)
+ }
+
+ return c.Build()
+}
+
// createReverseProxy creates a reverse proxy
func (r *oauthProxy) createReverseProxy() error {
- log.Infof("enabled reverse proxy mode, upstream url: %s", r.config.Upstream)
+ r.log.Info("enabled reverse proxy mode, upstream url", zap.String("url", r.config.Upstream))
if err := r.createUpstreamProxy(r.endpoint); err != nil {
return err
}
@@ -148,7 +155,7 @@ func (r *oauthProxy) createReverseProxy() error {
engine.Use(middleware.Recover())
if r.config.EnableProfiling {
- log.Warn("enabling the debug profiling on /debug/pprof")
+ r.log.Warn("enabling the debug profiling on /debug/pprof")
engine.Any("/debug/pprof/:name", r.debugHandler)
}
if r.config.EnableLogging {
@@ -182,11 +189,14 @@ func (r *oauthProxy) createReverseProxy() error {
// step: provision in the protected resources
for _, x := range r.config.Resources {
if x.URL[len(x.URL)-1:] == "/" {
- log.Warnf("the resource url: %s is not a prefix, you probably want %s* or %s* to protect the resource", x.URL, x.URL, strings.TrimRight(x.URL, "/"))
+ r.log.Warn("the resource url is not a prefix",
+ zap.String("resource", x.URL),
+ zap.String("change", x.URL),
+ zap.String("ammended", strings.TrimRight(x.URL, "/")))
}
}
for _, x := range r.config.Resources {
- log.Infof("protecting resource: %s", x)
+ r.log.Info("protecting resource", zap.String("resource", x.String()))
switch x.WhiteListed {
case false:
engine.Match(x.Methods, x.URL, emptyHandler, r.authenticationMiddleware(x), r.admissionMiddleware(x), r.headersMiddleware(r.config.AddClaims))
@@ -195,13 +205,13 @@ func (r *oauthProxy) createReverseProxy() error {
}
}
for name, value := range r.config.MatchClaims {
- log.Infof("the token must container the claim: %s, required: %s", name, value)
+ r.log.Info("the token must contain", zap.String("claim", name), zap.String("value", value))
}
if r.config.RedirectionURL == "" {
- log.Warnf("no redirection url has been set, will use host headers")
+ r.log.Warn("no redirection url has been set, will use host headers")
}
if r.config.EnableEncryptedToken {
- log.Info("session access tokens will be encrypted")
+ r.log.Info("session access tokens will be encrypted")
}
engine.Use(r.proxyMiddleware())
@@ -211,10 +221,10 @@ func (r *oauthProxy) createReverseProxy() error {
// createForwardingProxy creates a forwarding proxy
func (r *oauthProxy) createForwardingProxy() error {
- log.Infof("enabling forward signing mode, listening on %s", r.config.Listen)
+ r.log.Info("enabling forward signing mode, listening on", zap.String("interface", r.config.Listen))
if r.config.SkipUpstreamTLSVerify {
- log.Warnf("TLS verification switched off. In forward signing mode it's recommended you verify! (--skip-upstream-tls-verify=false)")
+ r.log.Warn("TLS verification switched off. In forward signing mode it's recommended you verify! (--skip-upstream-tls-verify=false)")
}
if err := r.createUpstreamProxy(nil); err != nil {
return err
@@ -251,15 +261,14 @@ func (r *oauthProxy) createForwardingProxy() error {
if resp != nil && r.config.EnableLogging {
start := ctx.UserData.(time.Time)
latency := time.Since(start)
-
- log.WithFields(log.Fields{
- "method": resp.Request.Method,
- "status": resp.StatusCode,
- "bytes": resp.ContentLength,
- "host": resp.Request.Host,
- "path": resp.Request.URL.Path,
- "latency": latency.String(),
- }).Infof("[%d] |%s| |%10v| %-5s %s", resp.StatusCode, resp.Request.Host, latency, resp.Request.Method, resp.Request.URL.Path)
+ r.log.Info("client request",
+ zap.String("method", resp.Request.Method),
+ zap.String("path", resp.Request.URL.Path),
+ zap.Int("status", resp.StatusCode),
+ zap.Int64("bytes", resp.ContentLength),
+ zap.String("host", resp.Request.Host),
+ zap.String("path", resp.Request.URL.Path),
+ zap.String("latency", latency.String()))
}
return resp
@@ -276,7 +285,7 @@ func (r *oauthProxy) createForwardingProxy() error {
// Run starts the proxy service
func (r *oauthProxy) Run() error {
- listener, err := createHTTPListener(listenerConfig{
+ listener, err := r.createHTTPListener(listenerConfig{
listen: r.config.Listen,
certificate: r.config.TLSCertificate,
privateKey: r.config.TLSPrivateKey,
@@ -296,20 +305,18 @@ func (r *oauthProxy) Run() error {
r.listener = listener
go func() {
- log.Infof("keycloak proxy service starting on %s", r.config.Listen)
+ r.log.Info("keycloak proxy service starting on", zap.String("interface", r.config.Listen))
if err = server.Serve(listener); err != nil {
if err != http.ErrServerClosed {
- log.WithFields(log.Fields{
- "error": err.Error(),
- }).Fatalf("failed to start the http service")
+ r.log.Fatal("failed to start the http service", zap.Error(err))
}
}
}()
// step: are we running http service as well?
if r.config.ListenHTTP != "" {
- log.Infof("keycloak proxy http service starting on %s", r.config.ListenHTTP)
- httpListener, err := createHTTPListener(listenerConfig{
+ r.log.Info("keycloak proxy http service starting on", zap.String("interface", r.config.ListenHTTP))
+ httpListener, err := r.createHTTPListener(listenerConfig{
listen: r.config.ListenHTTP,
proxyProtocol: r.config.EnableProxyProtocol,
})
@@ -322,9 +329,7 @@ func (r *oauthProxy) Run() error {
}
go func() {
if err := httpsvc.Serve(httpListener); err != nil {
- log.WithFields(log.Fields{
- "error": err.Error(),
- }).Fatalf("failed to start the http redirect service")
+ r.log.Fatal("failed to start the http redirect service", zap.Error(err))
}
}()
}
@@ -343,7 +348,7 @@ type listenerConfig struct {
}
// createHTTPListener is responsible for creating a listening socket
-func createHTTPListener(config listenerConfig) (net.Listener, error) {
+func (r *oauthProxy) createHTTPListener(config listenerConfig) (net.Listener, error) {
var listener net.Listener
var err error
@@ -355,7 +360,7 @@ func createHTTPListener(config listenerConfig) (net.Listener, error) {
return nil, err
}
}
- log.Infof("listening on unix socket: %s", config.listen)
+ r.log.Info("listening on unix socket", zap.String("interface", config.listen))
if listener, err = net.Listen("unix", socket); err != nil {
return nil, err
}
@@ -367,15 +372,16 @@ func createHTTPListener(config listenerConfig) (net.Listener, error) {
// step: does it require proxy protocol?
if config.proxyProtocol {
- log.Infof("enabling the proxy protocol on listener: %s", config.listen)
+ r.log.Info("enabling the proxy protocol on listener", zap.String("interface", config.listen))
listener = &proxyproto.Listener{Listener: listener}
}
// step: does the socket require TLS?
if config.certificate != "" && config.privateKey != "" {
- log.Infof("tls enabled, certificate: %s, key: %s", config.certificate, config.privateKey)
+ r.log.Info("tls support enabled",
+ zap.String("certificate", config.certificate), zap.String("private_key", config.privateKey))
// step: creating a certificate rotation
- rotate, err := newCertificateRotator(config.certificate, config.privateKey)
+ rotate, err := newCertificateRotator(config.certificate, config.privateKey, r.log)
if err != nil {
return nil, err
}
@@ -412,9 +418,10 @@ func (r *oauthProxy) createUpstreamProxy(upstream *url.URL) error {
Timeout: r.config.UpstreamTimeout,
}).Dial
- // step: are we using a unix socket?
+ // are we using a unix socket?
if upstream != nil && upstream.Scheme == "unix" {
- log.Infof("using the unix domain socket: %s%s for upstream", upstream.Host, upstream.Path)
+ r.log.Info("using unix socket for upstream", zap.String("socket", fmt.Sprintf("%s%s", upstream.Host, upstream.Path)))
+
socketPath := fmt.Sprintf("%s%s", upstream.Host, upstream.Path)
dialer = func(network, address string) (net.Conn, error) {
return net.Dial("unix", socketPath)
@@ -424,18 +431,19 @@ func (r *oauthProxy) createUpstreamProxy(upstream *url.URL) error {
upstream.Scheme = "http"
}
- // step: create the upstream tls configure
+ // create the upstream tls configure
tlsConfig := &tls.Config{
InsecureSkipVerify: r.config.SkipUpstreamTLSVerify,
}
- // step: are we using a client certificate
+ // are we using a client certificate
// @TODO provide a means of reload on the client certificate when it expires. I'm not sure if it's just a
// case of update the http transport settings - Also we to place this go-routine?
if r.config.TLSClientCertificate != "" {
cert, err := ioutil.ReadFile(r.config.TLSClientCertificate)
if err != nil {
- log.Fatal(err)
+ r.log.Error("unable to read client certificate", zap.String("path", r.config.TLSClientCertificate), zap.Error(err))
+ return err
}
pool := x509.NewCertPool()
pool.AppendCertsFromPEM(cert)
@@ -443,12 +451,12 @@ func (r *oauthProxy) createUpstreamProxy(upstream *url.URL) error {
tlsConfig.ClientAuth = tls.RequireAndVerifyClientCert
}
- // step: create the forwarding proxy
+ // create the forwarding proxy
proxy := goproxy.NewProxyHttpServer()
proxy.Logger = httplog.New(ioutil.Discard, "", 0)
r.upstream = proxy
- // step: update the tls configuration of the reverse proxy
+ // update the tls configuration of the reverse proxy
r.upstream.(*goproxy.ProxyHttpServer).Tr = &http.Transport{
Dial: dialer,
TLSClientConfig: tlsConfig,
@@ -463,17 +471,17 @@ func (r *oauthProxy) createTemplates() error {
var list []string
if r.config.SignInPage != "" {
- log.Debugf("loading the custom sign in page: %s", r.config.SignInPage)
+ r.log.Debug("loading the custom sign in page", zap.String("page", r.config.SignInPage))
list = append(list, r.config.SignInPage)
}
if r.config.ForbiddenPage != "" {
- log.Debugf("loading the custom sign forbidden page: %s", r.config.ForbiddenPage)
+ r.log.Debug("loading the custom sign forbidden page", zap.String("page", r.config.ForbiddenPage))
list = append(list, r.config.ForbiddenPage)
}
if len(list) > 0 {
- log.Infof("loading the custom templates: %s", strings.Join(list, ","))
+ r.log.Info("loading the custom templates", zap.String("templates", strings.Join(list, ",")))
r.templates = template.Must(template.ParseFiles(list...))
r.router.(*echo.Echo).Renderer = r
}
@@ -485,3 +493,64 @@ func (r *oauthProxy) createTemplates() error {
func (r *oauthProxy) Render(w io.Writer, name string, data interface{}, c echo.Context) error {
return r.templates.ExecuteTemplate(w, name, data)
}
+
+// newOpenIDClient initializes the openID configuration, note: the redirection url is deliberately left blank
+// in order to retrieve it from the host header on request
+func (r *oauthProxy) newOpenIDClient() (*oidc.Client, oidc.ProviderConfig, *http.Client, error) {
+ var err error
+ var config oidc.ProviderConfig
+
+ // step: fix up the url if required, the underlining lib will add the .well-known/openid-configuration to the discovery url for us.
+ if strings.HasSuffix(r.config.DiscoveryURL, "/.well-known/openid-configuration") {
+ r.config.DiscoveryURL = strings.TrimSuffix(r.config.DiscoveryURL, "/.well-known/openid-configuration")
+ }
+
+ // step: create a idp http client
+ hc := &http.Client{
+ Transport: &http.Transport{
+ TLSClientConfig: &tls.Config{
+ InsecureSkipVerify: r.config.SkipOpenIDProviderTLSVerify,
+ },
+ },
+ Timeout: time.Second * 10,
+ }
+
+ // step: attempt to retrieve the provider configuration
+ completeCh := make(chan bool)
+ go func() {
+ for {
+ r.log.Info("attempting to retrieve configuration discovery url", zap.String("url", r.config.DiscoveryURL))
+ if config, err = oidc.FetchProviderConfig(hc, r.config.DiscoveryURL); err == nil {
+ break // break and complete
+ }
+ r.log.Warn("failed to get provider configuration from discovery", zap.Error(err))
+ time.Sleep(time.Second * 3)
+ }
+ completeCh <- true
+ }()
+ // wait for timeout or successful retrieval
+ select {
+ case <-time.After(30 * time.Second):
+ return nil, config, nil, errors.New("failed to retrieve the provider configuration from discovery url")
+ case <-completeCh:
+ r.log.Info("successfully retrieved openid configuration from the discovery")
+ }
+
+ client, err := oidc.NewClient(oidc.ClientConfig{
+ ProviderConfig: config,
+ Credentials: oidc.ClientCredentials{
+ ID: r.config.ClientID,
+ Secret: r.config.ClientSecret,
+ },
+ RedirectURL: fmt.Sprintf("%s/oauth/callback", r.config.RedirectionURL),
+ Scope: append(r.config.Scopes, oidc.DefaultScope...),
+ HTTPClient: hc,
+ })
+ if err != nil {
+ return nil, config, hc, err
+ }
+ // start the provider sync for key rotation
+ client.SyncProviderConfig(r.config.DiscoveryURL)
+
+ return client, config, hc, nil
+}
diff --git a/server_test.go b/server_test.go
index 28e518d..28c1837 100644
--- a/server_test.go
+++ b/server_test.go
@@ -27,7 +27,6 @@ import (
"testing"
"time"
- log "github.com/Sirupsen/logrus"
"github.com/gambol99/go-oidc/jose"
"github.com/stretchr/testify/assert"
)
@@ -317,7 +316,7 @@ func newTestProxyService(config *Config) (*oauthProxy, *fakeAuthServer, string)
config.RedirectionURL = service.URL
// step: we need to update the client config
- if proxy.client, proxy.idp, proxy.idpClient, err = newOpenIDClient(config); err != nil {
+ if proxy.client, proxy.idp, proxy.idpClient, err = proxy.newOpenIDClient(); err != nil {
panic("failed to recreate the openid client, error: " + err.Error())
}
@@ -347,6 +346,9 @@ func newFakeKeycloakConfig() *Config {
Listen: "127.0.0.1:0",
EnableAuthorizationHeader: true,
EnableLoginHandler: true,
+ EnableLogging: false,
+ DisableAllLogging: true,
+ Verbose: false,
Scopes: []string{},
Resources: []*Resource{
{
diff --git a/session.go b/session.go
index a842369..6bb11f9 100644
--- a/session.go
+++ b/session.go
@@ -19,8 +19,8 @@ import (
"net/http"
"strings"
- log "github.com/Sirupsen/logrus"
"github.com/gambol99/go-oidc/jose"
+ "go.uber.org/zap"
)
// getIdentity retrieves the user identity from a request, either from a session cookie or a bearer token
@@ -46,12 +46,11 @@ func (r *oauthProxy) getIdentity(req *http.Request) (*userContext, error) {
}
user.bearerToken = isBearer
- log.WithFields(log.Fields{
- "id": user.id,
- "name": user.name,
- "email": user.email,
- "roles": strings.Join(user.roles, ","),
- }).Debugf("found the user identity: %s in the request", user.email)
+ r.log.Debug("found the user identity",
+ zap.String("id", user.id),
+ zap.String("name", user.name),
+ zap.String("email", user.email),
+ zap.String("roles", strings.Join(user.roles, ",")))
return user, nil
}
diff --git a/store_boltdb.go b/store_boltdb.go
index 9218168..135b97b 100644
--- a/store_boltdb.go
+++ b/store_boltdb.go
@@ -21,7 +21,6 @@ import (
"strings"
"time"
- log "github.com/Sirupsen/logrus"
"github.com/boltdb/bolt"
)
@@ -42,8 +41,6 @@ type boltdbStore struct {
func newBoltDBStore(location *url.URL) (storage, error) {
// step: drop the initial slash
path := strings.TrimPrefix(location.Path, "/")
-
- log.Infof("creating the bolddb store, file: %s", path)
db, err := bolt.Open(path, 0600, &bolt.Options{
Timeout: 10 * time.Second,
})
@@ -64,11 +61,6 @@ func newBoltDBStore(location *url.URL) (storage, error) {
// Set adds a token to the store
func (r *boltdbStore) Set(key, value string) error {
- log.WithFields(log.Fields{
- "key": key,
- "value": value,
- }).Debugf("adding the key: %s in store", key)
-
return r.client.Update(func(tx *bolt.Tx) error {
bucket := tx.Bucket([]byte(dbName))
if bucket == nil {
@@ -80,10 +72,6 @@ func (r *boltdbStore) Set(key, value string) error {
// Get retrieves a token from the store
func (r *boltdbStore) Get(key string) (string, error) {
- log.WithFields(log.Fields{
- "key": key,
- }).Debugf("retrieving the key: %s from store", key)
-
var value string
err := r.client.View(func(tx *bolt.Tx) error {
bucket := tx.Bucket([]byte(dbName))
@@ -99,10 +87,6 @@ func (r *boltdbStore) Get(key string) (string, error) {
// Delete removes the key from the bucket
func (r *boltdbStore) Delete(key string) error {
- log.WithFields(log.Fields{
- "key": key,
- }).Debugf("deleting the key: %s from store", key)
-
return r.client.Update(func(tx *bolt.Tx) error {
bucket := tx.Bucket([]byte(dbName))
if bucket == nil {
@@ -114,6 +98,5 @@ func (r *boltdbStore) Delete(key string) error {
// Close closes of any open resources
func (r *boltdbStore) Close() error {
- log.Infof("closing the resourcese for boltdb store")
return r.client.Close()
}
diff --git a/store_redis.go b/store_redis.go
index aeb92f6..8979ce2 100644
--- a/store_redis.go
+++ b/store_redis.go
@@ -19,7 +19,6 @@ import (
"net/url"
"time"
- log "github.com/Sirupsen/logrus"
redis "gopkg.in/redis.v4"
)
@@ -29,8 +28,6 @@ type redisStore struct {
// newRedisStore creates a new redis store
func newRedisStore(location *url.URL) (storage, error) {
- log.Infof("creating a redis client for store: %s", location.Host)
-
// step: get any password
password := ""
if location.User != nil {
@@ -51,11 +48,6 @@ func newRedisStore(location *url.URL) (storage, error) {
// Set adds a token to the store
func (r redisStore) Set(key, value string) error {
- log.WithFields(log.Fields{
- "key": key,
- "value": value,
- }).Debugf("adding the key: %s to the store", key)
-
if err := r.client.Set(key, value, time.Duration(0)); err.Err() != nil {
return err.Err()
}
@@ -65,10 +57,6 @@ func (r redisStore) Set(key, value string) error {
// Get retrieves a token from the store
func (r redisStore) Get(key string) (string, error) {
- log.WithFields(log.Fields{
- "key": key,
- }).Debugf("retrieving the key: %s from store", key)
-
result := r.client.Get(key)
if result.Err() != nil {
return "", result.Err()
@@ -79,16 +67,11 @@ func (r redisStore) Get(key string) (string, error) {
// Delete remove the key
func (r redisStore) Delete(key string) error {
- log.WithFields(log.Fields{
- "key": key,
- }).Debugf("deleting the key: %s from store", key)
-
return r.client.Del(key).Err()
}
// Close closes of any open resources
func (r redisStore) Close() error {
- log.Infof("closing the resourcese for redis store")
if r.client != nil {
return r.client.Close()
}
diff --git a/stores.go b/stores.go
index 4eda6fe..6277db8 100644
--- a/stores.go
+++ b/stores.go
@@ -19,8 +19,8 @@ import (
"fmt"
"net/url"
- log "github.com/Sirupsen/logrus"
"github.com/gambol99/go-oidc/jose"
+ "go.uber.org/zap"
)
// createStorage creates the store client for use
@@ -71,9 +71,7 @@ func (r *oauthProxy) GetRefreshToken(token jose.JWT) (string, error) {
// DeleteRefreshToken removes a key from the store
func (r *oauthProxy) DeleteRefreshToken(token jose.JWT) error {
if err := r.store.Delete(getHashKey(&token)); err != nil {
- log.WithFields(log.Fields{
- "error": err.Error(),
- }).Errorf("unable to delete token")
+ r.log.Error("unable to delete token", zap.Error(err))
return err
}
diff --git a/utils.go b/utils.go
index 6a9ae0b..3cc47a1 100644
--- a/utils.go
+++ b/utils.go
@@ -40,7 +40,6 @@ import (
"unicode"
"unicode/utf8"
- log "github.com/Sirupsen/logrus"
"github.com/gambol99/go-oidc/jose"
"github.com/gambol99/go-oidc/oidc"
"github.com/labstack/echo"
@@ -144,69 +143,6 @@ func decodeText(state, key string) (string, error) {
return string(encoded), nil
}
-// newOpenIDClient initializes the openID configuration, note: the redirection url is deliberately left blank
-// in order to retrieve it from the host header on request
-func newOpenIDClient(cfg *Config) (*oidc.Client, oidc.ProviderConfig, *http.Client, error) {
- var err error
- var config oidc.ProviderConfig
-
- // fix up the url if required, the underlining lib will add the .well-known/openid-configuration to the discovery url for us.
- if strings.HasSuffix(cfg.DiscoveryURL, "/.well-known/openid-configuration") {
- cfg.DiscoveryURL = strings.TrimSuffix(cfg.DiscoveryURL, "/.well-known/openid-configuration")
- }
-
- hc := &http.Client{
- Transport: &http.Transport{
- TLSClientConfig: &tls.Config{
- InsecureSkipVerify: cfg.SkipOpenIDProviderTLSVerify,
- },
- IdleConnTimeout: time.Second * 10,
- },
- Timeout: time.Second * 10,
- }
-
- // attempt to retrieve the provider configuration
- completeCh := make(chan bool)
- go func() {
- for {
- log.Infof("attempting to retrieve openid configuration from discovery url: %s", cfg.DiscoveryURL)
- if config, err = oidc.FetchProviderConfig(hc, cfg.DiscoveryURL); err == nil {
- break // break and complete
- }
- log.Warnf("failed to get provider configuration from discovery url: %s, %s", cfg.DiscoveryURL, err)
- time.Sleep(time.Second * 3)
- }
- completeCh <- true
- }()
- // wait for timeout or successful retrieval
- select {
- case <-time.After(30 * time.Second):
- return nil, config, nil, errors.New("failed to retrieve the provider configuration from discovery url")
- case <-completeCh:
- log.Infof("successfully retrieved the openid configuration from the discovery url: %s", cfg.DiscoveryURL)
- }
-
- client, err := oidc.NewClient(oidc.ClientConfig{
- ProviderConfig: config,
- Credentials: oidc.ClientCredentials{
- ID: cfg.ClientID,
- Secret: cfg.ClientSecret,
- },
- RedirectURL: fmt.Sprintf("%s/oauth/callback", cfg.RedirectionURL),
- Scope: append(cfg.Scopes, oidc.DefaultScope...),
- SkipClientIDCheck: cfg.SkipClientID,
- HTTPClient: hc,
- })
- if err != nil {
- return nil, config, hc, err
- }
-
- // step: start the provider sync for key rotation
- client.SyncProviderConfig(cfg.DiscoveryURL)
-
- return client, config, hc, nil
-}
-
// decodeKeyPairs converts a list of strings (key=pair) to a map
func decodeKeyPairs(list []string) (map[string]string, error) {
kp := make(map[string]string)
diff --git a/utils_test.go b/utils_test.go
index cc43bf3..eabafb4 100644
--- a/utils_test.go
+++ b/utils_test.go
@@ -30,15 +30,6 @@ import (
"github.com/stretchr/testify/require"
)
-func TestNewOpenIDClient(t *testing.T) {
- _, auth, _ := newTestProxyService(nil)
- client, _, _, err := newOpenIDClient(&Config{
- DiscoveryURL: auth.location.String() + "/auth/realms/hod-test",
- })
- assert.NoError(t, err)
- assert.NotNil(t, client)
-}
-
func TestDecodeKeyPairs(t *testing.T) {
testCases := []struct {
List []string
--
GitLab