Merge branch '20475-dump-busy-queue'
[arvados.git] / lib / service / cmd.go
1 // Copyright (C) The Arvados Authors. All rights reserved.
2 //
3 // SPDX-License-Identifier: Apache-2.0
4
5 // Package service provides a cmd.Handler that brings up a system service.
6 package service
7
8 import (
9         "context"
10         "flag"
11         "fmt"
12         "io"
13         "net"
14         "net/http"
15         "net/http/httptest"
16         _ "net/http/pprof"
17         "net/url"
18         "os"
19         "strings"
20         "time"
21
22         "git.arvados.org/arvados.git/lib/cmd"
23         "git.arvados.org/arvados.git/lib/config"
24         "git.arvados.org/arvados.git/sdk/go/arvados"
25         "git.arvados.org/arvados.git/sdk/go/ctxlog"
26         "git.arvados.org/arvados.git/sdk/go/health"
27         "git.arvados.org/arvados.git/sdk/go/httpserver"
28         "github.com/coreos/go-systemd/daemon"
29         "github.com/julienschmidt/httprouter"
30         "github.com/prometheus/client_golang/prometheus"
31         "github.com/sirupsen/logrus"
32 )
33
34 type Handler interface {
35         http.Handler
36         CheckHealth() error
37         // Done returns a channel that closes when the handler shuts
38         // itself down, or nil if this never happens.
39         Done() <-chan struct{}
40 }
41
42 type NewHandlerFunc func(_ context.Context, _ *arvados.Cluster, token string, registry *prometheus.Registry) Handler
43
44 type command struct {
45         newHandler NewHandlerFunc
46         svcName    arvados.ServiceName
47         ctx        context.Context // enables tests to shutdown service; no public API yet
48 }
49
50 var requestQueueDumpCheckInterval = time.Minute
51
52 // Command returns a cmd.Handler that loads site config, calls
53 // newHandler with the current cluster and node configs, and brings up
54 // an http server with the returned handler.
55 //
56 // The handler is wrapped with server middleware (adding X-Request-ID
57 // headers, logging requests/responses, etc).
58 func Command(svcName arvados.ServiceName, newHandler NewHandlerFunc) cmd.Handler {
59         return &command{
60                 newHandler: newHandler,
61                 svcName:    svcName,
62                 ctx:        context.Background(),
63         }
64 }
65
66 func (c *command) RunCommand(prog string, args []string, stdin io.Reader, stdout, stderr io.Writer) int {
67         log := ctxlog.New(stderr, "json", "info")
68
69         var err error
70         defer func() {
71                 if err != nil {
72                         log.WithError(err).Error("exiting")
73                 }
74         }()
75
76         flags := flag.NewFlagSet("", flag.ContinueOnError)
77         flags.SetOutput(stderr)
78
79         loader := config.NewLoader(stdin, log)
80         loader.SetupFlags(flags)
81
82         // prog is [keepstore, keep-web, git-httpd, ...]  but the
83         // legacy config flags are [-legacy-keepstore-config,
84         // -legacy-keepweb-config, -legacy-git-httpd-config, ...]
85         legacyFlag := "-legacy-" + strings.Replace(prog, "keep-", "keep", 1) + "-config"
86         args = loader.MungeLegacyConfigArgs(log, args, legacyFlag)
87
88         versionFlag := flags.Bool("version", false, "Write version information to stdout and exit 0")
89         pprofAddr := flags.String("pprof", "", "Serve Go profile data at `[addr]:port`")
90         if ok, code := cmd.ParseFlags(flags, prog, args, "", stderr); !ok {
91                 return code
92         } else if *versionFlag {
93                 return cmd.Version.RunCommand(prog, args, stdin, stdout, stderr)
94         }
95
96         if *pprofAddr != "" {
97                 go func() {
98                         log.Println(http.ListenAndServe(*pprofAddr, nil))
99                 }()
100         }
101
102         if strings.HasSuffix(prog, "controller") {
103                 // Some config-loader checks try to make API calls via
104                 // controller. Those can't be expected to work if this
105                 // process _is_ the controller: we haven't started an
106                 // http server yet.
107                 loader.SkipAPICalls = true
108         }
109
110         cfg, err := loader.Load()
111         if err != nil {
112                 return 1
113         }
114         cluster, err := cfg.GetCluster("")
115         if err != nil {
116                 return 1
117         }
118
119         // Now that we've read the config, replace the bootstrap
120         // logger with a new one according to the logging config.
121         log = ctxlog.New(stderr, cluster.SystemLogs.Format, cluster.SystemLogs.LogLevel)
122         logger := log.WithFields(logrus.Fields{
123                 "PID":       os.Getpid(),
124                 "ClusterID": cluster.ClusterID,
125         })
126         ctx := ctxlog.Context(c.ctx, logger)
127
128         listenURL, internalURL, err := getListenAddr(cluster.Services, c.svcName, log)
129         if err != nil {
130                 return 1
131         }
132         ctx = context.WithValue(ctx, contextKeyURL{}, internalURL)
133
134         reg := prometheus.NewRegistry()
135         loader.RegisterMetrics(reg)
136
137         // arvados_version_running{version="1.2.3~4"} 1.0
138         mVersion := prometheus.NewGaugeVec(prometheus.GaugeOpts{
139                 Namespace: "arvados",
140                 Name:      "version_running",
141                 Help:      "Indicated version is running.",
142         }, []string{"version"})
143         mVersion.WithLabelValues(cmd.Version.String()).Set(1)
144         reg.MustRegister(mVersion)
145
146         handler := c.newHandler(ctx, cluster, cluster.SystemRootToken, reg)
147         if err = handler.CheckHealth(); err != nil {
148                 return 1
149         }
150
151         instrumented := httpserver.Instrument(reg, log,
152                 httpserver.HandlerWithDeadline(cluster.API.RequestTimeout.Duration(),
153                         httpserver.AddRequestIDs(
154                                 httpserver.Inspect(reg, cluster.ManagementToken,
155                                         httpserver.LogRequests(
156                                                 interceptHealthReqs(cluster.ManagementToken, handler.CheckHealth,
157                                                         httpserver.NewRequestLimiter(cluster.API.MaxConcurrentRequests, handler, reg)))))))
158         srv := &httpserver.Server{
159                 Server: http.Server{
160                         Handler:     ifCollectionInHost(instrumented, instrumented.ServeAPI(cluster.ManagementToken, instrumented)),
161                         BaseContext: func(net.Listener) context.Context { return ctx },
162                 },
163                 Addr: listenURL.Host,
164         }
165         if listenURL.Scheme == "https" || listenURL.Scheme == "wss" {
166                 tlsconfig, err := makeTLSConfig(cluster, logger)
167                 if err != nil {
168                         logger.WithError(err).Errorf("cannot start %s service on %s", c.svcName, listenURL.String())
169                         return 1
170                 }
171                 srv.TLSConfig = tlsconfig
172         }
173         err = srv.Start()
174         if err != nil {
175                 return 1
176         }
177         logger.WithFields(logrus.Fields{
178                 "URL":     listenURL,
179                 "Listen":  srv.Addr,
180                 "Service": c.svcName,
181                 "Version": cmd.Version.String(),
182         }).Info("listening")
183         if _, err := daemon.SdNotify(false, "READY=1"); err != nil {
184                 logger.WithError(err).Errorf("error notifying init daemon")
185         }
186         go func() {
187                 // Shut down server if caller cancels context
188                 <-ctx.Done()
189                 srv.Close()
190         }()
191         go func() {
192                 // Shut down server if handler dies
193                 <-handler.Done()
194                 srv.Close()
195         }()
196         go c.requestQueueDumpCheck(cluster, prog, reg, &srv.Server, logger)
197         err = srv.Wait()
198         if err != nil {
199                 return 1
200         }
201         return 0
202 }
203
204 // If SystemLogs.RequestQueueDumpDirectory is set, monitor the
205 // server's incoming HTTP request queue size. When it exceeds 90% of
206 // API.MaxConcurrentRequests, write the /_inspect/requests data to a
207 // JSON file in the specified directory.
208 func (c *command) requestQueueDumpCheck(cluster *arvados.Cluster, prog string, reg *prometheus.Registry, srv *http.Server, logger logrus.FieldLogger) {
209         outdir := cluster.SystemLogs.RequestQueueDumpDirectory
210         if outdir == "" || cluster.ManagementToken == "" {
211                 return
212         }
213         logger = logger.WithField("worker", "RequestQueueDump")
214         outfile := outdir + "/" + prog + "-requests.json"
215         for range time.NewTicker(requestQueueDumpCheckInterval).C {
216                 mfs, err := reg.Gather()
217                 if err != nil {
218                         logger.WithError(err).Warn("error getting metrics")
219                         continue
220                 }
221                 dump := false
222                 for _, mf := range mfs {
223                         if mf.Name != nil && *mf.Name == "arvados_concurrent_requests" && len(mf.Metric) == 1 {
224                                 n := int(mf.Metric[0].GetGauge().GetValue())
225                                 if n > 0 && n >= cluster.API.MaxConcurrentRequests*9/10 {
226                                         dump = true
227                                         break
228                                 }
229                         }
230                 }
231                 if dump {
232                         req, err := http.NewRequest("GET", "/_inspect/requests", nil)
233                         if err != nil {
234                                 logger.WithError(err).Warn("error in http.NewRequest")
235                                 continue
236                         }
237                         req.Header.Set("Authorization", "Bearer "+cluster.ManagementToken)
238                         resp := httptest.NewRecorder()
239                         srv.Handler.ServeHTTP(resp, req)
240                         if code := resp.Result().StatusCode; code != http.StatusOK {
241                                 logger.WithField("StatusCode", code).Warn("error getting /_inspect/requests")
242                                 continue
243                         }
244                         err = os.WriteFile(outfile, resp.Body.Bytes(), 0777)
245                         if err != nil {
246                                 logger.WithError(err).Warn("error writing file")
247                                 continue
248                         }
249                 }
250         }
251 }
252
253 // If an incoming request's target vhost has an embedded collection
254 // UUID or PDH, handle it with hTrue, otherwise handle it with
255 // hFalse.
256 //
257 // Facilitates routing "http://collections.example/metrics" to metrics
258 // and "http://{uuid}.collections.example/metrics" to a file in a
259 // collection.
260 func ifCollectionInHost(hTrue, hFalse http.Handler) http.Handler {
261         return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
262                 if arvados.CollectionIDFromDNSName(r.Host) != "" {
263                         hTrue.ServeHTTP(w, r)
264                 } else {
265                         hFalse.ServeHTTP(w, r)
266                 }
267         })
268 }
269
270 func interceptHealthReqs(mgtToken string, checkHealth func() error, next http.Handler) http.Handler {
271         mux := httprouter.New()
272         mux.Handler("GET", "/_health/ping", &health.Handler{
273                 Token:  mgtToken,
274                 Prefix: "/_health/",
275                 Routes: health.Routes{"ping": checkHealth},
276         })
277         mux.NotFound = next
278         return ifCollectionInHost(next, mux)
279 }
280
281 // Determine listenURL (addr:port where server should bind) and
282 // internalURL (target url that client should connect to) for a
283 // service.
284 //
285 // If the config does not specify ListenURL, we check all of the
286 // configured InternalURLs. If there is exactly one that matches our
287 // hostname, or exactly one that matches a local interface address,
288 // then we use that as listenURL.
289 //
290 // Note that listenURL and internalURL may use different protocols
291 // (e.g., listenURL is http, but the service sits behind a proxy, so
292 // clients connect using https).
293 func getListenAddr(svcs arvados.Services, prog arvados.ServiceName, log logrus.FieldLogger) (arvados.URL, arvados.URL, error) {
294         svc, ok := svcs.Map()[prog]
295         if !ok {
296                 return arvados.URL{}, arvados.URL{}, fmt.Errorf("unknown service name %q", prog)
297         }
298
299         if want := os.Getenv("ARVADOS_SERVICE_INTERNAL_URL"); want != "" {
300                 url, err := url.Parse(want)
301                 if err != nil {
302                         return arvados.URL{}, arvados.URL{}, fmt.Errorf("$ARVADOS_SERVICE_INTERNAL_URL (%q): %s", want, err)
303                 }
304                 if url.Path == "" {
305                         url.Path = "/"
306                 }
307                 for internalURL, conf := range svc.InternalURLs {
308                         if internalURL.String() == url.String() {
309                                 listenURL := conf.ListenURL
310                                 if listenURL.Host == "" {
311                                         listenURL = internalURL
312                                 }
313                                 return listenURL, internalURL, nil
314                         }
315                 }
316                 log.Warnf("possible configuration error: listening on %s (from $ARVADOS_SERVICE_INTERNAL_URL) even though configuration does not have a matching InternalURLs entry", url)
317                 internalURL := arvados.URL(*url)
318                 return internalURL, internalURL, nil
319         }
320
321         errors := []string{}
322         for internalURL, conf := range svc.InternalURLs {
323                 listenURL := conf.ListenURL
324                 if listenURL.Host == "" {
325                         // If ListenURL is not specified, assume
326                         // InternalURL is also usable as the listening
327                         // proto/addr/port (i.e., simple case with no
328                         // intermediate proxy/routing)
329                         listenURL = internalURL
330                 }
331                 listenAddr := listenURL.Host
332                 if _, _, err := net.SplitHostPort(listenAddr); err != nil {
333                         // url "https://foo.example/" (with no
334                         // explicit port name/number) means listen on
335                         // the well-known port for the specified
336                         // protocol, "foo.example:https".
337                         port := listenURL.Scheme
338                         if port == "ws" || port == "wss" {
339                                 port = "http" + port[2:]
340                         }
341                         listenAddr = net.JoinHostPort(listenAddr, port)
342                 }
343                 listener, err := net.Listen("tcp", listenAddr)
344                 if err == nil {
345                         listener.Close()
346                         return listenURL, internalURL, nil
347                 } else if strings.Contains(err.Error(), "cannot assign requested address") {
348                         // If 'Host' specifies a different server than
349                         // the current one, it'll resolve the hostname
350                         // to IP address, and then fail because it
351                         // can't bind an IP address it doesn't own.
352                         continue
353                 } else {
354                         errors = append(errors, fmt.Sprintf("%s: %s", listenURL, err))
355                 }
356         }
357         if len(errors) > 0 {
358                 return arvados.URL{}, arvados.URL{}, fmt.Errorf("could not enable the %q service on this host: %s", prog, strings.Join(errors, "; "))
359         }
360         return arvados.URL{}, arvados.URL{}, fmt.Errorf("configuration does not enable the %q service on this host", prog)
361 }
362
363 type contextKeyURL struct{}
364
365 func URLFromContext(ctx context.Context) (arvados.URL, bool) {
366         u, ok := ctx.Value(contextKeyURL{}).(arvados.URL)
367         return u, ok
368 }