diff --git a/cmd/dex/serve.go b/cmd/dex/serve.go index b47ea9ef..b6fba3af 100644 --- a/cmd/dex/serve.go +++ b/cmd/dex/serve.go @@ -6,7 +6,6 @@ import ( "errors" "fmt" "io/ioutil" - "log" "net" "net/http" "os" @@ -182,19 +181,19 @@ func serve(cmd *cobra.Command, args []string) error { } errc := make(chan error, 3) if c.Web.HTTP != "" { - log.Printf("listening (http) on %s", c.Web.HTTP) + logger.Errorf("listening (http) on %s", c.Web.HTTP) go func() { errc <- http.ListenAndServe(c.Web.HTTP, serv) }() } if c.Web.HTTPS != "" { - log.Printf("listening (https) on %s", c.Web.HTTPS) + logger.Errorf("listening (https) on %s", c.Web.HTTPS) go func() { errc <- http.ListenAndServeTLS(c.Web.HTTPS, c.Web.TLSCert, c.Web.TLSKey, serv) }() } if c.GRPC.Addr != "" { - log.Printf("listening (grpc) on %s", c.GRPC.Addr) + logger.Errorf("listening (grpc) on %s", c.GRPC.Addr) go func() { errc <- func() error { list, err := net.Listen("tcp", c.GRPC.Addr) @@ -202,7 +201,7 @@ func serve(cmd *cobra.Command, args []string) error { return fmt.Errorf("listen grpc: %v", err) } s := grpc.NewServer(grpcOptions...) - api.RegisterDexServer(s, server.NewAPI(serverConfig.Storage)) + api.RegisterDexServer(s, server.NewAPI(serverConfig.Storage, logger)) return s.Serve(list) }() }() diff --git a/connector/ldap/ldap.go b/connector/ldap/ldap.go index 1af9aab1..47ce6ff5 100644 --- a/connector/ldap/ldap.go +++ b/connector/ldap/ldap.go @@ -7,7 +7,6 @@ import ( "encoding/json" "fmt" "io/ioutil" - "log" "net" "golang.org/x/net/context" @@ -328,7 +327,7 @@ func (c *ldapConnector) userEntry(conn *ldap.Conn, username string) (user ldap.E switch n := len(resp.Entries); n { case 0: - log.Printf("ldap: no results returned for filter: %q", filter) + c.logger.Errorf("ldap: no results returned for filter: %q", filter) return ldap.Entry{}, false, nil case 1: return *resp.Entries[0], true, nil @@ -361,7 +360,7 @@ func (c *ldapConnector) Login(ctx context.Context, s connector.Scopes, username, // Detect a bad password through the LDAP error code. if ldapErr, ok := err.(*ldap.Error); ok { if ldapErr.ResultCode == ldap.LDAPResultInvalidCredentials { - log.Printf("ldap: invalid password for user %q", user.DN) + c.logger.Errorf("ldap: invalid password for user %q", user.DN) incorrectPass = true return nil } @@ -471,7 +470,7 @@ func (c *ldapConnector) groups(ctx context.Context, user ldap.Entry) ([]string, } if len(groups) == 0 { // TODO(ericchiang): Is this going to spam the logs? - log.Printf("ldap: groups search with filter %q returned no groups", filter) + c.logger.Errorf("ldap: groups search with filter %q returned no groups", filter) } var groupNames []string diff --git a/server/api.go b/server/api.go index 491537ae..0405bfde 100644 --- a/server/api.go +++ b/server/api.go @@ -3,11 +3,11 @@ package server import ( "errors" "fmt" - "log" "golang.org/x/crypto/bcrypt" "golang.org/x/net/context" + "github.com/Sirupsen/logrus" "github.com/coreos/dex/api" "github.com/coreos/dex/storage" "github.com/coreos/dex/version" @@ -18,12 +18,16 @@ import ( const apiVersion = 0 // NewAPI returns a server which implements the gRPC API interface. -func NewAPI(s storage.Storage) api.DexServer { - return dexAPI{s: s} +func NewAPI(s storage.Storage, logger logrus.FieldLogger) api.DexServer { + return dexAPI{ + s: s, + logger: logger, + } } type dexAPI struct { - s storage.Storage + s storage.Storage + logger logrus.FieldLogger } func (d dexAPI) CreateClient(ctx context.Context, req *api.CreateClientReq) (*api.CreateClientResp, error) { @@ -48,7 +52,7 @@ func (d dexAPI) CreateClient(ctx context.Context, req *api.CreateClientReq) (*ap LogoURL: req.Client.LogoUrl, } if err := d.s.CreateClient(c); err != nil { - log.Printf("api: failed to create client: %v", err) + d.logger.Errorf("api: failed to create client: %v", err) // TODO(ericchiang): Surface "already exists" errors. return nil, fmt.Errorf("create client: %v", err) } @@ -64,7 +68,7 @@ func (d dexAPI) DeleteClient(ctx context.Context, req *api.DeleteClientReq) (*ap if err == storage.ErrNotFound { return &api.DeleteClientResp{NotFound: true}, nil } - log.Printf("api: failed to delete client: %v", err) + d.logger.Errorf("api: failed to delete client: %v", err) return nil, fmt.Errorf("delete client: %v", err) } return &api.DeleteClientResp{}, nil @@ -104,7 +108,7 @@ func (d dexAPI) CreatePassword(ctx context.Context, req *api.CreatePasswordReq) UserID: req.Password.UserId, } if err := d.s.CreatePassword(p); err != nil { - log.Printf("api: failed to create password: %v", err) + d.logger.Errorf("api: failed to create password: %v", err) return nil, fmt.Errorf("create password: %v", err) } @@ -141,7 +145,7 @@ func (d dexAPI) UpdatePassword(ctx context.Context, req *api.UpdatePasswordReq) if err == storage.ErrNotFound { return &api.UpdatePasswordResp{NotFound: true}, nil } - log.Printf("api: failed to update password: %v", err) + d.logger.Errorf("api: failed to update password: %v", err) return nil, fmt.Errorf("update password: %v", err) } @@ -158,7 +162,7 @@ func (d dexAPI) DeletePassword(ctx context.Context, req *api.DeletePasswordReq) if err == storage.ErrNotFound { return &api.DeletePasswordResp{NotFound: true}, nil } - log.Printf("api: failed to delete password: %v", err) + d.logger.Errorf("api: failed to delete password: %v", err) return nil, fmt.Errorf("delete password: %v", err) } return &api.DeletePasswordResp{}, nil @@ -175,7 +179,7 @@ func (d dexAPI) GetVersion(ctx context.Context, req *api.VersionReq) (*api.Versi func (d dexAPI) ListPasswords(ctx context.Context, req *api.ListPasswordReq) (*api.ListPasswordResp, error) { passwordList, err := d.s.ListPasswords() if err != nil { - log.Printf("api: failed to list passwords: %v", err) + d.logger.Errorf("api: failed to list passwords: %v", err) return nil, fmt.Errorf("list passwords: %v", err) } diff --git a/server/api_test.go b/server/api_test.go index 9f325cba..1a386738 100644 --- a/server/api_test.go +++ b/server/api_test.go @@ -19,7 +19,7 @@ func TestPassword(t *testing.T) { } s := memory.New(logger) - serv := NewAPI(s) + serv := NewAPI(s, logger) ctx := context.Background() p := api.Password{ diff --git a/server/handlers.go b/server/handlers.go index 6ec1f4ff..28086b13 100644 --- a/server/handlers.go +++ b/server/handlers.go @@ -3,7 +3,6 @@ package server import ( "encoding/json" "fmt" - "log" "net/http" "net/url" "path" @@ -42,7 +41,7 @@ func (s *Server) handleHealth(w http.ResponseWriter, r *http.Request) { t := s.now().Sub(start) if err != nil { - log.Printf("Storage health check failed: %v", err) + s.logger.Errorf("Storage health check failed: %v", err) http.Error(w, "Health check failed", http.StatusInternalServerError) return } @@ -53,13 +52,13 @@ func (s *Server) handlePublicKeys(w http.ResponseWriter, r *http.Request) { // TODO(ericchiang): Cache this. keys, err := s.storage.GetKeys() if err != nil { - log.Printf("failed to get keys: %v", err) + s.logger.Errorf("failed to get keys: %v", err) http.Error(w, "Internal server error", http.StatusInternalServerError) return } if keys.SigningKeyPub == nil { - log.Printf("No public keys found.") + s.logger.Errorf("No public keys found.") http.Error(w, "Internal server error", http.StatusInternalServerError) return } @@ -74,7 +73,7 @@ func (s *Server) handlePublicKeys(w http.ResponseWriter, r *http.Request) { data, err := json.MarshalIndent(jwks, "", " ") if err != nil { - log.Printf("failed to marshal discovery data: %v", err) + s.logger.Errorf("failed to marshal discovery data: %v", err) http.Error(w, "Internal server error", http.StatusInternalServerError) return } @@ -137,14 +136,14 @@ func (s *Server) discoveryHandler() (http.HandlerFunc, error) { // handleAuthorization handles the OAuth2 auth endpoint. func (s *Server) handleAuthorization(w http.ResponseWriter, r *http.Request) { - authReq, err := parseAuthorizationRequest(s.storage, s.supportedResponseTypes, r) + authReq, err := s.parseAuthorizationRequest(s.supportedResponseTypes, r) if err != nil { s.renderError(w, http.StatusInternalServerError, err.Type, err.Description) return } authReq.Expiry = s.now().Add(time.Minute * 30) if err := s.storage.CreateAuthRequest(authReq); err != nil { - log.Printf("Failed to create authorization request: %v", err) + s.logger.Errorf("Failed to create authorization request: %v", err) s.renderError(w, http.StatusInternalServerError, errServerError, "") return } @@ -166,7 +165,9 @@ func (s *Server) handleAuthorization(w http.ResponseWriter, r *http.Request) { i++ } - s.templates.login(w, connectorInfos, authReq.ID) + if err := s.templates.login(w, connectorInfos, authReq.ID); err != nil { + s.logger.Errorf("Server template error: %v", err) + } } func (s *Server) handleConnectorLogin(w http.ResponseWriter, r *http.Request) { @@ -181,8 +182,8 @@ func (s *Server) handleConnectorLogin(w http.ResponseWriter, r *http.Request) { authReq, err := s.storage.GetAuthRequest(authReqID) if err != nil { - log.Printf("Failed to get auth request: %v", err) - s.renderError(w, http.StatusInternalServerError, errServerError, "") + s.logger.Errorf("Failed to get auth request: %v", err) + s.renderError(w, http.StatusInternalServerError, errServerError, "Connector Login Error") return } scopes := parseScopes(authReq.Scopes) @@ -195,8 +196,8 @@ func (s *Server) handleConnectorLogin(w http.ResponseWriter, r *http.Request) { return a, nil } if err := s.storage.UpdateAuthRequest(authReqID, updater); err != nil { - log.Printf("Failed to set connector ID on auth request: %v", err) - s.renderError(w, http.StatusInternalServerError, errServerError, "") + s.logger.Errorf("Failed to set connector ID on auth request: %v", err) + s.renderError(w, http.StatusInternalServerError, errServerError, "Connector Login Error") return } @@ -207,13 +208,15 @@ func (s *Server) handleConnectorLogin(w http.ResponseWriter, r *http.Request) { // TODO(ericchiang): Is this appropriate or should we also be using a nonce? callbackURL, err := conn.LoginURL(scopes, s.absURL("/callback"), authReqID) if err != nil { - log.Printf("Connector %q returned error when creating callback: %v", connID, err) - s.renderError(w, http.StatusInternalServerError, errServerError, "") + s.logger.Errorf("Connector %q returned error when creating callback: %v", connID, err) + s.renderError(w, http.StatusInternalServerError, errServerError, "Connector Login Error") return } http.Redirect(w, r, callbackURL, http.StatusFound) case connector.PasswordConnector: - s.templates.password(w, authReqID, r.URL.String(), "", false) + if err := s.templates.password(w, authReqID, r.URL.String(), "", false); err != nil { + s.logger.Errorf("Server template error: %v", err) + } default: s.notFound(w, r) } @@ -229,18 +232,20 @@ func (s *Server) handleConnectorLogin(w http.ResponseWriter, r *http.Request) { identity, ok, err := passwordConnector.Login(r.Context(), scopes, username, password) if err != nil { - log.Printf("Failed to login user: %v", err) - s.renderError(w, http.StatusInternalServerError, errServerError, "") + s.logger.Errorf("Failed to login user: %v", err) + s.renderError(w, http.StatusInternalServerError, errServerError, "Connector Login Error") return } if !ok { - s.templates.password(w, authReqID, r.URL.String(), username, true) + if err := s.templates.password(w, authReqID, r.URL.String(), username, true); err != nil { + s.logger.Errorf("Server template error: %v", err) + } return } redirectURL, err := s.finalizeLogin(identity, authReq, conn.Connector) if err != nil { - log.Printf("Failed to finalize login: %v", err) - s.renderError(w, http.StatusInternalServerError, errServerError, "") + s.logger.Errorf("Failed to finalize login: %v", err) + s.renderError(w, http.StatusInternalServerError, errServerError, "Connector Login Error") return } @@ -260,17 +265,17 @@ func (s *Server) handleConnectorCallback(w http.ResponseWriter, r *http.Request) // Section: "3.4.3 RelayState" state := r.URL.Query().Get("state") if state == "" { - s.renderError(w, http.StatusBadRequest, errInvalidRequest, "no 'state' parameter provided") + s.renderError(w, http.StatusBadRequest, errInvalidRequest, "No 'state' parameter provided.") return } authReq, err := s.storage.GetAuthRequest(state) if err != nil { if err == storage.ErrNotFound { - s.renderError(w, http.StatusBadRequest, errInvalidRequest, "invalid 'state' parameter provided") + s.renderError(w, http.StatusBadRequest, errInvalidRequest, "Invalid 'state' parameter provided.") return } - log.Printf("Failed to get auth request: %v", err) + s.logger.Errorf("Failed to get auth request: %v", err) s.renderError(w, http.StatusInternalServerError, errServerError, "") return } @@ -288,14 +293,14 @@ func (s *Server) handleConnectorCallback(w http.ResponseWriter, r *http.Request) identity, err := callbackConnector.HandleCallback(parseScopes(authReq.Scopes), r) if err != nil { - log.Printf("Failed to authenticate: %v", err) + s.logger.Errorf("Failed to authenticate: %v", err) s.renderError(w, http.StatusInternalServerError, errServerError, "") return } redirectURL, err := s.finalizeLogin(identity, authReq, conn.Connector) if err != nil { - log.Printf("Failed to finalize login: %v", err) + s.logger.Errorf("Failed to finalize login: %v", err) s.renderError(w, http.StatusInternalServerError, errServerError, "") return } @@ -327,12 +332,12 @@ func (s *Server) finalizeLogin(identity connector.Identity, authReq storage.Auth func (s *Server) handleApproval(w http.ResponseWriter, r *http.Request) { authReq, err := s.storage.GetAuthRequest(r.FormValue("req")) if err != nil { - log.Printf("Failed to get auth request: %v", err) + s.logger.Errorf("Failed to get auth request: %v", err) s.renderError(w, http.StatusInternalServerError, errServerError, "") return } if !authReq.LoggedIn { - log.Printf("Auth request does not have an identity for approval") + s.logger.Errorf("Auth request does not have an identity for approval") s.renderError(w, http.StatusInternalServerError, errServerError, "") return } @@ -345,11 +350,13 @@ func (s *Server) handleApproval(w http.ResponseWriter, r *http.Request) { } client, err := s.storage.GetClient(authReq.ClientID) if err != nil { - log.Printf("Failed to get client %q: %v", authReq.ClientID, err) + s.logger.Errorf("Failed to get client %q: %v", authReq.ClientID, err) s.renderError(w, http.StatusInternalServerError, errServerError, "") return } - s.templates.approval(w, authReq.ID, authReq.Claims.Username, client.Name, authReq.Scopes) + if err := s.templates.approval(w, authReq.ID, authReq.Claims.Username, client.Name, authReq.Scopes); err != nil { + s.logger.Errorf("Server template error: %v", err) + } case "POST": if r.FormValue("approval") != "approve" { s.renderError(w, http.StatusInternalServerError, "approval rejected", "") @@ -367,7 +374,7 @@ func (s *Server) sendCodeResponse(w http.ResponseWriter, r *http.Request, authRe if err := s.storage.DeleteAuthRequest(authReq.ID); err != nil { if err != storage.ErrNotFound { - log.Printf("Failed to delete authorization request: %v", err) + s.logger.Errorf("Failed to delete authorization request: %v", err) s.renderError(w, http.StatusInternalServerError, errServerError, "") } else { s.renderError(w, http.StatusBadRequest, errInvalidRequest, "Authorization request has already been completed.") @@ -396,21 +403,23 @@ func (s *Server) sendCodeResponse(w http.ResponseWriter, r *http.Request, authRe ConnectorData: authReq.ConnectorData, } if err := s.storage.CreateAuthCode(code); err != nil { - log.Printf("Failed to create auth code: %v", err) + s.logger.Errorf("Failed to create auth code: %v", err) s.renderError(w, http.StatusInternalServerError, errServerError, "") return } if authReq.RedirectURI == redirectURIOOB { - s.templates.oob(w, code.ID) + if err := s.templates.oob(w, code.ID); err != nil { + s.logger.Errorf("Server template error: %v", err) + } return } q.Set("code", code.ID) case responseTypeToken: idToken, expiry, err := s.newIDToken(authReq.ClientID, authReq.Claims, authReq.Scopes, authReq.Nonce) if err != nil { - log.Printf("failed to create ID token: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to create ID token: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) return } v := url.Values{} @@ -433,11 +442,11 @@ func (s *Server) handleToken(w http.ResponseWriter, r *http.Request) { if ok { var err error if clientID, err = url.QueryUnescape(clientID); err != nil { - tokenErr(w, errInvalidRequest, "client_id improperly encoded", http.StatusBadRequest) + s.tokenErrHelper(w, errInvalidRequest, "client_id improperly encoded", http.StatusBadRequest) return } if clientSecret, err = url.QueryUnescape(clientSecret); err != nil { - tokenErr(w, errInvalidRequest, "client_secret improperly encoded", http.StatusBadRequest) + s.tokenErrHelper(w, errInvalidRequest, "client_secret improperly encoded", http.StatusBadRequest) return } } else { @@ -448,15 +457,15 @@ func (s *Server) handleToken(w http.ResponseWriter, r *http.Request) { client, err := s.storage.GetClient(clientID) if err != nil { if err != storage.ErrNotFound { - log.Printf("failed to get client: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to get client: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) } else { - tokenErr(w, errInvalidClient, "Invalid client credentials.", http.StatusUnauthorized) + s.tokenErrHelper(w, errInvalidClient, "Invalid client credentials.", http.StatusUnauthorized) } return } if client.Secret != clientSecret { - tokenErr(w, errInvalidClient, "Invalid client credentials.", http.StatusUnauthorized) + s.tokenErrHelper(w, errInvalidClient, "Invalid client credentials.", http.StatusUnauthorized) return } @@ -467,7 +476,7 @@ func (s *Server) handleToken(w http.ResponseWriter, r *http.Request) { case grantTypeRefreshToken: s.handleRefreshToken(w, r, client) default: - tokenErr(w, errInvalidGrant, "", http.StatusBadRequest) + s.tokenErrHelper(w, errInvalidGrant, "", http.StatusBadRequest) } } @@ -479,29 +488,29 @@ func (s *Server) handleAuthCode(w http.ResponseWriter, r *http.Request, client s authCode, err := s.storage.GetAuthCode(code) if err != nil || s.now().After(authCode.Expiry) || authCode.ClientID != client.ID { if err != storage.ErrNotFound { - log.Printf("failed to get auth code: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to get auth code: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) } else { - tokenErr(w, errInvalidRequest, "Invalid or expired code parameter.", http.StatusBadRequest) + s.tokenErrHelper(w, errInvalidRequest, "Invalid or expired code parameter.", http.StatusBadRequest) } return } if authCode.RedirectURI != redirectURI { - tokenErr(w, errInvalidRequest, "redirect_uri did not match URI from initial request.", http.StatusBadRequest) + s.tokenErrHelper(w, errInvalidRequest, "redirect_uri did not match URI from initial request.", http.StatusBadRequest) return } idToken, expiry, err := s.newIDToken(client.ID, authCode.Claims, authCode.Scopes, authCode.Nonce) if err != nil { - log.Printf("failed to create ID token: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to create ID token: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) return } if err := s.storage.DeleteAuthCode(code); err != nil { - log.Printf("failed to delete auth code: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to delete auth code: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) return } @@ -525,8 +534,8 @@ func (s *Server) handleAuthCode(w http.ResponseWriter, r *http.Request, client s ConnectorData: authCode.ConnectorData, } if err := s.storage.CreateRefresh(refresh); err != nil { - log.Printf("failed to create refresh token: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to create refresh token: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) return } refreshToken = refresh.RefreshToken @@ -539,17 +548,17 @@ func (s *Server) handleRefreshToken(w http.ResponseWriter, r *http.Request, clie code := r.PostFormValue("refresh_token") scope := r.PostFormValue("scope") if code == "" { - tokenErr(w, errInvalidRequest, "No refresh token in request.", http.StatusBadRequest) + s.tokenErrHelper(w, errInvalidRequest, "No refresh token in request.", http.StatusBadRequest) return } refresh, err := s.storage.GetRefresh(code) if err != nil || refresh.ClientID != client.ID { if err != storage.ErrNotFound { - log.Printf("failed to get auth code: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to get auth code: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) } else { - tokenErr(w, errInvalidRequest, "Refresh token is invalid or has already been claimed by another client.", http.StatusBadRequest) + s.tokenErrHelper(w, errInvalidRequest, "Refresh token is invalid or has already been claimed by another client.", http.StatusBadRequest) } return } @@ -579,7 +588,7 @@ func (s *Server) handleRefreshToken(w http.ResponseWriter, r *http.Request, clie if len(unauthorizedScopes) > 0 { msg := fmt.Sprintf("Requested scopes contain unauthorized scope(s): %q.", unauthorizedScopes) - tokenErr(w, errInvalidRequest, msg, http.StatusBadRequest) + s.tokenErrHelper(w, errInvalidRequest, msg, http.StatusBadRequest) return } scopes = requestedScopes @@ -587,8 +596,8 @@ func (s *Server) handleRefreshToken(w http.ResponseWriter, r *http.Request, clie conn, ok := s.connectors[refresh.ConnectorID] if !ok { - log.Printf("connector ID not found: %q", refresh.ConnectorID) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("connector ID not found: %q", refresh.ConnectorID) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) return } @@ -608,8 +617,8 @@ func (s *Server) handleRefreshToken(w http.ResponseWriter, r *http.Request, clie } ident, err := refreshConn.Refresh(r.Context(), parseScopes(scopes), ident) if err != nil { - log.Printf("failed to refresh identity: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to refresh identity: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) return } @@ -625,22 +634,22 @@ func (s *Server) handleRefreshToken(w http.ResponseWriter, r *http.Request, clie idToken, expiry, err := s.newIDToken(client.ID, refresh.Claims, scopes, refresh.Nonce) if err != nil { - log.Printf("failed to create ID token: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to create ID token: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) return } // Refresh tokens are claimed exactly once. Delete the current token and // create a new one. if err := s.storage.DeleteRefresh(code); err != nil { - log.Printf("failed to delete auth code: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to delete auth code: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) return } refresh.RefreshToken = storage.NewID() if err := s.storage.CreateRefresh(refresh); err != nil { - log.Printf("failed to create refresh token: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to create refresh token: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) return } s.writeAccessToken(w, idToken, refresh.RefreshToken, expiry) @@ -665,8 +674,8 @@ func (s *Server) writeAccessToken(w http.ResponseWriter, idToken, refreshToken s } data, err := json.Marshal(resp) if err != nil { - log.Printf("failed to marshal access token response: %v", err) - tokenErr(w, errServerError, "", http.StatusInternalServerError) + s.logger.Errorf("failed to marshal access token response: %v", err) + s.tokenErrHelper(w, errServerError, "", http.StatusInternalServerError) return } w.Header().Set("Content-Type", "application/json") @@ -681,3 +690,9 @@ func (s *Server) renderError(w http.ResponseWriter, status int, err, description func (s *Server) notFound(w http.ResponseWriter, r *http.Request) { http.NotFound(w, r) } + +func (s *Server) tokenErrHelper(w http.ResponseWriter, typ string, description string, statusCode int) { + if err := tokenErr(w, typ, description, statusCode); err != nil { + s.logger.Errorf("token error repsonse: %v", err) + } +} diff --git a/server/oauth2.go b/server/oauth2.go index c9ea6273..d8211e73 100644 --- a/server/oauth2.go +++ b/server/oauth2.go @@ -3,7 +3,6 @@ package server import ( "encoding/json" "fmt" - "log" "net/http" "net/url" "strconv" @@ -41,20 +40,20 @@ func (err *authErr) ServeHTTP(w http.ResponseWriter, r *http.Request) { http.Redirect(w, r, redirectURI, http.StatusSeeOther) } -func tokenErr(w http.ResponseWriter, typ, description string, statusCode int) { +func tokenErr(w http.ResponseWriter, typ, description string, statusCode int) error { data := struct { Error string `json:"error"` Description string `json:"error_description,omitempty"` }{typ, description} body, err := json.Marshal(data) if err != nil { - log.Printf("failed to marshal token error response: %v", err) - return + return fmt.Errorf("failed to marshal token error response: %v", err) } w.Header().Set("Content-Type", "application/json") w.Header().Set("Content-Length", strconv.Itoa(len(body))) w.WriteHeader(statusCode) w.Write(body) + return nil } const ( @@ -159,7 +158,7 @@ func (s *Server) newIDToken(clientID string, claims storage.Claims, scopes []str if !ok { continue } - isTrusted, err := validateCrossClientTrust(s.storage, clientID, peerID) + isTrusted, err := s.validateCrossClientTrust(clientID, peerID) if err != nil { return "", expiry, err } @@ -183,7 +182,7 @@ func (s *Server) newIDToken(clientID string, claims storage.Claims, scopes []str keys, err := s.storage.GetKeys() if err != nil { - log.Printf("Failed to get keys: %v", err) + s.logger.Errorf("Failed to get keys: %v", err) return "", expiry, err } if idToken, err = keys.Sign(payload); err != nil { @@ -195,7 +194,7 @@ func (s *Server) newIDToken(clientID string, claims storage.Claims, scopes []str // parse the initial request from the OAuth2 client. // // For correctness the logic is largely copied from https://github.com/RangelReale/osin. -func parseAuthorizationRequest(s storage.Storage, supportedResponseTypes map[string]bool, r *http.Request) (req storage.AuthRequest, oauth2Err *authErr) { +func (s *Server) parseAuthorizationRequest(supportedResponseTypes map[string]bool, r *http.Request) (req storage.AuthRequest, oauth2Err *authErr) { if err := r.ParseForm(); err != nil { return req, &authErr{"", "", errInvalidRequest, "Failed to parse request."} } @@ -208,13 +207,13 @@ func parseAuthorizationRequest(s storage.Storage, supportedResponseTypes map[str clientID := r.Form.Get("client_id") - client, err := s.GetClient(clientID) + client, err := s.storage.GetClient(clientID) if err != nil { if err == storage.ErrNotFound { description := fmt.Sprintf("Invalid client_id (%q).", clientID) return req, &authErr{"", "", errUnauthorizedClient, description} } - log.Printf("Failed to get client: %v", err) + s.logger.Errorf("Failed to get client: %v", err) return req, &authErr{"", "", errServerError, ""} } @@ -246,7 +245,7 @@ func parseAuthorizationRequest(s storage.Storage, supportedResponseTypes map[str continue } - isTrusted, err := validateCrossClientTrust(s, clientID, peerID) + isTrusted, err := s.validateCrossClientTrust(clientID, peerID) if err != nil { return req, newErr(errServerError, "") } @@ -309,14 +308,14 @@ func parseCrossClientScope(scope string) (peerID string, ok bool) { return } -func validateCrossClientTrust(s storage.Storage, clientID, peerID string) (trusted bool, err error) { +func (s *Server) validateCrossClientTrust(clientID, peerID string) (trusted bool, err error) { if peerID == clientID { return true, nil } - peer, err := s.GetClient(peerID) + peer, err := s.storage.GetClient(peerID) if err != nil { if err != storage.ErrNotFound { - log.Printf("Failed to get client: %v", err) + s.logger.Errorf("Failed to get client: %v", err) return false, err } return false, nil diff --git a/server/rotation.go b/server/rotation.go index ba57dc58..326e7597 100644 --- a/server/rotation.go +++ b/server/rotation.go @@ -7,12 +7,12 @@ import ( "errors" "fmt" "io" - "log" "time" "golang.org/x/net/context" "gopkg.in/square/go-jose.v2" + "github.com/Sirupsen/logrus" "github.com/coreos/dex/storage" ) @@ -57,18 +57,20 @@ type keyRotater struct { strategy rotationStrategy now func() time.Time + + logger logrus.FieldLogger } // startKeyRotation begins key rotation in a new goroutine, closing once the context is canceled. // // The method blocks until after the first attempt to rotate keys has completed. That way // healthy storages will return from this call with valid keys. -func startKeyRotation(ctx context.Context, s storage.Storage, strategy rotationStrategy, now func() time.Time) { - rotater := keyRotater{s, strategy, now} +func (s *Server) startKeyRotation(ctx context.Context, strategy rotationStrategy, now func() time.Time) { + rotater := keyRotater{s.storage, strategy, now, s.logger} // Try to rotate immediately so properly configured storages will have keys. if err := rotater.rotate(); err != nil { - log.Printf("failed to rotate keys: %v", err) + s.logger.Errorf("failed to rotate keys: %v", err) } go func() { @@ -78,7 +80,7 @@ func startKeyRotation(ctx context.Context, s storage.Storage, strategy rotationS return case <-time.After(time.Second * 30): if err := rotater.rotate(); err != nil { - log.Printf("failed to rotate keys: %v", err) + s.logger.Errorf("failed to rotate keys: %v", err) } } } @@ -94,7 +96,7 @@ func (k keyRotater) rotate() error { if k.now().Before(keys.NextRotation) { return nil } - log.Println("keys expired, rotating") + k.logger.Infof("keys expired, rotating") // Generate the key outside of a storage transaction. key, err := k.strategy.key() @@ -154,6 +156,6 @@ func (k keyRotater) rotate() error { if err != nil { return err } - log.Printf("keys rotated, next rotation: %s", nextRotation) + k.logger.Infof("keys rotated, next rotation: %s", nextRotation) return nil } diff --git a/server/server.go b/server/server.go index 1a87cb9c..ce31f7d8 100644 --- a/server/server.go +++ b/server/server.go @@ -3,7 +3,6 @@ package server import ( "errors" "fmt" - "log" "net/http" "net/url" "path" @@ -222,8 +221,8 @@ func newServer(ctx context.Context, c Config, rotationStrategy rotationStrategy) handlePrefix("/theme", theme) s.mux = r - startKeyRotation(ctx, c.Storage, rotationStrategy, now) - startGarbageCollection(ctx, c.Storage, value(c.GCFrequency, 5*time.Minute), now) + s.startKeyRotation(ctx, rotationStrategy, now) + s.startGarbageCollection(ctx, value(c.GCFrequency, 5*time.Minute), now) return s, nil } @@ -260,8 +259,7 @@ func (db passwordDB) Login(ctx context.Context, s connector.Scopes, email, passw p, err := db.s.GetPassword(email) if err != nil { if err != storage.ErrNotFound { - log.Printf("get password: %v", err) - return connector.Identity{}, false, err + return connector.Identity{}, false, fmt.Errorf("get password: %v", err) } return connector.Identity{}, false, nil } @@ -333,17 +331,17 @@ func (k *keyCacher) GetKeys() (storage.Keys, error) { return storageKeys, nil } -func startGarbageCollection(ctx context.Context, s storage.Storage, frequency time.Duration, now func() time.Time) { +func (s *Server) startGarbageCollection(ctx context.Context, frequency time.Duration, now func() time.Time) { go func() { for { select { case <-ctx.Done(): return case <-time.After(frequency): - if r, err := s.GarbageCollect(now()); err != nil { - log.Printf("garbage collection failed: %v", err) + if r, err := s.storage.GarbageCollect(now()); err != nil { + s.logger.Errorf("garbage collection failed: %v", err) } else if r.AuthRequests > 0 || r.AuthCodes > 0 { - log.Printf("garbage collection run, delete auth requests=%d, auth codes=%d", r.AuthRequests, r.AuthCodes) + s.logger.Errorf("garbage collection run, delete auth requests=%d, auth codes=%d", r.AuthRequests, r.AuthCodes) } } } diff --git a/server/server_test.go b/server/server_test.go index 4c9621c9..96786fc8 100644 --- a/server/server_test.go +++ b/server/server_test.go @@ -98,6 +98,7 @@ func newTestServer(ctx context.Context, t *testing.T, updateConfig func(c *Confi Web: WebConfig{ Dir: filepath.Join(os.Getenv("GOPATH"), "src/github.com/coreos/dex/web"), }, + Logger: logger, } if updateConfig != nil { updateConfig(&config) diff --git a/server/templates.go b/server/templates.go index 649d5b08..45c1d198 100644 --- a/server/templates.go +++ b/server/templates.go @@ -4,7 +4,6 @@ import ( "fmt" "io" "io/ioutil" - "log" "net/http" "os" "path/filepath" @@ -178,27 +177,27 @@ func (n byName) Len() int { return len(n) } func (n byName) Less(i, j int) bool { return n[i].Name < n[j].Name } func (n byName) Swap(i, j int) { n[i], n[j] = n[j], n[i] } -func (t *templates) login(w http.ResponseWriter, connectors []connectorInfo, authReqID string) { +func (t *templates) login(w http.ResponseWriter, connectors []connectorInfo, authReqID string) error { sort.Sort(byName(connectors)) data := struct { Connectors []connectorInfo AuthReqID string }{connectors, authReqID} - renderTemplate(w, t.loginTmpl, data) + return renderTemplate(w, t.loginTmpl, data) } -func (t *templates) password(w http.ResponseWriter, authReqID, callback, lastUsername string, lastWasInvalid bool) { +func (t *templates) password(w http.ResponseWriter, authReqID, callback, lastUsername string, lastWasInvalid bool) error { data := struct { AuthReqID string PostURL string Username string Invalid bool }{authReqID, string(callback), lastUsername, lastWasInvalid} - renderTemplate(w, t.passwordTmpl, data) + return renderTemplate(w, t.passwordTmpl, data) } -func (t *templates) approval(w http.ResponseWriter, authReqID, username, clientName string, scopes []string) { +func (t *templates) approval(w http.ResponseWriter, authReqID, username, clientName string, scopes []string) error { accesses := []string{} for _, scope := range scopes { access, ok := scopeDescriptions[scope] @@ -213,14 +212,14 @@ func (t *templates) approval(w http.ResponseWriter, authReqID, username, clientN AuthReqID string Scopes []string }{username, clientName, authReqID, accesses} - renderTemplate(w, t.approvalTmpl, data) + return renderTemplate(w, t.approvalTmpl, data) } -func (t *templates) oob(w http.ResponseWriter, code string) { +func (t *templates) oob(w http.ResponseWriter, code string) error { data := struct { Code string }{code} - renderTemplate(w, t.oobTmpl, data) + return renderTemplate(w, t.oobTmpl, data) } // small io.Writer utilitiy to determine if executing the template wrote to the underlying response writer. @@ -234,15 +233,14 @@ func (w *writeRecorder) Write(p []byte) (n int, err error) { return w.w.Write(p) } -func renderTemplate(w http.ResponseWriter, tmpl *template.Template, data interface{}) { +func renderTemplate(w http.ResponseWriter, tmpl *template.Template, data interface{}) error { wr := &writeRecorder{w: w} if err := tmpl.Execute(wr, data); err != nil { - log.Printf("Error rendering template %s: %s", tmpl.Name(), err) - if !wr.wrote { // TODO(ericchiang): replace with better internal server error. http.Error(w, "Internal server error", http.StatusInternalServerError) } + return fmt.Errorf("Error rendering template %s: %s", tmpl.Name(), err) } - return + return nil } diff --git a/storage/kubernetes/storage.go b/storage/kubernetes/storage.go index f3821ee1..b6d482ba 100644 --- a/storage/kubernetes/storage.go +++ b/storage/kubernetes/storage.go @@ -3,7 +3,6 @@ package kubernetes import ( "errors" "fmt" - "log" "net/http" "strings" "time" @@ -83,11 +82,11 @@ func (c *Config) open(logger logrus.FieldLogger) (*client, error) { // they'll immediately be available, but ensures that the client will actually try // once. if err := cli.createThirdPartyResources(); err != nil { - log.Printf("failed creating third party resources: %v", err) + logger.Errorf("failed creating third party resources: %v", err) go func() { for { if err := cli.createThirdPartyResources(); err != nil { - log.Printf("failed creating third party resources: %v", err) + logger.Errorf("failed creating third party resources: %v", err) } else { return } @@ -119,13 +118,13 @@ func (cli *client) createThirdPartyResources() error { if err != nil { if e, ok := err.(httpError); ok { if e.StatusCode() == http.StatusConflict { - log.Printf("third party resource already created %q", r.ObjectMeta.Name) + cli.logger.Errorf("third party resource already created %q", r.ObjectMeta.Name) continue } } return err } - log.Printf("create third party resource %q", r.ObjectMeta.Name) + cli.logger.Errorf("create third party resource %q", r.ObjectMeta.Name) } return nil } @@ -397,7 +396,7 @@ func (cli *client) GarbageCollect(now time.Time) (result storage.GCResult, err e for _, authRequest := range authRequests.AuthRequests { if now.After(authRequest.Expiry) { if err := cli.delete(resourceAuthRequest, authRequest.ObjectMeta.Name); err != nil { - log.Printf("failed to delete auth request: %v", err) + cli.logger.Errorf("failed to delete auth request: %v", err) delErr = fmt.Errorf("failed to delete auth request: %v", err) } result.AuthRequests++ @@ -415,7 +414,7 @@ func (cli *client) GarbageCollect(now time.Time) (result storage.GCResult, err e for _, authCode := range authCodes.AuthCodes { if now.After(authCode.Expiry) { if err := cli.delete(resourceAuthCode, authCode.ObjectMeta.Name); err != nil { - log.Printf("failed to delete auth code %v", err) + cli.logger.Errorf("failed to delete auth code %v", err) delErr = fmt.Errorf("failed to delete auth code: %v", err) } result.AuthCodes++