Merge branch '21678-installer-diagnostics-internal'. Closes #21678
[arvados.git] / lib / service / cmd.go
index b7decd88a4bbc5a6cfad8d9373bd5894105a37af..9ed0acfb8f7151e805c7269dceacb696f425c07b 100644 (file)
@@ -12,28 +12,31 @@ import (
        "io"
        "net"
        "net/http"
+       "net/http/httptest"
        _ "net/http/pprof"
        "net/url"
        "os"
+       "regexp"
        "strings"
+       "time"
 
        "git.arvados.org/arvados.git/lib/cmd"
        "git.arvados.org/arvados.git/lib/config"
        "git.arvados.org/arvados.git/sdk/go/arvados"
-       "git.arvados.org/arvados.git/sdk/go/auth"
        "git.arvados.org/arvados.git/sdk/go/ctxlog"
        "git.arvados.org/arvados.git/sdk/go/health"
        "git.arvados.org/arvados.git/sdk/go/httpserver"
        "github.com/coreos/go-systemd/daemon"
        "github.com/julienschmidt/httprouter"
        "github.com/prometheus/client_golang/prometheus"
-       "github.com/prometheus/client_golang/prometheus/promhttp"
        "github.com/sirupsen/logrus"
 )
 
 type Handler interface {
        http.Handler
        CheckHealth() error
+       // Done returns a channel that closes when the handler shuts
+       // itself down, or nil if this never happens.
        Done() <-chan struct{}
 }
 
@@ -45,6 +48,8 @@ type command struct {
        ctx        context.Context // enables tests to shutdown service; no public API yet
 }
 
+var requestQueueDumpCheckInterval = time.Minute
+
 // Command returns a cmd.Handler that loads site config, calls
 // newHandler with the current cluster and node configs, and brings up
 // an http server with the returned handler.
@@ -74,6 +79,13 @@ func (c *command) RunCommand(prog string, args []string, stdin io.Reader, stdout
 
        loader := config.NewLoader(stdin, log)
        loader.SetupFlags(flags)
+
+       // prog is [keepstore, keep-web, ...]  but the
+       // legacy config flags are [-legacy-keepstore-config,
+       // -legacy-keepweb-config, ...]
+       legacyFlag := "-legacy-" + strings.Replace(prog, "keep-", "keep", 1) + "-config"
+       args = loader.MungeLegacyConfigArgs(log, args, legacyFlag)
+
        versionFlag := flags.Bool("version", false, "Write version information to stdout and exit 0")
        pprofAddr := flags.String("pprof", "", "Serve Go profile data at `[addr]:port`")
        if ok, code := cmd.ParseFlags(flags, prog, args, "", stderr); !ok {
@@ -114,13 +126,24 @@ func (c *command) RunCommand(prog string, args []string, stdin io.Reader, stdout
        })
        ctx := ctxlog.Context(c.ctx, logger)
 
-       listenURL, err := getListenAddr(cluster.Services, c.svcName, log)
+       listenURL, internalURL, err := getListenAddr(cluster.Services, c.svcName, log)
        if err != nil {
                return 1
        }
-       ctx = context.WithValue(ctx, contextKeyURL{}, listenURL)
+       ctx = context.WithValue(ctx, contextKeyURL{}, internalURL)
 
        reg := prometheus.NewRegistry()
+       loader.RegisterMetrics(reg)
+
+       // arvados_version_running{version="1.2.3~4"} 1.0
+       mVersion := prometheus.NewGaugeVec(prometheus.GaugeOpts{
+               Namespace: "arvados",
+               Name:      "version_running",
+               Help:      "Indicated version is running.",
+       }, []string{"version"})
+       mVersion.WithLabelValues(cmd.Version.String()).Set(1)
+       reg.MustRegister(mVersion)
+
        handler := c.newHandler(ctx, cluster, cluster.SystemRootToken, reg)
        if err = handler.CheckHealth(); err != nil {
                return 1
@@ -129,19 +152,19 @@ func (c *command) RunCommand(prog string, args []string, stdin io.Reader, stdout
        instrumented := httpserver.Instrument(reg, log,
                httpserver.HandlerWithDeadline(cluster.API.RequestTimeout.Duration(),
                        httpserver.AddRequestIDs(
-                               httpserver.LogRequests(
-                                       interceptHealthReqs(cluster.ManagementToken, handler.CheckHealth,
-                                               interceptMetricsReqs(cluster.ManagementToken, reg, log,
-                                                       httpserver.NewRequestLimiter(cluster.API.MaxConcurrentRequests, handler, reg)))))))
+                               httpserver.Inspect(reg, cluster.ManagementToken,
+                                       httpserver.LogRequests(
+                                               interceptHealthReqs(cluster.ManagementToken, handler.CheckHealth,
+                                                       c.requestLimiter(handler, cluster, reg)))))))
        srv := &httpserver.Server{
                Server: http.Server{
-                       Handler:     instrumented.ServeAPI(cluster.ManagementToken, instrumented),
+                       Handler:     ifCollectionInHost(instrumented, instrumented.ServeAPI(cluster.ManagementToken, instrumented)),
                        BaseContext: func(net.Listener) context.Context { return ctx },
                },
                Addr: listenURL.Host,
        }
-       if listenURL.Scheme == "https" {
-               tlsconfig, err := tlsConfigWithCertUpdater(cluster, logger)
+       if listenURL.Scheme == "https" || listenURL.Scheme == "wss" {
+               tlsconfig, err := makeTLSConfig(cluster, logger)
                if err != nil {
                        logger.WithError(err).Errorf("cannot start %s service on %s", c.svcName, listenURL.String())
                        return 1
@@ -171,6 +194,7 @@ func (c *command) RunCommand(prog string, args []string, stdin io.Reader, stdout
                <-handler.Done()
                srv.Close()
        }()
+       go c.requestQueueDumpCheck(cluster, prog, reg, &srv.Server, logger)
        err = srv.Wait()
        if err != nil {
                return 1
@@ -178,6 +202,170 @@ func (c *command) RunCommand(prog string, args []string, stdin io.Reader, stdout
        return 0
 }
 
+// If SystemLogs.RequestQueueDumpDirectory is set, monitor the
+// server's incoming HTTP request limiters. When the number of
+// concurrent requests in any queue ("api" or "tunnel") exceeds 90% of
+// its maximum slots, write the /_inspect/requests data to a JSON file
+// in the specified directory.
+func (c *command) requestQueueDumpCheck(cluster *arvados.Cluster, prog string, reg *prometheus.Registry, srv *http.Server, logger logrus.FieldLogger) {
+       outdir := cluster.SystemLogs.RequestQueueDumpDirectory
+       if outdir == "" || cluster.ManagementToken == "" {
+               return
+       }
+       logger = logger.WithField("worker", "RequestQueueDump")
+       outfile := outdir + "/" + prog + "-requests.json"
+       for range time.NewTicker(requestQueueDumpCheckInterval).C {
+               mfs, err := reg.Gather()
+               if err != nil {
+                       logger.WithError(err).Warn("error getting metrics")
+                       continue
+               }
+               cur := map[string]int{} // queue label => current
+               max := map[string]int{} // queue label => max
+               for _, mf := range mfs {
+                       for _, m := range mf.GetMetric() {
+                               for _, ml := range m.GetLabel() {
+                                       if ml.GetName() == "queue" {
+                                               n := int(m.GetGauge().GetValue())
+                                               if name := mf.GetName(); name == "arvados_concurrent_requests" {
+                                                       cur[*ml.Value] = n
+                                               } else if name == "arvados_max_concurrent_requests" {
+                                                       max[*ml.Value] = n
+                                               }
+                                       }
+                               }
+                       }
+               }
+               dump := false
+               for queue, n := range cur {
+                       if n > 0 && max[queue] > 0 && n >= max[queue]*9/10 {
+                               dump = true
+                               break
+                       }
+               }
+               if dump {
+                       req, err := http.NewRequest("GET", "/_inspect/requests", nil)
+                       if err != nil {
+                               logger.WithError(err).Warn("error in http.NewRequest")
+                               continue
+                       }
+                       req.Header.Set("Authorization", "Bearer "+cluster.ManagementToken)
+                       resp := httptest.NewRecorder()
+                       srv.Handler.ServeHTTP(resp, req)
+                       if code := resp.Result().StatusCode; code != http.StatusOK {
+                               logger.WithField("StatusCode", code).Warn("error getting /_inspect/requests")
+                               continue
+                       }
+                       err = os.WriteFile(outfile, resp.Body.Bytes(), 0777)
+                       if err != nil {
+                               logger.WithError(err).Warn("error writing file")
+                               continue
+                       }
+               }
+       }
+}
+
+// Set up a httpserver.RequestLimiter with separate queues/streams for
+// API requests (obeying MaxConcurrentRequests etc) and gateway tunnel
+// requests (obeying MaxGatewayTunnels).
+func (c *command) requestLimiter(handler http.Handler, cluster *arvados.Cluster, reg *prometheus.Registry) http.Handler {
+       maxReqs := cluster.API.MaxConcurrentRequests
+       if maxRails := cluster.API.MaxConcurrentRailsRequests; maxRails > 0 &&
+               (maxRails < maxReqs || maxReqs == 0) &&
+               c.svcName == arvados.ServiceNameController {
+               // Ideally, we would accept up to
+               // MaxConcurrentRequests, and apply the
+               // MaxConcurrentRailsRequests limit only for requests
+               // that require calling upstream to RailsAPI. But for
+               // now we make the simplifying assumption that every
+               // controller request causes an upstream RailsAPI
+               // request.
+               maxReqs = maxRails
+       }
+       rqAPI := &httpserver.RequestQueue{
+               Label:                      "api",
+               MaxConcurrent:              maxReqs,
+               MaxQueue:                   cluster.API.MaxQueuedRequests,
+               MaxQueueTimeForMinPriority: cluster.API.MaxQueueTimeForLockRequests.Duration(),
+       }
+       rqTunnel := &httpserver.RequestQueue{
+               Label:         "tunnel",
+               MaxConcurrent: cluster.API.MaxGatewayTunnels,
+               MaxQueue:      0,
+       }
+       return &httpserver.RequestLimiter{
+               Handler:  handler,
+               Priority: c.requestPriority,
+               Registry: reg,
+               Queue: func(req *http.Request) *httpserver.RequestQueue {
+                       if req.Method == http.MethodPost && reTunnelPath.MatchString(req.URL.Path) {
+                               return rqTunnel
+                       } else {
+                               return rqAPI
+                       }
+               },
+       }
+}
+
+// reTunnelPath matches paths of API endpoints that go in the "tunnel"
+// queue.
+var reTunnelPath = regexp.MustCompile(func() string {
+       rePathVar := regexp.MustCompile(`{.*?}`)
+       out := ""
+       for _, endpoint := range []arvados.APIEndpoint{
+               arvados.EndpointContainerGatewayTunnel,
+               arvados.EndpointContainerGatewayTunnelCompat,
+               arvados.EndpointContainerSSH,
+               arvados.EndpointContainerSSHCompat,
+       } {
+               if out != "" {
+                       out += "|"
+               }
+               out += `\Q/` + rePathVar.ReplaceAllString(endpoint.Path, `\E[^/]*\Q`) + `\E`
+       }
+       return "^(" + out + ")$"
+}())
+
+func (c *command) requestPriority(req *http.Request, queued time.Time) int64 {
+       switch {
+       case req.Method == http.MethodPost && strings.HasPrefix(req.URL.Path, "/arvados/v1/containers/") && strings.HasSuffix(req.URL.Path, "/lock"):
+               // Return 503 immediately instead of queueing. We want
+               // to send feedback to dispatchcloud ASAP to stop
+               // bringing up new containers.
+               return httpserver.MinPriority
+       case req.Method == http.MethodPost && strings.HasPrefix(req.URL.Path, "/arvados/v1/logs"):
+               // "Create log entry" is the most harmless kind of
+               // request to drop. Negative priority is called "low"
+               // in aggregate metrics.
+               return -1
+       case req.Header.Get("Origin") != "":
+               // Handle interactive requests first. Positive
+               // priority is called "high" in aggregate metrics.
+               return 1
+       default:
+               // Zero priority is called "normal" in aggregate
+               // metrics.
+               return 0
+       }
+}
+
+// If an incoming request's target vhost has an embedded collection
+// UUID or PDH, handle it with hTrue, otherwise handle it with
+// hFalse.
+//
+// Facilitates routing "http://collections.example/metrics" to metrics
+// and "http://{uuid}.collections.example/metrics" to a file in a
+// collection.
+func ifCollectionInHost(hTrue, hFalse http.Handler) http.Handler {
+       return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+               if arvados.CollectionIDFromDNSName(r.Host) != "" {
+                       hTrue.ServeHTTP(w, r)
+               } else {
+                       hFalse.ServeHTTP(w, r)
+               }
+       })
+}
+
 func interceptHealthReqs(mgtToken string, checkHealth func() error, next http.Handler) http.Handler {
        mux := httprouter.New()
        mux.Handler("GET", "/_health/ping", &health.Handler{
@@ -186,43 +374,75 @@ func interceptHealthReqs(mgtToken string, checkHealth func() error, next http.Ha
                Routes: health.Routes{"ping": checkHealth},
        })
        mux.NotFound = next
-       return mux
+       return ifCollectionInHost(next, mux)
 }
 
-func interceptMetricsReqs(mgtToken string, reg *prometheus.Registry, log logrus.FieldLogger, next http.Handler) http.Handler {
-       mux := httprouter.New()
-       metricsH := auth.RequireLiteralToken(mgtToken,
-               promhttp.HandlerFor(reg, promhttp.HandlerOpts{
-                       ErrorLog: log,
-               }))
-       mux.Handler("GET", "/metrics", metricsH)
-       mux.Handler("GET", "/metrics.json", metricsH)
-       mux.NotFound = next
-       return mux
-}
-
-func getListenAddr(svcs arvados.Services, prog arvados.ServiceName, log logrus.FieldLogger) (arvados.URL, error) {
+// Determine listenURL (addr:port where server should bind) and
+// internalURL (target url that client should connect to) for a
+// service.
+//
+// If the config does not specify ListenURL, we check all of the
+// configured InternalURLs. If there is exactly one that matches our
+// hostname, or exactly one that matches a local interface address,
+// then we use that as listenURL.
+//
+// Note that listenURL and internalURL may use different protocols
+// (e.g., listenURL is http, but the service sits behind a proxy, so
+// clients connect using https).
+func getListenAddr(svcs arvados.Services, prog arvados.ServiceName, log logrus.FieldLogger) (arvados.URL, arvados.URL, error) {
        svc, ok := svcs.Map()[prog]
        if !ok {
-               return arvados.URL{}, fmt.Errorf("unknown service name %q", prog)
+               return arvados.URL{}, arvados.URL{}, fmt.Errorf("unknown service name %q", prog)
        }
 
-       if want := os.Getenv("ARVADOS_SERVICE_INTERNAL_URL"); want == "" {
-       } else if url, err := url.Parse(want); err != nil {
-               return arvados.URL{}, fmt.Errorf("$ARVADOS_SERVICE_INTERNAL_URL (%q): %s", want, err)
-       } else {
+       if want := os.Getenv("ARVADOS_SERVICE_INTERNAL_URL"); want != "" {
+               url, err := url.Parse(want)
+               if err != nil {
+                       return arvados.URL{}, arvados.URL{}, fmt.Errorf("$ARVADOS_SERVICE_INTERNAL_URL (%q): %s", want, err)
+               }
                if url.Path == "" {
                        url.Path = "/"
                }
-               return arvados.URL(*url), nil
+               for internalURL, conf := range svc.InternalURLs {
+                       if internalURL.String() == url.String() {
+                               listenURL := conf.ListenURL
+                               if listenURL.Host == "" {
+                                       listenURL = internalURL
+                               }
+                               return listenURL, internalURL, nil
+                       }
+               }
+               log.Warnf("possible configuration error: listening on %s (from $ARVADOS_SERVICE_INTERNAL_URL) even though configuration does not have a matching InternalURLs entry", url)
+               internalURL := arvados.URL(*url)
+               return internalURL, internalURL, nil
        }
 
        errors := []string{}
-       for url := range svc.InternalURLs {
-               listener, err := net.Listen("tcp", url.Host)
+       for internalURL, conf := range svc.InternalURLs {
+               listenURL := conf.ListenURL
+               if listenURL.Host == "" {
+                       // If ListenURL is not specified, assume
+                       // InternalURL is also usable as the listening
+                       // proto/addr/port (i.e., simple case with no
+                       // intermediate proxy/routing)
+                       listenURL = internalURL
+               }
+               listenAddr := listenURL.Host
+               if _, _, err := net.SplitHostPort(listenAddr); err != nil {
+                       // url "https://foo.example/" (with no
+                       // explicit port name/number) means listen on
+                       // the well-known port for the specified
+                       // protocol, "foo.example:https".
+                       port := listenURL.Scheme
+                       if port == "ws" || port == "wss" {
+                               port = "http" + port[2:]
+                       }
+                       listenAddr = net.JoinHostPort(listenAddr, port)
+               }
+               listener, err := net.Listen("tcp", listenAddr)
                if err == nil {
                        listener.Close()
-                       return url, nil
+                       return listenURL, internalURL, nil
                } else if strings.Contains(err.Error(), "cannot assign requested address") {
                        // If 'Host' specifies a different server than
                        // the current one, it'll resolve the hostname
@@ -230,13 +450,13 @@ func getListenAddr(svcs arvados.Services, prog arvados.ServiceName, log logrus.F
                        // can't bind an IP address it doesn't own.
                        continue
                } else {
-                       errors = append(errors, fmt.Sprintf("tried %v, got %v", url, err))
+                       errors = append(errors, fmt.Sprintf("%s: %s", listenURL, err))
                }
        }
        if len(errors) > 0 {
-               return arvados.URL{}, fmt.Errorf("could not enable the %q service on this host: %s", prog, strings.Join(errors, "; "))
+               return arvados.URL{}, arvados.URL{}, fmt.Errorf("could not enable the %q service on this host: %s", prog, strings.Join(errors, "; "))
        }
-       return arvados.URL{}, fmt.Errorf("configuration does not enable the %q service on this host", prog)
+       return arvados.URL{}, arvados.URL{}, fmt.Errorf("configuration does not enable the %q service on this host", prog)
 }
 
 type contextKeyURL struct{}