Add state and description codes: Part 2

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=

middleware/src/middleware.go

@@ -8,13 +8,15 @@ import (
 	"log"
 	"os/exec"
 	"regexp"
+	"strconv"
 	"strings"
 	"time"
 
 	"github.com/digitalbitbox/bitbox-base/middleware/src/authentication"
 	"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"
@@ -177,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
 		}
@@ -192,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 {
@@ -234,23 +264,25 @@ 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 {
 				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,
@@ -259,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())
 		}
 	}
 }
@@ -713,6 +755,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 +791,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()

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"
 )

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),

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
 )

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=