Reduce traffic during pastes

Suspend KeyDownMessages while processing a macro.
Make sure we don't emit huge debugging traces.
Allow 30 seconds for RPC to finish (not ideal)
Reduced default delay between keys (and allow as low as 0)
Move the HID keyboard descriptor LED state
as it seems to interfere with boot mode
Run paste/macros in background on their own queue and return a token for cancellation.
Fixed error in length check for macro key state.
Removed redundant clear operation.
Use Once instead of init()
Add a time limit for each message type/queue.

Author: IDisposable

cloud.go

@@ -478,7 +478,7 @@ func handleSessionRequest(
 	cloudLogger.Trace().Interface("session", session).Msg("new session accepted")
 
 	// Cancel any ongoing keyboard macro when session changes
-	cancelKeyboardMacro()
+	cancelAllRunningKeyboardMacros()
 
 	currentSession = session
 	_ = wsjson.Write(context.Background(), c, gin.H{"type": "answer", "data": sd})

hidrpc.go

@@ -26,34 +26,61 @@ func handleHidRPCMessage(message hidrpc.Message, session *Session) {
 			return
 		}
 		session.hidRPCAvailable = true
+
 	case hidrpc.TypeKeypressReport, hidrpc.TypeKeyboardReport:
 		rpcErr = handleHidRPCKeyboardInput(message)
+
 	case hidrpc.TypeKeyboardMacroReport:
 		keyboardMacroReport, err := message.KeyboardMacroReport()
 		if err != nil {
 			logger.Warn().Err(err).Msg("failed to get keyboard macro report")
 			return
 		}
-		rpcErr = rpcExecuteKeyboardMacro(keyboardMacroReport.Steps)
+		token := rpcExecuteKeyboardMacro(keyboardMacroReport.IsPaste, keyboardMacroReport.Steps)
+		logger.Debug().Str("token", token.String()).Msg("started keyboard macro")
+		message, err := hidrpc.NewKeyboardMacroTokenMessage(token).Marshal()
+
+		if err != nil {
+			logger.Warn().Err(err).Msg("failed to marshal running macro token message")
+			return
+		}
+		if err := session.HidChannel.Send(message); err != nil {
+			logger.Warn().Err(err).Msg("failed to send running macro token message")
+			return
+		}
+
 	case hidrpc.TypeCancelKeyboardMacroReport:
 		rpcCancelKeyboardMacro()
 		return
+
+	case hidrpc.TypeKeyboardMacroTokenState:
+		tokenState, err := message.KeyboardMacroTokenState()
+		if err != nil {
+			logger.Warn().Err(err).Msg("failed to get keyboard macro token")
+			return
+		}
+		rpcCancelKeyboardMacroByToken(tokenState.Token)
+		return
+
 	case hidrpc.TypeKeypressKeepAliveReport:
 		rpcErr = handleHidRPCKeypressKeepAlive(session)
+
 	case hidrpc.TypePointerReport:
 		pointerReport, err := message.PointerReport()
 		if err != nil {
 			logger.Warn().Err(err).Msg("failed to get pointer report")
 			return
 		}
 		rpcErr = rpcAbsMouseReport(pointerReport.X, pointerReport.Y, pointerReport.Button)
+
 	case hidrpc.TypeMouseReport:
 		mouseReport, err := message.MouseReport()
 		if err != nil {
 			logger.Warn().Err(err).Msg("failed to get mouse report")
 			return
 		}
 		rpcErr = rpcRelMouseReport(mouseReport.DX, mouseReport.DY, mouseReport.Button)
+
 	default:
 		logger.Warn().Uint8("type", uint8(message.Type())).Msg("unknown HID RPC message type")
 	}
@@ -65,15 +92,18 @@ func handleHidRPCMessage(message hidrpc.Message, session *Session) {
 
 func onHidMessage(msg hidQueueMessage, session *Session) {
 	data := msg.Data
+	dataLen := len(data)
 
 	scopedLogger := hidRPCLogger.With().
 		Str("channel", msg.channel).
-		Bytes("data", data).
+		Dur("timelimit", msg.timelimit).
+		Int("data_len", dataLen).
+		Bytes("data", data[:min(dataLen, 32)]).
 		Logger()
 	scopedLogger.Debug().Msg("HID RPC message received")
 
-	if len(data) < 1 {
-		scopedLogger.Warn().Int("length", len(data)).Msg("received empty data in HID RPC message handler")
+	if dataLen < 1 {
+		scopedLogger.Warn().Msg("received empty data in HID RPC message handler")
 		return
 	}
 
@@ -96,7 +126,7 @@ func onHidMessage(msg hidQueueMessage, session *Session) {
 		r <- nil
 	}()
 	select {
-	case <-time.After(1 * time.Second):
+	case <-time.After(msg.timelimit * time.Second):
 		scopedLogger.Warn().Msg("HID RPC message timed out")
 	case <-r:
 		scopedLogger.Debug().Dur("duration", time.Since(t)).Msg("HID RPC message handled")
@@ -212,6 +242,8 @@ func reportHidRPC(params any, session *Session) {
 		message, err = hidrpc.NewKeydownStateMessage(params).Marshal()
 	case hidrpc.KeyboardMacroState:
 		message, err = hidrpc.NewKeyboardMacroStateMessage(params.State, params.IsPaste).Marshal()
+	case hidrpc.KeyboardMacroTokenState:
+		message, err = hidrpc.NewKeyboardMacroTokenMessage(params.Token).Marshal()
 	default:
 		err = fmt.Errorf("unknown HID RPC message type: %T", params)
 	}

internal/hidrpc/hidrpc.go

@@ -2,7 +2,9 @@ package hidrpc
 
 import (
 	"fmt"
+	"time"
 
+	"github.com/google/uuid"
 	"github.com/jetkvm/kvm/internal/usbgadget"
 )
 
@@ -22,26 +24,34 @@ const (
 	TypeKeyboardLedState          MessageType = 0x32
 	TypeKeydownState              MessageType = 0x33
 	TypeKeyboardMacroState        MessageType = 0x34
+	TypeKeyboardMacroTokenState   MessageType = 0x35
 )
 
+type QueueIndex int
+
 const (
-	Version byte = 0x01 // Version of the HID RPC protocol
+	Version        byte = 0x01 // Version of the HID RPC protocol
+	HandshakeQueue int  = 0    // Queue index for handshake messages
+	KeyboardQueue  int  = 1    // Queue index for keyboard messages
+	MouseQueue     int  = 2    // Queue index for mouse messages
+	MacroQueue     int  = 3    // Queue index for macro messages
+	OtherQueue     int  = 4    // Queue index for other messages
 )
 
 // GetQueueIndex returns the index of the queue to which the message should be enqueued.
-func GetQueueIndex(messageType MessageType) int {
+func GetQueueIndex(messageType MessageType) (int, time.Duration) {
 	switch messageType {
 	case TypeHandshake:
-		return 0
-	case TypeKeyboardReport, TypeKeypressReport, TypeKeyboardMacroReport, TypeKeyboardLedState, TypeKeydownState, TypeKeyboardMacroState:
-		return 1
+		return HandshakeQueue, 1
+	case TypeKeyboardReport, TypeKeypressReport, TypeKeyboardLedState, TypeKeydownState, TypeKeyboardMacroState:
+		return KeyboardQueue, 1
 	case TypePointerReport, TypeMouseReport, TypeWheelReport:
-		return 2
-	// we don't want to block the queue for this message
-	case TypeCancelKeyboardMacroReport:
-		return 3
+		return MouseQueue, 1
+	// we don't want to block the queue for these messages
+	case TypeKeyboardMacroReport, TypeCancelKeyboardMacroReport, TypeKeyboardMacroTokenState:
+		return MacroQueue, 60 // 1 minute timeout
 	default:
-		return 3
+		return OtherQueue, 5
 	}
 }
 
@@ -121,3 +131,13 @@ func NewKeyboardMacroStateMessage(state bool, isPaste bool) *Message {
 		d: data,
 	}
 }
+
+// NewKeyboardMacroTokenMessage creates a new keyboard macro token message.
+func NewKeyboardMacroTokenMessage(token uuid.UUID) *Message {
+	data, _ := token.MarshalBinary()
+
+	return &Message{
+		t: TypeKeyboardMacroState,
+		d: data,
+	}
+}

internal/hidrpc/message.go

@@ -3,6 +3,8 @@ package hidrpc
 import (
 	"encoding/binary"
 	"fmt"
+
+	"github.com/google/uuid"
 )
 
 // Message ..
@@ -23,6 +25,9 @@ func (m *Message) Type() MessageType {
 func (m *Message) String() string {
 	switch m.t {
 	case TypeHandshake:
+		if len(m.d) != 0 {
+			return fmt.Sprintf("Handshake{Malformed: %v}", m.d)
+		}
 		return "Handshake"
 	case TypeKeypressReport:
 		if len(m.d) < 2 {
@@ -45,12 +50,45 @@ func (m *Message) String() string {
 		}
 		return fmt.Sprintf("MouseReport{DX: %d, DY: %d, Button: %d}", m.d[0], m.d[1], m.d[2])
 	case TypeKeypressKeepAliveReport:
+		if len(m.d) != 0 {
+			return fmt.Sprintf("KeypressKeepAliveReport{Malformed: %v}", m.d)
+		}
 		return "KeypressKeepAliveReport"
+	case TypeWheelReport:
+		if len(m.d) < 3 {
+			return fmt.Sprintf("WheelReport{Malformed: %v}", m.d)
+		}
+		return fmt.Sprintf("WheelReport{Vertical: %d, Horizontal: %d}", int8(m.d[0]), int8(m.d[1]))
 	case TypeKeyboardMacroReport:
 		if len(m.d) < 5 {
 			return fmt.Sprintf("KeyboardMacroReport{Malformed: %v}", m.d)
 		}
 		return fmt.Sprintf("KeyboardMacroReport{IsPaste: %v, Length: %d}", m.d[0] == uint8(1), binary.BigEndian.Uint32(m.d[1:5]))
+	case TypeCancelKeyboardMacroReport:
+		if len(m.d) != 0 {
+			return fmt.Sprintf("CancelKeyboardMacroReport{Malformed: %v}", m.d)
+		}
+		return "CancelKeyboardMacroReport"
+	case TypeKeyboardMacroTokenState:
+		if len(m.d) != 16 {
+			return fmt.Sprintf("KeyboardMacroTokenState{Malformed: %v}", m.d)
+		}
+		return fmt.Sprintf("KeyboardMacroTokenState{Token: %s}", uuid.Must(uuid.FromBytes(m.d)).String())
+	case TypeKeyboardLedState:
+		if len(m.d) < 1 {
+			return fmt.Sprintf("KeyboardLedState{Malformed: %v}", m.d)
+		}
+		return fmt.Sprintf("KeyboardLedState{State: %d}", m.d[0])
+	case TypeKeydownState:
+		if len(m.d) < 1 {
+			return fmt.Sprintf("KeydownState{Malformed: %v}", m.d)
+		}
+		return fmt.Sprintf("KeydownState{State: %d}", m.d[0])
+	case TypeKeyboardMacroState:
+		if len(m.d) < 2 {
+			return fmt.Sprintf("KeyboardMacroState{Malformed: %v}", m.d)
+		}
+		return fmt.Sprintf("KeyboardMacroState{State: %v, IsPaste: %v}", m.d[0] == uint8(1), m.d[1] == uint8(1))
 	default:
 		return fmt.Sprintf("Unknown{Type: %d, Data: %v}", m.t, m.d)
 	}
@@ -67,7 +105,9 @@ func (m *Message) KeypressReport() (KeypressReport, error) {
 	if m.t != TypeKeypressReport {
 		return KeypressReport{}, fmt.Errorf("invalid message type: %d", m.t)
 	}
-
+	if len(m.d) < 2 {
+		return KeypressReport{}, fmt.Errorf("invalid message data length: %d", len(m.d))
+	}
 	return KeypressReport{
 		Key:   m.d[0],
 		Press: m.d[1] == uint8(1),
@@ -95,7 +135,7 @@ func (m *Message) KeyboardReport() (KeyboardReport, error) {
 // Macro ..
 type KeyboardMacroStep struct {
 	Modifier byte   // 1 byte
-	Keys     []byte // 6 bytes: hidKeyBufferSize
+	Keys     []byte // 6 bytes: HidKeyBufferSize
 	Delay    uint16 // 2 bytes
 }
 type KeyboardMacroReport struct {
@@ -105,7 +145,7 @@ type KeyboardMacroReport struct {
 }
 
 // HidKeyBufferSize is the size of the keys buffer in the keyboard report.
-const HidKeyBufferSize = 6
+const HidKeyBufferSize int = 6
 
 // KeyboardMacroReport returns the keyboard macro report from the message.
 func (m *Message) KeyboardMacroReport() (KeyboardMacroReport, error) {
@@ -205,3 +245,29 @@ func (m *Message) KeyboardMacroState() (KeyboardMacroState, error) {
 		IsPaste: m.d[1] == uint8(1),
 	}, nil
 }
+
+type KeyboardMacroTokenState struct {
+	Token uuid.UUID
+}
+
+// KeyboardMacroTokenState returns the keyboard macro token UUID from the message.
+func (m *Message) KeyboardMacroTokenState() (KeyboardMacroTokenState, error) {
+	if m.t != TypeKeyboardMacroTokenState {
+		return KeyboardMacroTokenState{}, fmt.Errorf("invalid message type: %d", m.t)
+	}
+
+	if len(m.d) == 0 {
+		return KeyboardMacroTokenState{Token: uuid.Nil}, nil
+	}
+
+	if len(m.d) != 16 {
+		return KeyboardMacroTokenState{}, fmt.Errorf("invalid UUID length: %d", len(m.d))
+	}
+
+	token, err := uuid.FromBytes(m.d)
+	if err != nil {
+		return KeyboardMacroTokenState{}, fmt.Errorf("invalid UUID: %v", err)
+	}
+
+	return KeyboardMacroTokenState{Token: token}, nil
+}