Merge remote-tracking branch 'upstream/dev' into keyboard-layouts

block_device.go

@@ -9,6 +9,7 @@ import (
 
 	"github.com/pojntfx/go-nbd/pkg/client"
 	"github.com/pojntfx/go-nbd/pkg/server"
+	"github.com/rs/zerolog"
 )
 
 type remoteImageBackend struct {
@@ -72,6 +73,8 @@ type NBDDevice struct {
 	serverConn net.Conn
 	clientConn net.Conn
 	dev        *os.File
+
+	l *zerolog.Logger
 }
 
 func NewNBDDevice() *NBDDevice {
@@ -90,10 +93,18 @@ func (d *NBDDevice) Start() error {
 		return err
 	}
 
+	if d.l == nil {
+		scopedLogger := nbdLogger.With().
+			Str("socket_path", nbdSocketPath).
+			Str("device_path", nbdDevicePath).
+			Logger()
+		d.l = &scopedLogger
+	}
+
 	// Remove the socket file if it already exists
 	if _, err := os.Stat(nbdSocketPath); err == nil {
 		if err := os.Remove(nbdSocketPath); err != nil {
-			nativeLogger.Warn().Err(err).Str("socket_path", nbdSocketPath).Msg("Failed to remove existing socket file")
+			d.l.Error().Err(err).Msg("failed to remove existing socket file")
 			os.Exit(1)
 		}
 	}
@@ -134,7 +145,8 @@ func (d *NBDDevice) runServerConn() {
 			MaximumBlockSize:   uint32(16 * 1024),
 			SupportsMultiConn:  false,
 		})
-	nativeLogger.Info().Err(err).Msg("nbd server exited")
+
+	d.l.Info().Err(err).Msg("nbd server exited")
 }
 
 func (d *NBDDevice) runClientConn() {
@@ -142,14 +154,14 @@ func (d *NBDDevice) runClientConn() {
 		ExportName: "jetkvm",
 		BlockSize:  uint32(4 * 1024),
 	})
-	nativeLogger.Info().Err(err).Msg("nbd client exited")
+	d.l.Info().Err(err).Msg("nbd client exited")
 }
 
 func (d *NBDDevice) Close() {
 	if d.dev != nil {
 		err := client.Disconnect(d.dev)
 		if err != nil {
-			nativeLogger.Warn().Err(err).Msg("error disconnecting nbd client")
+			d.l.Warn().Err(err).Msg("error disconnecting nbd client")
 		}
 		_ = d.dev.Close()
 	}

cloud.go

@@ -12,6 +12,7 @@ import (
 	"time"
 
 	"github.com/coder/websocket/wsjson"
+	"github.com/google/uuid"
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/prometheus/client_golang/prometheus/promauto"
 
@@ -19,6 +20,7 @@ import (
 
 	"github.com/coder/websocket"
 	"github.com/gin-gonic/gin"
+	"github.com/rs/zerolog"
 )
 
 type CloudRegisterRequest struct {
@@ -289,13 +291,15 @@ func runWebsocketClient() error {
 	header.Set("Authorization", "Bearer "+config.CloudToken)
 	dialCtx, cancelDial := context.WithTimeout(context.Background(), CloudWebSocketConnectTimeout)
 
-	scopedLogger := websocketLogger.With().
+	l := websocketLogger.With().
 		Str("source", wsURL.Host).
 		Str("sourceType", "cloud").
 		Logger()
 
+	scopedLogger := &l
+
 	defer cancelDial()
-	c, _, err := websocket.Dial(dialCtx, wsURL.String(), &websocket.DialOptions{
+	c, resp, err := websocket.Dial(dialCtx, wsURL.String(), &websocket.DialOptions{
 		HTTPHeader: header,
 		OnPingReceived: func(ctx context.Context, payload []byte) bool {
 			scopedLogger.Info().Bytes("payload", payload).Int("length", len(payload)).Msg("ping frame received")
@@ -306,6 +310,24 @@ func runWebsocketClient() error {
 			return true
 		},
 	})
+
+	// get the request id from the response header
+	connectionId := resp.Header.Get("X-Request-ID")
+	if connectionId == "" {
+		connectionId = resp.Header.Get("Cf-Ray")
+	}
+	if connectionId == "" {
+		connectionId = uuid.New().String()
+		scopedLogger.Warn().
+			Str("connectionId", connectionId).
+			Msg("no connection id received from the server, generating a new one")
+	}
+
+	lWithConnectionId := scopedLogger.With().
+		Str("connectionID", connectionId).
+		Logger()
+	scopedLogger = &lWithConnectionId
+
 	// if the context is canceled, we don't want to return an error
 	if err != nil {
 		if errors.Is(err, context.Canceled) {
@@ -315,13 +337,16 @@ func runWebsocketClient() error {
 		return err
 	}
 	defer c.CloseNow() //nolint:errcheck
-	cloudLogger.Info().Str("url", wsURL.String()).Msg("websocket connected")
+	cloudLogger.Info().
+		Str("url", wsURL.String()).
+		Str("connectionID", connectionId).
+		Msg("websocket connected")
 
 	// set the metrics when we successfully connect to the cloud.
 	wsResetMetrics(true, "cloud", wsURL.Host)
 
 	// we don't have a source for the cloud connection
-	return handleWebRTCSignalWsMessages(c, true, wsURL.Host, &scopedLogger)
+	return handleWebRTCSignalWsMessages(c, true, wsURL.Host, connectionId, scopedLogger)
 }
 
 func authenticateSession(ctx context.Context, c *websocket.Conn, req WebRTCSessionRequest) error {
@@ -355,7 +380,14 @@ func authenticateSession(ctx context.Context, c *websocket.Conn, req WebRTCSessi
 	return nil
 }
 
-func handleSessionRequest(ctx context.Context, c *websocket.Conn, req WebRTCSessionRequest, isCloudConnection bool, source string) error {
+func handleSessionRequest(
+	ctx context.Context,
+	c *websocket.Conn,
+	req WebRTCSessionRequest,
+	isCloudConnection bool,
+	source string,
+	scopedLogger *zerolog.Logger,
+) error {
 	var sourceType string
 	if isCloudConnection {
 		sourceType = "cloud"
@@ -381,6 +413,7 @@ func handleSessionRequest(ctx context.Context, c *websocket.Conn, req WebRTCSess
 		IsCloud:    isCloudConnection,
 		LocalIP:    req.IP,
 		ICEServers: req.ICEServers,
+		Logger:     scopedLogger,
 	})
 	if err != nil {
 		_ = wsjson.Write(context.Background(), c, gin.H{"error": err})

config.go

@@ -95,6 +95,7 @@ type Config struct {
 	TLSMode                string             `json:"tls_mode"` // options: "self-signed", "user-defined", ""
 	UsbConfig              *usbgadget.Config  `json:"usb_config"`
 	UsbDevices             *usbgadget.Devices `json:"usb_devices"`
+	DefaultLogLevel        string             `json:"default_log_level"`
 }
 
 const configPath = "/userdata/kvm_config.json"
@@ -124,6 +125,7 @@ var defaultConfig = &Config{
 		Keyboard:      true,
 		MassStorage:   true,
 	},
+	DefaultLogLevel: "INFO",
 }
 
 var (
@@ -167,6 +169,8 @@ func LoadConfig() {
 	}
 
 	config = &loadedConfig
+
+	rootLogger.UpdateLogLevel()
 }
 
 func SaveConfig() error {

display.go

@@ -5,6 +5,7 @@ import (
 	"fmt"
 	"os"
 	"strconv"
+	"sync"
 	"time"
 )
 
@@ -70,9 +71,15 @@ func updateDisplay() {
 	}
 }
 
-var displayInited = false
+var (
+	displayInited     = false
+	displayUpdateLock = sync.Mutex{}
+)
 
 func requestDisplayUpdate() {
+	displayUpdateLock.Lock()
+	defer displayUpdateLock.Unlock()
+
 	if !displayInited {
 		displayLogger.Info().Msg("display not inited, skipping updates")
 		return

hw.go

@@ -54,7 +54,7 @@ func GetDeviceID() string {
 func runWatchdog() {
 	file, err := os.OpenFile("/dev/watchdog", os.O_WRONLY, 0)
 	if err != nil {
-		logger.Warn().Err(err).Msg("unable to open /dev/watchdog, skipping watchdog reset")
+		watchdogLogger.Warn().Err(err).Msg("unable to open /dev/watchdog, skipping watchdog reset")
 		return
 	}
 	defer file.Close()
@@ -65,13 +65,13 @@ func runWatchdog() {
 		case <-ticker.C:
 			_, err = file.Write([]byte{0})
 			if err != nil {
-				logger.Warn().Err(err).Msg("error writing to /dev/watchdog, system may reboot")
+				watchdogLogger.Warn().Err(err).Msg("error writing to /dev/watchdog, system may reboot")
 			}
 		case <-appCtx.Done():
 			//disarm watchdog with magic value
 			_, err := file.Write([]byte("V"))
 			if err != nil {
-				logger.Warn().Err(err).Msg("failed to disarm watchdog, system may reboot")
+				watchdogLogger.Warn().Err(err).Msg("failed to disarm watchdog, system may reboot")
 			}
 			return
 		}

jsonrpc.go

@@ -47,12 +47,12 @@ type BacklightSettings struct {
 func writeJSONRPCResponse(response JSONRPCResponse, session *Session) {
 	responseBytes, err := json.Marshal(response)
 	if err != nil {
-		logger.Warn().Err(err).Msg("Error marshalling JSONRPC response")
+		jsonRpcLogger.Warn().Err(err).Msg("Error marshalling JSONRPC response")
 		return
 	}
 	err = session.RPCChannel.SendText(string(responseBytes))
 	if err != nil {
-		logger.Warn().Err(err).Msg("Error sending JSONRPC response")
+		jsonRpcLogger.Warn().Err(err).Msg("Error sending JSONRPC response")
 		return
 	}
 }
@@ -65,16 +65,24 @@ func writeJSONRPCEvent(event string, params interface{}, session *Session) {
 	}
 	requestBytes, err := json.Marshal(request)
 	if err != nil {
-		logger.Warn().Err(err).Msg("Error marshalling JSONRPC event")
+		jsonRpcLogger.Warn().Err(err).Msg("Error marshalling JSONRPC event")
 		return
 	}
 	if session == nil || session.RPCChannel == nil {
-		logger.Info().Msg("RPC channel not available")
+		jsonRpcLogger.Info().Msg("RPC channel not available")
 		return
 	}
-	err = session.RPCChannel.SendText(string(requestBytes))
+
+	requestString := string(requestBytes)
+	scopedLogger := jsonRpcLogger.With().
+		Str("data", requestString).
+		Logger()
+
+	scopedLogger.Info().Msg("sending JSONRPC event")
+
+	err = session.RPCChannel.SendText(requestString)
 	if err != nil {
-		logger.Warn().Err(err).Msg("Error sending JSONRPC event")
+		scopedLogger.Warn().Err(err).Msg("error sending JSONRPC event")
 		return
 	}
 }
@@ -83,6 +91,11 @@ func onRPCMessage(message webrtc.DataChannelMessage, session *Session) {
 	var request JSONRPCRequest
 	err := json.Unmarshal(message.Data, &request)
 	if err != nil {
+		jsonRpcLogger.Warn().
+			Str("data", string(message.Data)).
+			Err(err).
+			Msg("Error unmarshalling JSONRPC request")
+
 		errorResponse := JSONRPCResponse{
 			JSONRPC: "2.0",
 			Error: map[string]interface{}{
@@ -95,7 +108,13 @@ func onRPCMessage(message webrtc.DataChannelMessage, session *Session) {
 		return
 	}
 
-	logger.Trace().Str("method", request.Method).Interface("params", request.Params).Interface("id", request.ID).Msg("Received RPC request")
+	scopedLogger := jsonRpcLogger.With().
+		Str("method", request.Method).
+		Interface("params", request.Params).
+		Interface("id", request.ID).Logger()
+
+	scopedLogger.Trace().Msg("Received RPC request")
+
 	handler, ok := rpcHandlers[request.Method]
 	if !ok {
 		errorResponse := JSONRPCResponse{
@@ -110,9 +129,10 @@ func onRPCMessage(message webrtc.DataChannelMessage, session *Session) {
 		return
 	}
 
-	logger.Trace().Str("method", request.Method).Interface("id", request.ID).Msg("Calling RPC handler")
+	scopedLogger.Trace().Msg("Calling RPC handler")
 	result, err := callRPCHandler(handler, request.Params)
 	if err != nil {
+		scopedLogger.Error().Err(err).Msg("Error calling RPC handler")
 		errorResponse := JSONRPCResponse{
 			JSONRPC: "2.0",
 			Error: map[string]interface{}{
@@ -126,7 +146,8 @@ func onRPCMessage(message webrtc.DataChannelMessage, session *Session) {
 		return
 	}
 
-	logger.Trace().Interface("result", result).Interface("id", request.ID).Msg("RPC handler returned")
+	scopedLogger.Trace().Interface("result", result).Msg("RPC handler returned")
+
 	response := JSONRPCResponse{
 		JSONRPC: "2.0",
 		Result:  result,

log.go

@@ -12,8 +12,36 @@ import (
 	"github.com/rs/zerolog"
 )
 
+type Logger struct {
+	l               *zerolog.Logger
+	scopeLoggers    map[string]*zerolog.Logger
+	scopeLevels     map[string]zerolog.Level
+	scopeLevelMutex sync.Mutex
+
+	defaultLogLevelFromEnv    zerolog.Level
+	defaultLogLevelFromConfig zerolog.Level
+	defaultLogLevel           zerolog.Level
+}
+
+const (
+	defaultLogLevel = zerolog.ErrorLevel
+)
+
+type logOutput struct {
+	mu *sync.Mutex
+}
+
+func (w *logOutput) Write(p []byte) (n int, err error) {
+	w.mu.Lock()
+	defer w.mu.Unlock()
+
+	// TODO: write to file or syslog
+
+	return len(p), nil
+}
+
 var (
-	defaultLogOutput io.Writer = zerolog.ConsoleWriter{
+	consoleLogOutput io.Writer = zerolog.ConsoleWriter{
 		Out:           os.Stdout,
 		TimeFormat:    time.RFC3339,
 		PartsOrder:    []string{"time", "level", "scope", "component", "message"},
@@ -28,36 +56,10 @@ var (
 			return val
 		},
 	}
-	defaultLogLevel = zerolog.ErrorLevel
+	fileLogOutput    io.Writer = &logOutput{mu: &sync.Mutex{}}
-	rootLogger      = zerolog.New(defaultLogOutput).With().
+	defaultLogOutput           = zerolog.MultiLevelWriter(consoleLogOutput, fileLogOutput)
-			Str("scope", "jetkvm").
-			Timestamp().
-			Stack().
-			Logger()
-)
 
-var (
+	zerologLevels = map[string]zerolog.Level{
-	scopeLevels     map[string]zerolog.Level
-	scopeLevelMutex = sync.Mutex{}
-)
-
-var (
-	logger          = getLogger("jetkvm")
-	cloudLogger     = getLogger("cloud")
-	websocketLogger = getLogger("websocket")
-	nativeLogger    = getLogger("native")
-	ntpLogger       = getLogger("ntp")
-	displayLogger   = getLogger("display")
-	usbLogger       = getLogger("usb")
-	ginLogger       = getLogger("gin")
-	websecureLogger = getLogger("websecure")
-)
-
-func updateLogLevel() {
-	scopeLevelMutex.Lock()
-	defer scopeLevelMutex.Unlock()
-
-	logLevels := map[string]zerolog.Level{
 		"DISABLE": zerolog.Disabled,
 		"NOLEVEL": zerolog.NoLevel,
 		"PANIC":   zerolog.PanicLevel,
@@ -69,9 +71,35 @@ func updateLogLevel() {
 		"TRACE":   zerolog.TraceLevel,
 	}
 
-	scopeLevels = make(map[string]zerolog.Level)
+	rootZerologLogger = zerolog.New(defaultLogOutput).With().
+				Str("scope", "jetkvm").
+				Timestamp().
+				Stack().
+				Logger()
+	rootLogger = NewLogger(rootZerologLogger)
+)
 
-	for name, level := range logLevels {
+func NewLogger(zerologLogger zerolog.Logger) *Logger {
+	return &Logger{
+		l:                         &zerologLogger,
+		scopeLoggers:              make(map[string]*zerolog.Logger),
+		scopeLevels:               make(map[string]zerolog.Level),
+		scopeLevelMutex:           sync.Mutex{},
+		defaultLogLevelFromEnv:    -2,
+		defaultLogLevelFromConfig: -2,
+		defaultLogLevel:           defaultLogLevel,
+	}
+}
+
+func (l *Logger) updateLogLevel() {
+	l.scopeLevelMutex.Lock()
+	defer l.scopeLevelMutex.Unlock()
+
+	l.scopeLevels = make(map[string]zerolog.Level)
+
+	finalDefaultLogLevel := l.defaultLogLevel
+
+	for name, level := range zerologLevels {
 		env := os.Getenv(fmt.Sprintf("JETKVM_LOG_%s", name))
 
 		if env == "" {
@@ -87,8 +115,10 @@ func updateLogLevel() {
 		}
 
 		if strings.ToLower(env) == "all" {
-			if defaultLogLevel > level {
+			l.defaultLogLevelFromEnv = level
-				defaultLogLevel = level
+
+			if finalDefaultLogLevel > level {
+				finalDefaultLogLevel = level
 			}
 
 			continue
@@ -96,26 +126,117 @@ func updateLogLevel() {
 
 		scopes := strings.Split(strings.ToLower(env), ",")
 		for _, scope := range scopes {
-			scopeLevels[scope] = level
+			l.scopeLevels[scope] = level
+		}
+	}
+
+	l.defaultLogLevel = finalDefaultLogLevel
+}
+
+func (l *Logger) getScopeLoggerLevel(scope string) zerolog.Level {
+	if l.scopeLevels == nil {
+		l.updateLogLevel()
+	}
+
+	var scopeLevel zerolog.Level
+	if l.defaultLogLevelFromConfig != -2 {
+		scopeLevel = l.defaultLogLevelFromConfig
+	}
+	if l.defaultLogLevelFromEnv != -2 {
+		scopeLevel = l.defaultLogLevelFromEnv
+	}
+
+	// if the scope is not in the map, use the default level from the root logger
+	if level, ok := l.scopeLevels[scope]; ok {
+		scopeLevel = level
+	}
+
+	return scopeLevel
+}
+
+func (l *Logger) newScopeLogger(scope string) zerolog.Logger {
+	scopeLevel := l.getScopeLoggerLevel(scope)
+	logger := l.l.Level(scopeLevel).With().Str("component", scope).Logger()
+
+	return logger
+}
+
+func (l *Logger) getLogger(scope string) *zerolog.Logger {
+	logger, ok := l.scopeLoggers[scope]
+	if !ok || logger == nil {
+		scopeLogger := l.newScopeLogger(scope)
+		l.scopeLoggers[scope] = &scopeLogger
+	}
+
+	return l.scopeLoggers[scope]
+}
+
+func (l *Logger) UpdateLogLevel() {
+	needUpdate := false
+
+	if config != nil && config.DefaultLogLevel != "" {
+		if logLevel, ok := zerologLevels[config.DefaultLogLevel]; ok {
+			l.defaultLogLevelFromConfig = logLevel
+		} else {
+			l.l.Warn().Str("logLevel", config.DefaultLogLevel).Msg("invalid defaultLogLevel from config, using ERROR")
+		}
+
+		if l.defaultLogLevelFromConfig != l.defaultLogLevel {
+			needUpdate = true
+		}
+	}
+
+	l.updateLogLevel()
+
+	if needUpdate {
+		for scope, logger := range l.scopeLoggers {
+			currentLevel := logger.GetLevel()
+			targetLevel := l.getScopeLoggerLevel(scope)
+			if currentLevel != targetLevel {
+				*logger = l.newScopeLogger(scope)
+			}
 		}
 	}
 }
 
-func getLogger(scope string) zerolog.Logger {
+func ErrorfL(l *zerolog.Logger, format string, err error, args ...interface{}) error {
-	if scopeLevels == nil {
+	if l == nil {
-		updateLogLevel()
+		l = rootLogger.getLogger("jetkvm")
 	}
 
-	l := rootLogger.With().Str("component", scope).Logger()
+	l.Error().Err(err).Msgf(format, args...)
 
-	// if the scope is not in the map, use the default level from the root logger
+	if err == nil {
-	if level, ok := scopeLevels[scope]; ok {
+		return fmt.Errorf(format, args...)
-		return l.Level(level)
 	}
 
-	return l.Level(defaultLogLevel)
+	err_msg := err.Error() + ": %v"
+	err_args := append(args, err)
+
+	return fmt.Errorf(err_msg, err_args...)
 }
 
+var (
+	logger          = rootLogger.getLogger("jetkvm")
+	cloudLogger     = rootLogger.getLogger("cloud")
+	websocketLogger = rootLogger.getLogger("websocket")
+	webrtcLogger    = rootLogger.getLogger("webrtc")
+	nativeLogger    = rootLogger.getLogger("native")
+	nbdLogger       = rootLogger.getLogger("nbd")
+	ntpLogger       = rootLogger.getLogger("ntp")
+	jsonRpcLogger   = rootLogger.getLogger("jsonrpc")
+	watchdogLogger  = rootLogger.getLogger("watchdog")
+	websecureLogger = rootLogger.getLogger("websecure")
+	otaLogger       = rootLogger.getLogger("ota")
+	serialLogger    = rootLogger.getLogger("serial")
+	terminalLogger  = rootLogger.getLogger("terminal")
+	displayLogger   = rootLogger.getLogger("display")
+	wolLogger       = rootLogger.getLogger("wol")
+	usbLogger       = rootLogger.getLogger("usb")
+	// external components
+	ginLogger = rootLogger.getLogger("gin")
+)
+
 type pionLogger struct {
 	logger *zerolog.Logger
 }
@@ -159,7 +280,7 @@ func (c pionLogger) Errorf(format string, args ...interface{}) {
 type pionLoggerFactory struct{}
 
 func (c pionLoggerFactory) NewLogger(subsystem string) logging.LeveledLogger {
-	logger := getLogger(subsystem).With().
+	logger := rootLogger.getLogger(subsystem).With().
 		Str("scope", "pion").
 		Str("component", subsystem).
 		Logger()

main.go

@@ -14,22 +14,26 @@ import (
 var appCtx context.Context
 
 func Main() {
+	LoadConfig()
+	logger.Debug().Msg("config loaded")
+
 	var cancel context.CancelFunc
 	appCtx, cancel = context.WithCancel(context.Background())
 	defer cancel()
-	logger.Info().Msg("Starting JetKvm")
+	logger.Info().Msg("starting JetKvm")
+
 	go runWatchdog()
 	go confirmCurrentSystem()
 
 	http.DefaultClient.Timeout = 1 * time.Minute
-	LoadConfig()
-	logger.Debug().Msg("config loaded")
 
 	err := rootcerts.UpdateDefaultTransport()
 	if err != nil {
 		logger.Warn().Err(err).Msg("failed to load CA certs")
 	}
 
+	initNetwork()
+
 	go TimeSyncLoop()
 
 	StartNativeCtrlSocketServer()

native.go

@@ -3,6 +3,7 @@ package kvm
 import (
 	"bytes"
 	"encoding/json"
+	"errors"
 	"fmt"
 	"io"
 	"net"
@@ -75,25 +76,33 @@ func CallCtrlAction(action string, params map[string]interface{}) (*CtrlResponse
 		return nil, fmt.Errorf("error marshaling ctrl action: %w", err)
 	}
 
-	nativeLogger.Info().Str("action", ctrlAction.Action).Msg("sending ctrl action")
+	scopedLogger := nativeLogger.With().
+		Str("action", ctrlAction.Action).
+		Interface("params", ctrlAction.Params).Logger()
+
+	scopedLogger.Debug().Msg("sending ctrl action")
 
 	err = WriteCtrlMessage(jsonData)
 	if err != nil {
 		delete(ongoingRequests, ctrlAction.Seq)
-		return nil, fmt.Errorf("error writing ctrl message: %w", err)
+		return nil, ErrorfL(&scopedLogger, "error writing ctrl message", err)
 	}
 
 	select {
 	case response := <-responseChan:
 		delete(ongoingRequests, seq)
 		if response.Error != "" {
-			return nil, fmt.Errorf("error native response: %s", response.Error)
+			return nil, ErrorfL(
+				&scopedLogger,
+				"error native response: %s",
+				errors.New(response.Error),
+			)
 		}
 		return response, nil
 	case <-time.After(5 * time.Second):
 		close(responseChan)
 		delete(ongoingRequests, seq)
-		return nil, fmt.Errorf("timeout waiting for response")
+		return nil, ErrorfL(&scopedLogger, "timeout waiting for response", nil)
 	}
 }
 
@@ -115,31 +124,35 @@ func waitCtrlClientConnected() {
 }
 
 func StartNativeSocketServer(socketPath string, handleClient func(net.Conn), isCtrl bool) net.Listener {
+	scopedLogger := nativeLogger.With().
+		Str("socket_path", socketPath).
+		Logger()
+
 	// Remove the socket file if it already exists
 	if _, err := os.Stat(socketPath); err == nil {
 		if err := os.Remove(socketPath); err != nil {
-			nativeLogger.Warn().Err(err).Str("socket_path", socketPath).Msg("Failed to remove existing socket file")
+			scopedLogger.Warn().Err(err).Msg("failed to remove existing socket file")
 			os.Exit(1)
 		}
 	}
 
 	listener, err := net.Listen("unixpacket", socketPath)
 	if err != nil {
-		nativeLogger.Warn().Err(err).Str("socket_path", socketPath).Msg("Failed to start server")
+		scopedLogger.Warn().Err(err).Msg("failed to start server")
 		os.Exit(1)
 	}
 
-	nativeLogger.Info().Str("socket_path", socketPath).Msg("Server listening")
+	scopedLogger.Info().Msg("server listening")
 
 	go func() {
 		conn, err := listener.Accept()
 		listener.Close()
 		if err != nil {
-			nativeLogger.Warn().Err(err).Str("socket_path", socketPath).Msg("failed to accept sock")
+			scopedLogger.Warn().Err(err).Msg("failed to accept socket")
 		}
 		if isCtrl {
 			close(ctrlClientConnected)
-			nativeLogger.Debug().Msg("first native ctrl socket client connected")
+			scopedLogger.Debug().Msg("first native ctrl socket client connected")
 		}
 		handleClient(conn)
 	}()
@@ -160,9 +173,14 @@ func StartNativeVideoSocketServer() {
 func handleCtrlClient(conn net.Conn) {
 	defer conn.Close()
 
-	nativeLogger.Debug().Msg("native socket client connected")
+	scopedLogger := nativeLogger.With().
+		Str("addr", conn.RemoteAddr().String()).
+		Str("type", "ctrl").
+		Logger()
+
+	scopedLogger.Info().Msg("native ctrl socket client connected")
 	if ctrlSocketConn != nil {
-		nativeLogger.Debug().Msg("closing existing native socket connection")
+		scopedLogger.Debug().Msg("closing existing native socket connection")
 		ctrlSocketConn.Close()
 	}
 
@@ -175,7 +193,7 @@ func handleCtrlClient(conn net.Conn) {
 	for {
 		n, err := conn.Read(readBuf)
 		if err != nil {
-			nativeLogger.Warn().Err(err).Msg("error reading from ctrl sock")
+			scopedLogger.Warn().Err(err).Msg("error reading from ctrl sock")
 			break
 		}
 		readMsg := string(readBuf[:n])
@@ -183,10 +201,10 @@ func handleCtrlClient(conn net.Conn) {
 		ctrlResp := CtrlResponse{}
 		err = json.Unmarshal([]byte(readMsg), &ctrlResp)
 		if err != nil {
-			nativeLogger.Warn().Err(err).Str("data", readMsg).Msg("error parsing ctrl sock msg")
+			scopedLogger.Warn().Err(err).Str("data", readMsg).Msg("error parsing ctrl sock msg")
 			continue
 		}
-		nativeLogger.Trace().Interface("data", ctrlResp).Msg("ctrl sock msg")
+		scopedLogger.Trace().Interface("data", ctrlResp).Msg("ctrl sock msg")
 
 		if ctrlResp.Seq != 0 {
 			responseChan, ok := ongoingRequests[ctrlResp.Seq]
@@ -200,20 +218,25 @@ func handleCtrlClient(conn net.Conn) {
 		}
 	}
 
-	nativeLogger.Debug().Msg("ctrl sock disconnected")
+	scopedLogger.Debug().Msg("ctrl sock disconnected")
 }
 
 func handleVideoClient(conn net.Conn) {
 	defer conn.Close()
 
-	nativeLogger.Info().Str("addr", conn.RemoteAddr().String()).Msg("Native video socket client connected")
+	scopedLogger := nativeLogger.With().
+		Str("addr", conn.RemoteAddr().String()).
+		Str("type", "video").
+		Logger()
+
+	scopedLogger.Info().Msg("native video socket client connected")
 
 	inboundPacket := make([]byte, maxFrameSize)
 	lastFrame := time.Now()
 	for {
 		n, err := conn.Read(inboundPacket)
 		if err != nil {
-			nativeLogger.Warn().Err(err).Msg("error during read")
+			scopedLogger.Warn().Err(err).Msg("error during read")
 			return
 		}
 		now := time.Now()
@@ -222,7 +245,7 @@ func handleVideoClient(conn net.Conn) {
 		if currentSession != nil {
 			err := currentSession.VideoTrack.WriteSample(media.Sample{Data: inboundPacket[:n], Duration: sinceLastFrame})
 			if err != nil {
-				nativeLogger.Warn().Err(err).Msg("error writing sample")
+				scopedLogger.Warn().Err(err).Msg("error writing sample")
 			}
 		}
 	}
@@ -277,7 +300,7 @@ func ExtractAndRunNativeBin() error {
 		}
 	}()
 
-	nativeLogger.Info().Int("pid", cmd.Process.Pid).Msg("Binary started")
+	nativeLogger.Info().Int("pid", cmd.Process.Pid).Msg("jetkvm_native binary started")
 
 	return nil
 }

network.go

@@ -105,7 +105,11 @@ func checkNetworkState() {
 	}
 
 	if newState != networkState {
-		logger.Info().Msg("network state changed")
+		logger.Info().
+			Interface("newState", newState).
+			Interface("oldState", networkState).
+			Msg("network state changed")
+
 		// restart MDNS
 		_ = startMDNS()
 		networkState = newState
@@ -116,7 +120,7 @@ func checkNetworkState() {
 func startMDNS() error {
 	// If server was previously running, stop it
 	if mDNSConn != nil {
-		logger.Info().Msg("Stopping mDNS server")
+		logger.Info().Msg("stopping mDNS server")
 		err := mDNSConn.Close()
 		if err != nil {
 			logger.Warn().Err(err).Msg("failed to stop mDNS server")
@@ -124,7 +128,11 @@ func startMDNS() error {
 	}
 
 	// Start a new server
-	logger.Info().Msg("Starting mDNS server on jetkvm.local")
+	hostname := "jetkvm.local"
+
+	scopedLogger := logger.With().Str("hostname", hostname).Logger()
+	scopedLogger.Info().Msg("starting mDNS server")
+
 	addr4, err := net.ResolveUDPAddr("udp4", mdns.DefaultAddressIPv4)
 	if err != nil {
 		return err
@@ -146,10 +154,11 @@ func startMDNS() error {
 	}
 
 	mDNSConn, err = mdns.Server(ipv4.NewPacketConn(l4), ipv6.NewPacketConn(l6), &mdns.Config{
-		LocalNames:    []string{"jetkvm.local"}, //TODO: make it configurable
+		LocalNames:    []string{hostname}, //TODO: make it configurable
 		LoggerFactory: defaultLoggerFactory,
 	})
 	if err != nil {
+		scopedLogger.Warn().Err(err).Msg("failed to start mDNS server")
 		mDNSConn = nil
 		return err
 	}
@@ -190,7 +199,7 @@ func getNTPServersFromDHCPInfo() ([]string, error) {
 	return servers, nil
 }
 
-func init() {
+func initNetwork() {
 	ensureConfigLoaded()
 
 	updates := make(chan netlink.LinkUpdate)

ntp.go

@@ -1,7 +1,6 @@
 package kvm
 
 import (
-	"errors"
 	"fmt"
 	"net/http"
 	"os/exec"
@@ -111,23 +110,36 @@ func SyncSystemTime() (err error) {
 func queryNetworkTime() (*time.Time, error) {
 	ntpServers, err := getNTPServersFromDHCPInfo()
 	if err != nil {
-		ntpLogger.Error().Str("error", err.Error()).Msg("failed to get NTP servers from DHCP info")
+		ntpLogger.Info().Err(err).Msg("failed to get NTP servers from DHCP info")
 	}
 
 	if ntpServers == nil {
 		ntpServers = defaultNTPServers
-		ntpLogger.Info().Str("ntp_servers", fmt.Sprintf("%v", ntpServers)).Msg("Using default NTP servers")
+		ntpLogger.Info().
+			Interface("ntp_servers", ntpServers).
+			Msg("Using default NTP servers")
 	} else {
-		ntpLogger.Info().Str("ntp_servers", fmt.Sprintf("%v", ntpServers)).Msg("Using NTP servers from DHCP")
+		ntpLogger.Info().
+			Interface("ntp_servers", ntpServers).
+			Msg("Using NTP servers from DHCP")
 	}
 
 	for _, server := range ntpServers {
 		now, err := queryNtpServer(server, timeSyncTimeout)
 		if err == nil {
-			ntpLogger.Info().Str("ntp_server", server).Str("time", now.Format(time.RFC3339)).Msg("NTP server returned time")
+			ntpLogger.Info().
+				Str("ntp_server", server).
+				Str("time", now.Format(time.RFC3339)).
+				Msg("NTP server returned time")
 			return now, nil
+		} else {
+			ntpLogger.Error().
+				Str("ntp_server", server).
+				Str("error", err.Error()).
+				Msg("failed to query NTP server")
 		}
 	}
+
 	httpUrls := []string{
 		"http://apple.com",
 		"http://cloudflare.com",
@@ -135,12 +147,20 @@ func queryNetworkTime() (*time.Time, error) {
 	for _, url := range httpUrls {
 		now, err := queryHttpTime(url, timeSyncTimeout)
 		if err == nil {
-			ntpLogger.Info().Str("http_url", url).Str("time", now.Format(time.RFC3339)).Msg("HTTP server returned time")
+			ntpLogger.Info().
+				Str("http_url", url).
+				Str("time", now.Format(time.RFC3339)).
+				Msg("HTTP server returned time")
 			return now, nil
+		} else {
+			ntpLogger.Error().
+				Str("http_url", url).
+				Str("error", err.Error()).
+				Msg("failed to query HTTP server")
 		}
 	}
-	ntpLogger.Error().Msg("failed to query network time")
+
-	return nil, errors.New("failed to query network time")
+	return nil, ErrorfL(ntpLogger, "failed to query network time, all NTP servers and HTTP servers failed", nil)
 }
 
 func queryNtpServer(server string, timeout time.Duration) (now *time.Time, err error) {

ota.go

@@ -16,6 +16,7 @@ import (
 	"time"
 
 	"github.com/Masterminds/semver/v3"
+	"github.com/rs/zerolog"
 )
 
 type UpdateMetadata struct {
@@ -191,7 +192,11 @@ func downloadFile(ctx context.Context, path string, url string, downloadProgress
 	return nil
 }
 
-func verifyFile(path string, expectedHash string, verifyProgress *float32) error {
+func verifyFile(path string, expectedHash string, verifyProgress *float32, scopedLogger *zerolog.Logger) error {
+	if scopedLogger == nil {
+		scopedLogger = otaLogger
+	}
+
 	unverifiedPath := path + ".unverified"
 	fileToHash, err := os.Open(unverifiedPath)
 	if err != nil {
@@ -235,7 +240,7 @@ func verifyFile(path string, expectedHash string, verifyProgress *float32) error
 	}
 
 	hashSum := hash.Sum(nil)
-	logger.Info().Str("path", path).Str("hash", hex.EncodeToString(hashSum)).Msg("SHA256 hash of")
+	scopedLogger.Info().Str("path", path).Str("hash", hex.EncodeToString(hashSum)).Msg("SHA256 hash of")
 
 	if hex.EncodeToString(hashSum) != expectedHash {
 		return fmt.Errorf("hash mismatch: %x != %s", hashSum, expectedHash)
@@ -285,7 +290,12 @@ func triggerOTAStateUpdate() {
 }
 
 func TryUpdate(ctx context.Context, deviceId string, includePreRelease bool) error {
-	logger.Info().Msg("Trying to update...")
+	scopedLogger := otaLogger.With().
+		Str("deviceId", deviceId).
+		Str("includePreRelease", fmt.Sprintf("%v", includePreRelease)).
+		Logger()
+
+	scopedLogger.Info().Msg("Trying to update...")
 	if otaState.Updating {
 		return fmt.Errorf("update already in progress")
 	}
@@ -303,6 +313,7 @@ func TryUpdate(ctx context.Context, deviceId string, includePreRelease bool) err
 	updateStatus, err := GetUpdateStatus(ctx, deviceId, includePreRelease)
 	if err != nil {
 		otaState.Error = fmt.Sprintf("Error checking for updates: %v", err)
+		scopedLogger.Error().Err(err).Msg("Error checking for updates")
 		return fmt.Errorf("error checking for updates: %w", err)
 	}
 
@@ -320,11 +331,15 @@ func TryUpdate(ctx context.Context, deviceId string, includePreRelease bool) err
 	rebootNeeded := false
 
 	if appUpdateAvailable {
-		logger.Info().Str("local", local.AppVersion).Str("remote", remote.AppVersion).Msg("App update available")
+		scopedLogger.Info().
+			Str("local", local.AppVersion).
+			Str("remote", remote.AppVersion).
+			Msg("App update available")
 
 		err := downloadFile(ctx, "/userdata/jetkvm/jetkvm_app.update", remote.AppUrl, &otaState.AppDownloadProgress)
 		if err != nil {
 			otaState.Error = fmt.Sprintf("Error downloading app update: %v", err)
+			scopedLogger.Error().Err(err).Msg("Error downloading app update")
 			triggerOTAStateUpdate()
 			return err
 		}
@@ -333,9 +348,15 @@ func TryUpdate(ctx context.Context, deviceId string, includePreRelease bool) err
 		otaState.AppDownloadProgress = 1
 		triggerOTAStateUpdate()
 
-		err = verifyFile("/userdata/jetkvm/jetkvm_app.update", remote.AppHash, &otaState.AppVerificationProgress)
+		err = verifyFile(
+			"/userdata/jetkvm/jetkvm_app.update",
+			remote.AppHash,
+			&otaState.AppVerificationProgress,
+			&scopedLogger,
+		)
 		if err != nil {
 			otaState.Error = fmt.Sprintf("Error verifying app update hash: %v", err)
+			scopedLogger.Error().Err(err).Msg("Error verifying app update hash")
 			triggerOTAStateUpdate()
 			return err
 		}
@@ -346,18 +367,22 @@ func TryUpdate(ctx context.Context, deviceId string, includePreRelease bool) err
 		otaState.AppUpdateProgress = 1
 		triggerOTAStateUpdate()
 
-		logger.Info().Msg("App update downloaded")
+		scopedLogger.Info().Msg("App update downloaded")
 		rebootNeeded = true
 	} else {
-		logger.Info().Msg("App is up to date")
+		scopedLogger.Info().Msg("App is up to date")
 	}
 
 	if systemUpdateAvailable {
-		logger.Info().Str("local", local.SystemVersion).Str("remote", remote.SystemVersion).Msg("System update available")
+		scopedLogger.Info().
+			Str("local", local.SystemVersion).
+			Str("remote", remote.SystemVersion).
+			Msg("System update available")
 
 		err := downloadFile(ctx, "/userdata/jetkvm/update_system.tar", remote.SystemUrl, &otaState.SystemDownloadProgress)
 		if err != nil {
 			otaState.Error = fmt.Sprintf("Error downloading system update: %v", err)
+			scopedLogger.Error().Err(err).Msg("Error downloading system update")
 			triggerOTAStateUpdate()
 			return err
 		}
@@ -366,18 +391,25 @@ func TryUpdate(ctx context.Context, deviceId string, includePreRelease bool) err
 		otaState.SystemDownloadProgress = 1
 		triggerOTAStateUpdate()
 
-		err = verifyFile("/userdata/jetkvm/update_system.tar", remote.SystemHash, &otaState.SystemVerificationProgress)
+		err = verifyFile(
+			"/userdata/jetkvm/update_system.tar",
+			remote.SystemHash,
+			&otaState.SystemVerificationProgress,
+			&scopedLogger,
+		)
 		if err != nil {
 			otaState.Error = fmt.Sprintf("Error verifying system update hash: %v", err)
+			scopedLogger.Error().Err(err).Msg("Error verifying system update hash")
 			triggerOTAStateUpdate()
 			return err
 		}
-		logger.Info().Msg("System update downloaded")
+		scopedLogger.Info().Msg("System update downloaded")
 		verifyFinished := time.Now()
 		otaState.SystemVerifiedAt = &verifyFinished
 		otaState.SystemVerificationProgress = 1
 		triggerOTAStateUpdate()
 
+		scopedLogger.Info().Msg("Starting rk_ota command")
 		cmd := exec.Command("rk_ota", "--misc=update", "--tar_path=/userdata/jetkvm/update_system.tar", "--save_dir=/userdata/jetkvm/ota_save", "--partition=all")
 		var b bytes.Buffer
 		cmd.Stdout = &b
@@ -385,6 +417,7 @@ func TryUpdate(ctx context.Context, deviceId string, includePreRelease bool) err
 		err = cmd.Start()
 		if err != nil {
 			otaState.Error = fmt.Sprintf("Error starting rk_ota command: %v", err)
+			scopedLogger.Error().Err(err).Msg("Error starting rk_ota command")
 			return fmt.Errorf("error starting rk_ota command: %w", err)
 		}
 		ctx, cancel := context.WithCancel(context.Background())
@@ -416,25 +449,30 @@ func TryUpdate(ctx context.Context, deviceId string, includePreRelease bool) err
 		output := b.String()
 		if err != nil {
 			otaState.Error = fmt.Sprintf("Error executing rk_ota command: %v\nOutput: %s", err, output)
+			scopedLogger.Error().
+				Err(err).
+				Str("output", output).
+				Int("exitCode", cmd.ProcessState.ExitCode()).
+				Msg("Error executing rk_ota command")
 			return fmt.Errorf("error executing rk_ota command: %w\nOutput: %s", err, output)
 		}
-
+		scopedLogger.Info().Str("output", output).Msg("rk_ota success")
-		logger.Info().Str("output", output).Msg("rk_ota success")
 		otaState.SystemUpdateProgress = 1
 		otaState.SystemUpdatedAt = &verifyFinished
 		triggerOTAStateUpdate()
 		rebootNeeded = true
 	} else {
-		logger.Info().Msg("System is up to date")
+		scopedLogger.Info().Msg("System is up to date")
 	}
 
 	if rebootNeeded {
-		logger.Info().Msg("System Rebooting in 10s")
+		scopedLogger.Info().Msg("System Rebooting in 10s")
 		time.Sleep(10 * time.Second)
 		cmd := exec.Command("reboot")
 		err := cmd.Start()
 		if err != nil {
 			otaState.Error = fmt.Sprintf("Failed to start reboot: %v", err)
+			scopedLogger.Error().Err(err).Msg("Failed to start reboot")
 			return fmt.Errorf("failed to start reboot: %w", err)
 		} else {
 			os.Exit(0)

serial.go

@@ -35,17 +35,19 @@ var (
 )
 
 func runATXControl() {
+	scopedLogger := serialLogger.With().Str("service", "atx_control").Logger()
+
 	reader := bufio.NewReader(port)
 	for {
 		line, err := reader.ReadString('\n')
 		if err != nil {
-			logger.Warn().Err(err).Msg("Error reading from serial port")
+			scopedLogger.Warn().Err(err).Msg("Error reading from serial port")
 			return
 		}
 
 		// Each line should be 4 binary digits + newline
 		if len(line) != 5 {
-			logger.Warn().Int("length", len(line)).Msg("Invalid line length")
+			scopedLogger.Warn().Int("length", len(line)).Msg("Invalid line length")
 			continue
 		}
 
@@ -66,7 +68,12 @@ func runATXControl() {
 			newLedPWRState != ledPWRState ||
 			newBtnRSTState != btnRSTState ||
 			newBtnPWRState != btnPWRState {
-			logger.Debug().Bool("hdd", newLedHDDState).Bool("pwr", newLedPWRState).Bool("rst", newBtnRSTState).Bool("pwr", newBtnPWRState).Msg("Status changed")
+			scopedLogger.Debug().
+				Bool("hdd", newLedHDDState).
+				Bool("pwr", newLedPWRState).
+				Bool("rst", newBtnRSTState).
+				Bool("pwr", newBtnPWRState).
+				Msg("Status changed")
 
 			// Update states
 			ledHDDState = newLedHDDState
@@ -133,45 +140,46 @@ func unmountDCControl() error {
 var dcState DCPowerState
 
 func runDCControl() {
+	scopedLogger := serialLogger.With().Str("service", "dc_control").Logger()
 	reader := bufio.NewReader(port)
 	for {
 		line, err := reader.ReadString('\n')
 		if err != nil {
-			logger.Warn().Err(err).Msg("Error reading from serial port")
+			scopedLogger.Warn().Err(err).Msg("Error reading from serial port")
 			return
 		}
 
 		// Split the line by semicolon
 		parts := strings.Split(strings.TrimSpace(line), ";")
 		if len(parts) != 4 {
-			logger.Warn().Str("line", line).Msg("Invalid line")
+			scopedLogger.Warn().Str("line", line).Msg("Invalid line")
 			continue
 		}
 
 		// Parse new states
 		powerState, err := strconv.Atoi(parts[0])
 		if err != nil {
-			logger.Warn().Err(err).Msg("Invalid power state")
+			scopedLogger.Warn().Err(err).Msg("Invalid power state")
 			continue
 		}
 		dcState.IsOn = powerState == 1
 		milliVolts, err := strconv.ParseFloat(parts[1], 64)
 		if err != nil {
-			logger.Warn().Err(err).Msg("Invalid voltage")
+			scopedLogger.Warn().Err(err).Msg("Invalid voltage")
 			continue
 		}
 		volts := milliVolts / 1000 // Convert mV to V
 
 		milliAmps, err := strconv.ParseFloat(parts[2], 64)
 		if err != nil {
-			logger.Warn().Err(err).Msg("Invalid current")
+			scopedLogger.Warn().Err(err).Msg("Invalid current")
 			continue
 		}
 		amps := milliAmps / 1000 // Convert mA to A
 
 		milliWatts, err := strconv.ParseFloat(parts[3], 64)
 		if err != nil {
-			logger.Warn().Err(err).Msg("Invalid power")
+			scopedLogger.Warn().Err(err).Msg("Invalid power")
 			continue
 		}
 		watts := milliWatts / 1000 // Convert mW to W
@@ -225,12 +233,19 @@ func reopenSerialPort() error {
 	var err error
 	port, err = serial.Open(serialPortPath, defaultMode)
 	if err != nil {
-		logger.Warn().Err(err).Msg("Error opening serial port")
+		serialLogger.Error().
+			Err(err).
+			Str("path", serialPortPath).
+			Interface("mode", defaultMode).
+			Msg("Error opening serial port")
 	}
 	return nil
 }
 
 func handleSerialChannel(d *webrtc.DataChannel) {
+	scopedLogger := serialLogger.With().
+		Uint16("data_channel_id", *d.ID()).Logger()
+
 	d.OnOpen(func() {
 		go func() {
 			buf := make([]byte, 1024)
@@ -238,13 +253,13 @@ func handleSerialChannel(d *webrtc.DataChannel) {
 				n, err := port.Read(buf)
 				if err != nil {
 					if err != io.EOF {
-						logger.Warn().Err(err).Msg("Failed to read from serial port")
+						scopedLogger.Warn().Err(err).Msg("Failed to read from serial port")
 					}
 					break
 				}
 				err = d.Send(buf[:n])
 				if err != nil {
-					logger.Warn().Err(err).Msg("Failed to send serial output")
+					scopedLogger.Warn().Err(err).Msg("Failed to send serial output")
 					break
 				}
 			}
@@ -257,11 +272,15 @@ func handleSerialChannel(d *webrtc.DataChannel) {
 		}
 		_, err := port.Write(msg.Data)
 		if err != nil {
-			logger.Warn().Err(err).Msg("Failed to write to serial")
+			scopedLogger.Warn().Err(err).Msg("Failed to write to serial")
 		}
 	})
 
-	d.OnClose(func() {
+	d.OnError(func(err error) {
+		scopedLogger.Warn().Err(err).Msg("Serial channel error")
+	})
 
+	d.OnClose(func() {
+		scopedLogger.Info().Msg("Serial channel closed")
 	})
 }

terminal.go

@@ -16,6 +16,9 @@ type TerminalSize struct {
 }
 
 func handleTerminalChannel(d *webrtc.DataChannel) {
+	scopedLogger := terminalLogger.With().
+		Uint16("data_channel_id", *d.ID()).Logger()
+
 	var ptmx *os.File
 	var cmd *exec.Cmd
 	d.OnOpen(func() {
@@ -23,7 +26,7 @@ func handleTerminalChannel(d *webrtc.DataChannel) {
 		var err error
 		ptmx, err = pty.Start(cmd)
 		if err != nil {
-			logger.Warn().Err(err).Msg("Failed to start pty")
+			scopedLogger.Warn().Err(err).Msg("Failed to start pty")
 			d.Close()
 			return
 		}
@@ -34,13 +37,13 @@ func handleTerminalChannel(d *webrtc.DataChannel) {
 				n, err := ptmx.Read(buf)
 				if err != nil {
 					if err != io.EOF {
-						logger.Warn().Err(err).Msg("Failed to read from pty")
+						scopedLogger.Warn().Err(err).Msg("Failed to read from pty")
 					}
 					break
 				}
 				err = d.Send(buf[:n])
 				if err != nil {
-					logger.Warn().Err(err).Msg("Failed to send pty output")
+					scopedLogger.Warn().Err(err).Msg("Failed to send pty output")
 					break
 				}
 			}
@@ -63,11 +66,11 @@ func handleTerminalChannel(d *webrtc.DataChannel) {
 					return
 				}
 			}
-			logger.Warn().Err(err).Msg("Failed to parse terminal size")
+			scopedLogger.Warn().Err(err).Msg("Failed to parse terminal size")
 		}
 		_, err := ptmx.Write(msg.Data)
 		if err != nil {
-			logger.Warn().Err(err).Msg("Failed to write to pty")
+			scopedLogger.Warn().Err(err).Msg("Failed to write to pty")
 		}
 	})
 
@@ -78,5 +81,10 @@ func handleTerminalChannel(d *webrtc.DataChannel) {
 		if cmd != nil && cmd.Process != nil {
 			_ = cmd.Process.Kill()
 		}
+		scopedLogger.Info().Msg("Terminal channel closed")
+	})
+
+	d.OnError(func(err error) {
+		scopedLogger.Warn().Err(err).Msg("Terminal channel error")
 	})
 }

usb.go

@@ -15,7 +15,7 @@ func initUsbGadget() {
 		"jetkvm",
 		config.UsbDevices,
 		config.UsbConfig,
-		&usbLogger,
+		usbLogger,
 	)
 
 	go func() {

web.go

@@ -69,7 +69,7 @@ func setupRouter() *gin.Engine {
 	r := gin.Default()
 	r.Use(gin_logger.SetLogger(
 		gin_logger.WithLogger(func(*gin.Context, zerolog.Logger) zerolog.Logger {
-			return ginLogger
+			return *ginLogger
 		}),
 	))
 	staticFS, _ := fs.Sub(staticFiles, "static")
@@ -189,6 +189,7 @@ var (
 func handleLocalWebRTCSignal(c *gin.Context) {
 	// get the source from the request
 	source := c.ClientIP()
+	connectionID := uuid.New().String()
 
 	scopedLogger := websocketLogger.With().
 		Str("component", "websocket").
@@ -226,20 +227,23 @@ func handleLocalWebRTCSignal(c *gin.Context) {
 		return
 	}
 
-	err = handleWebRTCSignalWsMessages(wsCon, false, source, &scopedLogger)
+	err = handleWebRTCSignalWsMessages(wsCon, false, source, connectionID, &scopedLogger)
 	if err != nil {
 		c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()})
 		return
 	}
 }
 
-func handleWebRTCSignalWsMessages(wsCon *websocket.Conn, isCloudConnection bool, source string, scopedLogger *zerolog.Logger) error {
+func handleWebRTCSignalWsMessages(
+	wsCon *websocket.Conn,
+	isCloudConnection bool,
+	source string,
+	connectionID string,
+	scopedLogger *zerolog.Logger,
+) error {
 	runCtx, cancelRun := context.WithCancel(context.Background())
 	defer cancelRun()
 
-	// Add connection tracking to detect reconnections
-	connectionID := uuid.New().String()
-
 	// connection type
 	var sourceType string
 	if isCloudConnection {
@@ -363,7 +367,7 @@ func handleWebRTCSignalWsMessages(wsCon *websocket.Conn, isCloudConnection bool,
 
 			metricConnectionSessionRequestCount.WithLabelValues(sourceType, source).Inc()
 			metricConnectionLastSessionRequestTimestamp.WithLabelValues(sourceType, source).SetToCurrentTime()
-			err = handleSessionRequest(runCtx, wsCon, req, isCloudConnection, source)
+			err = handleSessionRequest(runCtx, wsCon, req, isCloudConnection, source, &l)
 			if err != nil {
 				l.Warn().Str("error", err.Error()).Msg("error starting new session")
 				continue

web_tls.go

@@ -38,12 +38,12 @@ func initCertStore() {
 		websecureLogger.Warn().Msg("TLS store already initialized, it should not be initialized again")
 		return
 	}
-	certStore = websecure.NewCertStore(tlsStorePath, &websecureLogger)
+	certStore = websecure.NewCertStore(tlsStorePath, websecureLogger)
 	certStore.LoadCertificates()
 
 	certSigner = websecure.NewSelfSigner(
 		certStore,
-		&websecureLogger,
+		websecureLogger,
 		webSecureSelfSignedDefaultDomain,
 		webSecureSelfSignedOrganization,
 		webSecureSelfSignedOU,

webrtc.go

@@ -11,6 +11,7 @@ import (
 	"github.com/coder/websocket/wsjson"
 	"github.com/gin-gonic/gin"
 	"github.com/pion/webrtc/v4"
+	"github.com/rs/zerolog"
 )
 
 type Session struct {
@@ -28,6 +29,7 @@ type SessionConfig struct {
 	LocalIP    string
 	IsCloud    bool
 	ws         *websocket.Conn
+	Logger     *zerolog.Logger
 }
 
 func (s *Session) ExchangeOffer(offerStr string) (string, error) {
@@ -70,19 +72,27 @@ func newSession(config SessionConfig) (*Session, error) {
 	}
 	iceServer := webrtc.ICEServer{}
 
+	var scopedLogger *zerolog.Logger
+	if config.Logger != nil {
+		l := config.Logger.With().Str("component", "webrtc").Logger()
+		scopedLogger = &l
+	} else {
+		scopedLogger = webrtcLogger
+	}
+
 	if config.IsCloud {
 		if config.ICEServers == nil {
-			logger.Info().Msg("ICE Servers not provided by cloud")
+			scopedLogger.Info().Msg("ICE Servers not provided by cloud")
 		} else {
 			iceServer.URLs = config.ICEServers
-			logger.Info().Interface("iceServers", iceServer.URLs).Msg("Using ICE Servers provided by cloud")
+			scopedLogger.Info().Interface("iceServers", iceServer.URLs).Msg("Using ICE Servers provided by cloud")
 		}
 
 		if config.LocalIP == "" || net.ParseIP(config.LocalIP) == nil {
-			logger.Info().Str("localIP", config.LocalIP).Msg("Local IP address not provided or invalid, won't set NAT1To1IPs")
+			scopedLogger.Info().Str("localIP", config.LocalIP).Msg("Local IP address not provided or invalid, won't set NAT1To1IPs")
 		} else {
 			webrtcSettingEngine.SetNAT1To1IPs([]string{config.LocalIP}, webrtc.ICECandidateTypeSrflx)
-			logger.Info().Str("localIP", config.LocalIP).Msg("Setting NAT1To1IPs")
+			scopedLogger.Info().Str("localIP", config.LocalIP).Msg("Setting NAT1To1IPs")
 		}
 	}
 
@@ -96,7 +106,7 @@ func newSession(config SessionConfig) (*Session, error) {
 	session := &Session{peerConnection: peerConnection}
 
 	peerConnection.OnDataChannel(func(d *webrtc.DataChannel) {
-		logger.Info().Str("label", d.Label()).Uint16("id", *d.ID()).Msg("New DataChannel")
+		scopedLogger.Info().Str("label", d.Label()).Uint16("id", *d.ID()).Msg("New DataChannel")
 		switch d.Label() {
 		case "rpc":
 			session.RPCChannel = d
@@ -144,17 +154,17 @@ func newSession(config SessionConfig) (*Session, error) {
 	var isConnected bool
 
 	peerConnection.OnICECandidate(func(candidate *webrtc.ICECandidate) {
-		logger.Info().Interface("candidate", candidate).Msg("Our WebRTC peerConnection has a new ICE candidate")
+		scopedLogger.Info().Interface("candidate", candidate).Msg("WebRTC peerConnection has a new ICE candidate")
 		if candidate != nil {
 			err := wsjson.Write(context.Background(), config.ws, gin.H{"type": "new-ice-candidate", "data": candidate.ToJSON()})
 			if err != nil {
-				logger.Warn().Err(err).Msg("failed to write new-ice-candidate to WebRTC signaling channel")
+				scopedLogger.Warn().Err(err).Msg("failed to write new-ice-candidate to WebRTC signaling channel")
 			}
 		}
 	})
 
 	peerConnection.OnICEConnectionStateChange(func(connectionState webrtc.ICEConnectionState) {
-		logger.Info().Str("connectionState", connectionState.String()).Msg("Connection State has changed")
+		scopedLogger.Info().Str("connectionState", connectionState.String()).Msg("ICE Connection State has changed")
 		if connectionState == webrtc.ICEConnectionStateConnected {
 			if !isConnected {
 				isConnected = true
@@ -167,15 +177,17 @@ func newSession(config SessionConfig) (*Session, error) {
 		}
 		//state changes on closing browser tab disconnected->failed, we need to manually close it
 		if connectionState == webrtc.ICEConnectionStateFailed {
+			scopedLogger.Debug().Msg("ICE Connection State is failed, closing peerConnection")
 			_ = peerConnection.Close()
 		}
 		if connectionState == webrtc.ICEConnectionStateClosed {
+			scopedLogger.Debug().Msg("ICE Connection State is closed, unmounting virtual media")
 			if session == currentSession {
 				currentSession = nil
 			}
 			if session.shouldUmountVirtualMedia {
 				err := rpcUnmountImage()
-				logger.Debug().Err(err).Msg("unmount image failed on connection close")
+				scopedLogger.Warn().Err(err).Msg("unmount image failed on connection close")
 			}
 			if isConnected {
 				isConnected = false

wol.go

@@ -3,7 +3,6 @@ package kvm
 import (
 	"bytes"
 	"encoding/binary"
-	"fmt"
 	"net"
 )
 
@@ -12,7 +11,7 @@ func rpcSendWOLMagicPacket(macAddress string) error {
 	// Parse the MAC address
 	mac, err := net.ParseMAC(macAddress)
 	if err != nil {
-		return fmt.Errorf("invalid MAC address: %v", err)
+		return ErrorfL(wolLogger, "invalid MAC address", err)
 	}
 
 	// Create the magic packet
@@ -21,16 +20,18 @@ func rpcSendWOLMagicPacket(macAddress string) error {
 	// Set up UDP connection
 	conn, err := net.Dial("udp", "255.255.255.255:9")
 	if err != nil {
-		return fmt.Errorf("failed to establish UDP connection: %v", err)
+		return ErrorfL(wolLogger, "failed to establish UDP connection", err)
 	}
 	defer conn.Close()
 
 	// Send the packet
 	_, err = conn.Write(packet)
 	if err != nil {
-		return fmt.Errorf("failed to send WOL packet: %v", err)
+		return ErrorfL(wolLogger, "failed to send WOL packet", err)
 	}
 
+	wolLogger.Info().Str("mac", macAddress).Msg("WOL packet sent")
+
 	return nil
 }