diff --git a/dist/roverd b/dist/roverd index 090cfac0..636b9ada 100755 Binary files a/dist/roverd and b/dist/roverd differ diff --git a/dist/roverd-debian-laptop b/dist/roverd-debian-laptop index 851006be..59cb7ce7 100755 Binary files a/dist/roverd-debian-laptop and b/dist/roverd-debian-laptop differ diff --git a/pi/roverd/cmd/roverd/main.go b/pi/roverd/cmd/roverd/main.go index 221de8b9..7911d163 100644 --- a/pi/roverd/cmd/roverd/main.go +++ b/pi/roverd/cmd/roverd/main.go @@ -29,6 +29,7 @@ func main() { defer cancel() logger := log.New(os.Stdout, "roverd: ", log.LstdFlags|log.Lmicroseconds|log.LUTC) + console := roverd.NewConsoleNotifier(logger) serialPort, err := roverd.OpenSerial(cfg.Serial) if err != nil { @@ -90,7 +91,13 @@ func main() { autoCharge := roverd.NewAutoChargeController(adapter, eventStream, logger) go autoCharge.Run(ctx, sensorSamples) - client := roverd.NewWSClient(cfg, adapter, sensorFrames, eventStream, mediaSupervisor, cameraServo, headlight, laser, logger) + client := roverd.NewWSClient(cfg, adapter, sensorFrames, eventStream, mediaSupervisor, cameraServo, headlight, laser, logger, console) + + // Startup is announced only after every configured hardware dependency has + // initialized successfully. A message here therefore means the control loop + // is genuinely ready, rather than merely that systemd launched the process. + console.Notify("roverd started and hardware initialization completed.") + defer console.Notify("roverd stopped.") retryDelay := time.Second for ctx.Err() == nil { diff --git a/pi/roverd/console_notifier.go b/pi/roverd/console_notifier.go new file mode 100644 index 00000000..ef0d6d3c --- /dev/null +++ b/pi/roverd/console_notifier.go @@ -0,0 +1,67 @@ +package roverd + +import ( + "fmt" + "log" + "os" + "sync" + "time" +) + +const roverConsolePath = "/dev/tty1" + +// ConsoleNotifier writes the small set of rover lifecycle events that must be +// visible even when nobody is logged in. This intentionally targets tty1 +// directly instead of using wall: wall discovers recipients through utmp, so +// it does not reliably reach a virtual console that is only showing a login +// prompt. +type ConsoleNotifier struct { + path string + logger *log.Logger + mu sync.Mutex +} + +// NewConsoleNotifier returns the production notifier for the rover's primary +// local virtual console. Keeping the path inside the notifier also gives tests +// a way to substitute a regular temporary file without touching a real TTY. +func NewConsoleNotifier(logger *log.Logger) *ConsoleNotifier { + return newConsoleNotifier(roverConsolePath, logger) +} + +func newConsoleNotifier(path string, logger *log.Logger) *ConsoleNotifier { + return &ConsoleNotifier{path: path, logger: logger} +} + +// Notify appends one self-contained alert to the console. Console output is a +// diagnostic convenience rather than part of rover control, so an unavailable +// tty is logged but never allowed to stop startup, reconnection, docking, or +// reboot behavior. +func (n *ConsoleNotifier) Notify(message string) { + if n == nil { + return + } + + n.mu.Lock() + defer n.mu.Unlock() + + console, err := os.OpenFile(n.path, os.O_WRONLY|os.O_APPEND, 0) + if err != nil { + n.logFailure("open", err) + return + } + defer console.Close() + + // Leading and trailing CRLFs keep the alert separate from an agetty login + // prompt, while plain text avoids leaving an unknown terminal in a modified + // color or cursor state. + timestamp := time.Now().UTC().Format("2006-01-02 15:04:05 UTC") + if _, err := fmt.Fprintf(console, "\r\n*** rover alert - %s ***\r\n%s\r\n", timestamp, message); err != nil { + n.logFailure("write", err) + } +} + +func (n *ConsoleNotifier) logFailure(operation string, err error) { + if n.logger != nil { + n.logger.Printf("console notification %s failed for %s: %v", operation, n.path, err) + } +} diff --git a/pi/roverd/console_notifier_test.go b/pi/roverd/console_notifier_test.go new file mode 100644 index 00000000..4a5196ed --- /dev/null +++ b/pi/roverd/console_notifier_test.go @@ -0,0 +1,40 @@ +package roverd + +import ( + "io" + "log" + "os" + "path/filepath" + "strings" + "testing" +) + +func TestConsoleNotifierWritesVisibleAlert(t *testing.T) { + path := filepath.Join(t.TempDir(), "tty1") + if err := os.WriteFile(path, nil, 0o600); err != nil { + t.Fatalf("create fake console: %v", err) + } + + notifier := newConsoleNotifier(path, log.New(io.Discard, "", 0)) + notifier.Notify("control server connection lost") + + contents, err := os.ReadFile(path) + if err != nil { + t.Fatalf("read fake console: %v", err) + } + output := string(contents) + if !strings.Contains(output, "*** rover alert - ") { + t.Fatalf("alert header missing from %q", output) + } + if !strings.Contains(output, "control server connection lost") { + t.Fatalf("alert message missing from %q", output) + } +} + +func TestConsoleNotifierTreatsMissingConsoleAsNonfatal(t *testing.T) { + // A missing TTY is normal on some headless or containerized hosts. The + // contract is therefore simply that Notify returns instead of escalating a + // display failure into a rover-process failure. + notifier := newConsoleNotifier(filepath.Join(t.TempDir(), "missing"), log.New(io.Discard, "", 0)) + notifier.Notify("roverd started") +} diff --git a/pi/roverd/wsclient.go b/pi/roverd/wsclient.go index 241a11fa..ebf92fee 100644 --- a/pi/roverd/wsclient.go +++ b/pi/roverd/wsclient.go @@ -24,8 +24,12 @@ type WSClient struct { headlight *GPIOToggle laser *GPIOToggle log *log.Logger + console *ConsoleNotifier recoverMu sync.Mutex recovering bool + watchdogMu sync.Mutex + watchdogOpen bool + watchdogOK bool ttsQueue chan *ttsPayload chromeTTS *chromeTTSDaemon lastAux motorPWMPayload @@ -41,7 +45,7 @@ type WSClient struct { audioMu sync.RWMutex } -func NewWSClient(cfg *Config, adapter *SerialAdapter, frames <-chan []byte, events chan RoverEvent, media *MediaSupervisor, servo *CameraServo, headlight *GPIOToggle, laser *GPIOToggle, logger *log.Logger) *WSClient { +func NewWSClient(cfg *Config, adapter *SerialAdapter, frames <-chan []byte, events chan RoverEvent, media *MediaSupervisor, servo *CameraServo, headlight *GPIOToggle, laser *GPIOToggle, logger *log.Logger, console *ConsoleNotifier) *WSClient { var ttsQueue chan *ttsPayload if cfg.Audio.TTSEnabled { ttsQueue = make(chan *ttsPayload, 2) @@ -65,6 +69,7 @@ func NewWSClient(cfg *Config, adapter *SerialAdapter, frames <-chan []byte, even headlight: headlight, laser: laser, log: logger, + console: console, ttsQueue: ttsQueue, chromeTTS: chromeTTS, audioLevels: AudioLevels{ @@ -305,6 +310,7 @@ func (c *WSClient) handleRebootCommand(payload *rebootPayload) error { go func() { time.Sleep(delay) + c.console.Notify("Remote reboot requested. Rebooting the rover now.") c.log.Printf("rebooting pi after remote reboot command") cmd := exec.Command("systemctl", "reboot") if err := cmd.Start(); err != nil { @@ -331,6 +337,7 @@ func (c *WSClient) handleUpdateCommand() error { c.emitEvent("system.updateStarting", map[string]any{ "source": "remoteCommand", }) + c.console.Notify("Remote software update requested. roverd will restart if the update succeeds.") // The helper is launched asynchronously because a successful update may // restart roverd before this websocket command could stream progress back to @@ -495,6 +502,10 @@ func (c *WSClient) forwardSensors(ctx context.Context, conn *websocket.Conn) { lastRecovery = now resetTimer() case frame := <-c.sensorFrames: + // A real sensor frame is the authoritative end of a watchdog + // episode. Successfully sending the OI restart commands alone does + // not prove that the Roomba resumed producing sensor data. + c.closeSensorWatchdogEpisode() lastFrame = time.Now() resetTimer() msg := sensorMessage{ @@ -641,6 +652,7 @@ func (c *WSClient) keepalive(ctx context.Context, conn *websocket.Conn) error { func (c *WSClient) markConnected() { c.connMu.Lock() + wasConnected := c.connected c.connected = true c.seekIssued = false c.rebootIssued = false @@ -654,13 +666,19 @@ func (c *WSClient) markConnected() { c.rebootT = nil } c.connMu.Unlock() + + // Only print on a state transition. Run is retried indefinitely, and a + // message on every successful internal operation would quickly bury the + // useful lifecycle history at the login prompt. + if !wasConnected { + c.console.Notify("Control server connected.") + } } func (c *WSClient) markDisconnected() { c.connMu.Lock() - if c.connected { - c.connected = false - } + wasConnected := c.connected + c.connected = false if c.disconnectT == nil { c.disconnectT = time.AfterFunc(disconnectSeekDelay, c.handleDisconnectTimeout) } @@ -668,6 +686,13 @@ func (c *WSClient) markDisconnected() { c.rebootT = time.AfterFunc(disconnectRebootDelay, c.handleRebootTimeout) } c.connMu.Unlock() + + // Initial dial failures are already represented by the startup message and + // journal retry logs. The prominent disconnect alert is reserved for losing + // a connection that was actually established. + if wasConnected { + c.console.Notify("Control server connection lost. Automatic dock seek in 1 minute; rover reboot in 6 minutes if the connection is not restored.") + } } func (c *WSClient) handleDisconnectTimeout() { @@ -679,6 +704,7 @@ func (c *WSClient) handleDisconnectTimeout() { c.seekIssued = true c.connMu.Unlock() + c.console.Notify("Control server has been disconnected for 1 minute. Seeking the dock now.") if err := c.adapter.SeekDock(); err != nil { c.log.Printf("seek dock on disconnect failed: %v", err) return @@ -695,6 +721,7 @@ func (c *WSClient) handleRebootTimeout() { c.rebootIssued = true c.connMu.Unlock() + c.console.Notify("Control server has been disconnected for 6 minutes. Rebooting the rover now.") c.log.Printf("rebooting pi after prolonged websocket disconnect") cmd := exec.Command("systemctl", "reboot") if err := cmd.Start(); err != nil { @@ -720,10 +747,16 @@ func (c *WSClient) recoverSensorStream(idleFor time.Duration, cmdPause time.Dura c.emitEvent("sensorWatchdog.restart", map[string]any{ "idleMs": idleFor.Milliseconds(), }) + if c.openSensorWatchdogEpisode() { + c.console.Notify(fmt.Sprintf("Sensor watchdog is restarting the Roomba sensor stream after %.1f seconds without data.", idleFor.Seconds())) + } if err := c.adapter.StartOI(); err != nil { c.log.Printf("watchdog start OI failed: %v", err) c.emitEvent("sensorWatchdog.error", map[string]any{"error": err.Error()}) + // Unlike the restart notice, every concrete command failure is useful + // diagnostic information and may change between recovery attempts. + c.console.Notify(fmt.Sprintf("Sensor watchdog recovery failed while starting the Roomba OI: %v", err)) return } if cmdPause > 0 { @@ -733,12 +766,53 @@ func (c *WSClient) recoverSensorStream(idleFor time.Duration, cmdPause time.Dura if err := c.adapter.StartSensorStream(defaultStreamPackets); err != nil { c.log.Printf("watchdog start stream failed: %v", err) c.emitEvent("sensorWatchdog.error", map[string]any{"error": err.Error()}) + c.console.Notify(fmt.Sprintf("Sensor watchdog recovery failed while starting the sensor stream: %v", err)) return } c.emitEvent("sensorWatchdog.ok", map[string]any{ "idleMs": idleFor.Milliseconds(), }) + if c.markSensorWatchdogCommandsOK() { + // Match the existing sensorWatchdog.ok contract precisely: this says + // the recovery commands succeeded, not that a new frame has arrived. + c.console.Notify("Sensor watchdog successfully sent the sensor-stream restart commands.") + } +} + +// openSensorWatchdogEpisode reports whether this is the first recovery attempt +// since sensor frames stopped. The watchdog can retry every few seconds, so +// tracking the outage as one episode keeps the login console readable. +func (c *WSClient) openSensorWatchdogEpisode() bool { + c.watchdogMu.Lock() + defer c.watchdogMu.Unlock() + + if c.watchdogOpen { + return false + } + c.watchdogOpen = true + c.watchdogOK = false + return true +} + +// markSensorWatchdogCommandsOK suppresses duplicate success notices while the +// rover is still waiting for a real frame to close the current outage. +func (c *WSClient) markSensorWatchdogCommandsOK() bool { + c.watchdogMu.Lock() + defer c.watchdogMu.Unlock() + + if c.watchdogOK { + return false + } + c.watchdogOK = true + return true +} + +func (c *WSClient) closeSensorWatchdogEpisode() { + c.watchdogMu.Lock() + c.watchdogOpen = false + c.watchdogOK = false + c.watchdogMu.Unlock() } func isModeOpcode(op byte) bool { diff --git a/pi/roverd/wsclient_watchdog_test.go b/pi/roverd/wsclient_watchdog_test.go new file mode 100644 index 00000000..174d77ab --- /dev/null +++ b/pi/roverd/wsclient_watchdog_test.go @@ -0,0 +1,27 @@ +package roverd + +import "testing" + +func TestSensorWatchdogConsoleEpisodeSuppressesDuplicateStatusMessages(t *testing.T) { + client := &WSClient{} + + if !client.openSensorWatchdogEpisode() { + t.Fatal("first recovery attempt should announce the watchdog episode") + } + if client.openSensorWatchdogEpisode() { + t.Fatal("repeated recovery attempt should not repeat the outage announcement") + } + if !client.markSensorWatchdogCommandsOK() { + t.Fatal("first successful command restart should be announced") + } + if client.markSensorWatchdogCommandsOK() { + t.Fatal("repeated successful command restart should not be announced") + } + + // Receiving a real frame closes the outage. A later silence is a distinct + // incident and must therefore be visible on the console again. + client.closeSensorWatchdogEpisode() + if !client.openSensorWatchdogEpisode() { + t.Fatal("new outage after a sensor frame should be announced") + } +} diff --git a/pi/systemd/roverd.service b/pi/systemd/roverd.service index e027f30b..71c75572 100644 --- a/pi/systemd/roverd.service +++ b/pi/systemd/roverd.service @@ -6,6 +6,10 @@ Wants=network-online.target [Service] Type=simple ExecStart=/usr/local/bin/roverd -config /etc/roverd.yaml +# roverd cannot report an unexpected exit after its process is already gone. +# ExecStopPost fills only that gap; ordinary lifecycle messages remain owned by +# roverd, and SERVICE_RESULT prevents clean stops from being labeled failures. +ExecStopPost=/bin/sh -c 'if [ "$SERVICE_RESULT" != "success" ]; then /usr/bin/printf "\r\n*** rover alert ***\r\nroverd exited unexpectedly; systemd will restart it.\r\n" > /dev/tty1 || true; fi' Restart=on-failure RestartSec=5 AmbientCapabilities=CAP_SYS_TTY_CONFIG CAP_SYS_RAWIO