Merge branch '13973-child-priority' refs #13973
[arvados.git] / services / crunch-dispatch-local / crunch-dispatch-local.go
index 848d723380da29d9a9e3337aa654e097fde782e1..fc10393626be103c17b01b5b1bfde615ed470bc9 100644 (file)
@@ -1,34 +1,53 @@
+// Copyright (C) The Arvados Authors. All rights reserved.
+//
+// SPDX-License-Identifier: AGPL-3.0
+
 package main
 
+// Dispatcher service for Crunch that runs containers locally.
+
 import (
+       "context"
        "flag"
-       "git.curoverse.com/arvados.git/sdk/go/arvadosclient"
-       "log"
+       "fmt"
        "os"
        "os/exec"
        "os/signal"
        "sync"
        "syscall"
        "time"
+
+       "git.curoverse.com/arvados.git/sdk/go/arvados"
+       "git.curoverse.com/arvados.git/sdk/go/arvadosclient"
+       "git.curoverse.com/arvados.git/sdk/go/dispatch"
+       "github.com/Sirupsen/logrus"
 )
 
+var version = "dev"
+
 func main() {
        err := doMain()
        if err != nil {
-               log.Fatalf("%q", err)
+               logrus.Fatalf("%q", err)
        }
 }
 
 var (
-       arv              arvadosclient.ArvadosClient
        runningCmds      map[string]*exec.Cmd
        runningCmdsMutex sync.Mutex
        waitGroup        sync.WaitGroup
-       doneProcessing   chan bool
-       sigChan          chan os.Signal
+       crunchRunCommand *string
 )
 
 func doMain() error {
+       logger := logrus.StandardLogger()
+       if os.Getenv("DEBUG") != "" {
+               logger.SetLevel(logrus.DebugLevel)
+       }
+       logger.Formatter = &logrus.JSONFormatter{
+               TimestampFormat: "2006-01-02T15:04:05.000000000Z07:00",
+       }
+
        flags := flag.NewFlagSet("crunch-dispatch-local", flag.ExitOnError)
 
        pollInterval := flags.Int(
@@ -36,48 +55,63 @@ func doMain() error {
                10,
                "Interval in seconds to poll for queued containers")
 
-       priorityPollInterval := flags.Int(
-               "container-priority-poll-interval",
-               60,
-               "Interval in seconds to check priority of a dispatched container")
-
-       crunchRunCommand := flags.String(
+       crunchRunCommand = flags.String(
                "crunch-run-command",
                "/usr/bin/crunch-run",
                "Crunch command to run container")
 
+       getVersion := flags.Bool(
+               "version",
+               false,
+               "Print version information and exit.")
+
        // Parse args; omit the first arg which is the command name
        flags.Parse(os.Args[1:])
 
-       var err error
-       arv, err = arvadosclient.MakeArvadosClient()
+       // Print version information if requested
+       if *getVersion {
+               fmt.Printf("crunch-dispatch-local %s\n", version)
+               return nil
+       }
+
+       logger.Printf("crunch-dispatch-local %s started", version)
+
+       runningCmds = make(map[string]*exec.Cmd)
+
+       arv, err := arvadosclient.MakeArvadosClient()
        if err != nil {
+               logger.Errorf("error making Arvados client: %v", err)
                return err
        }
+       arv.Retries = 25
 
-       // Channel to terminate
-       doneProcessing = make(chan bool)
+       dispatcher := dispatch.Dispatcher{
+               Logger:       logger,
+               Arv:          arv,
+               RunContainer: run,
+               PollPeriod:   time.Duration(*pollInterval) * time.Second,
+       }
 
-       // Map of running crunch jobs
-       runningCmds = make(map[string]*exec.Cmd)
+       ctx, cancel := context.WithCancel(context.Background())
+       err = dispatcher.Run(ctx)
+       if err != nil {
+               return err
+       }
 
-       // Graceful shutdown
-       sigChan = make(chan os.Signal, 1)
-       signal.Notify(sigChan, syscall.SIGINT, syscall.SIGTERM, syscall.SIGQUIT)
-       go func(sig <-chan os.Signal) {
-               for sig := range sig {
-                       log.Printf("Caught signal: %v", sig)
-                       doneProcessing <- true
-               }
-       }(sigChan)
+       c := make(chan os.Signal, 1)
+       signal.Notify(c, os.Interrupt, syscall.SIGTERM, syscall.SIGQUIT)
+       sig := <-c
+       logger.Printf("Received %s, shutting down", sig)
+       signal.Stop(c)
 
-       // Run all queued containers
-       runQueuedContainers(time.Duration(*pollInterval)*time.Second, time.Duration(*priorityPollInterval)*time.Second, *crunchRunCommand)
+       cancel()
 
+       runningCmdsMutex.Lock()
        // Finished dispatching; interrupt any crunch jobs that are still running
        for _, cmd := range runningCmds {
                cmd.Process.Signal(os.Interrupt)
        }
+       runningCmdsMutex.Unlock()
 
        // Wait for all running crunch jobs to complete / terminate
        waitGroup.Wait()
@@ -85,166 +119,98 @@ func doMain() error {
        return nil
 }
 
-// Poll for queued containers using pollInterval.
-// Invoke dispatchLocal for each ticker cycle, which will run all the queued containers.
-//
-// Any errors encountered are logged but the program would continue to run (not exit).
-// This is because, once one or more crunch jobs are running,
-// we would need to wait for them complete.
-func runQueuedContainers(pollInterval, priorityPollInterval time.Duration, crunchRunCommand string) {
-       ticker := time.NewTicker(pollInterval)
-
-       for {
-               select {
-               case <-ticker.C:
-                       dispatchLocal(priorityPollInterval, crunchRunCommand)
-               case <-doneProcessing:
-                       ticker.Stop()
-                       return
-               }
-       }
+func startFunc(container arvados.Container, cmd *exec.Cmd) error {
+       return cmd.Start()
 }
 
-// Container data
-type Container struct {
-       UUID         string `json:"uuid"`
-       State        string `json:"state"`
-       Priority     int    `json:"priority"`
-       LockedByUUID string `json:"locked_by_uuid"`
-}
+var startCmd = startFunc
 
-// ContainerList is a list of the containers from api
-type ContainerList struct {
-       Items []Container `json:"items"`
-}
+// Run a container.
+//
+// If the container is Locked, start a new crunch-run process and wait until
+// crunch-run completes.  If the priority is set to zero, set an interrupt
+// signal to the crunch-run process.
+//
+// If the container is in any other state, or is not Complete/Cancelled after
+// crunch-run terminates, mark the container as Cancelled.
+func run(dispatcher *dispatch.Dispatcher,
+       container arvados.Container,
+       status <-chan arvados.Container) {
 
-// Get the list of queued containers from API server and invoke run for each container.
-func dispatchLocal(pollInterval time.Duration, crunchRunCommand string) {
-       params := arvadosclient.Dict{
-               "filters": [][]string{[]string{"state", "=", "Queued"}},
-       }
+       uuid := container.UUID
 
-       var containers ContainerList
-       err := arv.List("containers", params, &containers)
-       if err != nil {
-               log.Printf("Error getting list of queued containers: %q", err)
-               return
-       }
+       if container.State == dispatch.Locked {
+               waitGroup.Add(1)
 
-       for i := 0; i < len(containers.Items); i++ {
-               log.Printf("About to run queued container %v", containers.Items[i].UUID)
-               // Run the container
-               go run(containers.Items[i].UUID, crunchRunCommand, pollInterval)
-       }
-}
+               cmd := exec.Command(*crunchRunCommand, uuid)
+               cmd.Stdin = nil
+               cmd.Stderr = os.Stderr
+               cmd.Stdout = os.Stderr
 
-func updateState(uuid, newState string) error {
-       err := arv.Update("containers", uuid,
-               arvadosclient.Dict{
-                       "container": arvadosclient.Dict{"state": newState}},
-               nil)
-       if err != nil {
-               log.Printf("Error updating container %s to '%s' state: %q", uuid, newState, err)
-       }
-       return err
-}
-
-// Run queued container:
-// Set container state to Locked
-// Run container using the given crunch-run command
-// Set the container state to Running
-// If the container priority becomes zero while crunch job is still running, terminate it.
-func run(uuid string, crunchRunCommand string, pollInterval time.Duration) {
-       if err := updateState(uuid, "Locked"); err != nil {
-               return
-       }
+               dispatcher.Logger.Printf("starting container %v", uuid)
 
-       cmd := exec.Command(crunchRunCommand, uuid)
-       cmd.Stdin = nil
-       cmd.Stderr = os.Stderr
-       cmd.Stdout = os.Stderr
+               // Add this crunch job to the list of runningCmds only if we
+               // succeed in starting crunch-run.
 
-       // Add this crunch job to the list of runningCmds only if we
-       // succeed in starting crunch-run.
-       runningCmdsMutex.Lock()
-       if err := cmd.Start(); err != nil {
-               log.Printf("Error starting crunch-run for %v: %q", uuid, err)
-               runningCmdsMutex.Unlock()
-               updateState(uuid, "Queued")
-               return
-       }
-       runningCmds[uuid] = cmd
-       runningCmdsMutex.Unlock()
-
-       defer func() {
-               setFinalState(uuid)
-
-               // Remove the crunch job from runningCmds
                runningCmdsMutex.Lock()
-               delete(runningCmds, uuid)
-               runningCmdsMutex.Unlock()
-       }()
-
-       log.Printf("Starting container %v", uuid)
-
-       // Add this crunch job to waitGroup
-       waitGroup.Add(1)
-       defer waitGroup.Done()
-
-       updateState(uuid, "Running")
+               if err := startCmd(container, cmd); err != nil {
+                       runningCmdsMutex.Unlock()
+                       dispatcher.Logger.Warnf("error starting %q for %s: %s", *crunchRunCommand, uuid, err)
+                       dispatcher.UpdateState(uuid, dispatch.Cancelled)
+               } else {
+                       runningCmds[uuid] = cmd
+                       runningCmdsMutex.Unlock()
+
+                       // Need to wait for crunch-run to exit
+                       done := make(chan struct{})
+
+                       go func() {
+                               if _, err := cmd.Process.Wait(); err != nil {
+                                       dispatcher.Logger.Warnf("error while waiting for crunch job to finish for %v: %q", uuid, err)
+                               }
+                               dispatcher.Logger.Debugf("sending done")
+                               done <- struct{}{}
+                       }()
+
+               Loop:
+                       for {
+                               select {
+                               case <-done:
+                                       break Loop
+                               case c := <-status:
+                                       // Interrupt the child process if priority changes to 0
+                                       if (c.State == dispatch.Locked || c.State == dispatch.Running) && c.Priority == 0 {
+                                               dispatcher.Logger.Printf("sending SIGINT to pid %d to cancel container %v", cmd.Process.Pid, uuid)
+                                               cmd.Process.Signal(os.Interrupt)
+                                       }
+                               }
+                       }
+                       close(done)
 
-       cmdExited := make(chan struct{})
+                       dispatcher.Logger.Printf("finished container run for %v", uuid)
 
-       // Kill the child process if container priority changes to zero
-       go func() {
-               ticker := time.NewTicker(pollInterval)
-               defer ticker.Stop()
-               for {
-                       select {
-                       case <-cmdExited:
-                               return
-                       case <-ticker.C:
-                       }
-                       var container Container
-                       err := arv.Get("containers", uuid, nil, &container)
-                       if err != nil {
-                               log.Printf("Error getting container %v: %q", uuid, err)
-                               continue
-                       }
-                       if container.Priority == 0 {
-                               log.Printf("Sending SIGINT to pid %d to cancel container %v", cmd.Process.Pid, uuid)
-                               cmd.Process.Signal(os.Interrupt)
-                       }
+                       // Remove the crunch job from runningCmds
+                       runningCmdsMutex.Lock()
+                       delete(runningCmds, uuid)
+                       runningCmdsMutex.Unlock()
                }
-       }()
-
-       // Wait for crunch-run to exit
-       if _, err := cmd.Process.Wait(); err != nil {
-               log.Printf("Error while waiting for crunch job to finish for %v: %q", uuid, err)
+               waitGroup.Done()
        }
-       close(cmdExited)
 
-       log.Printf("Finished container run for %v", uuid)
-}
-
-func setFinalState(uuid string) {
-       // The container state should now be 'Complete' if everything
-       // went well. If it started but crunch-run didn't change its
-       // final state to 'Running', fix that now. If it never even
-       // started, cancel it as unrunnable. (TODO: Requeue instead,
-       // and fix tests so they can tell something happened even if
-       // the final state is Queued.)
-       var container Container
-       err := arv.Get("containers", uuid, nil, &container)
+       // If the container is not finalized, then change it to "Cancelled".
+       err := dispatcher.Arv.Get("containers", uuid, nil, &container)
        if err != nil {
-               log.Printf("Error getting final container state: %v", err)
+               dispatcher.Logger.Warnf("error getting final container state: %v", err)
        }
-       fixState := map[string]string{
-               "Running": "Complete",
-               "Locked": "Cancelled",
+       if container.State == dispatch.Locked || container.State == dispatch.Running {
+               dispatcher.Logger.Warnf("after %q process termination, container state for %v is %q; updating it to %q",
+                       *crunchRunCommand, uuid, container.State, dispatch.Cancelled)
+               dispatcher.UpdateState(uuid, dispatch.Cancelled)
        }
-       if newState, ok := fixState[container.State]; ok {
-               log.Printf("After crunch-run process termination, the state is still '%s' for %v. Updating it to '%s'", container.State, uuid, newState)
-               updateState(uuid, newState)
+
+       // drain any subsequent status changes
+       for range status {
        }
+
+       dispatcher.Logger.Printf("finalized container %v", uuid)
 }