Change daemonize logic in watchdog and add timeout to file system read.

go/src/infra/tools/device_watchdog/main.go

 // Copyright 2016 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 // +build android
 
 // Watchdog daemon for android devices. It will attempt to reboot the device
 // if its uptime exceeds a specified maximum.
 package main
 
 /*
 #cgo LDFLAGS: -landroid -llog
 
 #include <android/log.h>
 #include <string.h>
 */
 import "C"
 
 import (
+        "errors"
         "flag"
         "fmt"
         "io/ioutil"
         "os"
+        "os/exec"
         "strconv"
         "strings"
         "syscall"
         "time"
         "unsafe"
 
         "github.com/luci/luci-go/common/runtime/paniccatcher"
 )
 
 var (
-        logHeader = C.CString("CIT_DeviceWatchdog")
+        logHeader  = C.CString("CIT_DeviceWatchdog")
+        errTimeout = errors.New("timeout")
+)
+
+const (
+        stdInFd  = 0
+        stdOutFd = 1
+        stdErrFd = 2
 )
 
 type logLevel int
 
 const (
         logInfo = iota
         logWarning
         logError
 )
 
-const (
-        stdInFd  = 0
-        stdOutFd = 1
-        stdErrFd = 2
-)
-
 func (l logLevel) getLogLevel() C.int {
         switch l {
         case logInfo:
                 return C.ANDROID_LOG_INFO
         case logWarning:
                 return C.ANDROID_LOG_WARN
         case logError:
                 return C.ANDROID_LOG_ERROR
         default:
                 panic("Unknown log level.")
         }
 }
 
 func logcatLog(level logLevel, format string, args ...interface{}) {
         cmsg := C.CString(fmt.Sprintf(format, args...))
         defer C.free(unsafe.Pointer(cmsg))
         C.__android_log_write(level.getLogLevel(), logHeader, cmsg)
 }
 
-// Spawn a child process via fork, create new process group, chdir and
-// redirect std in and out to /dev/null.
-func daemonize() (int, error) {
+// Spawn a child process via exec.
+func daemonize(maxUptime int) (int, error) {

[dnj, 2016/09/03 00:48:07]

WDYT about having daemonize take an args slice instead of manually recreating
the flags? You can just forward that directly to the spawned process. Note that
for "Exec"-style execution, argv[0] should be forwarded and will be the
executable's name.

[bpastene, 2016/09/09 00:51:43]

Done, but I'd rather replace argv[0] with /proc/self/exe in case it's run from
somewhere else.

         ret, _, errno := syscall.Syscall(syscall.SYS_FORK, 0, 0, 0)

[dnj, 2016/09/03 00:48:07]

Forking here may be a little sketchy. In other daemonize discussions, I see the
following outline:

1) Setsid, StartProcess(self, args), Exit
2) StartProcess(self, args), Exit
3) We're a daemon!

You're doing (1) right now via SYS_FORK, which you point out is potentially
risky b/c of goroutines and stuff. You may still have this risk in the current
code. Up to you if you want to try and solve it now or count on this being a
small enough platform to ignore it. Note that Go runtime has other
goroutines/threads running even if you didn't directly spawn them (e.g., garbage
collector, signal monitor), so this might be worth your time.

[bpastene, 2016/09/09 00:51:43]

I was modeling it after
https://chromium.googlesource.com/chromium/tools/build/+/master/scripts/slave...
(which is in production/used in a lot of places) but replacing the last fork
with a subprocess call instead.

I could replace the first fork with another subprocess call, but how would I get
the subprocess to resume execution right where its parent left off (to prevent a
fork bomb)? Another arg? I think it's just simpler/cleaner to keep it a fork,
especially since the 20 or so lines afterward are all that it needs to execute,
which it seems to do just fine.

[bpastene, 2016/09/09 19:38:53]

Nevermind. This is now all totally obsolete since you found the awesome
github.com/VividCortex/godaemon package.

         pid := int(ret)
         if errno != 0 {
                 return 0, errno
         }
         if pid > 0 {
                 return pid, nil
         }
-
         _, err := syscall.Setsid()
         if err != nil {
                 return 0, err
         }
-
         f, err := os.Open("/dev/null")
         if err != nil {
                 return 0, err
         }
         fd := f.Fd()
         syscall.Dup2(int(fd), stdInFd)
         syscall.Dup2(int(fd), stdOutFd)
         syscall.Dup2(int(fd), stdErrFd)
 
-        return pid, nil
+        binary, err := os.Readlink("/proc/self/exe")
+        if err != nil {
+                return 0, err
+        }
+        cmd := exec.Command(binary, "--max-uptime", strconv.Itoa(maxUptime), "--skip-daemonize")
+        err = cmd.Start()

[dnj, 2016/09/03 00:48:07]

You can avoid some junk by using "os.StartProcess" here:

argv = append(argv, "--skip-daemonize")
os.StartProcess(binary, argv, &os.ProcAttr{
  Dir: os.Getwd(),
  Env: os.Environ(),
  Files: []*os.File{f, f, f},
  nil,
})

You can even avoid the "--skip-daemonize" if you want to use environment
variables:

var daemonizeEnv = "_INFRA_DAEMONIZE_MARKER"

func clearDaemonizedMarker() bool {
  _, has := os.Getenv(daemonizeEnv)
  if has {
    if err := os.Unsetenv(daemonizeEnv); err != nil {
      panic(err)
    }
    return true
  }
}

Then, at the beginning of your application, you can check (and clear):

if !clearDaemonizedMarker() {
  // Daemonize / Exit
}
// I'm a daemon, move on with my life.

[bpastene, 2016/09/09 00:51:43]

I'm not sure what junk I'm avoiding, but done. (I feel like there's too many
ways to start a subprocess in go >.> )
What's the advantage of using an env var? I much prefer making it an explicit
argument.

+        if err != nil {
+                return 0, err
+        }
+        return cmd.Process.Pid, nil
+}
+
+type uptimeResult struct {
+        Uptime time.Duration
+        Err    error
 }
 
 // Read from /proc/uptime. Expected format:
 // "uptime_in_seconds cpu_idle_time_in_seconds"
-func getDeviceUptime() (time.Duration, error) {
+// Return the uptime via a channel for use with timeouts.
+func readUptime() (time.Duration, error) {
         bytes, err := ioutil.ReadFile("/proc/uptime")
         if err != nil {
                 return 0, fmt.Errorf("unable to open /proc/uptime: %s", err.Error())
         }
         // Split on the space to get uptime and drop cpu idle time.
         uptimeFields := strings.Fields(string(bytes))
         if len(uptimeFields) == 0 {
                 return 0, fmt.Errorf("unable to parse /proc/uptime")
         }
         uptime, err := strconv.ParseFloat(uptimeFields[0], 64)
         if err != nil {
                 return 0, fmt.Errorf("unable to parse uptime: %s", err.Error())
         }
         return time.Duration(uptime * float64(time.Second)), nil
 }
 
+func getUptime(requestQueue chan<- chan uptimeResult, timeoutPeriod time.Duration) (time.Duration, error) {

[dnj, 2016/09/03 00:48:07]

nit: chan<- chan<- uptimeResult

In other words, a channel that can be written to, and you can write to it
channels that can be written to.

[bpastene, 2016/09/09 00:51:43]

Done, but aren't I reading from those channels later on at line 153? I guess
that restriction only applies to channels that you receive from the channel, not
channels you create yourself?

[dnj, 2016/09/09 19:40:57]

Yeah a bidirectional channel can be converted into a monodirectional channel, so
"chan chan int" can be turned into "chan <- chan <- int"; just not the other way
around. Here you're creating a bidirectional, but only granting this method
access to one of those directions.

+        request := make(chan uptimeResult, 1)
+        defer close(request)
+
+        timer := time.NewTimer(timeoutPeriod)
+        defer timer.Stop()
+
+        select {
+        case requestQueue <- request:
+                break
+        case <-timer.C:
+                return 0, errTimeout
+        }
+
+        select {
+        case resp := <-request:
+                return resp.Uptime, resp.Err
+        case <-timer.C:
+                return 0, errTimeout
+        }
+}
+
 // Reboot device by writing to sysrq-trigger. See:
 // https://www.kernel.org/doc/Documentation/sysrq.txt
 func rebootDevice() error {
         fd, err := os.OpenFile("/proc/sysrq-trigger", os.O_WRONLY, 0)
         if err != nil {
                 return fmt.Errorf("Can't open /proc/sysrq-trigger: %s", err.Error())
         }
         defer fd.Close()
         _, err = fd.Write([]byte("b"))
         if err != nil {
                 return fmt.Errorf("Can't reboot: %s", err.Error())
         }
         return fmt.Errorf("I just rebooted. How am I still alive?!?\n")
 }
 
 func realMain() int {
         maxUptimeFlag := flag.Int("max-uptime", 120, "Maximum uptime in minutes before a reboot is triggered.")
+        skipDaemonizeFlag := flag.Bool("skip-daemonize", false, "Skips the daemonize logic. Otherwise it will spawn a copy daemon and exit.")
         flag.Parse()
 
-        os.Chdir("/")
-        pid, err := daemonize()
-        if err != nil {
-                logcatLog(logError, "Failed to daemonize: %s", err.Error())
-                return 1
-        }
-        if pid > 0 {
+        if !*skipDaemonizeFlag {
+                pid, err := daemonize(*maxUptimeFlag)
+                if err != nil {
+                        logcatLog(logError, "Failed to daemonize: %s", err.Error())
+                        return 1
+                }
                 logcatLog(logInfo, "Child spawned with pid %d, exiting parent\n", pid)
                 return 0
         }
 
+        requestQueue := make(chan chan uptimeResult)
+        go func() {
+                for request := range requestQueue {
+                        uptime, err := readUptime()
+                        request <- uptimeResult{Uptime: uptime, Err: err}
+                }
+        }()
+        defer close(requestQueue)
+
         maxUptime := time.Duration(*maxUptimeFlag) * time.Minute
+        consecutiveTimeouts := 0
+        maxTimeouts := 5

[dnj, 2016/09/03 00:48:07]

nit: "const maxTimeouts = 5"

[bpastene, 2016/09/09 00:51:43]

Done.

         for {
-                uptime, err := getDeviceUptime()
-                if err != nil {
+                uptime, err := getUptime(requestQueue, 5*time.Second)
+                switch err {
+                case nil:
+                        consecutiveTimeouts = 0
+                case errTimeout:
+                        consecutiveTimeouts++
+                default:
                         logcatLog(logError, "Failed to get uptime: %s", err.Error())
                         return 1
                 }
+                if consecutiveTimeouts == maxTimeouts {

[dnj, 2016/09/03 00:48:07]

nit: Just being paranoid, but might as well make this ">=".

[bpastene, 2016/09/09 00:51:43]

Done.

+                        logcatLog(logError, "%d consective timeouts when fetching uptime. Triggering reboot", maxTimeouts)

[dnj, 2016/09/03 00:48:07]

nit: currentTimeouts, not maxTimeouts.

[bpastene, 2016/09/09 00:51:43]

Done.

+                        break
+                } else if consecutiveTimeouts > 0 {

[dnj, 2016/09/03 00:48:07]

nit: No need for "else if", since the previous statement will exit this loop.
Just make this another "if".

[bpastene, 2016/09/09 00:51:43]

Done.

+                        logcatLog(logError, "Timeout when fetching uptime. Sleeping for 60s and trying again.")
+                        time.Sleep(60 * time.Second)
+                        continue
+                }
 
                 if uptime > maxUptime {
                         logcatLog(logInfo, "Max uptime exceeded: (%s > %s)\n", uptime, maxUptime)
                         break
                 }
                 logcatLog(logInfo, "No need to reboot, uptime < max_uptime: (%s < %s)\n", uptime, maxUptime)
+                // Add an additional second to the sleep to ensure it doesn't
+                // sleep several times in less than a second.
                 time.Sleep(maxUptime - uptime + time.Second)
         }
-        if err = rebootDevice(); err != nil {
+        if err := rebootDevice(); err != nil {
                 logcatLog(logError, "Failed to reboot device: %s", err.Error())
                 return 1
         }
         return 0
 }
 
 func main() {
         paniccatcher.Do(func() {
                 os.Exit(realMain())
         }, func(p *paniccatcher.Panic) {
                 logcatLog(logError, "Panic: %s\n%s", p.Reason, p.Stack)
                 os.Exit(1)
         })
 }