18870: Need to declare NODES as array
[arvados.git] / services / keepproxy / keepproxy.go
index c679e5b91cff8f9b86daa0b8ccda60aa20b36f96..f857ed3e4ebf4859e1355260ce85bc52fa50de90 100644 (file)
 //
 // SPDX-License-Identifier: AGPL-3.0
 
-package main
+package keepproxy
 
 import (
+       "context"
        "errors"
-       "flag"
        "fmt"
        "io"
        "io/ioutil"
        "net"
        "net/http"
-       "os"
-       "os/signal"
        "regexp"
        "strings"
-       "syscall"
        "time"
 
-       "git.arvados.org/arvados.git/lib/config"
+       "git.arvados.org/arvados.git/lib/service"
        "git.arvados.org/arvados.git/sdk/go/arvados"
        "git.arvados.org/arvados.git/sdk/go/arvadosclient"
+       "git.arvados.org/arvados.git/sdk/go/ctxlog"
        "git.arvados.org/arvados.git/sdk/go/health"
        "git.arvados.org/arvados.git/sdk/go/httpserver"
        "git.arvados.org/arvados.git/sdk/go/keepclient"
-       "github.com/coreos/go-systemd/daemon"
-       "github.com/ghodss/yaml"
        "github.com/gorilla/mux"
        lru "github.com/hashicorp/golang-lru"
-       log "github.com/sirupsen/logrus"
-)
-
-var version = "dev"
-
-var (
-       listener net.Listener
-       router   http.Handler
+       "github.com/prometheus/client_golang/prometheus"
+       "github.com/sirupsen/logrus"
 )
 
 const rfc3339NanoFixed = "2006-01-02T15:04:05.000000000Z07:00"
 
-func configure(logger log.FieldLogger, args []string) (*arvados.Cluster, error) {
-       flags := flag.NewFlagSet(args[0], flag.ExitOnError)
-
-       dumpConfig := flags.Bool("dump-config", false, "write current configuration to stdout and exit")
-       getVersion := flags.Bool("version", false, "Print version information and exit.")
-
-       loader := config.NewLoader(os.Stdin, logger)
-       loader.SetupFlags(flags)
-
-       args = loader.MungeLegacyConfigArgs(logger, args[1:], "-legacy-keepproxy-config")
-       flags.Parse(args)
-
-       // Print version information if requested
-       if *getVersion {
-               fmt.Printf("keepproxy %s\n", version)
-               return nil, nil
-       }
-
-       cfg, err := loader.Load()
-       if err != nil {
-               return nil, err
-       }
-       cluster, err := cfg.GetCluster("")
-       if err != nil {
-               return nil, err
-       }
-
-       if *dumpConfig {
-               out, err := yaml.Marshal(cfg)
-               if err != nil {
-                       return nil, err
-               }
-               if _, err := os.Stdout.Write(out); err != nil {
-                       return nil, err
-               }
-               return nil, nil
-       }
-       return cluster, nil
-}
-
-func main() {
-       logger := log.New()
-       logger.Formatter = &log.JSONFormatter{
-               TimestampFormat: rfc3339NanoFixed,
-       }
-
-       cluster, err := configure(logger, os.Args)
-       if err != nil {
-               log.Fatal(err)
-       }
-       if cluster == nil {
-               return
-       }
-
-       log.Printf("keepproxy %s started", version)
-
-       if err := run(logger, cluster); err != nil {
-               log.Fatal(err)
-       }
-
-       log.Println("shutting down")
-}
+var Command = service.Command(arvados.ServiceNameKeepproxy, newHandlerOrErrorHandler)
 
-func run(logger log.FieldLogger, cluster *arvados.Cluster) error {
+func newHandlerOrErrorHandler(ctx context.Context, cluster *arvados.Cluster, token string, reg *prometheus.Registry) service.Handler {
        client, err := arvados.NewClientFromConfig(cluster)
        if err != nil {
-               return err
+               return service.ErrorHandler(ctx, cluster, fmt.Errorf("Error setting up arvados client: %w", err))
        }
-       client.AuthToken = cluster.SystemRootToken
-
        arv, err := arvadosclient.New(client)
        if err != nil {
-               return fmt.Errorf("Error setting up arvados client %v", err)
-       }
-
-       // If a config file is available, use the keepstores defined there
-       // instead of the legacy autodiscover mechanism via the API server
-       for k := range cluster.Services.Keepstore.InternalURLs {
-               arv.KeepServiceURIs = append(arv.KeepServiceURIs, strings.TrimRight(k.String(), "/"))
-       }
-
-       if cluster.SystemLogs.LogLevel == "debug" {
-               keepclient.DebugPrintf = log.Printf
+               return service.ErrorHandler(ctx, cluster, fmt.Errorf("Error setting up arvados client: %w", err))
        }
        kc, err := keepclient.MakeKeepClient(arv)
        if err != nil {
-               return fmt.Errorf("Error setting up keep client %v", err)
+               return service.ErrorHandler(ctx, cluster, fmt.Errorf("Error setting up keep client: %w", err))
        }
        keepclient.RefreshServiceDiscoveryOnSIGHUP()
-
-       if cluster.Collections.DefaultReplication > 0 {
-               kc.Want_replicas = cluster.Collections.DefaultReplication
-       }
-
-       var listen arvados.URL
-       for listen = range cluster.Services.Keepproxy.InternalURLs {
-               break
-       }
-
-       var lErr error
-       listener, lErr = net.Listen("tcp", listen.Host)
-       if lErr != nil {
-               return fmt.Errorf("listen(%s): %v", listen.Host, lErr)
-       }
-
-       if _, err := daemon.SdNotify(false, "READY=1"); err != nil {
-               log.Printf("Error notifying init daemon: %v", err)
-       }
-       log.Println("listening at", listener.Addr())
-
-       // Shut down the server gracefully (by closing the listener)
-       // if SIGTERM is received.
-       term := make(chan os.Signal, 1)
-       go func(sig <-chan os.Signal) {
-               s := <-sig
-               log.Println("caught signal:", s)
-               listener.Close()
-       }(term)
-       signal.Notify(term, syscall.SIGTERM)
-       signal.Notify(term, syscall.SIGINT)
-
-       // Start serving requests.
-       router, err = MakeRESTRouter(kc, time.Duration(keepclient.DefaultProxyRequestTimeout), cluster, logger)
+       router, err := newHandler(ctx, kc, time.Duration(keepclient.DefaultProxyRequestTimeout), cluster)
        if err != nil {
-               return err
+               return service.ErrorHandler(ctx, cluster, err)
        }
-       return http.Serve(listener, httpserver.AddRequestIDs(httpserver.LogRequests(router)))
+       return router
 }
 
-type TokenCacheEntry struct {
+type tokenCacheEntry struct {
        expire int64
        user   *arvados.User
 }
 
-type APITokenCache struct {
+type apiTokenCache struct {
        tokens     *lru.TwoQueueCache
        expireTime int64
 }
 
 // RememberToken caches the token and set an expire time.  If the
 // token is already in the cache, it is not updated.
-func (cache *APITokenCache) RememberToken(token string, user *arvados.User) {
+func (cache *apiTokenCache) RememberToken(token string, user *arvados.User) {
        now := time.Now().Unix()
        _, ok := cache.tokens.Get(token)
        if !ok {
-               cache.tokens.Add(token, TokenCacheEntry{
+               cache.tokens.Add(token, tokenCacheEntry{
                        expire: now + cache.expireTime,
                        user:   user,
                })
@@ -195,13 +79,13 @@ func (cache *APITokenCache) RememberToken(token string, user *arvados.User) {
 
 // RecallToken checks if the cached token is known and still believed to be
 // valid.
-func (cache *APITokenCache) RecallToken(token string) (bool, *arvados.User) {
+func (cache *apiTokenCache) RecallToken(token string) (bool, *arvados.User) {
        val, ok := cache.tokens.Get(token)
        if !ok {
                return false, nil
        }
 
-       cacheEntry := val.(TokenCacheEntry)
+       cacheEntry := val.(tokenCacheEntry)
        now := time.Now().Unix()
        if now < cacheEntry.expire {
                // Token is known and still valid
@@ -213,18 +97,15 @@ func (cache *APITokenCache) RecallToken(token string) (bool, *arvados.User) {
        }
 }
 
-// GetRemoteAddress returns a string with the remote address for the request.
-// If the X-Forwarded-For header is set and has a non-zero length, it returns a
-// string made from a comma separated list of all the remote addresses,
-// starting with the one(s) from the X-Forwarded-For header.
-func GetRemoteAddress(req *http.Request) string {
-       if xff := req.Header.Get("X-Forwarded-For"); xff != "" {
-               return xff + "," + req.RemoteAddr
-       }
-       return req.RemoteAddr
+func (h *proxyHandler) Done() <-chan struct{} {
+       return nil
+}
+
+func (h *proxyHandler) CheckHealth() error {
+       return nil
 }
 
-func (h *proxyHandler) CheckAuthorizationHeader(req *http.Request) (pass bool, tok string, user *arvados.User) {
+func (h *proxyHandler) checkAuthorizationHeader(req *http.Request) (pass bool, tok string, user *arvados.User) {
        parts := strings.SplitN(req.Header.Get("Authorization"), " ", 2)
        if len(parts) < 2 || !(parts[0] == "OAuth2" || parts[0] == "Bearer") || len(parts[1]) == 0 {
                return false, "", nil
@@ -242,7 +123,7 @@ func (h *proxyHandler) CheckAuthorizationHeader(req *http.Request) (pass bool, t
                op = "write"
        }
 
-       if ok, user := h.APITokenCache.RecallToken(op + ":" + tok); ok {
+       if ok, user := h.apiTokenCache.RecallToken(op + ":" + tok); ok {
                // Valid in the cache, short circuit
                return true, tok, user
        }
@@ -266,7 +147,7 @@ func (h *proxyHandler) CheckAuthorizationHeader(req *http.Request) (pass bool, t
                }
        }
        if err != nil {
-               log.Printf("%s: CheckAuthorizationHeader error: %v", GetRemoteAddress(req), err)
+               ctxlog.FromContext(req.Context()).WithError(err).Info("checkAuthorizationHeader error")
                return false, "", nil
        }
 
@@ -289,7 +170,7 @@ func (h *proxyHandler) CheckAuthorizationHeader(req *http.Request) (pass bool, t
        }
 
        // Success!  Update cache
-       h.APITokenCache.RememberToken(op+":"+tok, user)
+       h.apiTokenCache.RememberToken(op+":"+tok, user)
 
        return true, tok, user
 }
@@ -305,16 +186,13 @@ var defaultTransport = *(http.DefaultTransport.(*http.Transport))
 type proxyHandler struct {
        http.Handler
        *keepclient.KeepClient
-       *APITokenCache
+       *apiTokenCache
        timeout   time.Duration
        transport *http.Transport
-       logger    log.FieldLogger
        cluster   *arvados.Cluster
 }
 
-// MakeRESTRouter returns an http.Handler that passes GET and PUT
-// requests to the appropriate handlers.
-func MakeRESTRouter(kc *keepclient.KeepClient, timeout time.Duration, cluster *arvados.Cluster, logger log.FieldLogger) (http.Handler, error) {
+func newHandler(ctx context.Context, kc *keepclient.KeepClient, timeout time.Duration, cluster *arvados.Cluster) (service.Handler, error) {
        rest := mux.NewRouter()
 
        transport := defaultTransport
@@ -336,11 +214,10 @@ func MakeRESTRouter(kc *keepclient.KeepClient, timeout time.Duration, cluster *a
                KeepClient: kc,
                timeout:    timeout,
                transport:  &transport,
-               APITokenCache: &APITokenCache{
+               apiTokenCache: &apiTokenCache{
                        tokens:     cacheQ,
                        expireTime: 300,
                },
-               logger:  logger,
                cluster: cluster,
        }
 
@@ -364,7 +241,7 @@ func MakeRESTRouter(kc *keepclient.KeepClient, timeout time.Duration, cluster *a
                Prefix: "/_health/",
        }).Methods("GET")
 
-       rest.NotFoundHandler = InvalidPathHandler{}
+       rest.NotFoundHandler = invalidPathHandler{}
        return h, nil
 }
 
@@ -372,30 +249,28 @@ var errLoopDetected = errors.New("loop detected")
 
 func (h *proxyHandler) checkLoop(resp http.ResponseWriter, req *http.Request) error {
        if via := req.Header.Get("Via"); strings.Index(via, " "+viaAlias) >= 0 {
-               h.logger.Printf("proxy loop detected (request has Via: %q): perhaps keepproxy is misidentified by gateway config as an external client, or its keep_services record does not have service_type=proxy?", via)
+               ctxlog.FromContext(req.Context()).Printf("proxy loop detected (request has Via: %q): perhaps keepproxy is misidentified by gateway config as an external client, or its keep_services record does not have service_type=proxy?", via)
                http.Error(resp, errLoopDetected.Error(), http.StatusInternalServerError)
                return errLoopDetected
        }
        return nil
 }
 
-func SetCorsHeaders(resp http.ResponseWriter) {
+func setCORSHeaders(resp http.ResponseWriter) {
        resp.Header().Set("Access-Control-Allow-Methods", "GET, HEAD, POST, PUT, OPTIONS")
        resp.Header().Set("Access-Control-Allow-Origin", "*")
        resp.Header().Set("Access-Control-Allow-Headers", "Authorization, Content-Length, Content-Type, X-Keep-Desired-Replicas")
        resp.Header().Set("Access-Control-Max-Age", "86486400")
 }
 
-type InvalidPathHandler struct{}
+type invalidPathHandler struct{}
 
-func (InvalidPathHandler) ServeHTTP(resp http.ResponseWriter, req *http.Request) {
-       log.Printf("%s: %s %s unroutable", GetRemoteAddress(req), req.Method, req.URL.Path)
+func (invalidPathHandler) ServeHTTP(resp http.ResponseWriter, req *http.Request) {
        http.Error(resp, "Bad request", http.StatusBadRequest)
 }
 
 func (h *proxyHandler) Options(resp http.ResponseWriter, req *http.Request) {
-       log.Printf("%s: %s %s", GetRemoteAddress(req), req.Method, req.URL.Path)
-       SetCorsHeaders(resp)
+       setCORSHeaders(resp)
 }
 
 var errBadAuthorizationHeader = errors.New("Missing or invalid Authorization header, or method not allowed")
@@ -408,7 +283,7 @@ func (h *proxyHandler) Get(resp http.ResponseWriter, req *http.Request) {
        if err := h.checkLoop(resp, req); err != nil {
                return
        }
-       SetCorsHeaders(resp)
+       setCORSHeaders(resp)
        resp.Header().Set("Via", req.Proto+" "+viaAlias)
 
        locator := mux.Vars(req)["locator"]
@@ -417,8 +292,15 @@ func (h *proxyHandler) Get(resp http.ResponseWriter, req *http.Request) {
        var expectLength, responseLength int64
        var proxiedURI = "-"
 
+       logger := ctxlog.FromContext(req.Context())
        defer func() {
-               log.Println(GetRemoteAddress(req), req.Method, req.URL.Path, status, expectLength, responseLength, proxiedURI, err)
+               httpserver.SetResponseLogFields(req.Context(), logrus.Fields{
+                       "locator":        locator,
+                       "expectLength":   expectLength,
+                       "responseLength": responseLength,
+                       "proxiedURI":     proxiedURI,
+                       "err":            err,
+               })
                if status != http.StatusOK {
                        http.Error(resp, err.Error(), status)
                }
@@ -429,10 +311,14 @@ func (h *proxyHandler) Get(resp http.ResponseWriter, req *http.Request) {
        var pass bool
        var tok string
        var user *arvados.User
-       if pass, tok, user = h.CheckAuthorizationHeader(req); !pass {
+       if pass, tok, user = h.checkAuthorizationHeader(req); !pass {
                status, err = http.StatusForbidden, errBadAuthorizationHeader
                return
        }
+       httpserver.SetResponseLogFields(req.Context(), logrus.Fields{
+               "userUUID":     user.UUID,
+               "userFullName": user.FullName,
+       })
 
        // Copy ArvadosClient struct and use the client's API token
        arvclient := *kc.Arvados
@@ -443,18 +329,6 @@ func (h *proxyHandler) Get(resp http.ResponseWriter, req *http.Request) {
 
        locator = removeHint.ReplaceAllString(locator, "$1")
 
-       if locator != "" {
-               parts := strings.SplitN(locator, "+", 3)
-               if len(parts) >= 2 {
-                       logger := h.logger
-                       if user != nil {
-                               logger = logger.WithField("user_uuid", user.UUID).
-                                       WithField("user_full_name", user.FullName)
-                       }
-                       logger.WithField("locator", fmt.Sprintf("%s+%s", parts[0], parts[1])).Infof("Block download")
-               }
-       }
-
        switch req.Method {
        case "HEAD":
                expectLength, proxiedURI, err = kc.Ask(locator)
@@ -469,7 +343,7 @@ func (h *proxyHandler) Get(resp http.ResponseWriter, req *http.Request) {
        }
 
        if expectLength == -1 {
-               log.Println("Warning:", GetRemoteAddress(req), req.Method, proxiedURI, "Content-Length not provided")
+               logger.Warn("Content-Length not provided")
        }
 
        switch respErr := err.(type) {
@@ -505,7 +379,7 @@ func (h *proxyHandler) Put(resp http.ResponseWriter, req *http.Request) {
        if err := h.checkLoop(resp, req); err != nil {
                return
        }
-       SetCorsHeaders(resp)
+       setCORSHeaders(resp)
        resp.Header().Set("Via", "HTTP/1.1 "+viaAlias)
 
        kc := h.makeKeepClient(req)
@@ -517,7 +391,13 @@ func (h *proxyHandler) Put(resp http.ResponseWriter, req *http.Request) {
        var locatorOut string = "-"
 
        defer func() {
-               log.Println(GetRemoteAddress(req), req.Method, req.URL.Path, status, expectLength, kc.Want_replicas, wroteReplicas, locatorOut, err)
+               httpserver.SetResponseLogFields(req.Context(), logrus.Fields{
+                       "expectLength":  expectLength,
+                       "wantReplicas":  kc.Want_replicas,
+                       "wroteReplicas": wroteReplicas,
+                       "locator":       strings.SplitN(locatorOut, "+A", 2)[0],
+                       "err":           err,
+               })
                if status != http.StatusOK {
                        http.Error(resp, err.Error(), status)
                }
@@ -531,7 +411,7 @@ func (h *proxyHandler) Put(resp http.ResponseWriter, req *http.Request) {
                for _, sc := range strings.Split(req.Header.Get("X-Keep-Storage-Classes"), ",") {
                        scl = append(scl, strings.Trim(sc, " "))
                }
-               kc.StorageClasses = scl
+               kc.SetStorageClasses(scl)
        }
 
        _, err = fmt.Sscanf(req.Header.Get("Content-Length"), "%d", &expectLength)
@@ -556,11 +436,15 @@ func (h *proxyHandler) Put(resp http.ResponseWriter, req *http.Request) {
        var pass bool
        var tok string
        var user *arvados.User
-       if pass, tok, user = h.CheckAuthorizationHeader(req); !pass {
+       if pass, tok, user = h.checkAuthorizationHeader(req); !pass {
                err = errBadAuthorizationHeader
                status = http.StatusForbidden
                return
        }
+       httpserver.SetResponseLogFields(req.Context(), logrus.Fields{
+               "userUUID":     user.UUID,
+               "userFullName": user.FullName,
+       })
 
        // Copy ArvadosClient struct and use the client's API token
        arvclient := *kc.Arvados
@@ -589,18 +473,6 @@ func (h *proxyHandler) Put(resp http.ResponseWriter, req *http.Request) {
                locatorOut, wroteReplicas, err = kc.PutHR(locatorIn, req.Body, expectLength)
        }
 
-       if locatorOut != "" {
-               parts := strings.SplitN(locatorOut, "+", 3)
-               if len(parts) >= 2 {
-                       logger := h.logger
-                       if user != nil {
-                               logger = logger.WithField("user_uuid", user.UUID).
-                                       WithField("user_full_name", user.FullName)
-                       }
-                       logger.WithField("locator", fmt.Sprintf("%s+%s", parts[0], parts[1])).Infof("Block upload")
-               }
-       }
-
        // Tell the client how many successful PUTs we accomplished
        resp.Header().Set(keepclient.XKeepReplicasStored, fmt.Sprintf("%d", wroteReplicas))
 
@@ -642,7 +514,7 @@ func (h *proxyHandler) Put(resp http.ResponseWriter, req *http.Request) {
 //   Aborts on any errors
 // Concatenates responses from all those keep servers and returns
 func (h *proxyHandler) Index(resp http.ResponseWriter, req *http.Request) {
-       SetCorsHeaders(resp)
+       setCORSHeaders(resp)
 
        prefix := mux.Vars(req)["prefix"]
        var err error
@@ -655,7 +527,7 @@ func (h *proxyHandler) Index(resp http.ResponseWriter, req *http.Request) {
        }()
 
        kc := h.makeKeepClient(req)
-       ok, token, _ := h.CheckAuthorizationHeader(req)
+       ok, token, _ := h.checkAuthorizationHeader(req)
        if !ok {
                status, err = http.StatusForbidden, errBadAuthorizationHeader
                return