From 8354bcd6163bebfa66c9ebb2056da32a187169fb Mon Sep 17 00:00:00 2001
From: Claude <noreply@anthropic.com>
Date: Thu, 2 Apr 2026 02:12:37 +0000
Subject: [PATCH] debug: add logging to trace call signaling flow

Temporary diagnostic logging to identify why calls hang at
Connecting. Logs added to:
- CallManager.onSignalingEvent: event kind, age, state
- CallController: answer received, ICE candidates (buffered vs
  direct), flush count, local ICE generation

https://claude.ai/code/session_017hZm7yu7CzmcQgZGSaqSXS
---
 .../amethyst/service/call/CallController.kt              | 9 +++++++--
 .../vitorpamplona/amethyst/commons/call/CallManager.kt   | 8 +++++++-
 2 files changed, 14 insertions(+), 3 deletions(-)

diff --git a/amethyst/src/main/java/com/vitorpamplona/amethyst/service/call/CallController.kt b/amethyst/src/main/java/com/vitorpamplona/amethyst/service/call/CallController.kt
index 728f6d1ba..bb2072cb8 100644
--- a/amethyst/src/main/java/com/vitorpamplona/amethyst/service/call/CallController.kt
+++ b/amethyst/src/main/java/com/vitorpamplona/amethyst/service/call/CallController.kt
@@ -177,6 +177,7 @@ class CallController(
     }
 
     fun onCallAnswerReceived(sdpAnswer: String) {
+        Log.d(TAG) { "Answer received, SDP length=${sdpAnswer.length}, session=${webRtcSession != null}" }
         webRtcSession?.setRemoteDescription(
             SessionDescription(SessionDescription.Type.ANSWER, sdpAnswer),
         )
@@ -188,12 +189,14 @@ class CallController(
         try {
             val candidate = parseIceCandidate(json)
             if (webRtcSession != null && remoteDescriptionSet) {
+                Log.d(TAG) { "Adding ICE candidate directly: ${candidate.sdp.take(50)}" }
                 webRtcSession?.addIceCandidate(candidate)
             } else {
+                Log.d(TAG) { "Buffering ICE candidate (session=${webRtcSession != null}, remoteSet=$remoteDescriptionSet)" }
                 pendingIceCandidates.add(candidate)
             }
-        } catch (_: Exception) {
-            // Ignore malformed ICE candidates
+        } catch (e: Exception) {
+            Log.e(TAG, "Failed to parse ICE candidate: $json", e)
         }
     }
 
@@ -201,6 +204,7 @@ class CallController(
         remoteDescriptionSet = true
         val session = webRtcSession ?: return
         val candidates = pendingIceCandidates.toList()
+        Log.d(TAG) { "Flushing ${candidates.size} buffered ICE candidates" }
         pendingIceCandidates.clear()
         candidates.forEach { session.addIceCandidate(it) }
     }
@@ -309,6 +313,7 @@ class CallController(
     }
 
     private fun onLocalIceCandidate(candidate: IceCandidate) {
+        Log.d(TAG) { "Local ICE candidate: ${candidate.sdp.take(50)}" }
         val callId = currentCallId ?: return
         val peerPubKey = currentPeerPubKey ?: return
         val candidateJson = serializeIceCandidate(candidate)
diff --git a/commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/call/CallManager.kt b/commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/call/CallManager.kt
index 8a9dd32db..83660deca 100644
--- a/commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/call/CallManager.kt
+++ b/commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/call/CallManager.kt
@@ -31,6 +31,7 @@ import com.vitorpamplona.quartz.nipACWebRtcCalls.events.CallIceCandidateEvent
 import com.vitorpamplona.quartz.nipACWebRtcCalls.events.CallOfferEvent
 import com.vitorpamplona.quartz.nipACWebRtcCalls.events.CallRejectEvent
 import com.vitorpamplona.quartz.nipACWebRtcCalls.tags.CallType
+import com.vitorpamplona.quartz.utils.Log
 import com.vitorpamplona.quartz.utils.TimeUtils
 import kotlinx.coroutines.CoroutineScope
 import kotlinx.coroutines.Job
@@ -198,9 +199,14 @@ class CallManager(
     }
 
     fun onSignalingEvent(event: Event) {
-        if (isEventTooOld(event)) return
+        if (isEventTooOld(event)) {
+            Log.d("CallManager") { "Discarding old event kind=${event.kind} age=${TimeUtils.now() - event.createdAt}s" }
+            return
+        }
         if (!processedEventIds.add(event.id)) return
 
+        Log.d("CallManager") { "Processing signaling event kind=${event.kind} id=${event.id.take(8)} state=${_state.value::class.simpleName}" }
+
         when (event) {
             is CallOfferEvent -> onIncomingCallEvent(event)
             is CallAnswerEvent -> onCallAnswered(event)