feat: Structured log messages

.github/workflows/lint.yml

@@ -13,11 +13,11 @@ jobs:
         with:
           fetch-depth: 0
       - name: Setup go
-        uses: actions/setup-go@v3
+        uses: actions/setup-go@v5
         with:
-          go-version: 1.18.x
+          go-version: 1.21.x
       - name: Setup node
-        uses: actions/setup-node@v3
+        uses: actions/setup-node@v4
         with:
           node-version: 16
 

.github/workflows/main.yml

@@ -12,15 +12,15 @@ jobs:
       is_new_version: ${{ steps.check_versions.outputs.is_new_version }}
     steps:
       - name: Checkout
-        uses: actions/checkout@v3
+        uses: actions/checkout@v4
         with:
           fetch-depth: 0
       - name: Setup go
-        uses: actions/setup-go@v3
+        uses: actions/setup-go@v5
         with:
           go-version-file: 'interfacer/go.mod'
       - name: Setup node
-        uses: actions/setup-node@v3
+        uses: actions/setup-node@v4
         with:
           node-version-file: '.nvmrc'
       - name: Install Firefox

interfacer/go.mod

@@ -5,38 +5,41 @@ go 1.21
 require (
 	github.com/NYTimes/gziphandler v1.1.1
 	github.com/gdamore/tcell v1.4.0
-	github.com/go-errors/errors v1.4.2
-	github.com/gorilla/websocket v1.5.0
+	github.com/go-errors/errors v1.5.1
+	github.com/gorilla/websocket v1.5.1
 	github.com/onsi/ginkgo v1.16.5
-	github.com/onsi/gomega v1.19.0
+	github.com/onsi/gomega v1.30.0
 	github.com/shibukawa/configdir v0.0.0-20170330084843-e180dbdc8da0
 	github.com/spf13/pflag v1.0.5
-	github.com/spf13/viper v1.12.0
+	github.com/spf13/viper v1.18.1
 	github.com/ulule/limiter v2.2.2+incompatible
-	golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8
+	golang.org/x/sys v0.15.0
 )
 
 require (
-	github.com/fsnotify/fsnotify v1.5.4 // indirect
+	github.com/fsnotify/fsnotify v1.7.0 // indirect
 	github.com/gdamore/encoding v1.0.0 // indirect
+	github.com/google/go-cmp v0.6.0 // indirect
 	github.com/hashicorp/hcl v1.0.0 // indirect
 	github.com/lucasb-eyer/go-colorful v1.2.0 // indirect
-	github.com/magiconair/properties v1.8.6 // indirect
-	github.com/mattn/go-runewidth v0.0.13 // indirect
+	github.com/magiconair/properties v1.8.7 // indirect
+	github.com/mattn/go-runewidth v0.0.15 // indirect
 	github.com/mitchellh/mapstructure v1.5.0 // indirect
-	github.com/nxadm/tail v1.4.8 // indirect
-	github.com/pelletier/go-toml v1.9.5 // indirect
-	github.com/pelletier/go-toml/v2 v2.0.2 // indirect
+	github.com/nxadm/tail v1.4.11 // indirect
+	github.com/pelletier/go-toml/v2 v2.1.0 // indirect
 	github.com/pkg/errors v0.9.1 // indirect
-	github.com/rivo/uniseg v0.2.0 // indirect
-	github.com/spf13/afero v1.9.0 // indirect
-	github.com/spf13/cast v1.5.0 // indirect
-	github.com/spf13/jwalterweatherman v1.1.0 // indirect
-	github.com/subosito/gotenv v1.4.0 // indirect
-	golang.org/x/net v0.0.0-20220708220712-1185a9018129 // indirect
-	golang.org/x/text v0.3.7 // indirect
-	gopkg.in/ini.v1 v1.66.6 // indirect
+	github.com/rivo/uniseg v0.4.4 // indirect
+	github.com/sagikazarmark/locafero v0.4.0 // indirect
+	github.com/sagikazarmark/slog-shim v0.1.0 // indirect
+	github.com/sourcegraph/conc v0.3.0 // indirect
+	github.com/spf13/afero v1.11.0 // indirect
+	github.com/spf13/cast v1.6.0 // indirect
+	github.com/subosito/gotenv v1.6.0 // indirect
+	go.uber.org/multierr v1.11.0 // indirect
+	golang.org/x/exp v0.0.0-20231206192017-f3f8817b8deb // indirect
+	golang.org/x/net v0.19.0 // indirect
+	golang.org/x/text v0.14.0 // indirect
+	gopkg.in/ini.v1 v1.67.0 // indirect
 	gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7 // indirect
-	gopkg.in/yaml.v2 v2.4.0 // indirect
 	gopkg.in/yaml.v3 v3.0.1 // indirect
 )

interfacer/src/browsh/browsh.go

@@ -69,20 +69,19 @@ func Initialise() {
 
 // Shutdown tries its best to cleanly shutdown browsh and the associated browser
 func Shutdown(err error) {
-	if *isDebug {
-		if e, ok := err.(*errors.Error); ok {
-			slog.Error(e.ErrorStack())
-		} else {
-			slog.Error(err.Error())
-		}
+	msg := "shutting down"
+	var e *errors.Error
+	if errors.As(err, &e) {
+		slog.Error(msg, "errorStack", e.ErrorStack())
+	} else {
+		slog.Error(msg, "error", err)
 	}
-	exitCode := 0
 	if screen != nil {
 		screen.Fini()
 	}
-	if err.Error() != "normal" {
+	exitCode := 0
+	if !errors.Is(err, errNormalExit) {
 		exitCode = 1
-		println(err.Error())
 	}
 	os.Exit(exitCode)
 }
@@ -99,6 +98,7 @@ func saveScreenshot(base64String string) {
 	if err != nil {
 		Shutdown(err)
 	}
+	defer file.Close()
 	if _, err := file.Write(dec); err != nil {
 		Shutdown(err)
 	}
@@ -111,7 +111,6 @@ func saveScreenshot(base64String string) {
 	}
 	message := "Screenshot saved to " + fullPath
 	sendMessageToWebExtension("/status," + message)
-	file.Close()
 }
 
 // Shell provides nice and easy shell commands
@@ -121,9 +120,13 @@ func Shell(command string) string {
 	parts = parts[1:]
 	out, err := exec.Command(head, parts...).CombinedOutput()
 	if err != nil {
-		errorMessge := fmt.Sprintf(
-			"Browsh tried to run `%s` but failed with: %s", command, string(out))
-		Shutdown(errors.New(errorMessge))
+		err := fmt.Errorf(
+			"Browsh tried to run `%s` but failed with: %s, err: %w",
+			command,
+			string(out),
+			err,
+		)
+		Shutdown(err)
 	}
 	return strings.TrimSpace(string(out))
 }

interfacer/src/browsh/comms.go

@@ -33,13 +33,13 @@ func startWebSocketServer() {
 	port := viper.GetString("browsh.websocket-port")
 	slog.Info("Starting websocket server...")
 	if netErr := http.ListenAndServe(":"+port, serverMux); netErr != nil {
-		Shutdown(errors.New(fmt.Errorf("Error starting websocket server: %v", netErr)))
+		Shutdown(fmt.Errorf("Error starting websocket server: %w", netErr))
 	}
 }
 
 func sendMessageToWebExtension(message string) {
 	if !IsConnectedToWebExtension {
-		slog.Info("Webextension not connected. Message not sent: " + message)
+		slog.Info("Webextension not connected. Message not sent", "message", message)
 		return
 	}
 	stdinChannel <- message
@@ -59,7 +59,7 @@ func webSocketReader(ws *websocket.Conn) {
 				return
 			}
 			if websocket.IsUnexpectedCloseError(err, websocket.CloseGoingAway) {
-				slog.Info("Socket reader detected that the connection unexpectedly dissapeared")
+				slog.Error("Socket reader detected that the connection unexpectedly dissapeared")
 				triggerSocketWriterClose()
 				return
 			}
@@ -90,7 +90,7 @@ func handleWebextensionCommand(message []byte) {
 	case "/screenshot":
 		saveScreenshot(parts[1])
 	default:
-		slog.Info("WEBEXT: " + string(message))
+		slog.Info("WEBEXT", "message", string(message))
 	}
 }
 
@@ -103,13 +103,13 @@ func handleRawFrameTextCommands(parts []string) {
 			Shutdown(err)
 		}
 		if incoming.RequestID != "" {
-			slog.Info("Raw text for " + incoming.RequestID)
+			slog.Info("Raw text for", "RequestID", incoming.RequestID)
 			rawTextRequests.store(incoming.RequestID, incoming.RawJSON)
 		} else {
 			slog.Info("Raw text but no associated request ID")
 		}
 	} else {
-		slog.Info("WEBEXT: " + strings.Join(parts[0:], ","))
+		slog.Info("WEBEXT", "command", strings.Join(parts[0:], ","))
 	}
 }
 
@@ -130,12 +130,12 @@ func webSocketWriter(ws *websocket.Conn) {
 	defer ws.Close()
 	for {
 		message = <-stdinChannel
-		slog.Info(fmt.Sprintf("TTY sending: %s", message))
+		slog.Info("TTY sending", "message", message)
 		if err := ws.WriteMessage(websocket.TextMessage, []byte(message)); err != nil {
-			if err == websocket.ErrCloseSent {
+			if errors.Is(err, websocket.ErrCloseSent) {
 				slog.Info("Socket writer detected that the browser closed the websocket")
 			} else {
-				slog.Info("Socket writer detected unexpected closure of websocket")
+				slog.Error("Socket writer detected unexpected closure of websocket", "error", err)
 			}
 			return
 		}

interfacer/src/browsh/firefox.go

@@ -5,7 +5,7 @@ import (
 	"embed"
 	"encoding/json"
 	"fmt"
-	"io/ioutil"
+	"io/fs"
 	"log/slog"
 	"net"
 	"os"
@@ -70,11 +70,11 @@ func startHeadlessFirefox() {
 	}
 	profile := viper.GetString("firefox.profile")
 	if profile != "browsh-default" {
-		slog.Info("Using profile: " + profile)
+		slog.Info("Using Firefox profile", "profile", profile)
 		args = append(args, "-P", profile)
 	} else {
 		profilePath := getFirefoxProfilePath()
-		slog.Info("Using default profile at: " + profilePath)
+		slog.Info("Using default profile", "path", profilePath)
 		args = append(args, "--profile", profilePath)
 	}
 	firefoxProcess := exec.Command(firefoxPath, args...)
@@ -88,7 +88,7 @@ func startHeadlessFirefox() {
 	}
 	in := bufio.NewScanner(stdout)
 	for in.Scan() {
-		slog.Info("FF-CONSOLE: " + in.Text())
+		slog.Info("FF-CONSOLE", "stdout", in.Text())
 	}
 }
 
@@ -115,10 +115,13 @@ func ensureFirefoxBinary() string {
 			path = getFirefoxPath()
 		}
 	}
-	slog.Info("Using Firefox at: " + path)
-	if _, err := os.Stat(path); os.IsNotExist(err) {
-		Shutdown(errors.New("Firefox binary not found: " + path))
+	if _, err := os.Stat(path); err != nil {
+		if errors.Is(err, fs.ErrNotExist) {
+			err = errors.New("Firefox binary not found: " + path)
+		}
+		Shutdown(err)
 	}
+	slog.Info("Using Firefox", "path", path)
 	return path
 }
 
@@ -186,7 +189,7 @@ func startWERFirefox() {
 			strings.Contains(in.Text(), "dbus") {
 			continue
 		}
-		slog.Info("FF-CONSOLE: " + in.Text())
+		slog.Info("FF-CONSOLE", "stdout", in.Text())
 	}
 	slog.Info("WER Firefox unexpectedly closed")
 }
@@ -237,7 +240,9 @@ func installWebextension() {
 		Shutdown(err)
 	}
 	path := path.Join(os.TempDir(), "browsh-webext-addon")
-	ioutil.WriteFile(path, []byte(data), 0644)
+	if err := os.WriteFile(path, []byte(data), 0644); err != nil {
+		Shutdown(err)
+	}
 	args := map[string]interface{}{"path": path}
 	sendFirefoxCommand("Addon:Install", args)
 }
@@ -263,14 +268,14 @@ func readMarionette() {
 	buffer := make([]byte, 4096)
 	count, err := marionette.Read(buffer)
 	if err != nil {
-		slog.Info("Error reading from Marionette connection")
+		slog.Error("Error reading from Marionette connection", "error", err)
 		return
 	}
-	slog.Info("FF-MRNT: " + string(buffer[:count]))
+	slog.Info("FF-MRNT", "buffer", string(buffer[:count]))
 }
 
 func sendFirefoxCommand(command string, args map[string]interface{}) {
-	slog.Info("Sending `" + command + "` to Firefox Marionette")
+	slog.Info("Sending command to Firefox Marionette", "command", command, "args", args)
 	fullCommand := []interface{}{0, ffCommandCount, command, args}
 	marshalled, _ := json.Marshal(fullCommand)
 	message := fmt.Sprintf("%d:%s", len(marshalled), marshalled)

interfacer/src/browsh/firefox_windows.go

@@ -20,11 +20,11 @@ func getFirefoxPath() string {
 		`Software\Mozilla\`+flavor+` `+versionString+`\bin`,
 		registry.QUERY_VALUE)
 	if err != nil {
-		Shutdown(errors.New("Error reading Windows registry: " + fmt.Sprintf("%s", err)))
+		Shutdown(fmt.Errorf("Error reading Windows registry: %w", err))
 	}
 	path, _, err := k.GetStringValue("PathToExe")
 	if err != nil {
-		Shutdown(errors.New("Error reading Windows registry: " + fmt.Sprintf("%s", err)))
+		Shutdown(fmt.Errorf("Error reading Windows registry: %w", err))
 	}
 
 	return path
@@ -38,16 +38,16 @@ func getWindowsFirefoxVersionString() string {
 		`Software\Mozilla\`+flavor,
 		registry.QUERY_VALUE)
 	if err != nil {
-		Shutdown(errors.New("Error reading Windows registry: " + fmt.Sprintf("%s", err)))
+		Shutdown(fmt.Errorf("Error reading Windows registry: %w", err))
 	}
 	defer k.Close()
 
 	versionString, _, err := k.GetStringValue("")
 	if err != nil {
-		Shutdown(errors.New("Error reading Windows registry: " + fmt.Sprintf("%s", err)))
+		Shutdown(fmt.Errorf("Error reading Windows registry: %w", err))
 	}
 
-	slog.Info("Windows registry Firefox version: " + versionString)
+	slog.Info("Windows registry Firefox", "version", versionString)
 
 	return versionString
 }

interfacer/src/browsh/frame_builder.go

@@ -103,9 +103,7 @@ func parseJSONFramePixels(jsonString string) {
 		Shutdown(err)
 	}
 	if !isTabPresent(incoming.Meta.TabID) {
-		slog.Info(
-			fmt.Sprintf("Not building frame for non-existent tab ID: %d", incoming.Meta.TabID),
-		)
+		slog.Warn("Not building frame for non-existent tab ID", "TabID", incoming.Meta.TabID)
 		return
 	}
 	if len(Tabs[incoming.Meta.TabID].frame.text) == 0 {
@@ -144,7 +142,7 @@ func (f *frame) resetCells() {
 
 func (f *frame) isIncomingFrameTextValid(incoming incomingFrameText) bool {
 	if len(incoming.Text) == 0 {
-		slog.Info("Not parsing zero-size text frame")
+		slog.Warn("Not parsing zero-size text frame")
 		return false
 	}
 	return true
@@ -229,7 +227,7 @@ func (f *frame) populateFramePixels(incoming incomingFramePixels) {
 
 func (f *frame) isIncomingFramePixelsValid(incoming incomingFramePixels) bool {
 	if len(incoming.Colours) == 0 {
-		slog.Info("Not parsing zero-size text frame")
+		slog.Warn("Not parsing zero-size text frame")
 		return false
 	}
 	return true

interfacer/src/browsh/raw_text_server.go

@@ -148,7 +148,7 @@ func handleHTTPServerRequest(w http.ResponseWriter, r *http.Request) {
 			return
 		}
 	}
-	slog.Info(r.Header.Get("User-Agent"))
+	slog.Info("Handling request", "User-Agent", r.Header.Get("User-Agent"))
 	if isKubeReadinessProbe(r.Header.Get("User-Agent")) {
 		io.WriteString(w, "healthy")
 		return