services/mgmt/device: further restrict devicemanager 'test mode' & extra logging
In addition to setting the local mounttable port to be auto-assigned, we also
need to set the device server's port the same way (to avoid port
collisions). The proxy we can just disable in test mode. Further restrictions include:
- disabling logging to the log dir in test mode (to avoid interference with the
main device manager's logs, and in particular not mess up what deviced.INFO
points to)
- disable neighborhood advertising
- skip attempting to set up the claimable service to avoid error log spam
I'm also adding extra logging around the shutdown flow, to help debug hanging
during Update (I once saw a successful Update RPC, but the device manager didn't
actually restart, presumably hung on a shutdown step).
Change-Id: Ibc7361f39758277d63bdfe06c7e4f39175600918
diff --git a/lib/appcycle/appcycle.go b/lib/appcycle/appcycle.go
index 2ae5af4..9afe008 100644
--- a/lib/appcycle/appcycle.go
+++ b/lib/appcycle/appcycle.go
@@ -45,6 +45,8 @@
}
func (m *AppCycle) stop(msg string) {
+ vlog.Infof("stop(%v)", msg)
+ defer vlog.Infof("stop(%v) done", msg)
m.RLock()
defer m.RUnlock()
if len(m.waiters) == 0 {
diff --git a/services/mgmt/device/deviced/server.go b/services/mgmt/device/deviced/server.go
index 83f1c23..295ce28 100644
--- a/services/mgmt/device/deviced/server.go
+++ b/services/mgmt/device/deviced/server.go
@@ -65,15 +65,17 @@
// setting and getting of exitErr.
var exitErr error
ns := starter.NamespaceArgs{
- ACLFile: filepath.Join(mtAclDir, "acls"),
- Neighborhood: *nhName,
+ ACLFile: filepath.Join(mtAclDir, "acls"),
}
if testMode {
ns.ListenSpec = ipc.ListenSpec{Addrs: ipc.ListenAddrs{{"tcp", "127.0.0.1:0"}}}
} else {
ns.ListenSpec = v23.GetListenSpec(ctx)
ns.Name = *publishAs
+ ns.Neighborhood = *nhName
}
+ // TODO(caprita): Move pairing token generation and printing into the
+ // claimable service setup.
var pairingToken string
if *usePairingToken {
var token [8]byte
@@ -91,10 +93,17 @@
RestartCallback: func() { exitErr = cmdline.ErrExitCode(*restartExitCode) },
PairingToken: pairingToken,
}
- if dev.ListenSpec, err = derivedListenSpec(ns.ListenSpec, *dmPort); err != nil {
- return err
+ if testMode {
+ dev.ListenSpec = ipc.ListenSpec{Addrs: ipc.ListenAddrs{{"tcp", "127.0.0.1:0"}}}
+ } else {
+ if dev.ListenSpec, err = derivedListenSpec(ns.ListenSpec, *dmPort); err != nil {
+ return err
+ }
}
- proxy := starter.ProxyArgs{Port: *proxyPort}
+ var proxy starter.ProxyArgs
+ if !testMode {
+ proxy.Port = *proxyPort
+ }
// We grab the shutdown channel at this point in order to ensure that we
// register a listener for the app cycle manager Stop before we start
// running the device manager service. Otherwise, any device manager
@@ -110,7 +119,7 @@
// Wait until shutdown. Ignore duplicate signals (sent by agent and
// received as part of process group).
signals.SameSignalTimeWindow = 500 * time.Millisecond
- <-shutdownChan
+ vlog.Info("Shutting down due to: ", <-shutdownChan)
return exitErr
}
diff --git a/services/mgmt/device/impl/device_service.go b/services/mgmt/device/impl/device_service.go
index cfdf1ae..ffe84a8 100644
--- a/services/mgmt/device/impl/device_service.go
+++ b/services/mgmt/device/impl/device_service.go
@@ -456,6 +456,9 @@
output += "if [ -z \"$DEVICE_MANAGER_DONT_REDIRECT_STDOUT_STDERR\" ]; then\n"
output += fmt.Sprintf(" TIMESTAMP=$(%s)\n", dateCommand)
output += fmt.Sprintf(" exec > %s-$TIMESTAMP 2> %s-$TIMESTAMP\n", stdoutLog, stderrLog)
+ output += " LOG_TO_STDERR=false\n"
+ output += "else\n"
+ output += " LOG_TO_STDERR=true\n"
output += "fi\n"
output += strings.Join(config.QuoteEnv(append(envelope.Env, configSettings...)), " ") + " "
// Escape the path to the binary; %q uses Go-syntax escaping, but it's
@@ -465,6 +468,7 @@
// veyron/tools/debug/impl.go) instead.
output += fmt.Sprintf("exec %q", filepath.Join(workspace, "deviced")) + " "
output += fmt.Sprintf("--log_dir=%q ", logs)
+ output += "--logtostderr=${LOG_TO_STDERR} "
output += strings.Join(envelope.Args, " ")
path = filepath.Join(workspace, "deviced.sh")
diff --git a/services/mgmt/device/starter/starter.go b/services/mgmt/device/starter/starter.go
index 19830ec..15d32cf 100644
--- a/services/mgmt/device/starter/starter.go
+++ b/services/mgmt/device/starter/starter.go
@@ -74,6 +74,14 @@
if err := impl.CheckCompatibility(args.Device.ConfigState.Root); err != nil {
return nil, err
}
+ // In test mode, we skip writing the info file to disk, and we skip
+ // attempting to start the claimable service: the device must have been
+ // claimed already to enable updates anyway, and checking for acls in
+ // NewClaimableDispatcher needlessly prints an acl signature
+ // verification error to the logs.
+ if args.Device.TestMode {
+ return startClaimedDevice(ctx, args)
+ }
// TODO(caprita): use some mechanism (a file lock or presence of entry
// in mounttable) to ensure only one device manager is running in an
@@ -81,31 +89,31 @@
mi := &impl.ManagerInfo{
Pid: os.Getpid(),
}
-
- if !args.Device.TestMode { // In test mode, we don't want to touch the state on disk
- if err := impl.SaveManagerInfo(filepath.Join(args.Device.ConfigState.Root, "device-manager"), mi); err != nil {
- return nil, fmt.Errorf("failed to save info: %v", err)
- }
+ if err := impl.SaveManagerInfo(filepath.Join(args.Device.ConfigState.Root, "device-manager"), mi); err != nil {
+ return nil, fmt.Errorf("failed to save info: %v", err)
}
// If the device has not yet been claimed, start the mounttable and
// claimable service and wait for it to be claimed.
// Once a device is claimed, close any previously running servers and
// start a new mounttable and device service.
- if claimable, claimed := impl.NewClaimableDispatcher(ctx, args.Device.ConfigState, args.Device.PairingToken); claimable != nil {
- stopClaimable, err := startClaimableDevice(ctx, claimable, args)
- if err != nil {
- return nil, err
- }
- stop := make(chan struct{})
- stopped := make(chan struct{})
- go waitToBeClaimedAndStartClaimedDevice(ctx, stopClaimable, claimed, stop, stopped, args)
- return func() {
- close(stop)
- <-stopped
- }, nil
+ claimable, claimed := impl.NewClaimableDispatcher(ctx, args.Device.ConfigState, args.Device.PairingToken)
+ if claimable == nil {
+ // Device has already been claimed, bypass claimable service
+ // stage.
+ return startClaimedDevice(ctx, args)
}
- return startClaimedDevice(ctx, args)
+ stopClaimable, err := startClaimableDevice(ctx, claimable, args)
+ if err != nil {
+ return nil, err
+ }
+ stop := make(chan struct{})
+ stopped := make(chan struct{})
+ go waitToBeClaimedAndStartClaimedDevice(ctx, stopClaimable, claimed, stop, stopped, args)
+ return func() {
+ close(stop)
+ <-stopped
+ }, nil
}
func startClaimableDevice(ctx *context.T, dispatcher ipc.Dispatcher, args Args) (func(), error) {
@@ -138,7 +146,9 @@
return nil, err
}
shutdown := func() {
+ vlog.Infof("Stopping claimable server...")
server.Stop()
+ vlog.Infof("Stopped claimable server.")
stopMT()
cancel()
}
@@ -251,7 +261,11 @@
return nil, fmt.Errorf("Failed to create proxy: %v", err)
}
vlog.Infof("Local proxy (%v)", proxy.Endpoint().Name())
- return proxy.Shutdown, nil
+ return func() {
+ vlog.Infof("Stopping proxy...")
+ proxy.Shutdown()
+ vlog.Infof("Stopped proxy.")
+ }, nil
}
func startMounttable(ctx *context.T, n NamespaceArgs) (string, func(), error) {
@@ -261,7 +275,11 @@
} else {
vlog.Infof("Local mounttable (%v) published as %q", mtName, n.Name)
}
- return mtName, stopMT, err
+ return mtName, func() {
+ vlog.Infof("Stopping mounttable...")
+ stopMT()
+ vlog.Infof("Stopped mounttable.")
+ }, err
}
// startDeviceServer creates an ipc.Server and sets it up to server the Device service.
@@ -296,8 +314,10 @@
}
shutdown = func() {
+ vlog.Infof("Stopping device server...")
server.Stop()
impl.Shutdown(dispatcher)
+ vlog.Infof("Stopped device.")
}
if err := server.ServeDispatcher(args.name(mt), dispatcher); err != nil {
shutdown()
