diff --git a/pkg/server/api/handlers/auth.go b/pkg/server/api/handlers/auth.go index 0c34cf6a..0cc613bc 100644 --- a/pkg/server/api/handlers/auth.go +++ b/pkg/server/api/handlers/auth.go @@ -53,8 +53,6 @@ type Session struct { func makeSession(user database.User, account database.Account) Session { legacy := account.AuthKeyHash == "" - log.Printf("account is %+v", account) - return Session{ // TODO: remove ID and use UUID ID: user.ID, @@ -75,7 +73,7 @@ func makeSession(user database.User, account database.Account) Session { func (a *App) getMe(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } @@ -83,7 +81,7 @@ func (a *App) getMe(w http.ResponseWriter, r *http.Request) { var account database.Account if err := db.Where("user_id = ?", user.ID).First(&account).Error; err != nil { - http.Error(w, "finding account", http.StatusInternalServerError) + handleError(w, "finding account", err, http.StatusInternalServerError) return } @@ -103,18 +101,14 @@ func (a *App) getMe(w http.ResponseWriter, r *http.Request) { } tx.Commit() - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(response); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, response) } // OauthCallbackHandler handler func (a *App) oauthCallbackHandler(w http.ResponseWriter, r *http.Request) { githubUser, err := gothic.CompleteUserAuth(w, r) if err != nil { - http.Error(w, errors.Wrap(err, "completing user uath").Error(), http.StatusInternalServerError) + handleError(w, "completing user uath", err, http.StatusInternalServerError) return } @@ -124,13 +118,13 @@ func (a *App) oauthCallbackHandler(w http.ResponseWriter, r *http.Request) { currentUser, err := findUserFromOauth(githubUser, tx) if err != nil { tx.Rollback() - http.Error(w, errors.Wrap(err, "Failed to upsert user").Error(), http.StatusInternalServerError) + handleError(w, "Failed to upsert user", err, http.StatusInternalServerError) return } err = operations.TouchLastLoginAt(currentUser, tx) if err != nil { tx.Rollback() - http.Error(w, errors.Wrap(err, "touching login timestamp").Error(), http.StatusInternalServerError) + handleError(w, "touching login timestamp", err, http.StatusInternalServerError) return } @@ -182,7 +176,7 @@ func (a *App) legacyPasswordLogin(w http.ResponseWriter, r *http.Request) { var params legacyPasswordLoginPayload err := json.NewDecoder(r.Body).Decode(¶ms) if err != nil { - http.Error(w, errors.Wrap(err, "decoding payload").Error(), http.StatusInternalServerError) + handleError(w, "decoding payload", err, http.StatusInternalServerError) return } @@ -192,7 +186,7 @@ func (a *App) legacyPasswordLogin(w http.ResponseWriter, r *http.Request) { http.Error(w, "Wrong email and password combination", http.StatusUnauthorized) return } else if conn.Error != nil { - http.Error(w, errors.Wrap(err, "getting user").Error(), http.StatusInternalServerError) + handleError(w, "getting user", err, http.StatusInternalServerError) return } @@ -206,7 +200,7 @@ func (a *App) legacyPasswordLogin(w http.ResponseWriter, r *http.Request) { var user database.User err = db.Where("id = ?", account.UserID).First(&user).Error if err != nil { - http.Error(w, errors.Wrap(err, "finding user").Error(), http.StatusInternalServerError) + handleError(w, "finding user", err, http.StatusInternalServerError) return } @@ -215,7 +209,7 @@ func (a *App) legacyPasswordLogin(w http.ResponseWriter, r *http.Request) { err = operations.TouchLastLoginAt(user, tx) if err != nil { tx.Rollback() - http.Error(w, errors.Wrap(err, "touching login timestamp").Error(), http.StatusInternalServerError) + handleError(w, "touching login timestamp", err, http.StatusInternalServerError) return } @@ -229,11 +223,7 @@ func (a *App) legacyPasswordLogin(w http.ResponseWriter, r *http.Request) { } setAuthCookie(w, user) - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(response); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, response) } type legacyRegisterPayload struct { @@ -263,7 +253,7 @@ func validateLegacyRegisterPayload(p legacyRegisterPayload) error { func (a *App) legacyRegister(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } @@ -271,11 +261,11 @@ func (a *App) legacyRegister(w http.ResponseWriter, r *http.Request) { var params legacyRegisterPayload if err := json.NewDecoder(r.Body).Decode(¶ms); err != nil { - http.Error(w, errors.Wrap(err, "decoding payload").Error(), http.StatusInternalServerError) + handleError(w, "decoding payload", err, http.StatusInternalServerError) return } if err := validateLegacyRegisterPayload(params); err != nil { - http.Error(w, errors.Wrap(err, "validating payload").Error(), http.StatusBadRequest) + handleError(w, "validating payload", err, http.StatusBadRequest) return } @@ -284,7 +274,7 @@ func (a *App) legacyRegister(w http.ResponseWriter, r *http.Request) { err := operations.LegacyRegisterUser(tx, user.ID, params.Email, params.AuthKey, params.CipherKeyEnc, params.Iteration) if err != nil { tx.Rollback() - http.Error(w, "creating user", http.StatusBadRequest) + handleError(w, "creating user", err, http.StatusBadRequest) return } @@ -292,7 +282,7 @@ func (a *App) legacyRegister(w http.ResponseWriter, r *http.Request) { var account database.Account if err := db.Where("user_id = ?", user.ID).First(&account).Error; err != nil { - http.Error(w, "finding account", http.StatusInternalServerError) + handleError(w, "finding account", err, http.StatusInternalServerError) return } @@ -302,14 +292,14 @@ func (a *App) legacyRegister(w http.ResponseWriter, r *http.Request) { func (a *App) legacyMigrate(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } db := database.DBConn if err := db.Model(&user).Update("encrypted = ?", true).Error; err != nil { - http.Error(w, "updating user", http.StatusInternalServerError) + handleError(w, "updating user", err, http.StatusInternalServerError) return } } diff --git a/pkg/server/api/handlers/digests.go b/pkg/server/api/handlers/digests.go index 8a12b6ad..3f9a002d 100644 --- a/pkg/server/api/handlers/digests.go +++ b/pkg/server/api/handlers/digests.go @@ -19,12 +19,10 @@ package handlers import ( - "encoding/json" "net/http" "strconv" "github.com/dnote/dnote/pkg/server/api/helpers" - "github.com/dnote/dnote/pkg/server/api/logger" "github.com/dnote/dnote/pkg/server/api/presenters" "github.com/dnote/dnote/pkg/server/database" "github.com/gorilla/mux" @@ -37,26 +35,22 @@ func respondWithDigest(w http.ResponseWriter, userID int, digestUUID string) { var digest database.Digest conn := db.Preload("Notes.Book").Where("user_id = ? AND uuid = ? ", userID, digestUUID).First(&digest) if conn.RecordNotFound() { - http.Error(w, "finding digest", http.StatusNotFound) + handleError(w, "digest not found", nil, http.StatusNotFound) return } else if err := conn.Error; err != nil { - logger.Err("finding digest %s", err.Error()) - http.Error(w, "finding digest", http.StatusInternalServerError) + + handleError(w, "finding digest", err, http.StatusInternalServerError) return } - w.Header().Set("Content-Type", "application/json") presented := presenters.PresentDigest(digest) - if err := json.NewEncoder(w).Encode(presented); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, presented) } func (a App) getDigest(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } @@ -69,7 +63,7 @@ func (a App) getDigest(w http.ResponseWriter, r *http.Request) { func (a App) getDemoDigest(w http.ResponseWriter, r *http.Request) { userID, err := helpers.GetDemoUserID() if err != nil { - http.Error(w, errors.Wrap(err, "finding demo user").Error(), http.StatusInternalServerError) + handleError(w, "finding demo user", err, http.StatusInternalServerError) return } @@ -108,7 +102,7 @@ func respondWithDigests(w http.ResponseWriter, r *http.Request, userID int) { page, err := parseGetDigestsParams(r) if err != nil { - http.Error(w, "parsing params", http.StatusBadRequest) + handleError(w, "parsing params", err, http.StatusBadRequest) return } perPage := 25 @@ -117,15 +111,13 @@ func respondWithDigests(w http.ResponseWriter, r *http.Request, userID int) { var digests []database.Digest conn := db.Where("user_id = ?", userID).Order("created_at DESC").Offset(offset).Limit(perPage) if err := conn.Find(&digests).Error; err != nil { - logger.Err("finding digests %s", err.Error()) - http.Error(w, "finding digests", http.StatusInternalServerError) + handleError(w, "finding digests", err, http.StatusInternalServerError) return } var total int if err := db.Model(database.Digest{}).Where("user_id = ?", userID).Count(&total).Error; err != nil { - logger.Err("counting digests %s", err.Error()) - http.Error(w, "finding digests", http.StatusInternalServerError) + handleError(w, "counting digests", err, http.StatusInternalServerError) return } @@ -133,17 +125,13 @@ func respondWithDigests(w http.ResponseWriter, r *http.Request, userID int) { Total: total, Digests: presenters.PresentDigests(digests), } - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(res); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, res) } func (a *App) getDigests(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } @@ -153,7 +141,7 @@ func (a *App) getDigests(w http.ResponseWriter, r *http.Request) { func (a *App) getDemoDigests(w http.ResponseWriter, r *http.Request) { userID, err := helpers.GetDemoUserID() if err != nil { - http.Error(w, errors.Wrap(err, "finding demo user").Error(), http.StatusInternalServerError) + handleError(w, "finding demo user", err, http.StatusInternalServerError) return } diff --git a/pkg/server/api/handlers/helpers.go b/pkg/server/api/handlers/helpers.go index fe3d7021..62afd60b 100644 --- a/pkg/server/api/handlers/helpers.go +++ b/pkg/server/api/handlers/helpers.go @@ -21,11 +21,12 @@ package handlers import ( crand "crypto/rand" "encoding/base64" + "encoding/json" "net/http" "strings" - "github.com/dnote/dnote/pkg/server/api/logger" "github.com/dnote/dnote/pkg/server/database" + "github.com/dnote/dnote/pkg/server/log" "github.com/jinzhu/gorm" "github.com/pkg/errors" ) @@ -108,9 +109,26 @@ func getClientType(origin string) string { } // handleError logs the error and responds with the given status code with a generic status text -func handleError(w http.ResponseWriter, logMessage string, err error, statusCode int) { - logger.Err("[%d] %s: %v\n", statusCode, logMessage, err) +func handleError(w http.ResponseWriter, msg string, err error, statusCode int) { + var message string + if err == nil { + message = msg + } else { + message = errors.Wrap(err, msg).Error() + } + + log.WithFields(log.Fields{ + "statusCode": statusCode, + }).Error(message) statusText := http.StatusText(statusCode) http.Error(w, statusText, statusCode) } + +// respondJSON encodes the given payload into a JSON format and writes it to the given response writer +func respondJSON(w http.ResponseWriter, payload interface{}) { + w.Header().Set("Content-Type", "application/json") + if err := json.NewEncoder(w).Encode(payload); err != nil { + handleError(w, "encoding response", err, http.StatusInternalServerError) + } +} diff --git a/pkg/server/api/handlers/limit.go b/pkg/server/api/handlers/limit.go index b3669d67..5e3f7267 100644 --- a/pkg/server/api/handlers/limit.go +++ b/pkg/server/api/handlers/limit.go @@ -24,6 +24,7 @@ import ( "sync" "time" + "github.com/dnote/dnote/pkg/server/log" "golang.org/x/time/rate" ) @@ -112,6 +113,9 @@ func limit(next http.Handler) http.HandlerFunc { if !limiter.Allow() { http.Error(w, "Too many requests", http.StatusTooManyRequests) + log.WithFields(log.Fields{ + "ip": identifier, + }).Warn("Too many requests") return } diff --git a/pkg/server/api/handlers/notes.go b/pkg/server/api/handlers/notes.go index 6d34f353..e5b9fcb0 100644 --- a/pkg/server/api/handlers/notes.go +++ b/pkg/server/api/handlers/notes.go @@ -19,7 +19,6 @@ package handlers import ( - "encoding/json" "net/http" "net/url" "strconv" @@ -37,11 +36,7 @@ import ( func respondWithNote(w http.ResponseWriter, note database.Note) { presentedNote := presenters.PresentNote(note) - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(presentedNote); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, presentedNote) } func preloadNote(conn *gorm.DB) *gorm.DB { @@ -55,7 +50,7 @@ func (a *App) getDemoNote(w http.ResponseWriter, r *http.Request) { demoUserID, err := helpers.GetDemoUserID() if err != nil { - http.Error(w, errors.Wrap(err, "finding demo user").Error(), http.StatusInternalServerError) + handleError(w, "finding demo user", err, http.StatusInternalServerError) return } @@ -65,10 +60,10 @@ func (a *App) getDemoNote(w http.ResponseWriter, r *http.Request) { conn.Find(¬e) if conn.RecordNotFound() { - http.Error(w, "not found", http.StatusNotFound) + handleError(w, "not found", nil, http.StatusNotFound) return } else if err := conn.Error; err != nil { - http.Error(w, errors.Wrap(err, "finding note").Error(), http.StatusInternalServerError) + handleError(w, "finding note", err, http.StatusInternalServerError) return } @@ -78,7 +73,7 @@ func (a *App) getDemoNote(w http.ResponseWriter, r *http.Request) { func (a *App) getNote(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } @@ -87,15 +82,15 @@ func (a *App) getNote(w http.ResponseWriter, r *http.Request) { noteUUID := vars["noteUUID"] var note database.Note - conn := db.Debug().Where("uuid = ? AND user_id = ?", noteUUID, user.ID) + conn := db.Where("uuid = ? AND user_id = ?", noteUUID, user.ID) conn = preloadNote(conn) conn.Find(¬e) if conn.RecordNotFound() { - http.Error(w, "not found", http.StatusNotFound) + handleError(w, "not found", nil, http.StatusNotFound) return } else if err := conn.Error; err != nil { - http.Error(w, errors.Wrap(err, "finding note").Error(), http.StatusInternalServerError) + handleError(w, "finding note", err, http.StatusInternalServerError) return } @@ -114,7 +109,7 @@ type GetNotesResponse struct { func (a *App) getDemoNotes(w http.ResponseWriter, r *http.Request) { userID, err := helpers.GetDemoUserID() if err != nil { - http.Error(w, errors.Wrap(err, "finding demo user id").Error(), http.StatusInternalServerError) + handleError(w, "finding demo user id", err, http.StatusInternalServerError) return } query := r.URL.Query() @@ -125,7 +120,7 @@ func (a *App) getDemoNotes(w http.ResponseWriter, r *http.Request) { func (a *App) getNotes(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } query := r.URL.Query() @@ -136,13 +131,13 @@ func (a *App) getNotes(w http.ResponseWriter, r *http.Request) { func respondGetNotes(userID int, query url.Values, w http.ResponseWriter) { err := validateGetNotesQuery(query) if err != nil { - http.Error(w, errors.Wrap(err, "validating query parameters").Error(), http.StatusBadRequest) + handleError(w, "validating query parameters", err, http.StatusBadRequest) return } q, err := parseGetNotesQuery(query) if err != nil { - http.Error(w, errors.Wrap(err, "parsing query parameters").Error(), http.StatusBadRequest) + handleError(w, "parsing query parameters", err, http.StatusBadRequest) return } @@ -152,9 +147,9 @@ func respondGetNotes(userID int, query url.Values, w http.ResponseWriter) { conn := baseConn.Where("notes.added_on >= ? AND notes.added_on < ?", dateLowerbound, dateUpperbound) var total int - err = conn.Debug().Model(database.Note{}).Count(&total).Error + err = conn.Model(database.Note{}).Count(&total).Error if err != nil { - http.Error(w, errors.Wrap(err, "counting total").Error(), http.StatusInternalServerError) + handleError(w, "counting total", err, http.StatusInternalServerError) return } @@ -166,7 +161,7 @@ func respondGetNotes(userID int, query url.Values, w http.ResponseWriter) { err = conn.Find(¬es).Error if err != nil { - http.Error(w, errors.Wrap(err, "finding notes").Error(), http.StatusInternalServerError) + handleError(w, "finding notes", err, http.StatusInternalServerError) return } } @@ -182,7 +177,7 @@ func respondGetNotes(userID int, query url.Values, w http.ResponseWriter) { prevDate, err := getPrevDate(baseConn, prevDateUpperbound) if err != nil { - http.Error(w, errors.Wrap(err, "getting prevDate").Error(), http.StatusInternalServerError) + handleError(w, "getting prevDate", err, http.StatusInternalServerError) return } @@ -193,12 +188,7 @@ func respondGetNotes(userID int, query url.Values, w http.ResponseWriter) { Total: total, PrevDate: prevDate, } - - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(response); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, response) } func getPrevDate(baseConn *gorm.DB, dateUpperbound int64) (*int64, error) { @@ -328,21 +318,17 @@ func orderGetNotes(conn *gorm.DB) *gorm.DB { func (a *App) legacyGetNotes(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } var notes []database.Note db := database.DBConn if err := db.Where("user_id = ? AND encrypted = false", user.ID).Find(¬es).Error; err != nil { - http.Error(w, "finding notes", http.StatusInternalServerError) + handleError(w, "finding notes", err, http.StatusInternalServerError) return } presented := presenters.PresentNotes(notes) - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(presented); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, presented) } diff --git a/pkg/server/api/handlers/routes.go b/pkg/server/api/handlers/routes.go index c5a7c05b..88a6de69 100644 --- a/pkg/server/api/handlers/routes.go +++ b/pkg/server/api/handlers/routes.go @@ -20,7 +20,7 @@ package handlers import ( "context" - "log" + "fmt" "net/http" "os" "strings" @@ -28,8 +28,8 @@ import ( "github.com/dnote/dnote/pkg/clock" "github.com/dnote/dnote/pkg/server/api/helpers" - "github.com/dnote/dnote/pkg/server/api/logger" "github.com/dnote/dnote/pkg/server/database" + "github.com/dnote/dnote/pkg/server/log" "github.com/gorilla/mux" "github.com/markbates/goth/gothic" "github.com/pkg/errors" @@ -153,8 +153,7 @@ func authWithSession(r *http.Request) (database.User, bool, error) { sessionKey, err := getCredential(r) if err != nil { - logger.Err(errors.Wrap(err, "getting credential").Error()) - return user, false, err + return user, false, errors.Wrap(err, "getting credential") } if sessionKey == "" { @@ -167,8 +166,7 @@ func authWithSession(r *http.Request) (database.User, bool, error) { if conn.RecordNotFound() { return user, false, nil } else if err := conn.Error; err != nil { - logger.Err(errors.Wrap(err, "finding session").Error()) - return user, false, err + return user, false, errors.Wrap(err, "finding session") } if session.ExpiresAt.Before(time.Now()) { @@ -180,8 +178,7 @@ func authWithSession(r *http.Request) (database.User, bool, error) { if conn.RecordNotFound() { return user, false, nil } else if err := conn.Error; err != nil { - logger.Err(errors.Wrap(err, "finding user from token").Error()) - return user, false, err + return user, false, errors.Wrap(err, "finding user from token") } return user, true, nil @@ -202,8 +199,7 @@ func authWithToken(r *http.Request, tokenType string) (database.User, database.T if conn.RecordNotFound() { return user, token, false, nil } else if err := conn.Error; err != nil { - logger.Err(errors.Wrap(err, "finding token").Error()) - return user, token, false, err + return user, token, false, errors.Wrap(err, "finding token") } if token.UsedAt != nil && time.Since(*token.UsedAt).Minutes() > 10 { @@ -211,8 +207,7 @@ func authWithToken(r *http.Request, tokenType string) (database.User, database.T } if err := db.Where("id = ?", token.UserID).First(&user).Error; err != nil { - logger.Err(errors.Wrap(err, "finding user").Error()) - return user, token, false, err + return user, token, false, errors.Wrap(err, "finding user") } return user, token, true, nil @@ -247,7 +242,7 @@ func tokenAuth(next http.HandlerFunc, tokenType string) http.HandlerFunc { user, token, ok, err := authWithToken(r, tokenType) if err != nil { // log the error and continue - logger.Err(errors.Wrap(err, "authenticating with token").Error()) + log.ErrorWrap(err, "authenticating with token") } ctx := r.Context() @@ -259,7 +254,7 @@ func tokenAuth(next http.HandlerFunc, tokenType string) http.HandlerFunc { user, ok, err = authWithSession(r) if err != nil { // log the error and continue - logger.Err(errors.Wrap(err, "authenticating with session").Error()) + log.ErrorWrap(err, "authenticating with session") } if !ok { @@ -286,18 +281,34 @@ func cors(next http.HandlerFunc) http.HandlerFunc { }) } +// logResponseWriter wraps http.ResponseWriter to expose HTTP status code for logging. +// The optional interfaces of http.ResponseWriter are lost because of the wrapping, and +// such interfaces should be implemented if needed. (i.e. http.Pusher, http.Flusher, etc.) +type logResponseWriter struct { + http.ResponseWriter + statusCode int +} + +func (w *logResponseWriter) WriteHeader(code int) { + w.statusCode = code + w.ResponseWriter.WriteHeader(code) +} + func logging(inner http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { start := time.Now() - inner.ServeHTTP(w, r) + lw := logResponseWriter{w, http.StatusOK} + inner.ServeHTTP(&lw, r) - log.Printf( - "%s\t%s\t%s", - r.Method, - r.RequestURI, - time.Since(start), - ) + log.WithFields(log.Fields{ + "remoteAddr": r.RemoteAddr, + "uri": r.RequestURI, + "statusCode": lw.statusCode, + "method": r.Method, + "duration": fmt.Sprintf("%dms", time.Since(start)/1000000), + "userAgent": r.Header.Get("User-Agent"), + }).Info("incoming request") }) } diff --git a/pkg/server/api/handlers/subscription.go b/pkg/server/api/handlers/subscription.go index d77c19be..948e1232 100644 --- a/pkg/server/api/handlers/subscription.go +++ b/pkg/server/api/handlers/subscription.go @@ -116,7 +116,7 @@ type createSubPayload struct { func (a *App) createSub(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } @@ -206,11 +206,11 @@ func validateUpdateSubPayload(p updateSubPayload) error { func (a *App) updateSub(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } if user.StripeCustomerID == "" { - http.Error(w, "Customer does not exist", http.StatusForbidden) + handleError(w, "Customer does not exist", nil, http.StatusForbidden) return } @@ -277,7 +277,7 @@ func respondWithEmptySub(w http.ResponseWriter) { func (a *App) getSub(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } if user.StripeCustomerID == "" { @@ -319,11 +319,7 @@ func (a *App) getSub(w http.ResponseWriter, r *http.Request) { resp.Items = append(resp.Items, i) } - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(resp); err != nil { - handleError(w, "encoding response", err, http.StatusInternalServerError) - return - } + respondJSON(w, resp) } // GetStripeSourceResponse is a response for getStripeToken @@ -337,11 +333,7 @@ type GetStripeSourceResponse struct { func respondWithEmptyStripeToken(w http.ResponseWriter) { var resp GetStripeSourceResponse - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(resp); err != nil { - handleError(w, "encoding response", err, http.StatusInternalServerError) - return - } + respondJSON(w, resp) } // getStripeCard retrieves card information from stripe and returns a stripe.Card @@ -397,7 +389,7 @@ func getStripeCard(stripeCustomerID, sourceID string) (*stripe.Card, error) { func (a *App) getStripeSource(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } if user.StripeCustomerID == "" { @@ -429,11 +421,7 @@ func (a *App) getStripeSource(w http.ResponseWriter, r *http.Request) { ExpYear: cd.ExpYear, } - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(resp); err != nil { - handleError(w, "encoding response", err, http.StatusInternalServerError) - return - } + respondJSON(w, resp) } func (a *App) stripeWebhook(w http.ResponseWriter, req *http.Request) { diff --git a/pkg/server/api/handlers/user.go b/pkg/server/api/handlers/user.go index 8af7e1f3..da973c1e 100644 --- a/pkg/server/api/handlers/user.go +++ b/pkg/server/api/handlers/user.go @@ -27,9 +27,8 @@ import ( "github.com/dnote/dnote/pkg/server/api/helpers" "github.com/dnote/dnote/pkg/server/api/operations" "github.com/dnote/dnote/pkg/server/database" + "github.com/dnote/dnote/pkg/server/log" "github.com/dnote/dnote/pkg/server/mailer" - - "github.com/pkg/errors" ) type updateProfilePayload struct { @@ -42,14 +41,14 @@ func (a *App) updateProfile(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } var params updateProfilePayload err := json.NewDecoder(r.Body).Decode(¶ms) if err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) + handleError(w, "decoding params", err, http.StatusInternalServerError) return } @@ -62,7 +61,7 @@ func (a *App) updateProfile(w http.ResponseWriter, r *http.Request) { var account database.Account err = db.Where("user_id = ?", user.ID).First(&account).Error if err != nil { - http.Error(w, errors.Wrap(err, "finding account").Error(), http.StatusInternalServerError) + handleError(w, "finding account", err, http.StatusInternalServerError) return } @@ -70,24 +69,19 @@ func (a *App) updateProfile(w http.ResponseWriter, r *http.Request) { user.Name = params.Name if err := tx.Save(&user).Error; err != nil { tx.Rollback() - http.Error(w, errors.Wrap(err, "saving user").Error(), http.StatusInternalServerError) + handleError(w, "saving user", err, http.StatusInternalServerError) return } if err := tx.Save(&account).Error; err != nil { tx.Rollback() - http.Error(w, errors.Wrap(err, "saving user").Error(), http.StatusInternalServerError) + handleError(w, "saving user", err, http.StatusInternalServerError) return } tx.Commit() session := makeSession(user, account) - - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(session); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, session) } type updateEmailPayload struct { @@ -103,14 +97,14 @@ func (a *App) updateEmail(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } var params updateEmailPayload err := json.NewDecoder(r.Body).Decode(¶ms) if err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) + handleError(w, "decoding params", err, http.StatusInternalServerError) return } @@ -123,7 +117,7 @@ func (a *App) updateEmail(w http.ResponseWriter, r *http.Request) { var account database.Account err = db.Where("user_id = ?", user.ID).First(&account).Error if err != nil { - http.Error(w, errors.Wrap(err, "finding account").Error(), http.StatusInternalServerError) + handleError(w, "finding account", err, http.StatusInternalServerError) return } @@ -148,18 +142,13 @@ func (a *App) updateEmail(w http.ResponseWriter, r *http.Request) { if err := tx.Save(&account).Error; err != nil { tx.Rollback() - http.Error(w, errors.Wrap(err, "saving account").Error(), http.StatusInternalServerError) + handleError(w, "saving account", err, http.StatusInternalServerError) return } tx.Commit() session := makeSession(user, account) - - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(session); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, session) } func respondWithCalendar(w http.ResponseWriter, userID int) { @@ -171,7 +160,7 @@ func respondWithCalendar(w http.ResponseWriter, userID int) { Order("added_date DESC").Rows() if err != nil { - http.Error(w, errors.Wrap(err, "Failed to count lessons").Error(), http.StatusInternalServerError) + handleError(w, "Failed to count lessons", err, http.StatusInternalServerError) return } @@ -182,22 +171,18 @@ func respondWithCalendar(w http.ResponseWriter, userID int) { var d time.Time if err := rows.Scan(&count, &d); err != nil { - http.Error(w, errors.Wrap(err, "counting notes").Error(), http.StatusInternalServerError) + handleError(w, "counting notes", err, http.StatusInternalServerError) } payload[d.Format("2006-1-2")] = count } - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(payload); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, payload) } func (a *App) getCalendar(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } @@ -207,7 +192,7 @@ func (a *App) getCalendar(w http.ResponseWriter, r *http.Request) { func (a *App) getDemoCalendar(w http.ResponseWriter, r *http.Request) { userID, err := helpers.GetDemoUserID() if err != nil { - http.Error(w, errors.Wrap(err, "finding demo user").Error(), http.StatusInternalServerError) + handleError(w, "finding demo user", err, http.StatusInternalServerError) return } @@ -219,14 +204,14 @@ func (a *App) createVerificationToken(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } var account database.Account err := db.Where("user_id = ?", user.ID).First(&account).Error if err != nil { - http.Error(w, errors.WithMessage(err, "finding account").Error(), http.StatusInternalServerError) + handleError(w, "finding account", err, http.StatusInternalServerError) return } @@ -241,7 +226,7 @@ func (a *App) createVerificationToken(w http.ResponseWriter, r *http.Request) { tokenValue, err := generateVerificationCode() if err != nil { - http.Error(w, errors.Wrap(err, "generating verification code").Error(), http.StatusInternalServerError) + handleError(w, "generating verification code", err, http.StatusInternalServerError) return } @@ -252,7 +237,7 @@ func (a *App) createVerificationToken(w http.ResponseWriter, r *http.Request) { } if err := db.Save(&token).Error; err != nil { - http.Error(w, errors.Wrap(err, "saving token").Error(), http.StatusInternalServerError) + handleError(w, "saving token", err, http.StatusInternalServerError) return } @@ -266,12 +251,12 @@ func (a *App) createVerificationToken(w http.ResponseWriter, r *http.Request) { } email := mailer.NewEmail("noreply@dnote.io", []string{account.Email.String}, subject) if err := email.ParseTemplate(mailer.EmailTypeEmailVerification, data); err != nil { - http.Error(w, errors.Wrap(err, "parsing template").Error(), http.StatusInternalServerError) + handleError(w, "parsing template", err, http.StatusInternalServerError) return } if err := email.Send(); err != nil { - http.Error(w, errors.Wrap(err, "sending email").Error(), http.StatusInternalServerError) + handleError(w, "sending email", err, http.StatusInternalServerError) return } @@ -287,7 +272,7 @@ func (a *App) verifyEmail(w http.ResponseWriter, r *http.Request) { var params verifyEmailPayload if err := json.NewDecoder(r.Body).Decode(¶ms); err != nil { - http.Error(w, errors.Wrap(err, "decoding payload").Error(), http.StatusInternalServerError) + handleError(w, "decoding payload", err, http.StatusInternalServerError) return } @@ -312,7 +297,7 @@ func (a *App) verifyEmail(w http.ResponseWriter, r *http.Request) { var account database.Account if err := db.Where("user_id = ?", token.UserID).First(&account).Error; err != nil { - http.Error(w, errors.WithMessage(err, "finding account").Error(), http.StatusInternalServerError) + handleError(w, "finding account", err, http.StatusInternalServerError) return } if account.EmailVerified { @@ -324,29 +309,25 @@ func (a *App) verifyEmail(w http.ResponseWriter, r *http.Request) { account.EmailVerified = true if err := tx.Save(&account).Error; err != nil { tx.Rollback() - http.Error(w, errors.WithMessage(err, "updating email_verified").Error(), http.StatusInternalServerError) + handleError(w, "updating email_verified", err, http.StatusInternalServerError) return } if err := tx.Model(&token).Update("used_at", time.Now()).Error; err != nil { tx.Rollback() - http.Error(w, errors.WithMessage(err, "updating reset token").Error(), http.StatusInternalServerError) + handleError(w, "updating reset token", err, http.StatusInternalServerError) return } tx.Commit() var user database.User if err := db.Where("id = ?", token.UserID).First(&user).Error; err != nil { - http.Error(w, errors.WithMessage(err, "finding user").Error(), http.StatusInternalServerError) + handleError(w, "finding user", err, http.StatusInternalServerError) return } session := makeSession(user, account) setAuthCookie(w, user) - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(session); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, session) } type updateEmailPreferencePayload struct { @@ -358,19 +339,19 @@ func (a *App) updateEmailPreference(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } var params updateEmailPreferencePayload if err := json.NewDecoder(r.Body).Decode(¶ms); err != nil { - http.Error(w, errors.Wrap(err, "decoding payload").Error(), http.StatusInternalServerError) + handleError(w, "decoding payload", err, http.StatusInternalServerError) return } var frequency database.EmailPreference if err := db.Where(database.EmailPreference{UserID: user.ID}).FirstOrCreate(&frequency).Error; err != nil { - http.Error(w, errors.Wrap(err, "finding frequency").Error(), http.StatusInternalServerError) + handleError(w, "finding frequency", err, http.StatusInternalServerError) return } @@ -379,7 +360,7 @@ func (a *App) updateEmailPreference(w http.ResponseWriter, r *http.Request) { frequency.DigestWeekly = params.DigestWeekly if err := tx.Save(&frequency).Error; err != nil { tx.Rollback() - http.Error(w, errors.Wrap(err, "saving frequency").Error(), http.StatusInternalServerError) + handleError(w, "saving frequency", err, http.StatusInternalServerError) return } @@ -388,18 +369,14 @@ func (a *App) updateEmailPreference(w http.ResponseWriter, r *http.Request) { // Use token if the user was authenticated by token if err := tx.Model(&token).Update("used_at", time.Now()).Error; err != nil { tx.Rollback() - http.Error(w, errors.WithMessage(err, "updating reset token").Error(), http.StatusInternalServerError) + handleError(w, "updating reset token", err, http.StatusInternalServerError) return } } tx.Commit() - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(frequency); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, frequency) } func (a *App) getEmailPreference(w http.ResponseWriter, r *http.Request) { @@ -407,21 +384,17 @@ func (a *App) getEmailPreference(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } var pref database.EmailPreference if err := db.Where(database.EmailPreference{UserID: user.ID}).First(&pref).Error; err != nil { - http.Error(w, errors.Wrap(err, "finding pref").Error(), http.StatusInternalServerError) + handleError(w, "finding pref", err, http.StatusInternalServerError) return } - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(pref); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, pref) } type updatePasswordPayload struct { @@ -436,23 +409,26 @@ func (a *App) updatePassword(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } var account database.Account if err := db.Where("user_id = ?", user.ID).First(&account).Error; err != nil { - http.Error(w, errors.Wrap(err, "getting account").Error(), http.StatusInternalServerError) + handleError(w, "getting account", err, http.StatusInternalServerError) return } var params updatePasswordPayload if err := json.NewDecoder(r.Body).Decode(¶ms); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) + handleError(w, "decoding params", err, http.StatusInternalServerError) return } oldAuthKeyHash := crypt.HashAuthKey(params.OldAuthKey, account.Salt, account.ServerKDFIteration) if oldAuthKeyHash != account.AuthKeyHash { http.Error(w, ErrLoginFailure.Error(), http.StatusUnauthorized) + log.WithFields(log.Fields{ + "account_id": account.ID, + }).Error("Existing password mismatch") return } @@ -460,19 +436,18 @@ func (a *App) updatePassword(w http.ResponseWriter, r *http.Request) { if err := db. Model(&account). - Debug(). Updates(map[string]interface{}{ "auth_key_hash": newAuthKeyHash, "client_kdf_iteration": params.NewKDFIteration, "server_kdf_iteration": account.ServerKDFIteration, "cipher_key_enc": params.NewCipherKeyEnc, }).Error; err != nil { - http.Error(w, errors.Wrap(err, "updating account").Error(), http.StatusInternalServerError) + handleError(w, "updating account", err, http.StatusInternalServerError) return } if err := operations.DeleteUserSessions(db, user.ID); err != nil { - http.Error(w, "deleting user sessions", http.StatusBadRequest) + handleError(w, "deleting user sessions", err, http.StatusBadRequest) return } diff --git a/pkg/server/api/handlers/v1_auth.go b/pkg/server/api/handlers/v1_auth.go index 659dd695..c7207d48 100644 --- a/pkg/server/api/handlers/v1_auth.go +++ b/pkg/server/api/handlers/v1_auth.go @@ -23,11 +23,11 @@ import ( "net/http" "time" - "github.com/pkg/errors" - "github.com/dnote/dnote/pkg/server/api/crypt" "github.com/dnote/dnote/pkg/server/api/operations" "github.com/dnote/dnote/pkg/server/database" + "github.com/dnote/dnote/pkg/server/log" + "github.com/pkg/errors" ) // ErrLoginFailure is an error for failed login @@ -75,7 +75,7 @@ func (a *App) signin(w http.ResponseWriter, r *http.Request) { var params signinPayload if err := json.NewDecoder(r.Body).Decode(¶ms); err != nil { - http.Error(w, errors.Wrap(err, "decoding payload").Error(), http.StatusInternalServerError) + handleError(w, "decoding payload", err, http.StatusInternalServerError) return } @@ -90,12 +90,15 @@ func (a *App) signin(w http.ResponseWriter, r *http.Request) { http.Error(w, ErrLoginFailure.Error(), http.StatusUnauthorized) return } else if err := conn.Error; err != nil { - http.Error(w, errors.Wrap(err, "getting user").Error(), http.StatusInternalServerError) + handleError(w, "getting user", err, http.StatusInternalServerError) return } authKeyHash := crypt.HashAuthKey(params.AuthKey, account.Salt, account.ServerKDFIteration) if account.AuthKeyHash != authKeyHash { + log.WithFields(log.Fields{ + "account_id": account.ID, + }).Error("Sign in password mismatch") http.Error(w, ErrLoginFailure.Error(), http.StatusUnauthorized) return } @@ -111,7 +114,7 @@ func (a *App) signoutOptions(w http.ResponseWriter, r *http.Request) { func (a *App) signout(w http.ResponseWriter, r *http.Request) { key, err := getCredential(r) if err != nil { - http.Error(w, "getting credential", http.StatusInternalServerError) + handleError(w, "getting credential", nil, http.StatusInternalServerError) return } @@ -122,7 +125,7 @@ func (a *App) signout(w http.ResponseWriter, r *http.Request) { err = operations.DeleteSession(database.DBConn, key) if err != nil { - http.Error(w, "deleting session", http.StatusInternalServerError) + handleError(w, "deleting session", nil, http.StatusInternalServerError) return } @@ -159,17 +162,17 @@ func (a *App) register(w http.ResponseWriter, r *http.Request) { var params registerPayload if err := json.NewDecoder(r.Body).Decode(¶ms); err != nil { - http.Error(w, errors.Wrap(err, "decoding payload").Error(), http.StatusInternalServerError) + handleError(w, "decoding payload", err, http.StatusInternalServerError) return } if err := validateRegisterPayload(params); err != nil { - http.Error(w, errors.Wrap(err, "validating payload").Error(), http.StatusBadRequest) + handleError(w, "validating payload", err, http.StatusBadRequest) return } var count int if err := db.Model(database.Account{}).Where("email = ?", params.Email).Count(&count).Error; err != nil { - http.Error(w, errors.Wrap(err, "checking duplicate").Error(), http.StatusInternalServerError) + handleError(w, "checking duplicate", err, http.StatusInternalServerError) return } if count > 0 { @@ -182,14 +185,15 @@ func (a *App) register(w http.ResponseWriter, r *http.Request) { user, err := operations.CreateUser(tx, params.Email, params.AuthKey, params.CipherKeyEnc, params.Iteration) if err != nil { tx.Rollback() - http.Error(w, "creating user", http.StatusBadRequest) + + handleError(w, "creating user", nil, http.StatusBadRequest) return } var account database.Account if err := tx.Where("user_id = ?", user.ID).First(&account).Error; err != nil { tx.Rollback() - http.Error(w, "finding account", http.StatusBadRequest) + handleError(w, "finding account", nil, http.StatusBadRequest) return } @@ -205,7 +209,7 @@ func respondWithSession(w http.ResponseWriter, userID int, cipherKeyEnc string) session, err := operations.CreateSession(db, userID) if err != nil { - http.Error(w, "creating session", http.StatusBadRequest) + handleError(w, "creating session", nil, http.StatusBadRequest) return } @@ -218,7 +222,7 @@ func respondWithSession(w http.ResponseWriter, userID int, cipherKeyEnc string) } w.Header().Set("Content-Type", "application/json") if err := json.NewEncoder(w).Encode(response); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) + handleError(w, "encoding response", err, http.StatusInternalServerError) return } } @@ -241,7 +245,7 @@ func (a *App) presignin(w http.ResponseWriter, r *http.Request) { var account database.Account conn := db.Where("email = ?", email).First(&account) if !conn.RecordNotFound() && conn.Error != nil { - http.Error(w, errors.Wrap(conn.Error, "getting user").Error(), http.StatusInternalServerError) + handleError(w, "getting user", conn.Error, http.StatusInternalServerError) return } @@ -258,7 +262,7 @@ func (a *App) presignin(w http.ResponseWriter, r *http.Request) { w.Header().Set("Content-Type", "application/json") if err := json.NewEncoder(w).Encode(response); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) + handleError(w, "encoding response", nil, http.StatusInternalServerError) return } } diff --git a/pkg/server/api/handlers/v1_books.go b/pkg/server/api/handlers/v1_books.go index b016e2d4..9d8d6cb3 100644 --- a/pkg/server/api/handlers/v1_books.go +++ b/pkg/server/api/handlers/v1_books.go @@ -56,24 +56,19 @@ func respondWithBooks(userID int, query url.Values, w http.ResponseWriter) { } if err := conn.Find(&books).Error; err != nil { - http.Error(w, errors.Wrap(err, "finding books").Error(), http.StatusInternalServerError) + handleError(w, "finding books", err, http.StatusInternalServerError) return } presentedBooks := presenters.PresentBooks(books) - - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(presentedBooks); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, presentedBooks) } // GetDemoBooks returns books for demo func (a *App) GetDemoBooks(w http.ResponseWriter, r *http.Request) { demoUserID, err := helpers.GetDemoUserID() if err != nil { - http.Error(w, errors.Wrap(err, "finding demo user").Error(), http.StatusInternalServerError) + handleError(w, "finding demo user", err, http.StatusInternalServerError) return } @@ -114,16 +109,12 @@ func (a *App) GetBook(w http.ResponseWriter, r *http.Request) { return } if err := conn.Error; err != nil { - http.Error(w, errors.Wrap(err, "finding book").Error(), http.StatusInternalServerError) + handleError(w, "finding book", err, http.StatusInternalServerError) return } p := presenters.PresentBook(book) - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(p); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, p) } type createBookPayload struct { @@ -173,21 +164,21 @@ func (a *App) UpdateBook(w http.ResponseWriter, r *http.Request) { var book database.Book if err := tx.Where("user_id = ? AND uuid = ?", user.ID, uuid).First(&book).Error; err != nil { - http.Error(w, errors.Wrap(err, "finding book").Error(), http.StatusInternalServerError) + handleError(w, "finding book", err, http.StatusInternalServerError) return } var params updateBookPayload err := json.NewDecoder(r.Body).Decode(¶ms) if err != nil { - http.Error(w, errors.Wrap(err, "decoding payload").Error(), http.StatusInternalServerError) + handleError(w, "decoding payload", err, http.StatusInternalServerError) return } book, err = operations.UpdateBook(tx, a.Clock, user, book, params.Name) if err != nil { tx.Rollback() - http.Error(w, errors.Wrap(err, "updating a book").Error(), http.StatusInternalServerError) + handleError(w, "updating a book", err, http.StatusInternalServerError) } tx.Commit() @@ -195,12 +186,7 @@ func (a *App) UpdateBook(w http.ResponseWriter, r *http.Request) { resp := UpdateBookResp{ Book: presenters.PresentBook(book), } - - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(resp); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, resp) } // DeleteBookResp is the response from create book api @@ -224,25 +210,25 @@ func (a *App) DeleteBook(w http.ResponseWriter, r *http.Request) { var book database.Book if err := tx.Where("user_id = ? AND uuid = ?", user.ID, uuid).First(&book).Error; err != nil { - http.Error(w, errors.Wrap(err, "finding book").Error(), http.StatusInternalServerError) + handleError(w, "finding book", err, http.StatusInternalServerError) return } var notes []database.Note if err := tx.Where("book_uuid = ? AND NOT deleted", uuid).Order("usn ASC").Find(¬es).Error; err != nil { - http.Error(w, errors.Wrap(err, "finding notes").Error(), http.StatusInternalServerError) + handleError(w, "finding notes", err, http.StatusInternalServerError) return } for _, note := range notes { if _, err := operations.DeleteNote(tx, user, note); err != nil { - http.Error(w, errors.Wrap(err, "deleting a note").Error(), http.StatusInternalServerError) + handleError(w, "deleting a note", err, http.StatusInternalServerError) return } } b, err := operations.DeleteBook(tx, user, book) if err != nil { - http.Error(w, errors.Wrap(err, "deleting book").Error(), http.StatusInternalServerError) + handleError(w, "deleting book", err, http.StatusInternalServerError) return } @@ -252,12 +238,7 @@ func (a *App) DeleteBook(w http.ResponseWriter, r *http.Request) { Status: http.StatusOK, Book: presenters.PresentBook(b), } - - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(resp); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, resp) } // BooksOptions handles OPTIONS endpoint diff --git a/pkg/server/api/handlers/v1_notes.go b/pkg/server/api/handlers/v1_notes.go index 84d51eba..af5646e3 100644 --- a/pkg/server/api/handlers/v1_notes.go +++ b/pkg/server/api/handlers/v1_notes.go @@ -20,6 +20,7 @@ package handlers import ( "encoding/json" + "fmt" "net/http" "github.com/dnote/dnote/pkg/server/api/helpers" @@ -27,7 +28,6 @@ import ( "github.com/dnote/dnote/pkg/server/api/presenters" "github.com/dnote/dnote/pkg/server/database" "github.com/gorilla/mux" - "github.com/pkg/errors" ) // CreateNote creates a note by generating an action and feeding it to the reducer @@ -64,25 +64,25 @@ func (a *App) UpdateNote(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } var params updateNotePayload err := json.NewDecoder(r.Body).Decode(¶ms) if err != nil { - http.Error(w, errors.Wrap(err, "decoding params").Error(), http.StatusInternalServerError) + handleError(w, "decoding params", err, http.StatusInternalServerError) return } if ok := validateUpdateNotePayload(params); !ok { - http.Error(w, "Invalid payload", http.StatusBadRequest) + handleError(w, "Invalid payload", nil, http.StatusBadRequest) return } var note database.Note if err := db.Where("uuid = ? AND user_id = ?", noteUUID, user.ID).First(¬e).Error; err != nil { - http.Error(w, errors.Wrap(err, "finding note").Error(), http.StatusInternalServerError) + handleError(w, "finding note", err, http.StatusInternalServerError) return } @@ -91,14 +91,14 @@ func (a *App) UpdateNote(w http.ResponseWriter, r *http.Request) { note, err = operations.UpdateNote(tx, user, a.Clock, note, params.BookUUID, params.Content) if err != nil { tx.Rollback() - http.Error(w, errors.Wrap(err, "updating note").Error(), http.StatusInternalServerError) + handleError(w, "updating note", err, http.StatusInternalServerError) return } var book database.Book if err := tx.Where("uuid = ? AND user_id = ?", note.BookUUID, user.ID).First(&book).Error; err != nil { tx.Rollback() - http.Error(w, errors.Wrapf(err, "finding book %s to preload", note.BookUUID).Error(), http.StatusInternalServerError) + handleError(w, fmt.Sprintf("finding book %s to preload", note.BookUUID), err, http.StatusInternalServerError) return } @@ -112,12 +112,7 @@ func (a *App) UpdateNote(w http.ResponseWriter, r *http.Request) { Status: http.StatusOK, Result: presenters.PresentNote(note), } - - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(resp); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, resp) } type deleteNoteResp struct { @@ -134,13 +129,13 @@ func (a *App) DeleteNote(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } var note database.Note if err := db.Where("uuid = ? AND user_id = ?", noteUUID, user.ID).Preload("Book").First(¬e).Error; err != nil { - http.Error(w, errors.Wrap(err, "finding note").Error(), http.StatusInternalServerError) + handleError(w, "finding note", err, http.StatusInternalServerError) return } @@ -149,7 +144,7 @@ func (a *App) DeleteNote(w http.ResponseWriter, r *http.Request) { n, err := operations.DeleteNote(tx, user, note) if err != nil { tx.Rollback() - http.Error(w, errors.Wrap(err, "deleting note").Error(), http.StatusInternalServerError) + handleError(w, "deleting note", err, http.StatusInternalServerError) return } @@ -159,10 +154,5 @@ func (a *App) DeleteNote(w http.ResponseWriter, r *http.Request) { Status: http.StatusNoContent, Result: presenters.PresentNote(n), } - - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(resp); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, resp) } diff --git a/pkg/server/api/handlers/v1_sync.go b/pkg/server/api/handlers/v1_sync.go index 13e94f54..c59eec1a 100644 --- a/pkg/server/api/handlers/v1_sync.go +++ b/pkg/server/api/handlers/v1_sync.go @@ -19,7 +19,6 @@ package handlers import ( - "encoding/json" "fmt" "net/http" "net/url" @@ -29,6 +28,7 @@ import ( "github.com/dnote/dnote/pkg/server/api/helpers" "github.com/dnote/dnote/pkg/server/database" + "github.com/dnote/dnote/pkg/server/log" "github.com/pkg/errors" ) @@ -252,30 +252,26 @@ type GetSyncFragmentResp struct { func (a *App) GetSyncFragment(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } afterUSN, limit, err := parseGetSyncFragmentQuery(r.URL.Query()) if err != nil { - http.Error(w, errors.Wrap(err, "parsing query params").Error(), http.StatusInternalServerError) + handleError(w, "parsing query params", err, http.StatusInternalServerError) return } fragment, err := a.newFragment(user.ID, user.MaxUSN, afterUSN, limit) if err != nil { - http.Error(w, errors.Wrap(err, "getting fragment").Error(), http.StatusInternalServerError) + handleError(w, "getting fragment", err, http.StatusInternalServerError) return } response := GetSyncFragmentResp{ Fragment: fragment, } - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(response); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, response) } // GetSyncStateResp represents a response from GetSyncFragment handler @@ -289,7 +285,7 @@ type GetSyncStateResp struct { func (a *App) GetSyncState(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "No authenticated user found", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } @@ -300,11 +296,12 @@ func (a *App) GetSyncState(w http.ResponseWriter, r *http.Request) { CurrentTime: a.Clock.Now().Unix(), } - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(response); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + log.WithFields(log.Fields{ + "user_id": user.ID, + "resp": response, + }).Info("getting sync state") + + respondJSON(w, response) } // Sync is a deprecated endpoint that used to support cli versions below v0.5.0 diff --git a/pkg/server/api/handlers/v2_books.go b/pkg/server/api/handlers/v2_books.go index cd77dae1..793a3bd2 100644 --- a/pkg/server/api/handlers/v2_books.go +++ b/pkg/server/api/handlers/v2_books.go @@ -56,13 +56,13 @@ func (a *App) CreateBookV2(w http.ResponseWriter, r *http.Request) { var params createBookPayload err := json.NewDecoder(r.Body).Decode(¶ms) if err != nil { - http.Error(w, errors.Wrap(err, "decoding payload").Error(), http.StatusInternalServerError) + handleError(w, "decoding payload", err, http.StatusInternalServerError) return } err = validateCreateBookPayload(params) if err != nil { - http.Error(w, errors.Wrap(err, "validating payload").Error(), http.StatusBadRequest) + handleError(w, "validating payload", err, http.StatusBadRequest) return } @@ -73,7 +73,7 @@ func (a *App) CreateBookV2(w http.ResponseWriter, r *http.Request) { Where("user_id = ? AND label = ?", user.ID, params.Name). Count(&bookCount).Error if err != nil { - http.Error(w, errors.Wrap(err, "checking duplicate").Error(), http.StatusInternalServerError) + handleError(w, "checking duplicate", err, http.StatusInternalServerError) return } if bookCount > 0 { @@ -83,17 +83,12 @@ func (a *App) CreateBookV2(w http.ResponseWriter, r *http.Request) { book, err := operations.CreateBook(user, a.Clock, params.Name) if err != nil { - http.Error(w, errors.Wrap(err, "inserting book").Error(), http.StatusInternalServerError) + handleError(w, "inserting book", err, http.StatusInternalServerError) } resp := CreateBookResp{ Book: presenters.PresentBook(book), } - - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(resp); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, resp) } // BooksOptionsV2 is a handler for OPTIONS endpoint for notes diff --git a/pkg/server/api/handlers/v2_notes.go b/pkg/server/api/handlers/v2_notes.go index 85920d98..eafb05bf 100644 --- a/pkg/server/api/handlers/v2_notes.go +++ b/pkg/server/api/handlers/v2_notes.go @@ -53,33 +53,33 @@ type CreateNoteV2Resp struct { func (a *App) CreateNoteV2(w http.ResponseWriter, r *http.Request) { user, ok := r.Context().Value(helpers.KeyUser).(database.User) if !ok { - http.Error(w, "Failed to get user", http.StatusInternalServerError) + handleError(w, "No authenticated user found", nil, http.StatusInternalServerError) return } var params createNoteV2Payload err := json.NewDecoder(r.Body).Decode(¶ms) if err != nil { - http.Error(w, errors.Wrap(err, "decoding payload").Error(), http.StatusInternalServerError) + handleError(w, "decoding payload", err, http.StatusInternalServerError) return } err = validateCreateNoteV2Payload(params) if err != nil { - http.Error(w, errors.Wrap(err, "validating payload").Error(), http.StatusBadRequest) + handleError(w, "validating payload", err, http.StatusBadRequest) return } var book database.Book db := database.DBConn if err := db.Where("uuid = ? AND user_id = ?", params.BookUUID, user.ID).First(&book).Error; err != nil { - http.Error(w, errors.Wrap(err, "finding book").Error(), http.StatusInternalServerError) + handleError(w, "finding book", err, http.StatusInternalServerError) return } note, err := operations.CreateNote(user, a.Clock, params.BookUUID, params.Content, params.AddedOn, params.EditedOn, false) if err != nil { - http.Error(w, errors.Wrap(err, "creating note").Error(), http.StatusInternalServerError) + handleError(w, "creating note", err, http.StatusInternalServerError) return } @@ -90,12 +90,7 @@ func (a *App) CreateNoteV2(w http.ResponseWriter, r *http.Request) { resp := CreateNoteV2Resp{ Result: presenters.PresentNote(note), } - - w.Header().Set("Content-Type", "application/json") - if err := json.NewEncoder(w).Encode(resp); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } + respondJSON(w, resp) } // NotesOptionsV2 is a handler for OPTIONS endpoint for notes diff --git a/pkg/server/api/logger/main.go b/pkg/server/api/logger/main.go deleted file mode 100644 index 9e35e4b9..00000000 --- a/pkg/server/api/logger/main.go +++ /dev/null @@ -1,108 +0,0 @@ -/* Copyright (C) 2019 Monomax Software Pty Ltd - * - * This file is part of Dnote. - * - * Dnote is free software: you can redistribute it and/or modify - * it under the terms of the GNU Affero General Public License as published by - * the Free Software Foundation, either version 3 of the License, or - * (at your option) any later version. - * - * Dnote is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU Affero General Public License for more details. - * - * You should have received a copy of the GNU Affero General Public License - * along with Dnote. If not, see . - */ - -// Package logger provides an interface to transmit log messages to a system log service -package logger - -import ( - "fmt" - "github.com/pkg/errors" - "log" - "log/syslog" - "os" -) - -var writer *syslog.Writer - -// Init initilizes the syslog writer -func Init() error { - var err error - - var endpoint string - if os.Getenv("GO_ENV") == "PRODUCTION" { - endpoint = os.Getenv("LogEndpoint") - - if endpoint == "" { - log.Println("No log endpoint provided. Not aggregating system logs.") - return nil - } - - writer, err = syslog.Dial("udp", endpoint, syslog.LOG_DEBUG|syslog.LOG_KERN, "dnote-api") - if err != nil { - return errors.Wrap(err, "dialing syslog manager") - } - } - - return nil -} - -// Info logs an info message -func Info(msg string, v ...interface{}) { - m := fmt.Sprintf(msg, v...) - log.Println(m) - - if writer == nil { - return - } - - if err := writer.Info(fmt.Sprintf("INFO: %s", m)); err != nil { - log.Println(errors.Wrap(err, "transmiting log")) - } -} - -// Err logs an error message -func Err(msg string, v ...interface{}) { - m := fmt.Sprintf(msg, v...) - log.Println(m) - - if writer == nil { - return - } - - if err := writer.Err(fmt.Sprintf("ERROR: %s", m)); err != nil { - log.Println(errors.Wrap(err, "transmiting log")) - } -} - -// Notice logs a notice message -func Notice(msg string, v ...interface{}) { - m := fmt.Sprintf(msg, v...) - log.Println(m) - - if writer == nil { - return - } - - if err := writer.Notice(fmt.Sprintf("NOTICE: %s", m)); err != nil { - log.Println(errors.Wrap(err, "transmiting log")) - } -} - -// Debug logs a debug message -func Debug(msg string, v ...interface{}) { - m := fmt.Sprintf(msg, v...) - log.Println(m) - - if writer == nil { - return - } - - if err := writer.Debug(fmt.Sprintf("DEBUG: %s", m)); err != nil { - log.Println(errors.Wrap(err, "transmiting log")) - } -} diff --git a/pkg/server/log/log.go b/pkg/server/log/log.go new file mode 100644 index 00000000..21bc76bb --- /dev/null +++ b/pkg/server/log/log.go @@ -0,0 +1,113 @@ +// Package log provides interfaces to write structured logs +package log + +import ( + "encoding/json" + "fmt" + "os" + "time" +) + +const ( + fieldKeyLevel = "level" + fieldKeyMessage = "msg" + fieldKeyTimestamp = "ts" + fieldKeyUnixTimestamp = "ts_unix" + + levelInfo = "info" + levelWarn = "warn" + levelError = "error" +) + +// Fields represents a set of information to be included in the log +type Fields map[string]interface{} + +// Entry represents a log entry +type Entry struct { + Fields Fields + Timestamp time.Time +} + +func newEntry(fields Fields) Entry { + return Entry{ + Fields: fields, + Timestamp: time.Now().UTC(), + } +} + +// WithFields creates a log entry with the given fields +func WithFields(fields Fields) Entry { + return newEntry(fields) +} + +// Info logs the given entry at an info level +func (e Entry) Info(msg string) { + e.write(levelInfo, msg) +} + +// Warn logs the given entry at a warning level +func (e Entry) Warn(msg string) { + e.write(levelWarn, msg) +} + +// Error logs the given entry at an error level +func (e Entry) Error(msg string) { + e.write(levelError, msg) +} + +// ErrorWrap logs the given entry with the error message annotated by the given message +func (e Entry) ErrorWrap(err error, msg string) { + m := fmt.Sprintf("%s: %v", msg, err) + + e.Error(m) +} + +func (e Entry) formatJSON(level, msg string) []byte { + data := make(Fields, len(e.Fields)+4) + + data[fieldKeyLevel] = level + data[fieldKeyMessage] = msg + data[fieldKeyTimestamp] = e.Timestamp + data[fieldKeyUnixTimestamp] = e.Timestamp.Unix() + + for k, v := range e.Fields { + switch v := v.(type) { + case error: + data[k] = v.Error() + default: + data[k] = v + } + } + + serialized, err := json.Marshal(data) + if err != nil { + fmt.Fprintf(os.Stderr, "formatting JSON: %v\n", err) + } + + return serialized +} + +func (e Entry) write(level, msg string) { + serialized := e.formatJSON(level, msg) + + _, err := fmt.Fprintln(os.Stderr, string(serialized)) + if err != nil { + fmt.Fprintf(os.Stderr, "writing to stderr: %v\n", err) + } +} + +// Info logs an info message without additional fields +func Info(msg string) { + newEntry(Fields{}).Info(msg) +} + +// Error logs an error message without additional fields +func Error(msg string) { + newEntry(Fields{}).Error(msg) +} + +// ErrorWrap logs an error message without additional fields. It annotates the given error's +// message with the given message +func ErrorWrap(err error, msg string) { + newEntry(Fields{}).ErrorWrap(err, msg) +}