From d2bfb5825caee862f0d7e7deb1b8cfbcf9cee047 Mon Sep 17 00:00:00 2001 From: Stephen J Day Date: Fri, 6 Feb 2015 16:19:19 -0800 Subject: [PATCH] Integrate contextual logging with regsitry app This changeset integrates contextual logging into the registry web application. Idiomatic context use is attempted within the current webapp layout. The functionality is centered around making lifecycle objects (application and request context) into contexts themselves. Relevant data has been moved into the context where appropriate. We still have some work to do to factor out the registry.Context object and the dispatching functionality to remove some awkward portions. The api tests were slightly refactored to use a test environment to eliminate common code. Signed-off-by: Stephen J Day --- cmd/registry/main.go | 24 ++++--- registry/api_test.go | 120 +++++++++++++++++----------------- registry/app.go | 77 ++++++++++++++-------- registry/app_test.go | 13 ++-- registry/basicauth.go | 11 ++++ registry/basicauth_prego14.go | 41 ++++++++++++ registry/context.go | 80 ++++++++++++++++++----- registry/images.go | 8 ++- registry/layer.go | 15 +++-- registry/layerupload.go | 30 ++++----- 10 files changed, 281 insertions(+), 138 deletions(-) create mode 100644 registry/basicauth.go create mode 100644 registry/basicauth_prego14.go diff --git a/cmd/registry/main.go b/cmd/registry/main.go index 98f3d5bda..0ed8fcd28 100644 --- a/cmd/registry/main.go +++ b/cmd/registry/main.go @@ -10,17 +10,18 @@ import ( log "github.com/Sirupsen/logrus" "github.com/bugsnag/bugsnag-go" - "github.com/gorilla/handlers" - "github.com/yvasiyarov/gorelic" - _ "github.com/docker/distribution/auth/silly" _ "github.com/docker/distribution/auth/token" "github.com/docker/distribution/configuration" + ctxu "github.com/docker/distribution/context" "github.com/docker/distribution/registry" _ "github.com/docker/distribution/storagedriver/filesystem" _ "github.com/docker/distribution/storagedriver/inmemory" _ "github.com/docker/distribution/storagedriver/s3" "github.com/docker/distribution/version" + "github.com/gorilla/handlers" + "github.com/yvasiyarov/gorelic" + "golang.org/x/net/context" ) var showVersion bool @@ -38,29 +39,34 @@ func main() { return } + ctx := context.Background() + config, err := resolveConfiguration() if err != nil { fatalf("configuration error: %v", err) } - app := registry.NewApp(*config) + log.SetLevel(logLevel(config.Loglevel)) + ctx = context.WithValue(ctx, "version", version.Version) + ctx = ctxu.WithLogger(ctx, ctxu.GetLogger(ctx, "version")) + + app := registry.NewApp(ctx, *config) handler := configureReporting(app) handler = handlers.CombinedLoggingHandler(os.Stdout, handler) - log.SetLevel(logLevel(config.Loglevel)) if config.HTTP.Debug.Addr != "" { go debugServer(config.HTTP.Debug.Addr) } if config.HTTP.TLS.Certificate == "" { - log.Infof("listening on %v", config.HTTP.Addr) + ctxu.GetLogger(app).Infof("listening on %v", config.HTTP.Addr) if err := http.ListenAndServe(config.HTTP.Addr, handler); err != nil { - log.Fatalln(err) + ctxu.GetLogger(app).Fatalln(err) } } else { - log.Infof("listening on %v, tls", config.HTTP.Addr) + ctxu.GetLogger(app).Infof("listening on %v, tls", config.HTTP.Addr) if err := http.ListenAndServeTLS(config.HTTP.Addr, config.HTTP.TLS.Certificate, config.HTTP.TLS.Key, handler); err != nil { - log.Fatalln(err) + ctxu.GetLogger(app).Fatalln(err) } } } diff --git a/registry/api_test.go b/registry/api_test.go index aa70e504c..5e3bd72c6 100644 --- a/registry/api_test.go +++ b/registry/api_test.go @@ -22,26 +22,15 @@ import ( "github.com/docker/distribution/testutil" "github.com/docker/libtrust" "github.com/gorilla/handlers" + "golang.org/x/net/context" ) // TestCheckAPI hits the base endpoint (/v2/) ensures we return the specified // 200 OK response. func TestCheckAPI(t *testing.T) { - config := configuration.Configuration{ - Storage: configuration.Storage{ - "inmemory": configuration.Parameters{}, - }, - } + env := newTestEnv(t) - app := NewApp(config) - server := httptest.NewServer(handlers.CombinedLoggingHandler(os.Stderr, app)) - builder, err := v2.NewURLBuilderFromString(server.URL) - - if err != nil { - t.Fatalf("error creating url builder: %v", err) - } - - baseURL, err := builder.BuildBaseURL() + baseURL, err := env.builder.BuildBaseURL() if err != nil { t.Fatalf("unexpected error building base url: %v", err) } @@ -73,20 +62,7 @@ func TestLayerAPI(t *testing.T) { // TODO(stevvooe): This test code is complete junk but it should cover the // complete flow. This must be broken down and checked against the // specification *before* we submit the final to docker core. - - config := configuration.Configuration{ - Storage: configuration.Storage{ - "inmemory": configuration.Parameters{}, - }, - } - - app := NewApp(config) - server := httptest.NewServer(handlers.CombinedLoggingHandler(os.Stderr, app)) - builder, err := v2.NewURLBuilderFromString(server.URL) - - if err != nil { - t.Fatalf("error creating url builder: %v", err) - } + env := newTestEnv(t) imageName := "foo/bar" // "build" our layer file @@ -99,7 +75,7 @@ func TestLayerAPI(t *testing.T) { // ----------------------------------- // Test fetch for non-existent content - layerURL, err := builder.BuildBlobURL(imageName, layerDigest) + layerURL, err := env.builder.BuildBlobURL(imageName, layerDigest) if err != nil { t.Fatalf("error building url: %v", err) } @@ -122,7 +98,7 @@ func TestLayerAPI(t *testing.T) { // ------------------------------------------ // Start an upload and cancel - uploadURLBase := startPushLayer(t, builder, imageName) + uploadURLBase := startPushLayer(t, env.builder, imageName) req, err := http.NewRequest("DELETE", uploadURLBase, nil) if err != nil { @@ -145,8 +121,8 @@ func TestLayerAPI(t *testing.T) { // ----------------------------------------- // Do layer push with an empty body and different digest - uploadURLBase = startPushLayer(t, builder, imageName) - resp, err = doPushLayer(t, builder, imageName, layerDigest, uploadURLBase, bytes.NewReader([]byte{})) + uploadURLBase = startPushLayer(t, env.builder, imageName) + resp, err = doPushLayer(t, env.builder, imageName, layerDigest, uploadURLBase, bytes.NewReader([]byte{})) if err != nil { t.Fatalf("unexpected error doing bad layer push: %v", err) } @@ -161,8 +137,8 @@ func TestLayerAPI(t *testing.T) { t.Fatalf("unexpected error digesting empty buffer: %v", err) } - uploadURLBase = startPushLayer(t, builder, imageName) - pushLayer(t, builder, imageName, zeroDigest, uploadURLBase, bytes.NewReader([]byte{})) + uploadURLBase = startPushLayer(t, env.builder, imageName) + pushLayer(t, env.builder, imageName, zeroDigest, uploadURLBase, bytes.NewReader([]byte{})) // ----------------------------------------- // Do layer push with an empty body and correct digest @@ -174,16 +150,16 @@ func TestLayerAPI(t *testing.T) { t.Fatalf("unexpected error digesting empty tar: %v", err) } - uploadURLBase = startPushLayer(t, builder, imageName) - pushLayer(t, builder, imageName, emptyDigest, uploadURLBase, bytes.NewReader(emptyTar)) + uploadURLBase = startPushLayer(t, env.builder, imageName) + pushLayer(t, env.builder, imageName, emptyDigest, uploadURLBase, bytes.NewReader(emptyTar)) // ------------------------------------------ // Now, actually do successful upload. layerLength, _ := layerFile.Seek(0, os.SEEK_END) layerFile.Seek(0, os.SEEK_SET) - uploadURLBase = startPushLayer(t, builder, imageName) - pushLayer(t, builder, imageName, layerDigest, uploadURLBase, layerFile) + uploadURLBase = startPushLayer(t, env.builder, imageName) + pushLayer(t, env.builder, imageName, layerDigest, uploadURLBase, layerFile) // ------------------------ // Use a head request to see if the layer exists. @@ -223,28 +199,12 @@ func TestLayerAPI(t *testing.T) { } func TestManifestAPI(t *testing.T) { - pk, err := libtrust.GenerateECP256PrivateKey() - if err != nil { - t.Fatalf("unexpected error generating private key: %v", err) - } - - config := configuration.Configuration{ - Storage: configuration.Storage{ - "inmemory": configuration.Parameters{}, - }, - } - - app := NewApp(config) - server := httptest.NewServer(handlers.CombinedLoggingHandler(os.Stderr, app)) - builder, err := v2.NewURLBuilderFromString(server.URL) - if err != nil { - t.Fatalf("unexpected error creating url builder: %v", err) - } + env := newTestEnv(t) imageName := "foo/bar" tag := "thetag" - manifestURL, err := builder.BuildManifestURL(imageName, tag) + manifestURL, err := env.builder.BuildManifestURL(imageName, tag) if err != nil { t.Fatalf("unexpected error getting manifest url: %v", err) } @@ -260,7 +220,7 @@ func TestManifestAPI(t *testing.T) { checkResponse(t, "getting non-existent manifest", resp, http.StatusNotFound) checkBodyHasErrorCodes(t, "getting non-existent manifest", resp, v2.ErrorCodeManifestUnknown) - tagsURL, err := builder.BuildTagsURL(imageName) + tagsURL, err := env.builder.BuildTagsURL(imageName) if err != nil { t.Fatalf("unexpected error building tags url: %v", err) } @@ -324,13 +284,13 @@ func TestManifestAPI(t *testing.T) { expectedLayers[dgst] = rs unsignedManifest.FSLayers[i].BlobSum = dgst - uploadURLBase := startPushLayer(t, builder, imageName) - pushLayer(t, builder, imageName, dgst, uploadURLBase, rs) + uploadURLBase := startPushLayer(t, env.builder, imageName) + pushLayer(t, env.builder, imageName, dgst, uploadURLBase, rs) } // ------------------- // Push the signed manifest with all layers pushed. - signedManifest, err := manifest.Sign(unsignedManifest, pk) + signedManifest, err := manifest.Sign(unsignedManifest, env.pk) if err != nil { t.Fatalf("unexpected error signing manifest: %v", err) } @@ -386,6 +346,46 @@ func TestManifestAPI(t *testing.T) { } } +type testEnv struct { + pk libtrust.PrivateKey + ctx context.Context + config configuration.Configuration + app *App + server *httptest.Server + builder *v2.URLBuilder +} + +func newTestEnv(t *testing.T) *testEnv { + ctx := context.Background() + config := configuration.Configuration{ + Storage: configuration.Storage{ + "inmemory": configuration.Parameters{}, + }, + } + + app := NewApp(ctx, config) + server := httptest.NewServer(handlers.CombinedLoggingHandler(os.Stderr, app)) + builder, err := v2.NewURLBuilderFromString(server.URL) + + if err != nil { + t.Fatalf("error creating url builder: %v", err) + } + + pk, err := libtrust.GenerateECP256PrivateKey() + if err != nil { + t.Fatalf("unexpected error generating private key: %v", err) + } + + return &testEnv{ + pk: pk, + ctx: ctx, + config: config, + app: app, + server: server, + builder: builder, + } +} + func putManifest(t *testing.T, msg, url string, v interface{}) *http.Response { var body []byte if sm, ok := v.(*manifest.SignedManifest); ok { diff --git a/registry/app.go b/registry/app.go index 6e5480c38..f40d35efd 100644 --- a/registry/app.go +++ b/registry/app.go @@ -7,10 +7,10 @@ import ( "os" "code.google.com/p/go-uuid/uuid" - log "github.com/Sirupsen/logrus" "github.com/docker/distribution/api/v2" "github.com/docker/distribution/auth" "github.com/docker/distribution/configuration" + ctxu "github.com/docker/distribution/context" "github.com/docker/distribution/storage" "github.com/docker/distribution/storage/notifications" "github.com/docker/distribution/storagedriver" @@ -23,6 +23,7 @@ import ( // on this object that will be accessible from all requests. Any writable // fields should be protected. type App struct { + context.Context Config configuration.Configuration // InstanceID is a unique id assigned to the application on each creation. @@ -43,16 +44,30 @@ type App struct { layerHandler storage.LayerHandler // allows dispatch of layer serving to external provider } +// Value intercepts calls context.Context.Value, returning the current app id, +// if requested. +func (app *App) Value(key interface{}) interface{} { + switch key { + case "app.id": + return app.InstanceID + } + + return app.Context.Value(key) +} + // NewApp takes a configuration and returns a configured app, ready to serve // requests. The app only implements ServeHTTP and can be wrapped in other // handlers accordingly. -func NewApp(configuration configuration.Configuration) *App { +func NewApp(ctx context.Context, configuration configuration.Configuration) *App { app := &App{ Config: configuration, + Context: ctx, InstanceID: uuid.New(), router: v2.Router(), } + app.Context = ctxu.WithLogger(app.Context, ctxu.GetLogger(app, "app.id")) + // Register the handler dispatchers. app.register(v2.RouteNameBase, func(ctx *Context, r *http.Request) http.Handler { return http.HandlerFunc(apiBase) @@ -118,11 +133,11 @@ func (app *App) configureEvents(configuration *configuration.Configuration) { var sinks []notifications.Sink for _, endpoint := range configuration.Notifications.Endpoints { if endpoint.Disabled { - log.Infof("endpoint %s disabled, skipping", endpoint.Name) + ctxu.GetLogger(app).Infof("endpoint %s disabled, skipping", endpoint.Name) continue } - log.Infof("configuring endpoint %v (%v), timeout=%s, headers=%v", endpoint.Name, endpoint.URL, endpoint.Timeout, endpoint.Headers) + ctxu.GetLogger(app).Infof("configuring endpoint %v (%v), timeout=%s, headers=%v", endpoint.Name, endpoint.URL, endpoint.Timeout, endpoint.Headers) endpoint := notifications.NewEndpoint(endpoint.Name, endpoint.URL, notifications.EndpointConfig{ Timeout: endpoint.Timeout, Threshold: endpoint.Threshold, @@ -190,27 +205,29 @@ func (ssrw *singleStatusResponseWriter) WriteHeader(status int) { ssrw.ResponseWriter.WriteHeader(status) } -// WithRequest adds an http request to the given context and requents -// a new context with an "http.request" value. -func WithRequest(ctx context.Context, r *http.Request) context.Context { - return context.WithValue(ctx, "http.request", r) +func (ssrw *singleStatusResponseWriter) Flush() { + if flusher, ok := ssrw.ResponseWriter.(http.Flusher); ok { + flusher.Flush() + } } // dispatcher returns a handler that constructs a request specific context and // handler, using the dispatch factory function. func (app *App) dispatcher(dispatch dispatchFunc) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - context := app.context(r) + context := app.context(w, r) - if err := app.authorized(w, r, context, context.vars["name"]); err != nil { + defer func() { + ctxu.GetResponseLogger(context).Infof("response completed") + }() + + if err := app.authorized(w, r, context); err != nil { return } // decorate the authorized repository with an event bridge. context.Repository = notifications.Listen( context.Repository, app.eventBridge(context, r)) - - context.log = log.WithField("name", context.Repository.Name()) handler := dispatch(context, r) ssrw := &singleStatusResponseWriter{ResponseWriter: w} @@ -230,24 +247,34 @@ func (app *App) dispatcher(dispatch dispatchFunc) http.Handler { // context constructs the context object for the application. This only be // called once per request. -func (app *App) context(r *http.Request) *Context { - vars := mux.Vars(r) +func (app *App) context(w http.ResponseWriter, r *http.Request) *Context { + ctx := ctxu.WithRequest(app, r) + ctx, w = ctxu.WithResponseWriter(ctx, w) + ctx = ctxu.WithVars(ctx, r) + ctx = ctxu.WithLogger(ctx, ctxu.GetRequestLogger(ctx)) + ctx = ctxu.WithLogger(ctx, ctxu.GetLogger(ctx, + "vars.name", + "vars.tag", + "vars.digest", + "vars.tag", + "vars.uuid")) + context := &Context{ App: app, - RequestID: uuid.New(), + Context: ctx, urlBuilder: v2.NewURLBuilderFromRequest(r), } - // Store vars for underlying handlers. - context.vars = vars - return context } // authorized checks if the request can proceed with access to the requested // repository. If it succeeds, the repository will be available on the // context. An error will be if access is not available. -func (app *App) authorized(w http.ResponseWriter, r *http.Request, context *Context, repo string) error { +func (app *App) authorized(w http.ResponseWriter, r *http.Request, context *Context) error { + ctxu.GetLogger(context).Debug("authorizing request") + repo := getName(context) + if app.accessController == nil { // No access controller, so we simply provide access. context.Repository = app.registry.Repository(repo) @@ -308,7 +335,7 @@ func (app *App) authorized(w http.ResponseWriter, r *http.Request, context *Cont } } - authCtx, err := app.accessController.Authorized(WithRequest(nil, r), accessRecords...) + ctx, err := app.accessController.Authorized(context.Context, accessRecords...) if err != nil { switch err := err.(type) { case auth.Challenge: @@ -323,16 +350,14 @@ func (app *App) authorized(w http.ResponseWriter, r *http.Request, context *Cont // the configuration or whatever is backing the access // controller. Just return a bad request with no information // to avoid exposure. The request should not proceed. - context.log.Errorf("error checking authorization: %v", err) + ctxu.GetLogger(context).Errorf("error checking authorization: %v", err) w.WriteHeader(http.StatusBadRequest) } return err } - // The authorized context should contain an auth.UserInfo - // object. If it doesn't, just use the zero value for now. - context.AuthUserInfo, _ = authCtx.Value("auth.user").(auth.UserInfo) + context.Context = ctx // At this point, the request should have access to the repository under // the requested operation. Make is available on the context. @@ -345,9 +370,9 @@ func (app *App) authorized(w http.ResponseWriter, r *http.Request, context *Cont // correct actor and source. func (app *App) eventBridge(ctx *Context, r *http.Request) notifications.Listener { actor := notifications.ActorRecord{ - Name: ctx.AuthUserInfo.Name, + Name: getUserName(ctx, r), } - request := notifications.NewRequestRecord(ctx.RequestID, r) + request := notifications.NewRequestRecord(ctxu.GetRequestID(ctx), r) return notifications.NewBridge(ctx.urlBuilder, app.events.source, actor, request, app.events.sink) } diff --git a/registry/app_test.go b/registry/app_test.go index d49c7bbd4..9b106575d 100644 --- a/registry/app_test.go +++ b/registry/app_test.go @@ -12,6 +12,7 @@ import ( "github.com/docker/distribution/configuration" "github.com/docker/distribution/storage" "github.com/docker/distribution/storagedriver/inmemory" + "golang.org/x/net/context" ) // TestAppDispatcher builds an application with a test dispatcher and ensures @@ -22,6 +23,7 @@ func TestAppDispatcher(t *testing.T) { driver := inmemory.New() app := &App{ Config: configuration.Configuration{}, + Context: context.Background(), router: v2.Router(), driver: driver, registry: storage.NewRegistryWithDriver(driver), @@ -37,19 +39,19 @@ func TestAppDispatcher(t *testing.T) { varCheckingDispatcher := func(expectedVars map[string]string) dispatchFunc { return func(ctx *Context, r *http.Request) http.Handler { // Always checks the same name context - if ctx.Repository.Name() != ctx.vars["name"] { + if ctx.Repository.Name() != getName(ctx) { t.Fatalf("unexpected name: %q != %q", ctx.Repository.Name(), "foo/bar") } // Check that we have all that is expected for expectedK, expectedV := range expectedVars { - if ctx.vars[expectedK] != expectedV { - t.Fatalf("unexpected %s in context vars: %q != %q", expectedK, ctx.vars[expectedK], expectedV) + if ctx.Value(expectedK) != expectedV { + t.Fatalf("unexpected %s in context vars: %q != %q", expectedK, ctx.Value(expectedK), expectedV) } } // Check that we only have variables that are expected - for k, v := range ctx.vars { + for k, v := range ctx.Value("vars").(map[string]string) { _, ok := expectedVars[k] if !ok { // name is checked on context @@ -135,6 +137,7 @@ func TestAppDispatcher(t *testing.T) { // TestNewApp covers the creation of an application via NewApp with a // configuration. func TestNewApp(t *testing.T) { + ctx := context.Background() config := configuration.Configuration{ Storage: configuration.Storage{ "inmemory": nil, @@ -152,7 +155,7 @@ func TestNewApp(t *testing.T) { // Mostly, with this test, given a sane configuration, we are simply // ensuring that NewApp doesn't panic. We might want to tweak this // behavior. - app := NewApp(config) + app := NewApp(ctx, config) server := httptest.NewServer(app) builder, err := v2.NewURLBuilderFromString(server.URL) diff --git a/registry/basicauth.go b/registry/basicauth.go new file mode 100644 index 000000000..55794ee32 --- /dev/null +++ b/registry/basicauth.go @@ -0,0 +1,11 @@ +// +build go1.4 + +package registry + +import ( + "net/http" +) + +func basicAuth(r *http.Request) (username, password string, ok bool) { + return r.BasicAuth() +} diff --git a/registry/basicauth_prego14.go b/registry/basicauth_prego14.go new file mode 100644 index 000000000..dc563135b --- /dev/null +++ b/registry/basicauth_prego14.go @@ -0,0 +1,41 @@ +// +build !go1.4 + +package registry + +import ( + "encoding/base64" + "net/http" + "strings" +) + +// NOTE(stevvooe): This is basic auth support from go1.4 present to ensure we +// can compile on go1.3 and earlier. + +// BasicAuth returns the username and password provided in the request's +// Authorization header, if the request uses HTTP Basic Authentication. +// See RFC 2617, Section 2. +func basicAuth(r *http.Request) (username, password string, ok bool) { + auth := r.Header.Get("Authorization") + if auth == "" { + return + } + return parseBasicAuth(auth) +} + +// parseBasicAuth parses an HTTP Basic Authentication string. +// "Basic QWxhZGRpbjpvcGVuIHNlc2FtZQ==" returns ("Aladdin", "open sesame", true). +func parseBasicAuth(auth string) (username, password string, ok bool) { + if !strings.HasPrefix(auth, "Basic ") { + return + } + c, err := base64.StdEncoding.DecodeString(strings.TrimPrefix(auth, "Basic ")) + if err != nil { + return + } + cs := string(c) + s := strings.IndexByte(cs, ':') + if s < 0 { + return + } + return cs[:s], cs[s+1:], true +} diff --git a/registry/context.go b/registry/context.go index 150e5de63..7c4dbb023 100644 --- a/registry/context.go +++ b/registry/context.go @@ -1,10 +1,14 @@ package registry import ( - "github.com/Sirupsen/logrus" + "fmt" + "net/http" + "github.com/docker/distribution/api/v2" - "github.com/docker/distribution/auth" + ctxu "github.com/docker/distribution/context" + "github.com/docker/distribution/digest" "github.com/docker/distribution/storage" + "golang.org/x/net/context" ) // Context should contain the request specific context for use in across @@ -13,9 +17,7 @@ import ( type Context struct { // App points to the application structure that created this context. *App - - // RequestID is the unique id of the request. - RequestID string + context.Context // Repository is the repository for the current request. All requests // should be scoped to a single repository. This field may be nil. @@ -26,15 +28,63 @@ type Context struct { // handler *must not* start the response via http.ResponseWriter. Errors v2.Errors - // AuthUserInfo contains information about an authorized client. - AuthUserInfo auth.UserInfo - - // vars contains the extracted gorilla/mux variables that can be used for - // assignment. - vars map[string]string - - // log provides a context specific logger. - log *logrus.Entry - urlBuilder *v2.URLBuilder + + // TODO(stevvooe): The goal is too completely factor this context and + // dispatching out of the web application. Ideally, we should lean on + // context.Context for injection of these resources. +} + +// Value overrides context.Context.Value to ensure that calls are routed to +// correct context. +func (ctx *Context) Value(key interface{}) interface{} { + return ctx.Context.Value(key) +} + +func getName(ctx context.Context) (name string) { + return ctxu.GetStringValue(ctx, "vars.name") +} + +func getTag(ctx context.Context) (tag string) { + return ctxu.GetStringValue(ctx, "vars.tag") +} + +var errDigestNotAvailable = fmt.Errorf("digest not available in context") + +func getDigest(ctx context.Context) (dgst digest.Digest, err error) { + dgstStr := ctxu.GetStringValue(ctx, "vars.digest") + + if dgstStr == "" { + ctxu.GetLogger(ctx).Errorf("digest not available") + return "", errDigestNotAvailable + } + + d, err := digest.ParseDigest(dgstStr) + if err != nil { + ctxu.GetLogger(ctx).Errorf("error parsing digest=%q: %v", dgstStr, err) + return "", err + } + + return d, nil +} + +func getUploadUUID(ctx context.Context) (uuid string) { + return ctxu.GetStringValue(ctx, "vars.uuid") +} + +// getUserName attempts to resolve a username from the context and request. If +// a username cannot be resolved, the empty string is returned. +func getUserName(ctx context.Context, r *http.Request) string { + username := ctxu.GetStringValue(ctx, "auth.user.name") + + // Fallback to request user with basic auth + if username == "" { + var ok bool + uname, _, ok := basicAuth(r) + if ok { + username = uname + } + } + + return username } diff --git a/registry/images.go b/registry/images.go index db6bd7058..c44b0b210 100644 --- a/registry/images.go +++ b/registry/images.go @@ -6,6 +6,7 @@ import ( "net/http" "github.com/docker/distribution/api/v2" + ctxu "github.com/docker/distribution/context" "github.com/docker/distribution/digest" "github.com/docker/distribution/manifest" "github.com/docker/distribution/storage" @@ -17,11 +18,9 @@ import ( func imageManifestDispatcher(ctx *Context, r *http.Request) http.Handler { imageManifestHandler := &imageManifestHandler{ Context: ctx, - Tag: ctx.vars["tag"], + Tag: getTag(ctx), } - imageManifestHandler.log = imageManifestHandler.log.WithField("tag", imageManifestHandler.Tag) - return handlers.MethodHandler{ "GET": http.HandlerFunc(imageManifestHandler.GetImageManifest), "PUT": http.HandlerFunc(imageManifestHandler.PutImageManifest), @@ -38,6 +37,7 @@ type imageManifestHandler struct { // GetImageManifest fetches the image manifest from the storage backend, if it exists. func (imh *imageManifestHandler) GetImageManifest(w http.ResponseWriter, r *http.Request) { + ctxu.GetLogger(imh).Debug("GetImageManifest") manifests := imh.Repository.Manifests() manifest, err := manifests.Get(imh.Tag) @@ -54,6 +54,7 @@ func (imh *imageManifestHandler) GetImageManifest(w http.ResponseWriter, r *http // PutImageManifest validates and stores and image in the registry. func (imh *imageManifestHandler) PutImageManifest(w http.ResponseWriter, r *http.Request) { + ctxu.GetLogger(imh).Debug("PutImageManifest") manifests := imh.Repository.Manifests() dec := json.NewDecoder(r.Body) @@ -98,6 +99,7 @@ func (imh *imageManifestHandler) PutImageManifest(w http.ResponseWriter, r *http // DeleteImageManifest removes the image with the given tag from the registry. func (imh *imageManifestHandler) DeleteImageManifest(w http.ResponseWriter, r *http.Request) { + ctxu.GetLogger(imh).Debug("DeleteImageManifest") manifests := imh.Repository.Manifests() if err := manifests.Delete(imh.Tag); err != nil { switch err := err.(type) { diff --git a/registry/layer.go b/registry/layer.go index bea1cc8b9..10569465c 100644 --- a/registry/layer.go +++ b/registry/layer.go @@ -4,6 +4,7 @@ import ( "net/http" "github.com/docker/distribution/api/v2" + ctxu "github.com/docker/distribution/context" "github.com/docker/distribution/digest" "github.com/docker/distribution/storage" "github.com/gorilla/handlers" @@ -11,9 +12,16 @@ import ( // layerDispatcher uses the request context to build a layerHandler. func layerDispatcher(ctx *Context, r *http.Request) http.Handler { - dgst, err := digest.ParseDigest(ctx.vars["digest"]) - + dgst, err := getDigest(ctx) if err != nil { + + if err == errDigestNotAvailable { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusNotFound) + ctx.Errors.Push(v2.ErrorCodeDigestInvalid, err) + }) + } + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { ctx.Errors.Push(v2.ErrorCodeDigestInvalid, err) }) @@ -24,8 +32,6 @@ func layerDispatcher(ctx *Context, r *http.Request) http.Handler { Digest: dgst, } - layerHandler.log = layerHandler.log.WithField("digest", dgst) - return handlers.MethodHandler{ "GET": http.HandlerFunc(layerHandler.GetLayer), "HEAD": http.HandlerFunc(layerHandler.GetLayer), @@ -42,6 +48,7 @@ type layerHandler struct { // GetLayer fetches the binary data from backend storage returns it in the // response. func (lh *layerHandler) GetLayer(w http.ResponseWriter, r *http.Request) { + ctxu.GetLogger(lh).Debug("GetImageLayer") layers := lh.Repository.Layers() layer, err := layers.Fetch(lh.Digest) diff --git a/registry/layerupload.go b/registry/layerupload.go index cfce98f3a..f30bb3aa6 100644 --- a/registry/layerupload.go +++ b/registry/layerupload.go @@ -7,8 +7,8 @@ import ( "net/url" "os" - "github.com/Sirupsen/logrus" "github.com/docker/distribution/api/v2" + ctxu "github.com/docker/distribution/context" "github.com/docker/distribution/digest" "github.com/docker/distribution/storage" "github.com/gorilla/handlers" @@ -19,7 +19,7 @@ import ( func layerUploadDispatcher(ctx *Context, r *http.Request) http.Handler { luh := &layerUploadHandler{ Context: ctx, - UUID: ctx.vars["uuid"], + UUID: getUploadUUID(ctx), } handler := http.Handler(handlers.MethodHandler{ @@ -33,12 +33,10 @@ func layerUploadDispatcher(ctx *Context, r *http.Request) http.Handler { }) if luh.UUID != "" { - luh.log = luh.log.WithField("uuid", luh.UUID) - state, err := hmacKey(ctx.Config.HTTP.Secret).unpackUploadState(r.FormValue("_state")) if err != nil { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - ctx.log.Infof("error resolving upload: %v", err) + ctxu.GetLogger(ctx).Infof("error resolving upload: %v", err) w.WriteHeader(http.StatusBadRequest) luh.Errors.Push(v2.ErrorCodeBlobUploadInvalid, err) }) @@ -47,7 +45,7 @@ func layerUploadDispatcher(ctx *Context, r *http.Request) http.Handler { if state.Name != ctx.Repository.Name() { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - ctx.log.Infof("mismatched repository name in upload state: %q != %q", state.Name, luh.Repository.Name()) + ctxu.GetLogger(ctx).Infof("mismatched repository name in upload state: %q != %q", state.Name, luh.Repository.Name()) w.WriteHeader(http.StatusBadRequest) luh.Errors.Push(v2.ErrorCodeBlobUploadInvalid, err) }) @@ -55,7 +53,7 @@ func layerUploadDispatcher(ctx *Context, r *http.Request) http.Handler { if state.UUID != luh.UUID { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - ctx.log.Infof("mismatched uuid in upload state: %q != %q", state.UUID, luh.UUID) + ctxu.GetLogger(ctx).Infof("mismatched uuid in upload state: %q != %q", state.UUID, luh.UUID) w.WriteHeader(http.StatusBadRequest) luh.Errors.Push(v2.ErrorCodeBlobUploadInvalid, err) }) @@ -64,7 +62,7 @@ func layerUploadDispatcher(ctx *Context, r *http.Request) http.Handler { layers := ctx.Repository.Layers() upload, err := layers.Resume(luh.UUID) if err != nil { - ctx.log.Errorf("error resolving upload: %v", err) + ctxu.GetLogger(ctx).Errorf("error resolving upload: %v", err) if err == storage.ErrLayerUploadUnknown { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusNotFound) @@ -86,7 +84,7 @@ func layerUploadDispatcher(ctx *Context, r *http.Request) http.Handler { // start over. if nn, err := upload.Seek(luh.State.Offset, os.SEEK_SET); err != nil { defer upload.Close() - ctx.log.Infof("error seeking layer upload: %v", err) + ctxu.GetLogger(ctx).Infof("error seeking layer upload: %v", err) return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusBadRequest) luh.Errors.Push(v2.ErrorCodeBlobUploadInvalid, err) @@ -94,7 +92,7 @@ func layerUploadDispatcher(ctx *Context, r *http.Request) http.Handler { }) } else if nn != luh.State.Offset { defer upload.Close() - ctx.log.Infof("seek to wrong offest: %d != %d", nn, luh.State.Offset) + ctxu.GetLogger(ctx).Infof("seek to wrong offest: %d != %d", nn, luh.State.Offset) return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusBadRequest) luh.Errors.Push(v2.ErrorCodeBlobUploadInvalid, err) @@ -202,7 +200,7 @@ func (luh *layerUploadHandler) PutLayerUploadComplete(w http.ResponseWriter, r * w.WriteHeader(http.StatusBadRequest) luh.Errors.Push(v2.ErrorCodeDigestInvalid, err) default: - luh.log.Errorf("unknown error completing upload: %#v", err) + ctxu.GetLogger(luh).Errorf("unknown error completing upload: %#v", err) w.WriteHeader(http.StatusInternalServerError) luh.Errors.Push(v2.ErrorCodeUnknown, err) } @@ -210,7 +208,7 @@ func (luh *layerUploadHandler) PutLayerUploadComplete(w http.ResponseWriter, r * // Clean up the backend layer data if there was an error. if err := luh.Upload.Cancel(); err != nil { // If the cleanup fails, all we can do is observe and report. - luh.log.Errorf("error canceling upload after error: %v", err) + ctxu.GetLogger(luh).Errorf("error canceling upload after error: %v", err) } return @@ -238,7 +236,7 @@ func (luh *layerUploadHandler) CancelLayerUpload(w http.ResponseWriter, r *http. } if err := luh.Upload.Cancel(); err != nil { - luh.log.Errorf("error encountered canceling upload: %v", err) + ctxu.GetLogger(luh).Errorf("error encountered canceling upload: %v", err) w.WriteHeader(http.StatusInternalServerError) luh.Errors.PushErr(err) } @@ -253,7 +251,7 @@ func (luh *layerUploadHandler) layerUploadResponse(w http.ResponseWriter, r *htt offset, err := luh.Upload.Seek(0, os.SEEK_CUR) if err != nil { - luh.log.Errorf("unable get current offset of layer upload: %v", err) + ctxu.GetLogger(luh).Errorf("unable get current offset of layer upload: %v", err) return err } @@ -265,7 +263,7 @@ func (luh *layerUploadHandler) layerUploadResponse(w http.ResponseWriter, r *htt token, err := hmacKey(luh.Config.HTTP.Secret).packUploadState(luh.State) if err != nil { - logrus.Infof("error building upload state token: %s", err) + ctxu.GetLogger(luh).Infof("error building upload state token: %s", err) return err } @@ -275,7 +273,7 @@ func (luh *layerUploadHandler) layerUploadResponse(w http.ResponseWriter, r *htt "_state": []string{token}, }) if err != nil { - logrus.Infof("error building upload url: %s", err) + ctxu.GetLogger(luh).Infof("error building upload url: %s", err) return err }