Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add info logging for 400s, error for 500s, adjust timestamp error level on GetCurrent #798

Merged
merged 4 commits into from
Jul 18, 2016
Merged

Add info logging for 400s, error for 500s, adjust timestamp error level on GetCurrent #798

Show file tree
Hide file tree
Changes from 2 commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
a982798
Add info logging for 400s, error for 500s, adjust timestamp error lev…
riyazdf Jun 22, 2016
824ab1b
bottleneck http error logging in root handler
riyazdf Jun 23, 2016
4018137
Change logrus to logger where possible
riyazdf Jul 14, 2016
ae03d54
Simplify logging on httpErr
riyazdf Jul 14, 2016
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
20 changes: 17 additions & 3 deletions server/handlers/default.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,7 @@ func atomicUpdateHandler(ctx context.Context, w http.ResponseWriter, r *http.Req

reader, err := r.MultipartReader()
if err != nil {
logger.Info("400 POST unable to parse TUF data")
return errors.ErrMalformedUpload.WithDetail(nil)
}
var updates []storage.MetaUpdate
Expand All @@ -71,8 +72,10 @@ func atomicUpdateHandler(ctx context.Context, w http.ResponseWriter, r *http.Req
}
role := strings.TrimSuffix(part.FileName(), ".json")
if role == "" {
logger.Info("400 POST empty role")
return errors.ErrNoFilename.WithDetail(nil)
} else if !data.ValidRole(role) {
logger.Infof("400 POST invalid role: %s", role)
return errors.ErrInvalidRole.WithDetail(role)
}
meta := &data.SignedMeta{}
Expand All @@ -81,6 +84,7 @@ func atomicUpdateHandler(ctx context.Context, w http.ResponseWriter, r *http.Req
dec := json.NewDecoder(io.TeeReader(part, inBuf))
err = dec.Decode(meta)
if err != nil {
logger.Info("400 POST malformed update JSON")
return errors.ErrMalformedJSON.WithDetail(nil)
}
version := meta.Signed.Version
Expand All @@ -94,6 +98,7 @@ func atomicUpdateHandler(ctx context.Context, w http.ResponseWriter, r *http.Req
if err != nil {
serializable, serializableError := validation.NewSerializableError(err)
if serializableError != nil {
logger.Info("400 POST error validating update")
return errors.ErrInvalidUpdate.WithDetail(nil)
}
return errors.ErrInvalidUpdate.WithDetail(serializable)
Expand All @@ -102,6 +107,7 @@ func atomicUpdateHandler(ctx context.Context, w http.ResponseWriter, r *http.Req
if err != nil {
// If we have an old version error, surface to user with error code
if _, ok := err.(storage.ErrOldVersion); ok {
logger.Info("400 POST old version error")
return errors.ErrOldVersion.WithDetail(err)
}
// More generic storage update error, possibly due to attempted rollback
Expand All @@ -124,13 +130,17 @@ func getHandler(ctx context.Context, w http.ResponseWriter, r *http.Request, var
tufRole := vars["tufRole"]
s := ctx.Value("metaStore")

logger := ctxu.GetLoggerWithField(ctx, gun, "gun")

store, ok := s.(storage.MetaStore)
if !ok {
logger.Error("500 GET: no storage exists")
return errors.ErrNoStorage.WithDetail(nil)
}

lastModified, output, err := getRole(ctx, store, gun, tufRole, checksum)
if err != nil {
logger.Infof("404 GET %s role", tufRole)
return err
}
if lastModified != nil {
Expand All @@ -152,6 +162,7 @@ func DeleteHandler(ctx context.Context, w http.ResponseWriter, r *http.Request)
s := ctx.Value("metaStore")
store, ok := s.(storage.MetaStore)
if !ok {
logrus.Error("500 DELETE repository: no storage exists")
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should this be logger.Error? (would need to pull the logger out of the context like other handlers)

return errors.ErrNoStorage.WithDetail(nil)
}
vars := mux.Vars(r)
Expand All @@ -176,15 +187,18 @@ func GetKeyHandler(ctx context.Context, w http.ResponseWriter, r *http.Request)
func getKeyHandler(ctx context.Context, w http.ResponseWriter, r *http.Request, vars map[string]string) error {
gun, ok := vars["imageName"]
if !ok || gun == "" {
logrus.Info("400 GET no gun in request")
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

logger.Info? (and move line 194 up?)

Copy link
Contributor Author

@riyazdf riyazdf Jul 14, 2016 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think we can for this one because we don't have the gun yet, but totally for the other logrus.Error (and I think I see a logrus.Warnf that can get fixed)

Edit: actually we can just push up 194, the information in the log will be the same

return errors.ErrUnknown.WithDetail("no gun")
}

logger := ctxu.GetLoggerWithField(ctx, gun, "gun")

role, ok := vars["tufRole"]
if !ok || role == "" {
logger.Info("400 GET no role in request")
return errors.ErrUnknown.WithDetail("no role")
}

logger := ctxu.GetLoggerWithField(ctx, gun, "gun")

s := ctx.Value("metaStore")
store, ok := s.(storage.MetaStore)
if !ok || store == nil {
Expand Down Expand Up @@ -215,7 +229,7 @@ func getKeyHandler(ctx context.Context, w http.ResponseWriter, r *http.Request,
case data.CanonicalSnapshotRole:
key, err = snapshot.GetOrCreateSnapshotKey(gun, store, crypto, keyAlgorithm)
default:
logger.Errorf("400 GET %s key: %v", role, err)
logger.Infof("400 GET %s key: %v", role, err)
return errors.ErrInvalidRole.WithDetail(role)
}
if err != nil {
Expand Down
2 changes: 1 addition & 1 deletion server/timestamp/timestamp.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -62,7 +62,7 @@ func GetOrCreateTimestamp(gun string, store storage.MetaStore, cryptoService sig

lastModified, timestampJSON, err := store.GetCurrent(gun, data.CanonicalTimestampRole)
if err != nil {
logrus.Error("error retrieving timestamp: ", err.Error())
logrus.Debug("error retrieving timestamp: ", err.Error())
return nil, nil, err
}

Expand Down
13 changes: 11 additions & 2 deletions utils/http.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,6 @@ import (
"net/http"
"time"

"github.com/Sirupsen/logrus"
ctxu "github.com/docker/distribution/context"
"github.com/docker/distribution/registry/api/errcode"
"github.com/docker/distribution/registry/auth"
Expand Down Expand Up @@ -79,9 +78,19 @@ func (root *rootHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
ctx = authCtx
}
if err := root.handler(ctx, w, r); err != nil {
if httpErr, ok := err.(errcode.ErrorCoder); ok {
// info level logging for non-5XX http errors
httpErrCode := httpErr.ErrorCode().Descriptor().HTTPStatusCode
if (httpErrCode < http.StatusOK || httpErrCode >= http.StatusMultipleChoices) && httpErrCode < http.StatusInternalServerError {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We shouldn't have an httpErr if the status is 200 but it we do it would probably want to be logged at info level. Seems like we could just collapse this could be simplified to:

if httpErrCode >= http.StatusInternalServerError {
    log.Error(httpErr)
} else {
    log.Info(httpErr)
}

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

good point, added!

log.Info(httpErr)
} else if httpErrCode >= http.StatusInternalServerError {
// error level logging for 5XX http errors
log.Error(httpErr)
}
}
e := errcode.ServeJSON(w, err)
if e != nil {
logrus.Error(e)
log.Error(e)
}
return
}
Expand Down