Move to logging contexts

Also restructured config_tx so it doesn't need copies of config data.
Fuller debug logging in hidrpc and make all reportHidRPC sends async.
Pass up errors from handleHidRPCMessage.
listenKeyboardEvents handles closed keyboard file and terminates loop.
Excess write failures cause close/open cycle

Author: IDisposable

block_device.go

@@ -7,6 +7,7 @@ import (
 	"os"
 	"time"
 
+	"github.com/jetkvm/kvm/internal/logging"
 	"github.com/pojntfx/go-nbd/pkg/server"
 	"github.com/rs/zerolog"
 )
@@ -16,6 +17,8 @@ type remoteImageBackend struct {
 
 func (r remoteImageBackend) ReadAt(p []byte, off int64) (n int, err error) {
 	virtualMediaStateMutex.RLock()
+
+	logger := logging.GetSubsystemLogger("nbd")
 	logger.Debug().Interface("currentVirtualMediaState", currentVirtualMediaState).Msg("currentVirtualMediaState")
 	logger.Debug().Int64("read size", int64(len(p))).Int64("off", off).Msg("read size and off")
 	if currentVirtualMediaState == nil {
@@ -81,7 +84,8 @@ func (d *NBDDevice) Start() error {
 	}
 
 	if d.l == nil {
-		scopedLogger := nbdLogger.With().
+		scopedLogger := logging.GetSubsystemLogger("nbd").
+			With().
 			Str("socket_path", nbdSocketPath).
 			Str("device_path", nbdDevicePath).
 			Logger()

cloud.go

@@ -13,6 +13,7 @@ import (
 
 	"github.com/coder/websocket/wsjson"
 	"github.com/google/uuid"
+	"github.com/jetkvm/kvm/internal/logging"
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/prometheus/client_golang/prometheus/promauto"
 
@@ -284,6 +285,7 @@ func disconnectCloud(reason error) {
 	cloudDisconnectLock.Lock()
 	defer cloudDisconnectLock.Unlock()
 
+	cloudLogger := logging.GetSubsystemLogger("cloud")
 	if cloudDisconnectChan == nil {
 		cloudLogger.Trace().Msg("cloud disconnect channel is not set, no need to disconnect")
 		return
@@ -323,7 +325,7 @@ func runWebsocketClient() error {
 	header.Set("Authorization", "Bearer "+config.CloudToken)
 	dialCtx, cancelDial := context.WithTimeout(context.Background(), CloudWebSocketConnectTimeout)
 
-	l := websocketLogger.With().
+	l := logging.GetSubsystemLogger("websocket").With().
 		Str("source", wsURL.Host).
 		Str("sourceType", "cloud").
 		Logger()
@@ -366,6 +368,8 @@ func runWebsocketClient() error {
 		Logger()
 	scopedLogger = &lWithConnectionId
 
+	cloudLogger := logging.GetSubsystemLogger("cloud")
+
 	// if the context is canceled, we don't want to return an error
 	if err != nil {
 		if errors.Is(err, context.Canceled) {
@@ -397,7 +401,7 @@ func authenticateSession(ctx context.Context, c *websocket.Conn, req WebRTCSessi
 		_ = wsjson.Write(context.Background(), c, gin.H{
 			"error": fmt.Sprintf("failed to initialize OIDC provider: %v", err),
 		})
-		cloudLogger.Warn().Err(err).Msg("failed to initialize OIDC provider")
+		logging.GetSubsystemLogger("cloud").Warn().Err(err).Msg("failed to initialize OIDC provider")
 		return err
 	}
 
@@ -474,11 +478,10 @@ func handleSessionRequest(
 		}()
 	}
 
-	cloudLogger.Info().Interface("session", session).Msg("new session accepted")
-	cloudLogger.Trace().Interface("session", session).Msg("new session accepted")
+	logging.GetSubsystemLogger("cloud").Info().Interface("session", session).Msg("new session accepted")
 
 	// Cancel any ongoing keyboard macro when session changes
-	cancelKeyboardMacro()
+	_ = cancelKeyboardMacro()
 
 	currentSession = session
 	_ = wsjson.Write(context.Background(), c, gin.H{"type": "answer", "data": sd})
@@ -495,21 +498,21 @@ func RunWebsocketClient() {
 
 		// If the network is not up, well, we can't connect to the cloud.
 		if !networkManager.IsOnline() {
-			cloudLogger.Warn().Msg("waiting for network to be online, will retry in 3 seconds")
+			logging.GetSubsystemLogger("cloud").Warn().Msg("waiting for network to be online, will retry in 3 seconds")
 			time.Sleep(3 * time.Second)
 			continue
 		}
 
 		// If the system time is not synchronized, the API request will fail anyway because the TLS handshake will fail.
 		if isTimeSyncNeeded() && !timeSync.IsSyncSuccess() {
-			cloudLogger.Warn().Msg("system time is not synced, will retry in 3 seconds")
+			logging.GetSubsystemLogger("cloud").Warn().Msg("system time is not synced, will retry in 3 seconds")
 			time.Sleep(3 * time.Second)
 			continue
 		}
 
 		err := runWebsocketClient()
 		if err != nil {
-			cloudLogger.Warn().Err(err).Msg("websocket client error")
+			logging.GetSubsystemLogger("cloud").Warn().Err(err).Msg("websocket client error")
 			metricCloudConnectionStatus.Set(0)
 			metricCloudConnectionFailureCount.Inc()
 			time.Sleep(5 * time.Second)
@@ -561,7 +564,7 @@ func rpcDeregisterDevice() error {
 			return fmt.Errorf("failed to save configuration after deregistering: %w", err)
 		}
 
-		cloudLogger.Info().Msg("device deregistered, disconnecting from cloud")
+		logging.GetSubsystemLogger("cloud").Info().Msg("device deregistered, disconnecting from cloud")
 		disconnectCloud(fmt.Errorf("device deregistered"))
 
 		setCloudConnectionState(CloudConnectionStateNotConfigured)

config.go

@@ -128,7 +128,7 @@ func (c *Config) GetUpdateAPIURL() string {
 func (c *Config) GetDisplayRotation() uint16 {
 	rotationInt, err := strconv.ParseUint(c.DisplayRotation, 10, 16)
 	if err != nil {
-		logger.Warn().Err(err).Msg("invalid display rotation, using default")
+		logging.GetSubsystemLogger("config").Warn().Err(err).Msg("invalid display rotation, using default")
 		return 270
 	}
 	return uint16(rotationInt)
@@ -138,7 +138,7 @@ func (c *Config) GetDisplayRotation() uint16 {
 func (c *Config) SetDisplayRotation(rotation string) error {
 	_, err := strconv.ParseUint(rotation, 10, 16)
 	if err != nil {
-		logger.Warn().Err(err).Msg("invalid display rotation, using default")
+		logging.GetSubsystemLogger("config").Warn().Err(err).Msg("invalid display rotation, using default")
 		return err
 	}
 	c.DisplayRotation = rotation
@@ -224,6 +224,8 @@ func LoadConfig() {
 	configLock.Lock()
 	defer configLock.Unlock()
 
+	logger := logging.GetSubsystemLogger("config")
+
 	if config != nil {
 		logger.Debug().Msg("config already loaded, skipping")
 		return
@@ -272,10 +274,9 @@ func LoadConfig() {
 		loadedConfig.KeyboardLayout = "en-US"
 	}
 
+	logging.UpdateConfigLogLevel(loadedConfig.DefaultLogLevel)
 	config = &loadedConfig
 
-	logging.UpdateConfigLogLevel(config.DefaultLogLevel)
-
 	configSuccess.Set(1.0)
 	configSuccessTime.SetToCurrentTime()
 
@@ -294,6 +295,7 @@ func saveConfig(path string) error {
 	configLock.Lock()
 	defer configLock.Unlock()
 
+	logger := logging.GetSubsystemLogger("config")
 	logger.Trace().Str("path", path).Msg("Saving config")
 
 	// fixup old keyboard layout value

display.go

@@ -10,6 +10,7 @@ import (
 	"sync"
 	"time"
 
+	"github.com/jetkvm/kvm/internal/logging"
 	"github.com/prometheus/common/version"
 )
 
@@ -75,7 +76,7 @@ func updateDisplay() {
 		nativeInstance.UpdateLabelIfChanged("hdmi_status_label", "Disconnected")
 		_, _ = nativeInstance.UIObjClearState("hdmi_status_label", "LV_STATE_CHECKED")
 	}
-	nativeInstance.UpdateLabelIfChanged("cloud_status_label", fmt.Sprintf("%d active", actionSessions))
+	nativeInstance.UpdateLabelIfChanged("cloud_status_label", fmt.Sprintf("%d active", getActiveSessions()))
 
 	if networkManager != nil && networkManager.IsUp() {
 		nativeInstance.UISetVar("main_screen", "home_screen")
@@ -185,14 +186,14 @@ func requestDisplayUpdate(shouldWakeDisplay bool, reason string) {
 	defer displayUpdateLock.Unlock()
 
 	if !displayInited {
-		displayLogger.Info().Msg("display not inited, skipping updates")
+		logging.GetSubsystemLogger("display").Info().Msg("display not inited, skipping updates")
 		return
 	}
 	go func() {
 		if shouldWakeDisplay {
 			wakeDisplay(false, reason)
 		}
-		displayLogger.Debug().Msg("display updating")
+		logging.GetSubsystemLogger("display").Debug().Msg("display updating")
 		// TODO: only run once regardless how many pending updates
 		updateDisplay()
 	}()
@@ -240,7 +241,7 @@ func updateStaticContents() {
 // configureDisplayOnNativeRestart is called when the native process restarts
 // it ensures the display is configured correctly after the restart
 func configureDisplayOnNativeRestart() {
-	displayLogger.Info().Msg("native restarted, configuring display")
+	logging.GetSubsystemLogger("display").Info().Msg("native restarted, configuring display")
 	updateStaticContents()
 	requestDisplayUpdate(true, "native_restart")
 }
@@ -266,7 +267,7 @@ func setDisplayBrightness(brightness int, reason string) error {
 		return err
 	}
 
-	displayLogger.Info().Int("brightness", brightness).Str("reason", reason).Msg("set brightness")
+	logging.GetSubsystemLogger("display").Info().Int("brightness", brightness).Str("reason", reason).Msg("set brightness")
 	return nil
 }
 
@@ -275,7 +276,7 @@ func setDisplayBrightness(brightness int, reason string) error {
 func tick_displayDim() {
 	err := setDisplayBrightness(config.DisplayMaxBrightness/2, "tick_display_dim")
 	if err != nil {
-		displayLogger.Warn().Err(err).Msg("failed to dim display")
+		logging.GetSubsystemLogger("display").Warn().Err(err).Msg("failed to dim display")
 	}
 
 	dimTicker.Stop()
@@ -288,7 +289,7 @@ func tick_displayDim() {
 func tick_displayOff() {
 	err := setDisplayBrightness(0, "tick_display_off")
 	if err != nil {
-		displayLogger.Warn().Err(err).Msg("failed to turn off display")
+		logging.GetSubsystemLogger("display").Warn().Err(err).Msg("failed to turn off display")
 	}
 
 	offTicker.Stop()
@@ -315,7 +316,7 @@ func wakeDisplay(force bool, reason string) {
 
 	err := setDisplayBrightness(config.DisplayMaxBrightness, reason)
 	if err != nil {
-		displayLogger.Warn().Err(err).Msg("failed to wake display")
+		logging.GetSubsystemLogger("display").Warn().Err(err).Msg("failed to wake display")
 	}
 
 	if config.DisplayDimAfterSec != 0 && dimTicker != nil {
@@ -348,6 +349,8 @@ func startBacklightTickers() {
 		offTicker.Stop()
 	}
 
+	displayLogger := logging.GetSubsystemLogger("display")
+
 	if config.DisplayDimAfterSec != 0 {
 		displayLogger.Info().Msg("dim_ticker has started")
 		dimTicker = time.NewTicker(time.Duration(config.DisplayDimAfterSec) * time.Second)
@@ -373,6 +376,7 @@ func startBacklightTickers() {
 
 func initDisplay() {
 	go func() {
+		displayLogger := logging.GetSubsystemLogger("display")
 		displayLogger.Info().Msg("setting initial display contents")
 		time.Sleep(500 * time.Millisecond)
 		updateStaticContents()

failsafe.go

@@ -1,11 +1,14 @@
 package kvm
 
 import (
+	"errors"
 	"fmt"
+	"io/fs"
 	"os"
 	"strings"
 	"sync"
 
+	"github.com/jetkvm/kvm/internal/logging"
 	"github.com/jetkvm/kvm/internal/supervisor"
 )
 
@@ -53,10 +56,10 @@ func checkFailsafeReason() {
 		}
 
 		// check if the last crash log file exists
-		l := failsafeLogger.With().Str("path", lastCrashPath).Logger()
+		l := logging.GetSubsystemLogger("failsafe").With().Str("path", lastCrashPath).Logger()
 		fi, err := os.Lstat(lastCrashPath)
 		if err != nil {
-			if !os.IsNotExist(err) {
+			if !errors.Is(err, fs.ErrNotExist) {
 				l.Warn().Err(err).Msg("failed to stat last crash log")
 			}
 			return
@@ -98,7 +101,7 @@ func notifyFailsafeMode(session *Session) {
 		return
 	}
 
-	jsonRpcLogger.Info().Str("reason", failsafeModeReason).Msg("sending failsafe mode notification")
+	logging.GetSubsystemLogger("failsafe").Info().Str("reason", failsafeModeReason).Msg("sending failsafe mode notification")
 
 	writeJSONRPCEvent("failsafeMode", FailsafeModeNotification{
 		Active: true,

go.mod

@@ -5,6 +5,7 @@ go 1.24.4
 require (
 	github.com/Masterminds/semver/v3 v3.4.0
 	github.com/beevik/ntp v1.5.0
+	github.com/caarlos0/env/v11 v11.3.1
 	github.com/coder/websocket v1.8.14
 	github.com/coreos/go-oidc/v3 v3.16.0
 	github.com/creack/pty v1.1.24
@@ -36,6 +37,8 @@ require (
 	golang.org/x/crypto v0.43.0
 	golang.org/x/net v0.46.0
 	golang.org/x/sys v0.37.0
+	google.golang.org/grpc v1.76.0
+	google.golang.org/protobuf v1.36.10
 )
 
 replace github.com/pojntfx/go-nbd v0.3.2 => github.com/chemhack/go-nbd v0.0.0-20241006125820-59e45f5b1e7b
@@ -44,7 +47,6 @@ require (
 	github.com/beorn7/perks v1.0.1 // indirect
 	github.com/bytedance/sonic v1.14.0 // indirect
 	github.com/bytedance/sonic/loader v0.3.0 // indirect
-	github.com/caarlos0/env/v11 v11.3.1 // indirect
 	github.com/cespare/xxhash/v2 v2.3.0 // indirect
 	github.com/cloudwego/base64x v0.1.6 // indirect
 	github.com/creack/goselect v0.1.2 // indirect
@@ -88,7 +90,6 @@ require (
 	github.com/prometheus/client_model v0.6.2 // indirect
 	github.com/robfig/cron/v3 v3.0.1 // indirect
 	github.com/rogpeppe/go-internal v1.14.1 // indirect
-	github.com/spf13/pflag v1.0.10 // indirect
 	github.com/twitchyliquid64/golang-asm v0.15.1 // indirect
 	github.com/u-root/uio v0.0.0-20230220225925-ffce2a382923 // indirect
 	github.com/ugorji/go/codec v1.3.0 // indirect
@@ -100,8 +101,5 @@ require (
 	golang.org/x/sync v0.17.0 // indirect
 	golang.org/x/text v0.30.0 // indirect
 	google.golang.org/genproto/googleapis/rpc v0.0.0-20250804133106-a7a43d27e69b // indirect
-	google.golang.org/grpc v1.76.0 // indirect
-	google.golang.org/grpc/cmd/protoc-gen-go-grpc v1.5.1 // indirect
-	google.golang.org/protobuf v1.36.10 // indirect
 	gopkg.in/yaml.v3 v3.0.1 // indirect
 )