diff --git a/hidrpc.go b/hidrpc.go index e7d19b9..7b9469f 100644 --- a/hidrpc.go +++ b/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) { diff --git a/internal/hidrpc/message.go b/internal/hidrpc/message.go index dd4c0c9..d44662c 100644 --- a/internal/hidrpc/message.go +++ b/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 diff --git a/log.go b/log.go index 1a091b1..8b8194e 100644 --- a/log.go +++ b/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") diff --git a/webrtc.go b/webrtc.go index f09b13d..d801ef8 100644 --- a/webrtc.go +++ b/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 })