13959: Merge branch 'master' into 13959-timeouts-and-logging
[arvados.git] / services / crunch-dispatch-slurm / crunch-dispatch-slurm.go
index 30cbb79dc186de45366d648e2a26e42266ee7de3..ce0360261dab4aa3ab424d27c29c782e268b567f 100644 (file)
@@ -14,24 +14,43 @@ import (
        "log"
        "math"
        "os"
-       "os/exec"
        "regexp"
        "strings"
        "time"
 
+       "git.curoverse.com/arvados.git/lib/dispatchcloud"
        "git.curoverse.com/arvados.git/sdk/go/arvados"
        "git.curoverse.com/arvados.git/sdk/go/arvadosclient"
        "git.curoverse.com/arvados.git/sdk/go/config"
        "git.curoverse.com/arvados.git/sdk/go/dispatch"
+       "github.com/Sirupsen/logrus"
        "github.com/coreos/go-systemd/daemon"
 )
 
-// Config used by crunch-dispatch-slurm
-type Config struct {
+type logger interface {
+       dispatch.Logger
+       Fatalf(string, ...interface{})
+}
+
+const initialNiceValue int64 = 10000
+
+var (
+       version           = "dev"
+       defaultConfigPath = "/etc/arvados/crunch-dispatch-slurm/crunch-dispatch-slurm.yml"
+)
+
+type Dispatcher struct {
+       *dispatch.Dispatcher
+       logger  logrus.FieldLogger
+       cluster *arvados.Cluster
+       sqCheck *SqueueChecker
+       slurm   Slurm
+
        Client arvados.Client
 
        SbatchArguments []string
        PollPeriod      arvados.Duration
+       PrioritySpread  int64
 
        // crunch-run command to invoke. The container UUID will be
        // appended. If nil, []string{"crunch-run"} will be used.
@@ -39,26 +58,43 @@ type Config struct {
        // Example: []string{"crunch-run", "--cgroup-parent-subsystem=memory"}
        CrunchRunCommand []string
 
+       // Extra RAM to reserve (in Bytes) for SLURM job, in addition
+       // to the amount specified in the container's RuntimeConstraints
+       ReserveExtraRAM int64
+
        // Minimum time between two attempts to run the same container
        MinRetryPeriod arvados.Duration
+
+       // Batch size for container queries
+       BatchSize int64
 }
 
 func main() {
-       err := doMain()
+       logger := logrus.StandardLogger()
+       if os.Getenv("DEBUG") != "" {
+               logger.SetLevel(logrus.DebugLevel)
+       }
+       logger.Formatter = &logrus.JSONFormatter{
+               TimestampFormat: "2006-01-02T15:04:05.000000000Z07:00",
+       }
+       disp := &Dispatcher{logger: logger}
+       err := disp.Run(os.Args[0], os.Args[1:])
        if err != nil {
-               log.Fatal(err)
+               logrus.Fatalf("%s", err)
        }
 }
 
-var (
-       theConfig Config
-       sqCheck   = &SqueueChecker{}
-)
-
-const defaultConfigPath = "/etc/arvados/crunch-dispatch-slurm/crunch-dispatch-slurm.yml"
+func (disp *Dispatcher) Run(prog string, args []string) error {
+       if err := disp.configure(prog, args); err != nil {
+               return err
+       }
+       disp.setup()
+       return disp.run()
+}
 
-func doMain() error {
-       flags := flag.NewFlagSet("crunch-dispatch-slurm", flag.ExitOnError)
+// configure() loads config files. Tests skip this.
+func (disp *Dispatcher) configure(prog string, args []string) error {
+       flags := flag.NewFlagSet(prog, flag.ExitOnError)
        flags.Usage = func() { usage(flags) }
 
        configPath := flags.String(
@@ -69,67 +105,106 @@ func doMain() error {
                "dump-config",
                false,
                "write current configuration to stdout and exit")
-
+       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:])
+       flags.Parse(args)
+
+       // Print version information if requested
+       if *getVersion {
+               fmt.Printf("crunch-dispatch-slurm %s\n", version)
+               return nil
+       }
 
-       err := readConfig(&theConfig, *configPath)
+       disp.logger.Printf("crunch-dispatch-slurm %s started", version)
+
+       err := disp.readConfig(*configPath)
        if err != nil {
                return err
        }
 
-       if theConfig.CrunchRunCommand == nil {
-               theConfig.CrunchRunCommand = []string{"crunch-run"}
+       if disp.CrunchRunCommand == nil {
+               disp.CrunchRunCommand = []string{"crunch-run"}
        }
 
-       if theConfig.PollPeriod == 0 {
-               theConfig.PollPeriod = arvados.Duration(10 * time.Second)
+       if disp.PollPeriod == 0 {
+               disp.PollPeriod = arvados.Duration(10 * time.Second)
        }
 
-       if theConfig.Client.APIHost != "" || theConfig.Client.AuthToken != "" {
+       if disp.Client.APIHost != "" || disp.Client.AuthToken != "" {
                // Copy real configs into env vars so [a]
                // MakeArvadosClient() uses them, and [b] they get
                // propagated to crunch-run via SLURM.
-               os.Setenv("ARVADOS_API_HOST", theConfig.Client.APIHost)
-               os.Setenv("ARVADOS_API_TOKEN", theConfig.Client.AuthToken)
+               os.Setenv("ARVADOS_API_HOST", disp.Client.APIHost)
+               os.Setenv("ARVADOS_API_TOKEN", disp.Client.AuthToken)
                os.Setenv("ARVADOS_API_HOST_INSECURE", "")
-               if theConfig.Client.Insecure {
+               if disp.Client.Insecure {
                        os.Setenv("ARVADOS_API_HOST_INSECURE", "1")
                }
-               os.Setenv("ARVADOS_KEEP_SERVICES", strings.Join(theConfig.Client.KeepServiceURIs, " "))
+               os.Setenv("ARVADOS_KEEP_SERVICES", strings.Join(disp.Client.KeepServiceURIs, " "))
                os.Setenv("ARVADOS_EXTERNAL_CLIENT", "")
        } else {
-               log.Printf("warning: Client credentials missing from config, so falling back on environment variables (deprecated).")
+               disp.logger.Warnf("Client credentials missing from config, so falling back on environment variables (deprecated).")
        }
 
        if *dumpConfig {
-               log.Fatal(config.DumpAndExit(theConfig))
+               return config.DumpAndExit(disp)
+       }
+
+       siteConfig, err := arvados.GetConfig(arvados.DefaultConfigFile)
+       if os.IsNotExist(err) {
+               disp.logger.Warnf("no cluster config (%s), proceeding with no node types defined", err)
+       } else if err != nil {
+               return fmt.Errorf("error loading config: %s", err)
+       } else if disp.cluster, err = siteConfig.GetCluster(""); err != nil {
+               return fmt.Errorf("config error: %s", err)
        }
 
+       return nil
+}
+
+// setup() initializes private fields after configure().
+func (disp *Dispatcher) setup() {
+       if disp.logger == nil {
+               disp.logger = logrus.StandardLogger()
+       }
        arv, err := arvadosclient.MakeArvadosClient()
        if err != nil {
-               log.Printf("Error making Arvados client: %v", err)
-               return err
+               disp.logger.Fatalf("Error making Arvados client: %v", err)
        }
        arv.Retries = 25
 
-       sqCheck = &SqueueChecker{Period: time.Duration(theConfig.PollPeriod)}
-       defer sqCheck.Stop()
-
-       dispatcher := &dispatch.Dispatcher{
+       disp.slurm = &slurmCLI{}
+       disp.sqCheck = &SqueueChecker{
+               Logger:         disp.logger,
+               Period:         time.Duration(disp.PollPeriod),
+               PrioritySpread: disp.PrioritySpread,
+               Slurm:          disp.slurm,
+       }
+       disp.Dispatcher = &dispatch.Dispatcher{
                Arv:            arv,
-               RunContainer:   run,
-               PollPeriod:     time.Duration(theConfig.PollPeriod),
-               MinRetryPeriod: time.Duration(theConfig.MinRetryPeriod),
+               Logger:         disp.logger,
+               BatchSize:      disp.BatchSize,
+               RunContainer:   disp.runContainer,
+               PollPeriod:     time.Duration(disp.PollPeriod),
+               MinRetryPeriod: time.Duration(disp.MinRetryPeriod),
+       }
+}
+
+func (disp *Dispatcher) run() error {
+       defer disp.sqCheck.Stop()
+
+       if disp.cluster != nil && len(disp.cluster.InstanceTypes) > 0 {
+               go dispatchcloud.SlurmNodeTypeFeatureKludge(disp.cluster)
        }
 
        if _, err := daemon.SdNotify(false, "READY=1"); err != nil {
                log.Printf("Error notifying init daemon: %v", err)
        }
-
-       go checkSqueueForOrphans(dispatcher, sqCheck)
-
-       return dispatcher.Run(context.Background())
+       go disp.checkSqueueForOrphans()
+       return disp.Dispatcher.Run(context.Background())
 }
 
 var containerUuidPattern = regexp.MustCompile(`^[a-z0-9]{5}-dz642-[a-z0-9]{15}$`)
@@ -139,21 +214,20 @@ var containerUuidPattern = regexp.MustCompile(`^[a-z0-9]{5}-dz642-[a-z0-9]{15}$`
 // jobs started by a previous dispatch process that never released
 // their slurm allocations even though their container states are
 // Cancelled or Complete. See https://dev.arvados.org/issues/10979
-func checkSqueueForOrphans(dispatcher *dispatch.Dispatcher, sqCheck *SqueueChecker) {
-       for _, uuid := range sqCheck.All() {
+func (disp *Dispatcher) checkSqueueForOrphans() {
+       for _, uuid := range disp.sqCheck.All() {
                if !containerUuidPattern.MatchString(uuid) {
                        continue
                }
-               err := dispatcher.TrackContainer(uuid)
+               err := disp.TrackContainer(uuid)
                if err != nil {
                        log.Printf("checkSqueueForOrphans: TrackContainer(%s): %s", uuid, err)
                }
        }
 }
 
-// sbatchCmd
-func sbatchFunc(container arvados.Container) *exec.Cmd {
-       mem := int64(math.Ceil(float64(container.RuntimeConstraints.RAM+container.RuntimeConstraints.KeepCacheRAM) / float64(1048576)))
+func (disp *Dispatcher) slurmConstraintArgs(container arvados.Container) []string {
+       mem := int64(math.Ceil(float64(container.RuntimeConstraints.RAM+container.RuntimeConstraints.KeepCacheRAM+disp.ReserveExtraRAM) / float64(1048576)))
 
        var disk int64
        for _, m := range container.Mounts {
@@ -162,75 +236,84 @@ func sbatchFunc(container arvados.Container) *exec.Cmd {
                }
        }
        disk = int64(math.Ceil(float64(disk) / float64(1048576)))
-
-       var sbatchArgs []string
-       sbatchArgs = append(sbatchArgs, theConfig.SbatchArguments...)
-       sbatchArgs = append(sbatchArgs, fmt.Sprintf("--job-name=%s", container.UUID))
-       sbatchArgs = append(sbatchArgs, fmt.Sprintf("--mem=%d", mem))
-       sbatchArgs = append(sbatchArgs, fmt.Sprintf("--cpus-per-task=%d", container.RuntimeConstraints.VCPUs))
-       sbatchArgs = append(sbatchArgs, fmt.Sprintf("--tmp=%d", disk))
-       if len(container.SchedulingParameters.Partitions) > 0 {
-               sbatchArgs = append(sbatchArgs, fmt.Sprintf("--partition=%s", strings.Join(container.SchedulingParameters.Partitions, ",")))
+       return []string{
+               fmt.Sprintf("--mem=%d", mem),
+               fmt.Sprintf("--cpus-per-task=%d", container.RuntimeConstraints.VCPUs),
+               fmt.Sprintf("--tmp=%d", disk),
        }
-
-       return exec.Command("sbatch", sbatchArgs...)
 }
 
-// scancelCmd
-func scancelFunc(container arvados.Container) *exec.Cmd {
-       return exec.Command("scancel", "--name="+container.UUID)
-}
-
-// Wrap these so that they can be overridden by tests
-var sbatchCmd = sbatchFunc
-var scancelCmd = scancelFunc
-
-// Submit job to slurm using sbatch.
-func submit(dispatcher *dispatch.Dispatcher, container arvados.Container, crunchRunCommand []string) error {
-       cmd := sbatchCmd(container)
-
-       // Send a tiny script on stdin to execute the crunch-run
-       // command (slurm requires this to be a #! script)
-       cmd.Stdin = strings.NewReader(execScript(append(crunchRunCommand, container.UUID)))
-
-       var stdout, stderr bytes.Buffer
-       cmd.Stdout = &stdout
-       cmd.Stderr = &stderr
-
-       // Mutex between squeue sync and running sbatch or scancel.
-       sqCheck.L.Lock()
-       defer sqCheck.L.Unlock()
+func (disp *Dispatcher) sbatchArgs(container arvados.Container) ([]string, error) {
+       var args []string
+       args = append(args, disp.SbatchArguments...)
+       args = append(args, "--job-name="+container.UUID, fmt.Sprintf("--nice=%d", initialNiceValue))
+
+       if disp.cluster == nil {
+               // no instance types configured
+               args = append(args, disp.slurmConstraintArgs(container)...)
+       } else if it, err := dispatchcloud.ChooseInstanceType(disp.cluster, &container); err == dispatchcloud.ErrInstanceTypesNotConfigured {
+               // ditto
+               args = append(args, disp.slurmConstraintArgs(container)...)
+       } else if err != nil {
+               return nil, err
+       } else {
+               // use instancetype constraint instead of slurm mem/cpu/tmp specs
+               args = append(args, "--constraint=instancetype="+it.Name)
+       }
 
-       log.Printf("exec sbatch %+q", cmd.Args)
-       err := cmd.Run()
+       if len(container.SchedulingParameters.Partitions) > 0 {
+               args = append(args, "--partition="+strings.Join(container.SchedulingParameters.Partitions, ","))
+       }
 
-       switch err.(type) {
-       case nil:
-               log.Printf("sbatch succeeded: %q", strings.TrimSpace(stdout.String()))
-               return nil
+       return args, nil
+}
 
-       case *exec.ExitError:
-               dispatcher.Unlock(container.UUID)
-               return fmt.Errorf("sbatch %+q failed: %v (stderr: %q)", cmd.Args, err, stderr.Bytes())
+func (disp *Dispatcher) submit(container arvados.Container, crunchRunCommand []string) error {
+       // append() here avoids modifying crunchRunCommand's
+       // underlying array, which is shared with other goroutines.
+       crArgs := append([]string(nil), crunchRunCommand...)
+       crArgs = append(crArgs, container.UUID)
+       crScript := strings.NewReader(execScript(crArgs))
 
-       default:
-               dispatcher.Unlock(container.UUID)
-               return fmt.Errorf("exec failed: %v", err)
+       sbArgs, err := disp.sbatchArgs(container)
+       if err != nil {
+               return err
        }
+       log.Printf("running sbatch %+q", sbArgs)
+       return disp.slurm.Batch(crScript, sbArgs)
 }
 
 // Submit a container to the slurm queue (or resume monitoring if it's
 // already in the queue).  Cancel the slurm job if the container's
 // priority changes to zero or its state indicates it's no longer
 // running.
-func run(disp *dispatch.Dispatcher, ctr arvados.Container, status <-chan arvados.Container) {
+func (disp *Dispatcher) runContainer(_ *dispatch.Dispatcher, ctr arvados.Container, status <-chan arvados.Container) {
        ctx, cancel := context.WithCancel(context.Background())
        defer cancel()
 
-       if ctr.State == dispatch.Locked && !sqCheck.HasUUID(ctr.UUID) {
+       if ctr.State == dispatch.Locked && !disp.sqCheck.HasUUID(ctr.UUID) {
                log.Printf("Submitting container %s to slurm", ctr.UUID)
-               if err := submit(disp, ctr, theConfig.CrunchRunCommand); err != nil {
-                       text := fmt.Sprintf("Error submitting container %s to slurm: %s", ctr.UUID, err)
+               if err := disp.submit(ctr, disp.CrunchRunCommand); err != nil {
+                       var text string
+                       if err, ok := err.(dispatchcloud.ConstraintsNotSatisfiableError); ok {
+                               var logBuf bytes.Buffer
+                               fmt.Fprintf(&logBuf, "cannot run container %s: %s\n", ctr.UUID, err)
+                               if len(err.AvailableTypes) == 0 {
+                                       fmt.Fprint(&logBuf, "No instance types are configured.\n")
+                               } else {
+                                       fmt.Fprint(&logBuf, "Available instance types:\n")
+                                       for _, t := range err.AvailableTypes {
+                                               fmt.Fprintf(&logBuf,
+                                                       "Type %q: %d VCPUs, %d RAM, %d Scratch, %f Price\n",
+                                                       t.Name, t.VCPUs, t.RAM, t.Scratch, t.Price,
+                                               )
+                                       }
+                               }
+                               text = logBuf.String()
+                               disp.UpdateState(ctr.UUID, dispatch.Cancelled)
+                       } else {
+                               text = fmt.Sprintf("Error submitting container %s to slurm: %s", ctr.UUID, err)
+                       }
                        log.Print(text)
 
                        lr := arvadosclient.Dict{"log": arvadosclient.Dict{
@@ -251,7 +334,7 @@ func run(disp *dispatch.Dispatcher, ctr arvados.Container, status <-chan arvados
        // no point in waiting for further dispatch updates: just
        // clean up and return.
        go func(uuid string) {
-               for ctx.Err() == nil && sqCheck.HasUUID(uuid) {
+               for ctx.Err() == nil && disp.sqCheck.HasUUID(uuid) {
                }
                cancel()
        }(ctr.UUID)
@@ -261,7 +344,7 @@ func run(disp *dispatch.Dispatcher, ctr arvados.Container, status <-chan arvados
                case <-ctx.Done():
                        // Disappeared from squeue
                        if err := disp.Arv.Get("containers", ctr.UUID, nil, &ctr); err != nil {
-                               log.Printf("Error getting final container state for %s: %s", ctr.UUID, err)
+                               log.Printf("error getting final container state for %s: %s", ctr.UUID, err)
                        }
                        switch ctr.State {
                        case dispatch.Running:
@@ -272,33 +355,38 @@ func run(disp *dispatch.Dispatcher, ctr arvados.Container, status <-chan arvados
                        return
                case updated, ok := <-status:
                        if !ok {
-                               log.Printf("Dispatcher says container %s is done: cancel slurm job", ctr.UUID)
-                               scancel(ctr)
+                               log.Printf("container %s is done: cancel slurm job", ctr.UUID)
+                               disp.scancel(ctr)
                        } else if updated.Priority == 0 {
-                               log.Printf("Container %s has state %q, priority %d: cancel slurm job", ctr.UUID, updated.State, updated.Priority)
-                               scancel(ctr)
+                               log.Printf("container %s has state %q, priority %d: cancel slurm job", ctr.UUID, updated.State, updated.Priority)
+                               disp.scancel(ctr)
+                       } else {
+                               p := int64(updated.Priority)
+                               if p <= 1000 {
+                                       // API is providing
+                                       // user-assigned priority. If
+                                       // ctrs have equal priority,
+                                       // run the older one first.
+                                       p = int64(p)<<50 - (updated.CreatedAt.UnixNano() >> 14)
+                               }
+                               disp.sqCheck.SetPriority(ctr.UUID, p)
                        }
                }
        }
 }
-
-func scancel(ctr arvados.Container) {
-       sqCheck.L.Lock()
-       cmd := scancelCmd(ctr)
-       msg, err := cmd.CombinedOutput()
-       sqCheck.L.Unlock()
-
+func (disp *Dispatcher) scancel(ctr arvados.Container) {
+       err := disp.slurm.Cancel(ctr.UUID)
        if err != nil {
-               log.Printf("%q %q: %s %q", cmd.Path, cmd.Args, err, msg)
+               log.Printf("scancel: %s", err)
                time.Sleep(time.Second)
-       } else if sqCheck.HasUUID(ctr.UUID) {
+       } else if disp.sqCheck.HasUUID(ctr.UUID) {
                log.Printf("container %s is still in squeue after scancel", ctr.UUID)
                time.Sleep(time.Second)
        }
 }
 
-func readConfig(dst interface{}, path string) error {
-       err := config.LoadFile(dst, path)
+func (disp *Dispatcher) readConfig(path string) error {
+       err := config.LoadFile(disp, path)
        if err != nil && os.IsNotExist(err) && path == defaultConfigPath {
                log.Printf("Config not specified. Continue with default configuration.")
                err = nil