add logs

hidrpc.go

@@ -2,6 +2,7 @@ package kvm
 
 import (
 	"fmt"
+	"time"
 
 	"github.com/jetkvm/kvm/internal/hidrpc"
 	"github.com/jetkvm/kvm/internal/usbgadget"
@@ -19,10 +20,15 @@ func onHidMessage(data []byte, session *Session) {
 	)
 
 	if err := hidrpc.Unmarshal(data, &message); err != nil {
-		logger.Warn().Err(err).Msg("failed to unmarshal HID RPC message")
+		logger.Warn().Err(err).Bytes("data", data).Msg("failed to unmarshal HID RPC message")
 		return
 	}
 
+	scopedLogger := hidRpcLogger.With().Str("payload", message.String()).Logger()
+
+	scopedLogger.Debug().Msg("received HID RPC message from the queue")
+	startTime := time.Now()
+
 	switch message.Type() {
 	case hidrpc.TypeHandshake:
 		message, err := hidrpc.NewHandshakeMessage().Marshal()
@@ -62,6 +68,9 @@ func onHidMessage(data []byte, session *Session) {
 	if rpcErr != nil {
 		logger.Warn().Err(rpcErr).Msg("failed to handle HID RPC message")
 	}
+
+	duration := time.Since(startTime)
+	scopedLogger.Debug().Dur("duration", duration).Msg("handled HID RPC message")
 }
 
 func handleHidRpcKeyboardInput(message hidrpc.Message) (*usbgadget.KeysDownState, error) {

internal/hidrpc/message.go

@@ -19,6 +19,23 @@ func (m *Message) Type() MessageType {
 	return m.t
 }
 
+func (m *Message) String() string {
+	switch m.t {
+	case TypeHandshake:
+		return "Handshake"
+	case TypeKeypressReport:
+		return fmt.Sprintf("KeypressReport{Key: %d, Press: %v}", m.d[0], m.d[1] == uint8(1))
+	case TypeKeyboardReport:
+		return fmt.Sprintf("KeyboardReport{Modifier: %d, Keys: %v}", m.d[0], m.d[1:])
+	case TypePointerReport:
+		return fmt.Sprintf("PointerReport{X: %d, Y: %d, Button: %d}", m.d[0], m.d[1], m.d[2])
+	case TypeMouseReport:
+		return fmt.Sprintf("MouseReport{DX: %d, DY: %d, Button: %d}", m.d[0], m.d[1], m.d[2])
+	default:
+		return fmt.Sprintf("Unknown{Type: %d, Data: %v}", m.t, m.d)
+	}
+}
+
 // KeypressReport ..
 type KeypressReport struct {
 	Key   byte

log.go

@@ -19,6 +19,7 @@ var (
 	nbdLogger       = logging.GetSubsystemLogger("nbd")
 	timesyncLogger  = logging.GetSubsystemLogger("timesync")
 	jsonRpcLogger   = logging.GetSubsystemLogger("jsonrpc")
+	hidRpcLogger    = logging.GetSubsystemLogger("hidrpc")
 	watchdogLogger  = logging.GetSubsystemLogger("watchdog")
 	websecureLogger = logging.GetSubsystemLogger("websecure")
 	otaLogger       = logging.GetSubsystemLogger("ota")

webrtc.go

@@ -148,6 +148,8 @@ func newSession(config SessionConfig) (*Session, error) {
 					return
 				}
 
+				scopedLogger.Debug().Str("data", string(msg.Data)).Msg("received data in HID RPC message handler")
+
 				// Enqueue to ensure ordered processing
 				session.hidQueue <- msg
 			})