Implement device watchdog.

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

-// +build !windows
+// 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 (
-        "C"
+        "flag"
         "fmt"
+        "io/ioutil"
+        "math"
+        "os"
+        "strconv"
+        "strings"
+        "syscall"
+        "time"
+        "unsafe"
+
+        "github.com/luci/luci-go/common/runtime/paniccatcher"
 )
 
+var (
+        logHeader = C.CString("CIT_DeviceWatchdog")
+)
+
+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) {
+        os.Chdir("/")

[dnj, 2016/08/15 23:02:14]

(I meant move this to realMain)

[bpastene, 2016/08/15 23:39:28]

Done.

+
+        ret, _, errno := syscall.Syscall(syscall.SYS_FORK, 0, 0, 0)
+        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
+}
+
+// Read from /proc/uptime. Expected format:
+// "uptime_in_seconds cpu_idle_time_in_seconds"
+func getDeviceUptime() (time.Duration, error) {
+        bytes, err := ioutil.ReadFile("/proc/uptime")
+        if err != nil {
+                return 0, fmt.Errorf("unable to  open /proc/uptime: %s", err.Error())

[dnj, 2016/08/15 23:02:14]

nit: two spaces

[bpastene, 2016/08/15 23:39:28]

Done.

+        }
+        // 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
+}
+
+// Reboot device by writing to sysrq-trigger. See:
+// https://www.kernel.org/doc/Documentation/sysrq.txt
+func rebootDevice() {
+        fd, err := os.OpenFile("/proc/sysrq-trigger", os.O_WRONLY, 0644)

[dnj, 2016/08/15 23:02:14]

nit: get rid of 0644 since you're not creating a file.

[bpastene, 2016/08/15 23:39:28]

Needs it: https://golang.org/pkg/os/#OpenFile

[dnj, 2016/08/15 23:50:03]

I was thinking pass 0 to be clear that you're not using the flag, but it doesn't
really matter.

[bpastene, 2016/08/16 19:47:26]

Done.

+        if err != nil {
+                logcatLog(logError, "Can't open /proc/sysrq-trigger: %s", err.Error())
+                os.Exit(1)
+        }
+        defer fd.Close()
+        _, err = fd.Write([]byte("b"))

[dnj, 2016/08/15 23:02:14]

nit, oneline:
if _, err := fd.Write(...); err != nil {

[bpastene, 2016/08/15 23:39:28]

That makes it more readable? I'm not sure I agree :(

[dnj, 2016/08/15 23:50:02]

It's a coding preference we've exhibited in LUCI project, it doesn't really
matter though. If you don't like it, you can leave as-is.

+        if err != nil {
+                logcatLog(logError, "Can't reboot: %s", err.Error())
+                os.Exit(1)

[dnj, 2016/08/15 23:02:14]

WDYT about having this function actually return an error, and then dealing with
the os.Exit part in realMain?

In general I like to consolidate exit points in a single place if possible.

[bpastene, 2016/08/15 23:39:28]

Done.

+        }
+        logcatLog(logError, "I just rebooted. How am I still alive?!?\n")
+        os.Exit(1)
+}
+
+func realMain() {

[dnj, 2016/08/15 23:02:14]

Just a thought, but if you made "realMain" return an int, all those "os.Exit(#)"
could become "return #", and you could os.Exit in main().

[bpastene, 2016/08/15 23:39:28]

Good idea; done.

+
+        maxUptimeFlag := flag.Int("max-uptime", 120, "Maximum uptime in minutes before a reboot is triggered.")

[dnj, 2016/08/15 23:02:14]

If you wanted to, you could use a clockflag.Duration to actually express a full
duration string:

e.g., -max-uptime 1h,30m

https://godoc.org/github.com/luci/luci-go/common/clock/clockflag

[bpastene, 2016/08/15 23:39:28]

I think that would add a lot more time.Duration-type-conversion logic than I can
handle

+        flag.Parse()
+
+        pid, err := daemonize()
+        if err != nil {
+                logcatLog(logError, "Failed to daemonize: %s", err.Error())
+                os.Exit(1)
+        }
+        if pid > 0 {
+                logcatLog(logInfo, "Child spawned with pid %d, exiting parent\n", pid)
+                os.Exit(0)
+        }
+
+        maxUptime := time.Duration(int64(*maxUptimeFlag) * int64(time.Minute))

[dnj, 2016/08/15 23:02:14]

Make this:
maxUptime := time.Duration(*maxUptimeFlag) * time.Minute

[bpastene, 2016/08/15 23:39:28]

Done.

+        for {
+                uptime, err := getDeviceUptime()
+                if err != nil {
+                        logcatLog(logError, "Failed to get uptime: %s", err.Error())
+                        os.Exit(1)
+                }
+
+                if uptime > maxUptime {
+                        logcatLog(logInfo, "Max uptime exceeded: (%.2f > %.2f)\n", float64(uptime)/float64(time.Minute), float64(maxUptime)/float64(time.Minute))
+                        rebootDevice()

[dnj, 2016/08/15 23:02:14]

Suggestion: break this into two loops:

// Wait until we've hit our max uptime.
for {
  ...
  if uptime > maxUptime {
    break
  }
  time.Sleep(maxUptime - uptime)
}

// Reboot the device. This should work immediately, so we will
// keep trying until it succeeds.
for {
  rebootDevice()
  logcatLog(logError, "THIS SHOUDL HAVE WORKED")
  time.Sleep(time.Second)
}

[bpastene, 2016/08/15 23:39:28]

If that first reboot attempt doesn't work, why would the second? I'd rather it
just try once and immediately fail loudly if it doesn't work.

[dnj, 2016/08/15 23:50:02]

My thought was that this is a terminal point, so you have three options:
1) Exit w/ error/panic
2) Try rebooting again.
3) Infinite loop.

The advantages of 2 and 3 is that the application sticks around trying to do
what it's supposed to do. With 1, it just silently disappears. If that's fine,
then go for it, but I prefer stricter terminal boundaries.

[bpastene, 2016/08/16 19:47:26]

With 1), it doesn't silently disappear, its error + panic gets dumped to logcat.

If it turns out that the rebooting can sometimes fail, or if the original error
gets pushed out of logcat too quickly, I'll definitely add some retries around
it. But I think I'd like to stick to the one-and-done approach for now

[dnj, 2016/08/16 19:51:47]

Okay seems fair. Then I would recommend still breaking this into a serial flow:

// Wait until we've hit our max uptime.
for {
  uptime, err := getDeviceUptime()
  if err != nil {
    (log)
    // What should you do if this fails? Maybe reboot anyway, or try again?:
    break / continue
  }

  if uptime > maxUptime {
    break
  }

  time.Sleep(maxUptime - uptime + time.Second)
}

if err := rebootDevice(); err != nil {
  log("failed to reboot")
  return 1
}
return 0

[bpastene, 2016/08/16 22:00:56]

Done.

+                } else {
+                        logcatLog(logInfo, "No need to reboot, uptime < max_uptime: (%.2f < %.2f)\n", float64(uptime)/float64(time.Minute), float64(maxUptime)/float64(time.Minute))
+                }
+                maxSleep := math.Max(float64(maxUptime-uptime), float64(time.Second))

[dnj, 2016/08/15 23:02:14]

Confused: you know "maxUptime" is >= "uptime", so you should be able to get rid
of this "math.Max" thing here and directly time.Sleep(maxUptime - uptime).

[bpastene, 2016/08/15 23:39:28]

Thanks to obscure floating point precision issues, that makes time.Sleep() get
called ~10 times in the last few seconds. Insuring it sleeps for at least one
second avoids that.

[dnj, 2016/08/15 23:50:03]

That's weird. Maybe just have it sleep fro (maxUptime - uptime + time.Second) to
push past that issue altogether?

If you don't like that and want to continue with the current approach, I'd ditch
'math' and all the float64 conversions and just do it manually:

maxSleep := maxUptime - uptime
if maxSleep < time.Second {
  maxSleep = time.Second
}

That way you're sticking with duration-level stuff the entire time instead of
converting around types.

[bpastene, 2016/08/16 19:47:26]

Ahh, the + 1 second is good idea. I'll do that.

+                time.Sleep(time.Duration(maxSleep))
+        }
+}
+
 func main() {
-        fmt.Println("Is this thing working?")
+        paniccatcher.Do(realMain, func(p *paniccatcher.Panic) {
+                logcatLog(logError, "Panic: %s\n%s", p.Reason, p.Stack)
+                os.Exit(1)
+        })
 }