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.

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
Show file tree
Hide file tree
Changes from 3 commits
Commits
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
28 changes: 20 additions & 8 deletions server/handlers/default.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,6 @@ import (
"net/http"
"strings"

"github.com/Sirupsen/logrus"
ctxu "github.com/docker/distribution/context"
"github.com/gorilla/mux"
"golang.org/x/net/context"
Expand Down Expand Up @@ -61,6 +60,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 +71,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 +83,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 +97,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 +106,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 +129,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 @@ -139,7 +148,7 @@ func getHandler(ctx context.Context, w http.ResponseWriter, r *http.Request, var
// of time.
utils.SetLastModifiedHeader(w.Header(), *lastModified)
} else {
logrus.Warnf("Got bytes out for %s's %s (checksum: %s), but missing lastModified date",
logger.Warnf("Got bytes out for %s's %s (checksum: %s), but missing lastModified date",
gun, tufRole, checksum)
}

Expand All @@ -149,14 +158,15 @@ func getHandler(ctx context.Context, w http.ResponseWriter, r *http.Request, var

// DeleteHandler deletes all data for a GUN. A 200 responses indicates success.
func DeleteHandler(ctx context.Context, w http.ResponseWriter, r *http.Request) error {
vars := mux.Vars(r)
gun := vars["imageName"]
logger := ctxu.GetLoggerWithField(ctx, gun, "gun")
s := ctx.Value("metaStore")
store, ok := s.(storage.MetaStore)
if !ok {
logger.Error("500 DELETE repository: no storage exists")
return errors.ErrNoStorage.WithDetail(nil)
}
vars := mux.Vars(r)
gun := vars["imageName"]
logger := ctxu.GetLoggerWithField(ctx, gun, "gun")
err := store.Delete(gun)
if err != nil {
logger.Error("500 DELETE repository")
Expand All @@ -175,16 +185,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"]
logger := ctxu.GetLoggerWithField(ctx, gun, "gun")
if !ok || gun == "" {
logger.Info("400 GET no gun in request")
return errors.ErrUnknown.WithDetail("no 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 +227,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
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
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