Improve logging when receiving weird to-device events

mautrix · Mar 26, 2021 · e692298 · e692298
1 parent 6002723
commit e692298
Show file tree

Hide file tree

Showing 2 changed files with 11 additions and 7 deletions.
diff --git a/crypto/keysharing.go b/crypto/keysharing.go
@@ -110,6 +110,7 @@ func (mach *OlmMachine) RequestRoomKey(ctx context.Context, toUser id.UserID, to
 
 func (mach *OlmMachine) importForwardedRoomKey(evt *DecryptedOlmEvent, content *event.ForwardedRoomKeyEventContent) bool {
 	if content.Algorithm != id.AlgorithmMegolmV1 || evt.Keys.Ed25519 == "" {
+		mach.Log.Debug("Ignoring weird forwarded room key from %s/%s: alg=%s, ed25519=%s, sessionid=%s, roomid=%s", evt.Sender, evt.SenderDevice, content.Algorithm, evt.Keys.Ed25519, content.SessionID, content.RoomID)
 		return false
 	}
 
@@ -135,7 +136,7 @@ func (mach *OlmMachine) importForwardedRoomKey(evt *DecryptedOlmEvent, content *
 		return false
 	}
 	mach.markSessionReceived(content.SessionID)
-	mach.Log.Trace("Created inbound group session %s/%s/%s", content.RoomID, content.SenderKey, content.SessionID)
+	mach.Log.Trace("Received forwarded inbound group session %s/%s/%s", content.RoomID, content.SenderKey, content.SessionID)
 	return true
 }
 

diff --git a/crypto/machine.go b/crypto/machine.go
@@ -223,23 +223,25 @@ func (mach *OlmMachine) HandleMemberEvent(evt *event.Event) {
 func (mach *OlmMachine) HandleToDeviceEvent(evt *event.Event) {
 	switch content := evt.Content.Parsed.(type) {
 	case *event.EncryptedEventContent:
-		mach.Log.Trace("Handling encrypted to-device event from %s/%s", evt.Sender, content.DeviceID)
+		mach.Log.Debug("Handling encrypted to-device event from %s/%s", evt.Sender, content.SenderKey)
 		decryptedEvt, err := mach.decryptOlmEvent(evt)
 		if err != nil {
 			mach.Log.Error("Failed to decrypt to-device event: %v", err)
 			return
 		}
-		switch content := decryptedEvt.Content.Parsed.(type) {
+		switch decryptedContent := decryptedEvt.Content.Parsed.(type) {
 		case *event.RoomKeyEventContent:
-			mach.receiveRoomKey(decryptedEvt, content)
+			mach.receiveRoomKey(decryptedEvt, decryptedContent)
 		case *event.ForwardedRoomKeyEventContent:
-			if mach.importForwardedRoomKey(decryptedEvt, content) {
-				if ch, ok := mach.roomKeyRequestFilled.Load(content.SessionID); ok {
+			if mach.importForwardedRoomKey(decryptedEvt, decryptedContent) {
+				if ch, ok := mach.roomKeyRequestFilled.Load(decryptedContent.SessionID); ok {
 					// close channel to notify listener that the key was received
 					close(ch.(chan struct{}))
 				}
 			}
-			// TODO handle m.dummy encrypted to-device event
+			// TODO handle m.dummy encrypted to-device event?
+		default:
+			mach.Log.Debug("Unhandled encrypted to-device event of type %s from %s/%s (session: %s)", decryptedEvt.Type.String(), decryptedEvt.Sender, decryptedEvt.SenderDevice, content.SessionID)
 		}
 	case *event.RoomKeyRequestEventContent:
 		mach.handleRoomKeyRequest(evt.Sender, content)
@@ -375,6 +377,7 @@ func (mach *OlmMachine) WaitForSession(roomID id.RoomID, senderKey id.SenderKey,
 func (mach *OlmMachine) receiveRoomKey(evt *DecryptedOlmEvent, content *event.RoomKeyEventContent) {
 	// TODO nio had a comment saying "handle this better" for the case where evt.Keys.Ed25519 is none?
 	if content.Algorithm != id.AlgorithmMegolmV1 || evt.Keys.Ed25519 == "" {
+		mach.Log.Debug("Ignoring weird room key from %s/%s: alg=%s, ed25519=%s, sessionid=%s, roomid=%s", evt.Sender, evt.SenderDevice, content.Algorithm, evt.Keys.Ed25519, content.SessionID, content.RoomID)
 		return
 	}