From 34407f69e763d7b05951c5db83beaf3fe2a62ef0 Mon Sep 17 00:00:00 2001 From: 0xb10c <0xb10c@gmail.com> Date: Thu, 5 Dec 2019 15:44:40 +0100 Subject: [PATCH 1/5] fix: readd Redis keys for Base state to Middleware This readds the Redis keys for the Base state which where mistakenly removed from 71c173ffd24f2a2b3a86b3b55703ee0d2d2e9b1a in a rebase. The descriptionCode key references a Redis sorted-set containing the currently active subsystem states. The stateCode references a Redis string storing the (integer) value of the currently active system state (one of IDLE;WORKING;WARNING;ERROR). --- middleware/src/redis/keys.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/middleware/src/redis/keys.go b/middleware/src/redis/keys.go index d9f31aa2..fdcf0da1 100644 --- a/middleware/src/redis/keys.go +++ b/middleware/src/redis/keys.go @@ -20,4 +20,6 @@ const ( BaseSetupDone BaseRedisKey = "base:setup" BaseSSHDPasswordLogin BaseRedisKey = "base:sshd:passwordlogin" BitcoindIBDClearnet BaseRedisKey = "bitcoind:ibd-clearnet" + BaseDescriptionCode BaseRedisKey = "base:descriptionCode" + BaseStateCode BaseRedisKey = "base:stateCode" ) From 59fda30953aa71cba6f28a3c91a7284b72f61746 Mon Sep 17 00:00:00 2001 From: 0xb10c <0xb10c@gmail.com> Date: Tue, 3 Dec 2019 21:12:58 +0100 Subject: [PATCH 2/5] add: handling of state for update+shutdown+reboot This adds the handling of the following system states to the Supervisor: - DOWNLOAD_UPDATE - UPDATE_FAILED - REBOOT - SHUTDOWN The Middleware logs a destinct logtag once one of these states become active. The Supervisor watches the Middleware log and handles the state changes by setting the respective `descriptionCodes` in the sorted set in Redis and the respective stateCode. The Middleware is notified that there was a state change in Redis via the named pipe IPC, but doesn't handle the notification yet. --- middleware/go.sum | 6 - middleware/src/middleware.go | 9 ++ middleware/src/util.go | 10 ++ tools/bbbsupervisor/go.mod | 2 +- tools/bbbsupervisor/go.sum | 4 +- .../bbbsupervisor/supervisor/eventhandling.go | 148 +++++++++++++++++- tools/bbbsupervisor/supervisor/supervisor.go | 18 +++ tools/bbbsupervisor/supervisor/util.go | 67 ++++++++ .../watcher/logwatcher/logwatcher.go | 11 ++ .../bbbsupervisor/watcher/trigger/trigger.go | 12 +- 10 files changed, 276 insertions(+), 11 deletions(-) diff --git a/middleware/go.sum b/middleware/go.sum index 853f0064..637a4a4a 100644 --- a/middleware/go.sum +++ b/middleware/go.sum @@ -1,15 +1,11 @@ github.com/aead/siphash v1.0.1/go.mod h1:Nywa3cDsYNNK3gaciGTWPwHt0wlpNV15vwmswBAUSII= github.com/btcsuite/btcd v0.20.1-beta h1:Ik4hyJqN8Jfyv3S4AGBOmyouMsYE3EdYODkMbQjwPGw= github.com/btcsuite/btcd v0.20.1-beta/go.mod h1:wVuoA8VJLEcwgqHBwHmzLRazpKxTv13Px/pDuV7OomQ= -github.com/btcsuite/btclog v0.0.0-20170628155309-84c8d2346e9f h1:bAs4lUbRJpnnkd9VhRV3jjAVU7DJVjMaK+IsvSeZvFo= github.com/btcsuite/btclog v0.0.0-20170628155309-84c8d2346e9f/go.mod h1:TdznJufoqS23FtqVCzL0ZqgP5MqXbb4fg/WgDys70nA= -github.com/btcsuite/btcutil v0.0.0-20190425235716-9e5f4b9a998d h1:yJzD/yFppdVCf6ApMkVy8cUxV0XrxdP9rVf6D87/Mng= github.com/btcsuite/btcutil v0.0.0-20190425235716-9e5f4b9a998d/go.mod h1:+5NJ2+qvTyV9exUAL/rxXi3DcLg2Ts+ymUAY5y4NvMg= -github.com/btcsuite/go-socks v0.0.0-20170105172521-4720035b7bfd h1:R/opQEbFEy9JGkIguV40SvRY1uliPX8ifOvi6ICsFCw= github.com/btcsuite/go-socks v0.0.0-20170105172521-4720035b7bfd/go.mod h1:HHNXQzUsZCxOoE+CPiyCTO6x34Zs86zZUiwtpXoGdtg= github.com/btcsuite/goleveldb v0.0.0-20160330041536-7834afc9e8cd/go.mod h1:F+uVaaLLH7j4eDXPRvw78tMflu7Ie2bzYOH4Y8rRKBY= github.com/btcsuite/snappy-go v0.0.0-20151229074030-0bdef8d06723/go.mod h1:8woku9dyThutzjeg+3xrA5iCpBRH8XEEg3lh6TiUghc= -github.com/btcsuite/websocket v0.0.0-20150119174127-31079b680792 h1:R8vQdOQdZ9Y3SkEwmHoWBmX1DNXhXZqlTpq6s4tyJGc= github.com/btcsuite/websocket v0.0.0-20150119174127-31079b680792/go.mod h1:ghJtEyQwv5/p4Mg4C0fgbePVuGr935/5ddU9Z3TmDRY= github.com/btcsuite/winsvc v1.0.0/go.mod h1:jsenWakMcC0zFBFurPLEAyrnc/teJEM1O46fmI40EZs= github.com/davecgh/go-spew v0.0.0-20171005155431-ecdeabc65495/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= @@ -43,7 +39,6 @@ github.com/pkg/errors v0.8.1 h1:iURUrRGxPUNPdy5/HRSm+Yj6okJ6UtLINN0Q9M4+h3I= github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= -github.com/stretchr/objx v0.1.0 h1:4G4v2dO3VZwixGIRoQ5Lfboy6nUhCyYzaqnIAPPhYs4= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/objx v0.2.0 h1:Hbg2NidpLE8veEBkEZTL3CvlkUIVzuU9jDplZO54c48= github.com/stretchr/objx v0.2.0/go.mod h1:qt09Ya8vawLte6SNmTgCsAVtYtaKzEcn8ATUoHMkEqE= @@ -68,7 +63,6 @@ golang.org/x/sync v0.0.0-20180314180146-1d60e4601c6f/go.mod h1:RxMgew5VJxzue5/jJ golang.org/x/sys v0.0.0-20180909124046-d0be0721c37e/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -golang.org/x/sys v0.0.0-20191104094858-e8c54fb511f6 h1:ZJUmhYTp8GbGC0ViZRc2U+MIYQ8xx9MscsdXnclfIhw= golang.org/x/sys v0.0.0-20191104094858-e8c54fb511f6/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20191105231009-c1f44814a5cd h1:3x5uuvBgE6oaXJjCOvpCC1IpgJogqQ+PqGGU3ZxAgII= golang.org/x/sys v0.0.0-20191105231009-c1f44814a5cd/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= diff --git a/middleware/src/middleware.go b/middleware/src/middleware.go index 64fbb8cf..6ce98187 100644 --- a/middleware/src/middleware.go +++ b/middleware/src/middleware.go @@ -15,6 +15,7 @@ import ( "github.com/digitalbitbox/bitbox-base/middleware/src/configuration" "github.com/digitalbitbox/bitbox-base/middleware/src/handlers" "github.com/digitalbitbox/bitbox-base/middleware/src/ipcnotification" + "github.com/digitalbitbox/bitbox-base/middleware/src/logtags" "github.com/digitalbitbox/bitbox-base/middleware/src/prometheus" "github.com/digitalbitbox/bitbox-base/middleware/src/redis" "github.com/digitalbitbox/bitbox-base/middleware/src/rpcmessages" @@ -246,11 +247,15 @@ func (middleware *Middleware) ipcNotificationLoop(reader *ipcnotification.Reader if success, ok := ipcnotification.ParseMenderUpdatePayload(notification.Payload); ok { switch success { case true: + // This logtag notifies the supervisor that the update was successful. + log.Println(logtags.LogTagMWUpdateSuccess) middleware.events <- handlers.Event{ Identifier: []byte(rpcmessages.OpBaseUpdateSuccess), QueueIfNoClient: true, } case false: + // This logtag notifies the supervisor that the update failed. + log.Println(logtags.LogTagMWUpdateFailure) middleware.events <- handlers.Event{ Identifier: []byte(rpcmessages.OpBaseUpdateFailure), QueueIfNoClient: true, @@ -713,6 +718,8 @@ func (middleware *Middleware) ShutdownBase() rpcmessages.ErrorResponse { } go func(delay time.Duration) { + // This logtag lets the Supervisor know that the Middleware initiated a reboot + log.Println(logtags.LogTagMWShutdown) time.Sleep(delay) cmd := exec.Command("shutdown", "now") err = cmd.Start() @@ -747,6 +754,8 @@ func (middleware *Middleware) RebootBase() rpcmessages.ErrorResponse { } go func(delay time.Duration) { + // This logtag lets the Supervisor know that the Middleware initiated a reboot + log.Println(logtags.LogTagMWReboot) time.Sleep(delay) cmd := exec.Command("reboot") err = cmd.Start() diff --git a/middleware/src/util.go b/middleware/src/util.go index 5b6b6a8e..eca760eb 100644 --- a/middleware/src/util.go +++ b/middleware/src/util.go @@ -13,6 +13,7 @@ import ( "time" "github.com/digitalbitbox/bitbox-base/middleware/src/handlers" + "github.com/digitalbitbox/bitbox-base/middleware/src/logtags" "github.com/digitalbitbox/bitbox-base/middleware/src/prometheus" "github.com/digitalbitbox/bitbox-base/middleware/src/redis" "github.com/digitalbitbox/bitbox-base/middleware/src/rpcmessages" @@ -303,6 +304,15 @@ func parseBaseUpdateStdout(outputLine string) (containsUpdateProgressInfo bool, } func (middleware *Middleware) setBaseUpdateStateAndNotify(state rpcmessages.BaseUpdateState) { + if state == rpcmessages.UpdateFailed { + // This log tag lets the Supervisor know that the update process failed. + log.Println(logtags.LogTagMWUpdateFailure) + } else if state == rpcmessages.UpdateDownloading { + // This log tag lets the Supervisor know that the Middleware has started the + // update process. + log.Println(logtags.LogTagMWUpdateStart) + } // The reboot-logtag is logged in the the middleware.RebootBase() method + middleware.baseUpdateProgress.State = state middleware.events <- handlers.Event{ Identifier: []byte(rpcmessages.OpBaseUpdateProgressChanged), diff --git a/tools/bbbsupervisor/go.mod b/tools/bbbsupervisor/go.mod index e0db52fb..7f28f334 100644 --- a/tools/bbbsupervisor/go.mod +++ b/tools/bbbsupervisor/go.mod @@ -3,7 +3,7 @@ module github.com/digitalbitbox/bitbox-base/tools/bbbsupervisor go 1.13 require ( - github.com/digitalbitbox/bitbox-base/middleware v0.0.0-20191204153728-1128dd782517 + github.com/digitalbitbox/bitbox-base/middleware v0.0.0-20191205145921-34407f69e763 github.com/digitalbitbox/bitbox02-api-go v0.0.0-20191204135529-eb28ed7e9cbd github.com/tidwall/gjson v1.3.4 ) diff --git a/tools/bbbsupervisor/go.sum b/tools/bbbsupervisor/go.sum index 66174fd1..f586545d 100644 --- a/tools/bbbsupervisor/go.sum +++ b/tools/bbbsupervisor/go.sum @@ -13,8 +13,8 @@ github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSs github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/dgrijalva/jwt-go v3.2.0+incompatible/go.mod h1:E3ru+11k8xSBh+hMPgOLZmtrrCbhqsmaPHjLKYnJCaQ= -github.com/digitalbitbox/bitbox-base/middleware v0.0.0-20191204153728-1128dd782517 h1:b34ka1KKniF6hzIW+5n7sDfBhEfzzAZAiE6srtmSnDM= -github.com/digitalbitbox/bitbox-base/middleware v0.0.0-20191204153728-1128dd782517/go.mod h1:UidGto4vnuuvotQdGoNHY5ipVmDWHkbnkaAo3Q5qTPw= +github.com/digitalbitbox/bitbox-base/middleware v0.0.0-20191205145921-34407f69e763 h1:03qjUjBcf5tLK61oDvY7as0wmkgulcIBfqBluVs3oC8= +github.com/digitalbitbox/bitbox-base/middleware v0.0.0-20191205145921-34407f69e763/go.mod h1:UidGto4vnuuvotQdGoNHY5ipVmDWHkbnkaAo3Q5qTPw= github.com/digitalbitbox/bitbox02-api-go v0.0.0-20191204135529-eb28ed7e9cbd h1:K29fNVgdarWFPuhnR05ZdZYuNeMe63Ym/18nJQohwsU= github.com/digitalbitbox/bitbox02-api-go v0.0.0-20191204135529-eb28ed7e9cbd/go.mod h1:yMwrh5lnSF+UDy+PLdCySxWHZubd2Tk/t2EQ1++4mgA= github.com/flynn/noise v0.0.0-20180327030543-2492fe189ae6/go.mod h1:1i71OnUq3iUe1ma7Lr6yG6/rjvM3emb6yoL7xLFzcVQ= diff --git a/tools/bbbsupervisor/supervisor/eventhandling.go b/tools/bbbsupervisor/supervisor/eventhandling.go index 5a24a53c..17c0aff1 100644 --- a/tools/bbbsupervisor/supervisor/eventhandling.go +++ b/tools/bbbsupervisor/supervisor/eventhandling.go @@ -7,6 +7,7 @@ import ( "github.com/digitalbitbox/bitbox-base/tools/bbbsupervisor/watcher" "github.com/digitalbitbox/bitbox-base/tools/bbbsupervisor/watcher/trigger" + "github.com/digitalbitbox/bitbox02-api-go/api/firmware/messages" ) /* This file includes the event parsing and handling code for the bbbsupervisor. */ @@ -19,7 +20,7 @@ func (s *Supervisor) eventLoop() { } // eventHandler handles errors and events. -// When a panic occours the error is recovered from without stopping the eventLoop(). +// When a panic occurs the error is recovered from without stopping the eventLoop(). func (s *Supervisor) eventHandler() { defer func() { if r := recover(); r != nil { @@ -41,6 +42,16 @@ func (s *Supervisor) eventHandler() { err = s.handleMiddlewareNoBitcoindConnectivity(event) case event.Trigger == trigger.PrometheusBitcoindIBD: err = s.handleBitcoindIBD(event) + case event.Trigger == trigger.MiddlewareBaseImageUpdateStart: + err = s.handleBaseImageUpdateStart(event) + case event.Trigger == trigger.MiddlewareBaseImageUpdateSuccess: + err = s.handleBaseImageUpdateSuccess(event) + case event.Trigger == trigger.MiddlewareBaseImageUpdateFailure: + err = s.handleBaseImageUpdateFailure(event) + case event.Trigger == trigger.MiddlewareRPCReboot: + err = s.handleBaseReboot(event) + case event.Trigger == trigger.MiddlewareRPCShutdown: + err = s.handleBaseShutdown(event) default: panic(fmt.Errorf("trigger %d is unhandled", event.Trigger)) } @@ -50,6 +61,141 @@ func (s *Supervisor) eventHandler() { } } +// handleBaseImageUpdateStart is called when the middleware logs the logtag +// `LogTagMWUpdateStart`. The UPDATE_FAILED state is deactivated and the +// DOWNLOAD_UPDATE state is activated. +func (s *Supervisor) handleBaseImageUpdateStart(event watcher.Event) error { + t := event.Trigger + log.Printf("Handling trigger %q\n", t.String()) + err := t.IsFlooding(30*time.Second, s.state.TriggerLastExecuted[t]) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.deactivateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_UPDATE_FAILED) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.activateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_DOWNLOAD_UPDATE) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.notifyMiddlewareSubsystemStateChanged() + if err != nil { + return fmt.Errorf("could not notify the middleware about a new systemstate for trigger %q: %w", t.String(), err) + } + + return nil +} + +// handleBaseImageUpdateSuccess is called when the Middleware logs the logtag +// `LogTagMWUpdateSuccess`. Both the UPDATE_FAILED and DOWNLOAD_UPDATE states +// are deactivated. +func (s *Supervisor) handleBaseImageUpdateSuccess(event watcher.Event) error { + t := event.Trigger + log.Printf("Handling trigger %q\n", t.String()) + err := t.IsFlooding(30*time.Second, s.state.TriggerLastExecuted[t]) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.deactivateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_UPDATE_FAILED) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.deactivateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_DOWNLOAD_UPDATE) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.notifyMiddlewareSubsystemStateChanged() + if err != nil { + return fmt.Errorf("could not notify the middleware about a new systemstate for trigger %q: %w", t.String(), err) + } + + return nil +} + +// handleBaseImageUpdateFailure is called when the Middleware logs the logtag +// `LogTagMWUpdateFailure`.The DOWNLOAD_UPDATE state is deactivated and the +// UPDATE_FAILED state is activated. +func (s *Supervisor) handleBaseImageUpdateFailure(event watcher.Event) error { + t := event.Trigger + log.Printf("Handling trigger %q\n", t.String()) + err := t.IsFlooding(time.Second, s.state.TriggerLastExecuted[t]) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.deactivateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_DOWNLOAD_UPDATE) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.activateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_UPDATE_FAILED) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.notifyMiddlewareSubsystemStateChanged() + if err != nil { + return fmt.Errorf("could not notify the middleware about a new systemstate for trigger %q: %w", t.String(), err) + } + + return nil +} + +// handleBaseShutdown is called when the Middleware logs the logtag +// `LogTagMWShutdown`. The SHUTDOWN state is activated. The state gets reset +// once the Supervisor restarts. +func (s *Supervisor) handleBaseShutdown(event watcher.Event) error { + t := event.Trigger + log.Printf("Handling trigger %q\n", t.String()) + err := t.IsFlooding(1*time.Second, s.state.TriggerLastExecuted[t]) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.activateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_SHUTDOWN) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.notifyMiddlewareSubsystemStateChanged() + if err != nil { + return fmt.Errorf("could not notify the middleware about a new systemstate for trigger %q: %w", t.String(), err) + } + + return nil +} + +// handleBaseReboot is called when the Middleware logs the logtag +// `LogTagMWReboot`. The REBOOT state gets activated. The state gets deactivated +// once the Supervisor restarts (e.g. after the reboot). +func (s *Supervisor) handleBaseReboot(event watcher.Event) error { + t := event.Trigger + log.Printf("Handling trigger %q\n", t.String()) + err := t.IsFlooding(time.Second, s.state.TriggerLastExecuted[t]) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.activateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_REBOOT) + if err != nil { + return fmt.Errorf("could not handle trigger %q: %w", t.String(), err) + } + + err = s.notifyMiddlewareSubsystemStateChanged() + if err != nil { + return fmt.Errorf("could not notify the middleware about a new systemstate for trigger %q: %w", t.String(), err) + } + + return nil +} + // handleElectrsNoBitcoindConnectivity handles the triggerElectrsNoBitcoindConnectivity // by restarting electrs which copies the current .cookie file and reloads authorization func (s *Supervisor) handleElectrsNoBitcoindConnectivity(event watcher.Event) error { diff --git a/tools/bbbsupervisor/supervisor/supervisor.go b/tools/bbbsupervisor/supervisor/supervisor.go index 4cdbe886..e301639c 100644 --- a/tools/bbbsupervisor/supervisor/supervisor.go +++ b/tools/bbbsupervisor/supervisor/supervisor.go @@ -54,6 +54,7 @@ import ( "github.com/digitalbitbox/bitbox-base/tools/bbbsupervisor/watcher/logwatcher" "github.com/digitalbitbox/bitbox-base/tools/bbbsupervisor/watcher/prometheuswatcher" "github.com/digitalbitbox/bitbox-base/tools/bbbsupervisor/watcher/trigger" + "github.com/digitalbitbox/bitbox02-api-go/api/firmware/messages" ) // supervisorState implements a current state for the supervisor. @@ -106,12 +107,29 @@ func New(redisPort string, prometheusPort string) *Supervisor { return &s } +// Start starts the supervisor by starting the watchers. func (s *Supervisor) Start() { log.Println("starting bbbsupervisor") s.setupWatchers() s.startWatchers() + + // When starting the Supervisor the SHUTDOWN and REBOOT system states are + // reset and the Middleware is notified about the change. + err := s.deactivateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_SHUTDOWN) + if err != nil { + log.Printf("Warning: %s\n", err) + } + err = s.deactivateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_REBOOT) + if err != nil { + log.Printf("Warning: %s\n", err) + } + err = s.notifyMiddlewareSubsystemStateChanged() + if err != nil { + log.Printf("Warning: %s", err) + } } +// Loop enters the event loop which processes events passed by the watchers. func (s *Supervisor) Loop() { log.Println("starting supervisor event loop") s.eventLoop() diff --git a/tools/bbbsupervisor/supervisor/util.go b/tools/bbbsupervisor/supervisor/util.go index cf2a6ee1..04352a4f 100644 --- a/tools/bbbsupervisor/supervisor/util.go +++ b/tools/bbbsupervisor/supervisor/util.go @@ -3,10 +3,14 @@ package supervisor import ( "fmt" "log" + "os" "os/exec" + "strconv" "strings" "github.com/digitalbitbox/bitbox-base/middleware/src/redis" + "github.com/digitalbitbox/bitbox-base/tools/bbbsupervisor/systemstate" + "github.com/digitalbitbox/bitbox02-api-go/api/firmware/messages" ) // unsetClearnetIDB unsets (0 - download blocks over Tor) the ibdClearnetRedisKey if set. @@ -85,3 +89,66 @@ func (s *Supervisor) disableBaseIBDState() (err error) { return nil } + +func (s *Supervisor) activateBaseSubsystemState(descCode messages.BitBoxBaseHeartbeatRequest_DescriptionCode) error { + log.Printf("Activating the sub-system state %q\n", descCode.String()) + err := s.redis.AddToSortedSet(redis.BaseDescriptionCode, systemstate.MapDescriptionCodePriority[descCode], strconv.Itoa(int(descCode))) + if err != nil { + return fmt.Errorf("could not activate the Base subsystem state %q: %w", descCode.String(), err) + } + + top, err := s.redis.GetTopFromSortedSet(redis.BaseDescriptionCode) + if err != nil { + return fmt.Errorf("could not get the top element from %q: %w", redis.BaseDescriptionCode, err) + } + + err = s.redis.SetString(redis.BaseStateCode, top) + if err != nil { + return fmt.Errorf("could not set the Base State code to %q: %w", top, err) + } + + return nil +} + +func (s *Supervisor) deactivateBaseSubsystemState(descCode messages.BitBoxBaseHeartbeatRequest_DescriptionCode) error { + log.Printf("Deactivating the sub-system state %q\n", descCode.String()) + err := s.redis.RemoveFromSortedSet(redis.BaseDescriptionCode, strconv.Itoa(int(descCode))) + if err != nil { + return fmt.Errorf("could not deactivate the Base subsystem state %q: %w", descCode.String(), err) + } + + top, err := s.redis.GetTopFromSortedSet(redis.BaseDescriptionCode) + if err != nil { + return fmt.Errorf("could not get the top element from %q: %w", redis.BaseDescriptionCode, err) + } + + err = s.redis.SetString(redis.BaseStateCode, top) + if err != nil { + return fmt.Errorf("could not set the Base State code to %q: %w", top, err) + } + + return nil +} + +func (s *Supervisor) notifyMiddlewareSubsystemStateChanged() error { + log.Println("Notifying the Middleware that a sub-system state changed") + pipe, err := os.OpenFile("/tmp/middleware-notification.pipe", os.O_RDWR, 0600) + if err != nil { + return fmt.Errorf("could not notify middleware that a subsystem state changed: %w", err) + } + + const notification string = "{\"version\": 1, \"topic\": \"systemstate-changed\", \"payload\": {}}\n" + + _, err = pipe.WriteString(notification) + if err != nil { + return fmt.Errorf("could not notify middleware that a subsystem state changed: %w", err) + } + + // close lets the pipe.WriteString fail and the goroutine exits + err = pipe.Close() + if err != nil { + return fmt.Errorf("could not close pipe: %w", err) + } + + return nil +} diff --git a/tools/bbbsupervisor/watcher/logwatcher/logwatcher.go b/tools/bbbsupervisor/watcher/logwatcher/logwatcher.go index 542d357d..fb660ba2 100644 --- a/tools/bbbsupervisor/watcher/logwatcher/logwatcher.go +++ b/tools/bbbsupervisor/watcher/logwatcher/logwatcher.go @@ -6,6 +6,7 @@ import ( "os/exec" "strings" + "github.com/digitalbitbox/bitbox-base/middleware/src/logtags" "github.com/digitalbitbox/bitbox-base/tools/bbbsupervisor/watcher" "github.com/digitalbitbox/bitbox-base/tools/bbbsupervisor/watcher/trigger" ) @@ -89,6 +90,16 @@ func (ew EventWriter) parseEvent(line string, unit string) *watcher.Event { // bbbmiddleware unable to connect bitcoind case strings.Contains(line, "GetBlockChainInfo rpc call failed"): return &watcher.Event{Unit: unit, Trigger: trigger.MiddlewareNoBitcoindConnectivity} + case strings.Contains(line, logtags.LogTagMWUpdateStart): + return &watcher.Event{Unit: unit, Trigger: trigger.MiddlewareBaseImageUpdateStart} + case strings.Contains(line, logtags.LogTagMWUpdateSuccess): + return &watcher.Event{Unit: unit, Trigger: trigger.MiddlewareBaseImageUpdateSuccess} + case strings.Contains(line, logtags.LogTagMWUpdateFailure): + return &watcher.Event{Unit: unit, Trigger: trigger.MiddlewareBaseImageUpdateFailure} + case strings.Contains(line, logtags.LogTagMWReboot): + return &watcher.Event{Unit: unit, Trigger: trigger.MiddlewareRPCReboot} + case strings.Contains(line, logtags.LogTagMWShutdown): + return &watcher.Event{Unit: unit, Trigger: trigger.MiddlewareRPCShutdown} } return nil } diff --git a/tools/bbbsupervisor/watcher/trigger/trigger.go b/tools/bbbsupervisor/watcher/trigger/trigger.go index 42b92d33..ae530273 100644 --- a/tools/bbbsupervisor/watcher/trigger/trigger.go +++ b/tools/bbbsupervisor/watcher/trigger/trigger.go @@ -5,7 +5,7 @@ import ( "time" ) -// Trigger is dispached by a watcher when something happens +// Trigger is dispatched by a watcher when something happens type Trigger int // String returns a human readable value for a trigger @@ -21,6 +21,11 @@ const ( ElectrsNoBitcoindConnectivity MiddlewareNoBitcoindConnectivity PrometheusBitcoindIBD + MiddlewareBaseImageUpdateStart + MiddlewareBaseImageUpdateSuccess + MiddlewareBaseImageUpdateFailure + MiddlewareRPCReboot + MiddlewareRPCShutdown ) // Map of possible triggers. Mapped by their trigger to a trigger name @@ -29,6 +34,11 @@ var triggerNames = map[Trigger]string{ ElectrsNoBitcoindConnectivity: "electrsNoBitcoindConnectivity", MiddlewareNoBitcoindConnectivity: "triggerMiddlewareNoBitcoindConnectivity", PrometheusBitcoindIBD: "prometheusBitcoindIBD", + MiddlewareBaseImageUpdateStart: "middlewareBaseImageUpdateStart", + MiddlewareBaseImageUpdateSuccess: "middlewareBaseImageUpdateSuccess", + MiddlewareBaseImageUpdateFailure: "MiddlewareBaseImageUpdateFailure", + MiddlewareRPCReboot: "middlewareRPCReboot", + MiddlewareRPCShutdown: "middlewareRPCShutdown", } // IsFlooding checks if a trigger is flooding From 71031f3fa9508594f6b70a21baabfef29e901b60 Mon Sep 17 00:00:00 2001 From: 0xb10c <0xb10c@gmail.com> Date: Tue, 3 Dec 2019 22:04:46 +0100 Subject: [PATCH 3/5] add: handling of state for bitcoin ibd This adds the handling of the `INITIAL_BLOCK_SYNC` (Bitcoin Core IDB) state to the Supervisor. The Supervisor activates the subsystem state when Bitcoin Core switches to IBD and deactivates the state once Bitcoin Core finishes IBD. --- .../bbbsupervisor/supervisor/eventhandling.go | 42 ++++++++++++++++--- 1 file changed, 37 insertions(+), 5 deletions(-) diff --git a/tools/bbbsupervisor/supervisor/eventhandling.go b/tools/bbbsupervisor/supervisor/eventhandling.go index 17c0aff1..20082a6a 100644 --- a/tools/bbbsupervisor/supervisor/eventhandling.go +++ b/tools/bbbsupervisor/supervisor/eventhandling.go @@ -268,12 +268,28 @@ func (s *Supervisor) handleBitcoindIBD(event watcher.Event) error { if isActive == 1 { err := s.setBBBConfigValue("bitcoin_ibd", "true") if err != nil { - return fmt.Errorf("Handling trigger %s: Initial set. Setting BBB config value to `true` failed: %v", t.String(), err) + return fmt.Errorf("Handling trigger %q: Initial set. Setting BBB config value to `true` failed: %s", t.String(), err) + } + err = s.activateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC) + if err != nil { + return fmt.Errorf("Handling trigger %q: Initial set. Could not activate subsystem state %q: %s", t.String(), messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC.String(), err) + } + err = s.notifyMiddlewareSubsystemStateChanged() + if err != nil { + return fmt.Errorf("Handling trigger %q: Initial set. Could not notify middleware about activated subsystem state %q: %s", t.String(), messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC.String(), err) } } else { err := s.disableBaseIBDState() if err != nil { - return fmt.Errorf("Handling trigger %s: Initial state set. %s", t.String(), err.Error()) + return fmt.Errorf("Handling trigger %q: Initial state set. %s", t.String(), err.Error()) + } + err = s.deactivateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC) + if err != nil { + return fmt.Errorf("Handling trigger %q: Initial set. Could not deactivate subsystem state %q: %s", t.String(), messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC.String(), err) + } + err = s.notifyMiddlewareSubsystemStateChanged() + if err != nil { + return fmt.Errorf("Handling trigger %q: Initial set. Could not notify middleware about deactivated subsystem state %q: %s", t.String(), messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC.String(), err) } } s.state.PrometheusLastStateIBD = isActive // set the initial value for the state @@ -281,17 +297,33 @@ func (s *Supervisor) handleBitcoindIBD(event watcher.Event) error { } if wasActive == 1 && isActive == 0 { // IBD finished - log.Println("Setting bitcoin_ibd since the IBD finished.") + log.Println("IBD finished: unsetting bitcoind_idb.") err := s.disableBaseIBDState() if err != nil { - return fmt.Errorf("Handling trigger %s: %s", t.String(), err.Error()) + return fmt.Errorf("Handling trigger %q: %s", t.String(), err.Error()) + } + err = s.deactivateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC) + if err != nil { + return fmt.Errorf("Handling trigger %q: Could not deactivate subsystem state %q: %s", t.String(), messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC.String(), err) + } + err = s.notifyMiddlewareSubsystemStateChanged() + if err != nil { + return fmt.Errorf("Handling trigger %q: Could not notify middleware about deactivated subsystem state %q: %s", t.String(), messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC.String(), err) } s.state.PrometheusLastStateIBD = isActive } else if wasActive == 0 && isActive == 1 { // IBD (re)started log.Println("Setting bitcoin_ibd since the IBD (re)started.") err := s.setBBBConfigValue("bitcoin_ibd", "true") if err != nil { - return fmt.Errorf("Handling trigger %s: setting BBB config value to `true` failed: %v", t.String(), err) + return fmt.Errorf("Handling trigger %q: setting BBB config value to `true` failed: %s", t.String(), err) + } + err = s.activateBaseSubsystemState(messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC) + if err != nil { + return fmt.Errorf("Handling trigger %q: Could not activate subsystem state %q: %s", t.String(), messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC.String(), err) + } + err = s.notifyMiddlewareSubsystemStateChanged() + if err != nil { + return fmt.Errorf("Handling trigger %q: Could not notify middleware about activated subsystem state %q: %s", t.String(), messages.BitBoxBaseHeartbeatRequest_INITIAL_BLOCK_SYNC.String(), err) } s.state.PrometheusLastStateIBD = isActive } From 4052a06494391ecc39a817ceb2055592a92a095e Mon Sep 17 00:00:00 2001 From: 0xb10c <0xb10c@gmail.com> Date: Tue, 3 Dec 2019 22:38:26 +0100 Subject: [PATCH 4/5] add: send description&stateCode from Redis to HSM --- middleware/src/middleware.go | 37 ++++++++++++++++++++++++++++++++---- 1 file changed, 33 insertions(+), 4 deletions(-) diff --git a/middleware/src/middleware.go b/middleware/src/middleware.go index 6ce98187..56f70812 100644 --- a/middleware/src/middleware.go +++ b/middleware/src/middleware.go @@ -8,6 +8,7 @@ import ( "log" "os/exec" "regexp" + "strconv" "strings" "time" @@ -178,13 +179,11 @@ func (middleware *Middleware) updateCheckLoop() { } } -// hsmHeartbeatLoop func (middleware *Middleware) hsmHeartbeatLoop() { for { - // TODO(@0xB10C) fetch the `stateCode` and `descriptionCode` from redis keys set byt the supervisor - err := middleware.hsmFirmware.BitBoxBaseHeartbeat(messages.BitBoxBaseHeartbeatRequest_IDLE, messages.BitBoxBaseHeartbeatRequest_EMPTY) + err := middleware.hsmHeartbeat() if err != nil { - log.Printf("Received an error from the HSM: %s\n", err) + log.Printf("Warning while sending a HSM heartbeat: %s\n", err) time.Sleep(time.Second) continue } @@ -193,6 +192,36 @@ func (middleware *Middleware) hsmHeartbeatLoop() { } } +func (middleware *Middleware) hsmHeartbeat() error { + stateCode, err := middleware.redisClient.GetInt(redis.BaseStateCode) + if err != nil { + err = middleware.hsmFirmware.BitBoxBaseHeartbeat(messages.BitBoxBaseHeartbeatRequest_ERROR, messages.BitBoxBaseHeartbeatRequest_REDIS_ERROR) + if err != nil { + return fmt.Errorf("could not get the stateCode from Redis: %s", err) + } + } + + descriptionCodeString, err := middleware.redisClient.GetTopFromSortedSet(redis.BaseDescriptionCode) + if err != nil { + err = middleware.hsmFirmware.BitBoxBaseHeartbeat(messages.BitBoxBaseHeartbeatRequest_ERROR, messages.BitBoxBaseHeartbeatRequest_REDIS_ERROR) + if err != nil { + return fmt.Errorf("could not get the hightest priority descriptionCode from Redis: %s", err) + } + } + + descriptionCode, err := strconv.Atoi(descriptionCodeString) + if err != nil { + return fmt.Errorf("could not convert the descriptionCode from Redis %q to a string: %s", descriptionCodeString, err) + } + + err = middleware.hsmFirmware.BitBoxBaseHeartbeat(messages.BitBoxBaseHeartbeatRequest_StateCode(stateCode), messages.BitBoxBaseHeartbeatRequest_DescriptionCode(descriptionCode)) + if err != nil { + return fmt.Errorf("received an error from the HSM: %w", err) + } + + return nil +} + // Start gives a trigger for the handler to start the rpc event loop func (middleware *Middleware) Start() <-chan handlers.Event { if middleware.hsmFirmware != nil { From 1ba783fa4f988b245135fad3e1507b42a7ed09c0 Mon Sep 17 00:00:00 2001 From: 0xb10c <0xb10c@gmail.com> Date: Wed, 4 Dec 2019 13:19:50 +0100 Subject: [PATCH 5/5] add: send a HSM heartbeat on IPC notification This adds an extra HSM heartbeat that is send when a IPC notification with the topic "systemstate-changed" arrives over the named pipe. --- middleware/src/middleware.go | 18 +++++++++++++----- 1 file changed, 13 insertions(+), 5 deletions(-) diff --git a/middleware/src/middleware.go b/middleware/src/middleware.go index 56f70812..33b1bc65 100644 --- a/middleware/src/middleware.go +++ b/middleware/src/middleware.go @@ -264,13 +264,11 @@ func (middleware *Middleware) ipcNotificationLoop(reader *ipcnotification.Reader for { notification := <-notifications - if notification.Version != supportedNotificationVersion { - log.Printf("Dropping IPC notification with unsupported version: %s\n", notification.String()) + log.Printf("Dropping an IPC notification with unsupported version: %s\n", notification.String()) } - log.Printf("Received notification with topic '%s': %v\n", notification.Topic, notification.Payload) - + log.Printf("Received an IPC notification with topic '%s': %v\n", notification.Topic, notification.Payload) switch notification.Topic { case "mender-update": if success, ok := ipcnotification.ParseMenderUpdatePayload(notification.Payload); ok { @@ -293,8 +291,18 @@ func (middleware *Middleware) ipcNotificationLoop(reader *ipcnotification.Reader } else { log.Printf("Could not parse %s notification payload: %v\n", notification.Topic, notification.Payload) } + case "systemstate-changed": + if middleware.hsmFirmware == nil { + log.Println("Received an IPC notification that the system state changed, but there is no HSM recognized. Not sending an extra HSM heartbeat.") + break + } + log.Println("Received an IPC notification that the system state changed. Sending an extra HSM heartbeat.") + err := middleware.hsmHeartbeat() + if err != nil { + log.Printf("Warning: error while sending a extra HSM heartbeat because the systemstate changed: %s\n", err) + } default: - log.Printf("Dropping IPC notification with unknown topic: %s\n", notification.String()) + log.Printf("Dropping an IPC notification with unknown topic: %s\n", notification.String()) } } }