nick/amethyst
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases 1 Wiki Activity

update logging to new style

Browse Source
This commit is contained in:
davotoula
2026-03-30 14:50:42 +02:00
parent 17f071b0f4
commit 40ce80786e
7 changed files with 64 additions and 64 deletions
Download Patch File Download Diff File Expand all files Collapse all files
amethyst/src/main/java/com/vitorpamplona/amethyst/ui/screen/loggedIn/chess/ChessViewModelNew.kt
+3 -3
View File
@@ -99,7 +99,7 @@ class ChessViewModelNew(
// ============================================ // ============================================
init { init {
Log.d("chessdebug", "[AndroidVM] init: instanceId=$instanceId, userPubkey=${account.userProfile().pubkeyHex.take(8)}") Log.d("chessdebug") { "[AndroidVM] init: instanceId=$instanceId, userPubkey=${account.userProfile().pubkeyHex.take(8)}" }
logic.startPolling() logic.startPolling()
} }
@@ -144,10 +144,10 @@ class ChessViewModelNew(
if (event.kind != JesterProtocol.KIND) return if (event.kind != JesterProtocol.KIND) return
val jesterEvent = val jesterEvent =
event.toJesterEvent() ?: run { event.toJesterEvent() ?: run {
Log.d("chessdebug", "[AndroidVM] handleIncomingEvent: failed to parse kind ${event.kind} event ${event.id.take(8)} as JesterEvent") Log.d("chessdebug") { "[AndroidVM] handleIncomingEvent: failed to parse kind ${event.kind} event ${event.id.take(8)} as JesterEvent" }
return return
} }
Log.d("chessdebug", "[AndroidVM] handleIncomingEvent: id=${event.id.take(8)}, pubkey=${event.pubKey.take(8)}, isStart=${jesterEvent.isStartEvent()}, isMove=${jesterEvent.isMoveEvent()}") Log.d("chessdebug") { "[AndroidVM] handleIncomingEvent: id=${event.id.take(8)}, pubkey=${event.pubKey.take(8)}, isStart=${jesterEvent.isStartEvent()}, isMove=${jesterEvent.isMoveEvent()}" }
logic.handleIncomingEvent(jesterEvent) logic.handleIncomingEvent(jesterEvent)
} }
amethyst/src/main/java/com/vitorpamplona/amethyst/ui/screen/loggedIn/chess/datasource/ChessFeedFilterSubAssembler.kt
+2 -2
View File
@@ -25,7 +25,7 @@ import com.vitorpamplona.amethyst.service.relays.SincePerRelayMap
import com.vitorpamplona.quartz.nip01Core.core.Event import com.vitorpamplona.quartz.nip01Core.core.Event
import com.vitorpamplona.quartz.nip01Core.relay.client.INostrClient import com.vitorpamplona.quartz.nip01Core.relay.client.INostrClient
import com.vitorpamplona.quartz.nip01Core.relay.client.pool.RelayBasedFilter import com.vitorpamplona.quartz.nip01Core.relay.client.pool.RelayBasedFilter
import com.vitorpamplona.quartz.nip01Core.relay.client.reqs.IRequestListener import com.vitorpamplona.quartz.nip01Core.relay.client.reqs.SubscriptionListener
import com.vitorpamplona.quartz.nip01Core.relay.client.subscriptions.Subscription import com.vitorpamplona.quartz.nip01Core.relay.client.subscriptions.Subscription
import com.vitorpamplona.quartz.nip01Core.relay.filters.Filter import com.vitorpamplona.quartz.nip01Core.relay.filters.Filter
import com.vitorpamplona.quartz.nip01Core.relay.normalizer.NormalizedRelayUrl import com.vitorpamplona.quartz.nip01Core.relay.normalizer.NormalizedRelayUrl
@@ -62,7 +62,7 @@ class ChessFeedFilterSubAssembler(
override fun newSub(key: ChessQueryState): Subscription = override fun newSub(key: ChessQueryState): Subscription =
requestNewSubscription( requestNewSubscription(
object : IRequestListener { object : SubscriptionListener {
override fun onEose( override fun onEose(
relay: NormalizedRelayUrl, relay: NormalizedRelayUrl,
forFilters: List<Filter>?, forFilters: List<Filter>?,
commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/chess/ChessEventCollector.kt
+7 -7
View File
@@ -90,7 +90,7 @@ class ChessEventCollector(
*/ */
fun addEvent(event: JesterEvent): Boolean { fun addEvent(event: JesterEvent): Boolean {
if (processedEventIds.contains(event.id)) { if (processedEventIds.contains(event.id)) {
Log.d("chessdebug", "[Collector] DEDUP: event ${event.id.take(8)} already processed for game ${startEventId.take(8)}") Log.d("chessdebug") { "[Collector] DEDUP: event ${event.id.take(8)} already processed for game ${startEventId.take(8)}" }
return false return false
} }
@@ -100,7 +100,7 @@ class ChessEventCollector(
val isMoveEvent = event.isMoveEvent() && eventStartId == startEventId val isMoveEvent = event.isMoveEvent() && eventStartId == startEventId
if (!isStartEvent && !isMoveEvent) { if (!isStartEvent && !isMoveEvent) {
Log.d("chessdebug", "[Collector] REJECTED: event ${event.id.take(8)} not for game ${startEventId.take(8)} (isStart=$isStartEvent, isMove=$isMoveEvent, eventStartId=${eventStartId?.take(8)})") Log.d("chessdebug") { "[Collector] REJECTED: event ${event.id.take(8)} not for game ${startEventId.take(8)} (isStart=$isStartEvent, isMove=$isMoveEvent, eventStartId=${eventStartId?.take(8)})" }
return false return false
} }
@@ -136,7 +136,7 @@ class ChessEventCollector(
if (_startEvent.compareAndSet(null, event)) { if (_startEvent.compareAndSet(null, event)) {
processedEventIds.add(event.id) processedEventIds.add(event.id)
incrementEventCount() incrementEventCount()
Log.d("chessdebug", "[Collector] START event added: id=${event.id.take(8)}, pubkey=${event.pubKey.take(8)}, createdAt=${event.createdAt}") Log.d("chessdebug") { "[Collector] START event added: id=${event.id.take(8)}, pubkey=${event.pubKey.take(8)}, createdAt=${event.createdAt}" }
return true return true
} }
return false return false
@@ -156,7 +156,7 @@ class ChessEventCollector(
if (moves.putIfAbsent(event.id, event) == null) { if (moves.putIfAbsent(event.id, event) == null) {
processedEventIds.add(event.id) processedEventIds.add(event.id)
incrementEventCount() incrementEventCount()
Log.d("chessdebug", "[Collector] MOVE event added: id=${event.id.take(8)}, pubkey=${event.pubKey.take(8)}, move=${event.move()}, historySize=${event.history().size}, fen=${event.fen()?.take(30)}, result=${event.result()}, totalMoves=${moves.size}") Log.d("chessdebug") { "[Collector] MOVE event added: id=${event.id.take(8)}, pubkey=${event.pubKey.take(8)}, move=${event.move()}, historySize=${event.history().size}, fen=${event.fen()?.take(30)}, result=${event.result()}, totalMoves=${moves.size}" }
return true return true
} }
return false return false
@@ -263,7 +263,7 @@ class ChessEventCollectorManager {
fun addEvent(event: JesterEvent): Boolean { fun addEvent(event: JesterEvent): Boolean {
// For start events, create collector with event ID // For start events, create collector with event ID
if (event.isStartEvent()) { if (event.isStartEvent()) {
Log.d("chessdebug", "[CollectorMgr] Routing START event ${event.id.take(8)} from ${event.pubKey.take(8)}") Log.d("chessdebug") { "[CollectorMgr] Routing START event ${event.id.take(8)} from ${event.pubKey.take(8)}" }
val collector = getOrCreate(event.id) val collector = getOrCreate(event.id)
return collector.addEvent(event) return collector.addEvent(event)
} }
@@ -271,12 +271,12 @@ class ChessEventCollectorManager {
// For move events, find the collector by startEventId // For move events, find the collector by startEventId
val startId = val startId =
event.startEventId() ?: run { event.startEventId() ?: run {
Log.d("chessdebug", "[CollectorMgr] REJECTED: move event ${event.id.take(8)} has no startEventId") Log.d("chessdebug") { "[CollectorMgr] REJECTED: move event ${event.id.take(8)} has no startEventId" }
return false return false
} }
val collector = val collector =
collectors[startId] ?: run { collectors[startId] ?: run {
Log.d("chessdebug", "[CollectorMgr] REJECTED: no collector for game ${startId.take(8)} (active games: ${collectors.keys.map { it.take(8) }})") Log.d("chessdebug") { "[CollectorMgr] REJECTED: no collector for game ${startId.take(8)} (active games: ${collectors.keys.map { it.take(8) }})" }
return false return false
} }
return collector.addEvent(event) return collector.addEvent(event)
commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/chess/ChessEventPolling.kt
+4 -4
View File
@@ -172,10 +172,10 @@ class ChessPollingDelegate(
*/ */
fun start() { fun start() {
if (_isPolling.value) { if (_isPolling.value) {
Log.d("chessdebug", "[Polling] start: already polling, skipping") Log.d("chessdebug") { "[Polling] start: already polling, skipping" }
return return
} }
Log.d("chessdebug", "[Polling] start: gameInterval=${config.activeGamePollInterval}ms, challengeInterval=${config.challengePollInterval}ms") Log.d("chessdebug") { "[Polling] start: gameInterval=${config.activeGamePollInterval}ms, challengeInterval=${config.challengePollInterval}ms" }
_isPolling.value = true _isPolling.value = true
// Poll for active games // Poll for active games
@@ -184,11 +184,11 @@ class ChessPollingDelegate(
while (isActive) { while (isActive) {
val gameIds = getEffectiveGameIds() val gameIds = getEffectiveGameIds()
if (gameIds.isNotEmpty()) { if (gameIds.isNotEmpty()) {
Log.d("chessdebug", "[Polling] polling ${gameIds.size} games: ${gameIds.map { it.take(8) }}, focused=${_focusedGameId.value?.take(8)}") Log.d("chessdebug") { "[Polling] polling ${gameIds.size} games: ${gameIds.map { it.take(8) }}, focused=${_focusedGameId.value?.take(8)}" }
try { try {
onRefreshGames(gameIds) onRefreshGames(gameIds)
} catch (e: Exception) { } catch (e: Exception) {
Log.d("chessdebug", "[Polling] ERROR during game refresh: ${e.message}") Log.d("chessdebug") { "[Polling] ERROR during game refresh: ${e.message}" }
} }
} }
delay(config.activeGamePollInterval) delay(config.activeGamePollInterval)
commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/chess/ChessGameLoader.kt
+8 -8
View File
@@ -65,7 +65,7 @@ object ChessGameLoader {
viewerPubkey: String, viewerPubkey: String,
): LiveChessGameState? { ): LiveChessGameState? {
if (result !is ReconstructionResult.Success) { if (result !is ReconstructionResult.Success) {
Log.d("chessdebug", "[GameLoader] toLiveGameState: reconstruction was not successful") Log.d("chessdebug") { "[GameLoader] toLiveGameState: reconstruction was not successful" }
return null return null
} }
@@ -79,7 +79,7 @@ object ChessGameLoader {
ViewerRole.SPECTATOR -> viewerPubkey to (state.blackPubkey ?: "") ViewerRole.SPECTATOR -> viewerPubkey to (state.blackPubkey ?: "")
} }
Log.d("chessdebug", "[GameLoader] toLiveGameState: game=${state.startEventId.take(8)}, role=${state.viewerRole}, color=${state.playerColor}, isSpectator=${state.viewerRole == ViewerRole.SPECTATOR}, isPending=${state.isPendingChallenge}, moves=${state.moveHistory.size}") Log.d("chessdebug") { "[GameLoader] toLiveGameState: game=${state.startEventId.take(8)}, role=${state.viewerRole}, color=${state.playerColor}, isSpectator=${state.viewerRole == ViewerRole.SPECTATOR}, isPending=${state.isPendingChallenge}, moves=${state.moveHistory.size}" }
return LiveChessGameState( return LiveChessGameState(
startEventId = state.startEventId, startEventId = state.startEventId,
@@ -98,7 +98,7 @@ object ChessGameLoader {
// Mark finished if the game has ended // Mark finished if the game has ended
if (state.isFinished() && state.gameStatus is com.vitorpamplona.quartz.nip64Chess.GameStatus.Finished) { if (state.isFinished() && state.gameStatus is com.vitorpamplona.quartz.nip64Chess.GameStatus.Finished) {
val gameResult = (state.gameStatus as com.vitorpamplona.quartz.nip64Chess.GameStatus.Finished).result val gameResult = (state.gameStatus as com.vitorpamplona.quartz.nip64Chess.GameStatus.Finished).result
Log.d("chessdebug", "[GameLoader] Marking game ${state.startEventId.take(8)} as finished: $gameResult") Log.d("chessdebug") { "[GameLoader] Marking game ${state.startEventId.take(8)} as finished: $gameResult" }
gameState.markAsFinished(gameResult) gameState.markAsFinished(gameResult)
} }
@@ -121,23 +121,23 @@ object ChessGameLoader {
events: JesterGameEvents, events: JesterGameEvents,
viewerPubkey: String, viewerPubkey: String,
): LoadGameResult { ): LoadGameResult {
Log.d("chessdebug", "[GameLoader] loadGame: startEvent=${events.startEvent?.id?.take(8)}, moves=${events.moves.size}, viewer=${viewerPubkey.take(8)}") Log.d("chessdebug") { "[GameLoader] loadGame: startEvent=${events.startEvent?.id?.take(8)}, moves=${events.moves.size}, viewer=${viewerPubkey.take(8)}" }
val result = ChessStateReconstructor.reconstruct(events, viewerPubkey) val result = ChessStateReconstructor.reconstruct(events, viewerPubkey)
return when (result) { return when (result) {
is ReconstructionResult.Success -> { is ReconstructionResult.Success -> {
val liveState = toLiveGameState(result, viewerPubkey) val liveState = toLiveGameState(result, viewerPubkey)
if (liveState != null) { if (liveState != null) {
Log.d("chessdebug", "[GameLoader] loadGame SUCCESS: game=${result.state.startEventId.take(8)}, status=${result.state.gameStatus}") Log.d("chessdebug") { "[GameLoader] loadGame SUCCESS: game=${result.state.startEventId.take(8)}, status=${result.state.gameStatus}" }
LoadGameResult.Success(liveState, result.state) LoadGameResult.Success(liveState, result.state)
} else { } else {
Log.d("chessdebug", "[GameLoader] loadGame FAILED: could not convert to live state") Log.d("chessdebug") { "[GameLoader] loadGame FAILED: could not convert to live state" }
LoadGameResult.Error("Failed to convert reconstructed state to live state") LoadGameResult.Error("Failed to convert reconstructed state to live state")
} }
} }
is ReconstructionResult.Error -> { is ReconstructionResult.Error -> {
Log.d("chessdebug", "[GameLoader] loadGame ERROR: ${result.message}") Log.d("chessdebug") { "[GameLoader] loadGame ERROR: ${result.message}" }
LoadGameResult.Error(result.message) LoadGameResult.Error(result.message)
} }
} }
@@ -159,7 +159,7 @@ object ChessGameLoader {
playerColor: Color, playerColor: Color,
isPendingChallenge: Boolean = false, isPendingChallenge: Boolean = false,
): LiveChessGameState { ): LiveChessGameState {
Log.d("chessdebug", "[GameLoader] createNewGame: game=${startEventId.take(8)}, player=${playerPubkey.take(8)}, opponent=${opponentPubkey.take(8)}, color=$playerColor, isPending=$isPendingChallenge") Log.d("chessdebug") { "[GameLoader] createNewGame: game=${startEventId.take(8)}, player=${playerPubkey.take(8)}, opponent=${opponentPubkey.take(8)}, color=$playerColor, isPending=$isPendingChallenge" }
val engine = ChessEngine() val engine = ChessEngine()
engine.reset() engine.reset()
commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/chess/ChessLobbyLogic.kt
+36 -36
View File
@@ -217,7 +217,7 @@ class ChessLobbyLogic(
} }
} }
Log.d("chessdebug", "[Lobby] handleIncomingEvent: id=${event.id.take(8)}, pubkey=${event.pubKey.take(8)}, isStart=${event.isStartEvent()}, isMove=${event.isMoveEvent()}, createdAt=${event.createdAt}") Log.d("chessdebug") { "[Lobby] handleIncomingEvent: id=${event.id.take(8)}, pubkey=${event.pubKey.take(8)}, isStart=${event.isStartEvent()}, isMove=${event.isMoveEvent()}, createdAt=${event.createdAt}" }
when { when {
event.isStartEvent() -> handleStartEvent(event) event.isStartEvent() -> handleStartEvent(event)
event.isMoveEvent() -> handleMoveEvent(event) event.isMoveEvent() -> handleMoveEvent(event)
@@ -228,7 +228,7 @@ class ChessLobbyLogic(
val startEventId = event.id val startEventId = event.id
val challengerColor = event.playerColor() ?: Color.WHITE val challengerColor = event.playerColor() ?: Color.WHITE
Log.d("chessdebug", "[Lobby] handleStartEvent: game=${startEventId.take(8)}, challenger=${event.pubKey.take(8)}, color=$challengerColor, opponent=${event.opponentPubkey()?.take(8)}") Log.d("chessdebug") { "[Lobby] handleStartEvent: game=${startEventId.take(8)}, challenger=${event.pubKey.take(8)}, color=$challengerColor, opponent=${event.opponentPubkey()?.take(8)}" }
val challenge = val challenge =
ChessChallenge( ChessChallenge(
@@ -247,23 +247,23 @@ class ChessLobbyLogic(
private fun handleMoveEvent(event: JesterEvent) { private fun handleMoveEvent(event: JesterEvent) {
val startEventId = val startEventId =
event.startEventId() ?: run { event.startEventId() ?: run {
Log.d("chessdebug", "[Lobby] handleMoveEvent: REJECTED - no startEventId for event ${event.id.take(8)}") Log.d("chessdebug") { "[Lobby] handleMoveEvent: REJECTED - no startEventId for event ${event.id.take(8)}" }
return return
} }
val san = val san =
event.move() ?: run { event.move() ?: run {
Log.d("chessdebug", "[Lobby] handleMoveEvent: REJECTED - no move in event ${event.id.take(8)}") Log.d("chessdebug") { "[Lobby] handleMoveEvent: REJECTED - no move in event ${event.id.take(8)}" }
return return
} }
val fen = val fen =
event.fen() ?: run { event.fen() ?: run {
Log.d("chessdebug", "[Lobby] handleMoveEvent: REJECTED - no FEN in event ${event.id.take(8)}") Log.d("chessdebug") { "[Lobby] handleMoveEvent: REJECTED - no FEN in event ${event.id.take(8)}" }
return return
} }
val history = event.history() val history = event.history()
val moveNumber = history.size val moveNumber = history.size
Log.d("chessdebug", "[Lobby] handleMoveEvent: game=${startEventId.take(8)}, move=$san, moveNumber=$moveNumber, from=${event.pubKey.take(8)}, result=${event.result()}") Log.d("chessdebug") { "[Lobby] handleMoveEvent: game=${startEventId.take(8)}, move=$san, moveNumber=$moveNumber, from=${event.pubKey.take(8)}, result=${event.result()}" }
// Check if this is our game (we're either the author or tagged as opponent) // Check if this is our game (we're either the author or tagged as opponent)
val opponentFromTag = event.opponentPubkey() val opponentFromTag = event.opponentPubkey()
@@ -274,13 +274,13 @@ class ChessLobbyLogic(
// If this is our game but we haven't loaded it yet, load it now // If this is our game but we haven't loaded it yet, load it now
// This happens when someone accepts our challenge (makes first move) // This happens when someone accepts our challenge (makes first move)
if (gameState == null && isOurGame) { if (gameState == null && isOurGame) {
Log.d("chessdebug", "[Lobby] handleMoveEvent: game ${startEventId.take(8)} not loaded but is ours - calling handleGameAccepted") Log.d("chessdebug") { "[Lobby] handleMoveEvent: game ${startEventId.take(8)} not loaded but is ours - calling handleGameAccepted" }
handleGameAccepted(startEventId) handleGameAccepted(startEventId)
return // handleGameAccepted will load the game and poll for events return // handleGameAccepted will load the game and poll for events
} }
if (gameState == null) { if (gameState == null) {
Log.d("chessdebug", "[Lobby] handleMoveEvent: game ${startEventId.take(8)} not loaded and not ours - ignoring") Log.d("chessdebug") { "[Lobby] handleMoveEvent: game ${startEventId.take(8)} not loaded and not ours - ignoring" }
return return
} }
@@ -295,7 +295,7 @@ class ChessLobbyLogic(
else -> null else -> null
} }
if (gameResult != null) { if (gameResult != null) {
Log.d("chessdebug", "[Lobby] handleMoveEvent: game ${startEventId.take(8)} ENDED: $result, termination=${event.termination()}") Log.d("chessdebug") { "[Lobby] handleMoveEvent: game ${startEventId.take(8)} ENDED: $result, termination=${event.termination()}" }
gameState.markAsFinished(gameResult) gameState.markAsFinished(gameResult)
state.moveToCompleted(startEventId, result, event.termination()) state.moveToCompleted(startEventId, result, event.termination())
pollingDelegate.removeGameId(startEventId) pollingDelegate.removeGameId(startEventId)
@@ -305,12 +305,12 @@ class ChessLobbyLogic(
// Only apply opponent moves optimistically // Only apply opponent moves optimistically
if (event.pubKey != userPubkey) { if (event.pubKey != userPubkey) {
Log.d("chessdebug", "[Lobby] handleMoveEvent: applying opponent move $san (move #$moveNumber) to game ${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] handleMoveEvent: applying opponent move $san (move #$moveNumber) to game ${startEventId.take(8)}" }
gameState.applyOpponentMove(san, fen, moveNumber) gameState.applyOpponentMove(san, fen, moveNumber)
// Update head event ID for move linking // Update head event ID for move linking
gameState.updateHeadEventId(event.id) gameState.updateHeadEventId(event.id)
} else { } else {
Log.d("chessdebug", "[Lobby] handleMoveEvent: skipping own move $san for game ${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] handleMoveEvent: skipping own move $san for game ${startEventId.take(8)}" }
} }
} }
@@ -323,7 +323,7 @@ class ChessLobbyLogic(
playerColor: Color = Color.WHITE, playerColor: Color = Color.WHITE,
timeControl: String? = null, // Not supported in Jester, kept for API compatibility timeControl: String? = null, // Not supported in Jester, kept for API compatibility
) { ) {
Log.d("chessdebug", "[Lobby] createChallenge: opponent=${opponentPubkey?.take(8)}, color=$playerColor") Log.d("chessdebug") { "[Lobby] createChallenge: opponent=${opponentPubkey?.take(8)}, color=$playerColor" }
scope.launch(Dispatchers.Default) { scope.launch(Dispatchers.Default) {
state.setBroadcastStatus( state.setBroadcastStatus(
ChessBroadcastStatus.Broadcasting( ChessBroadcastStatus.Broadcasting(
@@ -336,7 +336,7 @@ class ChessLobbyLogic(
val startEventId = retryWithBackoffResult { publisher.publishStart(playerColor, opponentPubkey) } val startEventId = retryWithBackoffResult { publisher.publishStart(playerColor, opponentPubkey) }
if (startEventId != null) { if (startEventId != null) {
Log.d("chessdebug", "[Lobby] createChallenge SUCCESS: startEventId=${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] createChallenge SUCCESS: startEventId=${startEventId.take(8)}" }
// Add challenge to local state - shows in "Your Challenges" section // Add challenge to local state - shows in "Your Challenges" section
val challenge = val challenge =
ChessChallenge( ChessChallenge(
@@ -359,7 +359,7 @@ class ChessLobbyLogic(
state.setBroadcastStatus(ChessBroadcastStatus.Idle) state.setBroadcastStatus(ChessBroadcastStatus.Idle)
state.setError(null) state.setError(null)
} else { } else {
Log.d("chessdebug", "[Lobby] createChallenge FAILED: publish returned null") Log.d("chessdebug") { "[Lobby] createChallenge FAILED: publish returned null" }
state.setBroadcastStatus( state.setBroadcastStatus(
ChessBroadcastStatus.Failed("Challenge", "Failed to publish"), ChessBroadcastStatus.Failed("Challenge", "Failed to publish"),
) )
@@ -375,7 +375,7 @@ class ChessLobbyLogic(
* In Jester protocol, acceptance is implicit - we just track the game locally. * In Jester protocol, acceptance is implicit - we just track the game locally.
*/ */
fun acceptChallenge(challenge: ChessChallenge) { fun acceptChallenge(challenge: ChessChallenge) {
Log.d("chessdebug", "[Lobby] acceptChallenge: game=${challenge.gameId.take(8)}, challenger=${challenge.challengerPubkey.take(8)}, color=${challenge.challengerColor.opposite()}") Log.d("chessdebug") { "[Lobby] acceptChallenge: game=${challenge.gameId.take(8)}, challenger=${challenge.challengerPubkey.take(8)}, color=${challenge.challengerColor.opposite()}" }
// Mark as accepted SYNCHRONOUSLY before launching coroutine // Mark as accepted SYNCHRONOUSLY before launching coroutine
// This prevents race where navigation happens before coroutine runs, // This prevents race where navigation happens before coroutine runs,
// which would cause loadGame() to incorrectly mark as spectator // which would cause loadGame() to incorrectly mark as spectator
@@ -440,24 +440,24 @@ class ChessLobbyLogic(
// Skip if already loaded or in-flight (multiple move events from same game trigger this) // Skip if already loaded or in-flight (multiple move events from same game trigger this)
val lastLoaded = recentlyLoadedGames[startEventId] val lastLoaded = recentlyLoadedGames[startEventId]
if (lastLoaded != null && (TimeUtils.now() - lastLoaded) < 10) { if (lastLoaded != null && (TimeUtils.now() - lastLoaded) < 10) {
Log.d("chessdebug", "[Lobby] handleGameAccepted: SKIPPED game ${startEventId.take(8)} - loaded ${TimeUtils.now() - lastLoaded}s ago") Log.d("chessdebug") { "[Lobby] handleGameAccepted: SKIPPED game ${startEventId.take(8)} - loaded ${TimeUtils.now() - lastLoaded}s ago" }
return return
} }
// Mark immediately to prevent concurrent launches // Mark immediately to prevent concurrent launches
recentlyLoadedGames[startEventId] = TimeUtils.now() recentlyLoadedGames[startEventId] = TimeUtils.now()
Log.d("chessdebug", "[Lobby] handleGameAccepted: game ${startEventId.take(8)} - fetching from relays") Log.d("chessdebug") { "[Lobby] handleGameAccepted: game ${startEventId.take(8)} - fetching from relays" }
scope.launch(Dispatchers.Default) { scope.launch(Dispatchers.Default) {
state.setBroadcastStatus(ChessBroadcastStatus.Syncing(0f)) state.setBroadcastStatus(ChessBroadcastStatus.Syncing(0f))
val events = fetcher.fetchGameEvents(startEventId) val events = fetcher.fetchGameEvents(startEventId)
Log.d("chessdebug", "[Lobby] handleGameAccepted: fetched ${events.moves.size} moves for game ${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] handleGameAccepted: fetched ${events.moves.size} moves for game ${startEventId.take(8)}" }
val result = ChessGameLoader.loadGame(events, userPubkey) val result = ChessGameLoader.loadGame(events, userPubkey)
when (result) { when (result) {
is LoadGameResult.Success -> { is LoadGameResult.Success -> {
recentlyLoadedGames[startEventId] = TimeUtils.now() recentlyLoadedGames[startEventId] = TimeUtils.now()
Log.d("chessdebug", "[Lobby] handleGameAccepted SUCCESS: game ${startEventId.take(8)}, role=${result.reconstructedState.viewerRole}") Log.d("chessdebug") { "[Lobby] handleGameAccepted SUCCESS: game ${startEventId.take(8)}, role=${result.reconstructedState.viewerRole}" }
state.addActiveGame(startEventId, result.liveState) state.addActiveGame(startEventId, result.liveState)
pollingDelegate.addGameId(startEventId) pollingDelegate.addGameId(startEventId)
state.setBroadcastStatus(ChessBroadcastStatus.Idle) state.setBroadcastStatus(ChessBroadcastStatus.Idle)
@@ -465,7 +465,7 @@ class ChessLobbyLogic(
} }
is LoadGameResult.Error -> { is LoadGameResult.Error -> {
Log.d("chessdebug", "[Lobby] handleGameAccepted FAILED: game ${startEventId.take(8)}, error=${result.message}") Log.d("chessdebug") { "[Lobby] handleGameAccepted FAILED: game ${startEventId.take(8)}, error=${result.message}" }
state.setError("Failed to load game: ${result.message}") state.setError("Failed to load game: ${result.message}")
state.setBroadcastStatus(ChessBroadcastStatus.Idle) state.setBroadcastStatus(ChessBroadcastStatus.Idle)
} }
@@ -482,15 +482,15 @@ class ChessLobbyLogic(
from: String, from: String,
to: String, to: String,
) { ) {
Log.d("chessdebug", "[Lobby] publishMove: game=${startEventId.take(8)}, from=$from, to=$to") Log.d("chessdebug") { "[Lobby] publishMove: game=${startEventId.take(8)}, from=$from, to=$to" }
val gameState = val gameState =
state.getGameState(startEventId) ?: run { state.getGameState(startEventId) ?: run {
Log.d("chessdebug", "[Lobby] publishMove: REJECTED - no game state for ${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] publishMove: REJECTED - no game state for ${startEventId.take(8)}" }
return return
} }
if (state.isSpectating(startEventId)) { if (state.isSpectating(startEventId)) {
Log.d("chessdebug", "[Lobby] publishMove: REJECTED - spectating game ${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] publishMove: REJECTED - spectating game ${startEventId.take(8)}" }
state.setError("Cannot move while spectating") state.setError("Cannot move while spectating")
return return
} }
@@ -500,11 +500,11 @@ class ChessLobbyLogic(
val moveResult = val moveResult =
gameState.makeMove(from, actualTo, promotion) ?: run { gameState.makeMove(from, actualTo, promotion) ?: run {
Log.d("chessdebug", "[Lobby] publishMove: REJECTED - makeMove returned null for $from->$actualTo in game ${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] publishMove: REJECTED - makeMove returned null for $from->$actualTo in game ${startEventId.take(8)}" }
return return
} }
Log.d("chessdebug", "[Lobby] publishMove: move validated: san=${moveResult.san}, fen=${moveResult.fen.take(30)}, history=${moveResult.history.size} moves, headEvent=${moveResult.headEventId.take(8)}") Log.d("chessdebug") { "[Lobby] publishMove: move validated: san=${moveResult.san}, fen=${moveResult.fen.take(30)}, history=${moveResult.history.size} moves, headEvent=${moveResult.headEventId.take(8)}" }
scope.launch(Dispatchers.Default) { scope.launch(Dispatchers.Default) {
state.setBroadcastStatus( state.setBroadcastStatus(
@@ -518,7 +518,7 @@ class ChessLobbyLogic(
val newEventId = retryWithBackoffResult { publisher.publishMove(moveResult) } val newEventId = retryWithBackoffResult { publisher.publishMove(moveResult) }
if (newEventId != null) { if (newEventId != null) {
Log.d("chessdebug", "[Lobby] publishMove SUCCESS: newEventId=${newEventId.take(8)} for game ${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] publishMove SUCCESS: newEventId=${newEventId.take(8)} for game ${startEventId.take(8)}" }
// Update head event ID for next move linking // Update head event ID for next move linking
gameState.updateHeadEventId(newEventId) gameState.updateHeadEventId(newEventId)
@@ -537,7 +537,7 @@ class ChessLobbyLogic(
) )
state.setError(null) state.setError(null)
} else { } else {
Log.d("chessdebug", "[Lobby] publishMove FAILED: reverting move ${moveResult.san} for game ${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] publishMove FAILED: reverting move ${moveResult.san} for game ${startEventId.take(8)}" }
// Revert the move since publishing failed // Revert the move since publishing failed
gameState.undoLastMove() gameState.undoLastMove()
@@ -550,7 +550,7 @@ class ChessLobbyLogic(
} }
fun resign(startEventId: String) { fun resign(startEventId: String) {
Log.d("chessdebug", "[Lobby] resign: game=${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] resign: game=${startEventId.take(8)}" }
val gameState = state.getGameState(startEventId) ?: return val gameState = state.getGameState(startEventId) ?: return
if (state.isSpectating(startEventId)) { if (state.isSpectating(startEventId)) {
@@ -599,7 +599,7 @@ class ChessLobbyLogic(
} }
fun loadGameAsSpectator(startEventId: String) { fun loadGameAsSpectator(startEventId: String) {
Log.d("chessdebug", "[Lobby] loadGameAsSpectator: game=${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] loadGameAsSpectator: game=${startEventId.take(8)}" }
scope.launch(Dispatchers.Default) { scope.launch(Dispatchers.Default) {
state.setBroadcastStatus(ChessBroadcastStatus.Syncing(0f)) state.setBroadcastStatus(ChessBroadcastStatus.Syncing(0f))
@@ -626,11 +626,11 @@ class ChessLobbyLogic(
} }
fun loadGame(startEventId: String) { fun loadGame(startEventId: String) {
Log.d("chessdebug", "[Lobby] loadGame: game=${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] loadGame: game=${startEventId.take(8)}" }
scope.launch(Dispatchers.Default) { scope.launch(Dispatchers.Default) {
// Don't load if game already exists or was accepted (acceptChallenge will handle it) // Don't load if game already exists or was accepted (acceptChallenge will handle it)
if (state.getGameState(startEventId) != null || state.wasAccepted(startEventId)) { if (state.getGameState(startEventId) != null || state.wasAccepted(startEventId)) {
Log.d("chessdebug", "[Lobby] loadGame: skipping - already exists or was accepted for ${startEventId.take(8)}") Log.d("chessdebug") { "[Lobby] loadGame: skipping - already exists or was accepted for ${startEventId.take(8)}" }
return@launch return@launch
} }
@@ -680,13 +680,13 @@ class ChessLobbyLogic(
// Skip if this game was just loaded (prevents duplicate fetch after discoverUserGames) // Skip if this game was just loaded (prevents duplicate fetch after discoverUserGames)
val lastLoaded = recentlyLoadedGames[startEventId] val lastLoaded = recentlyLoadedGames[startEventId]
if (lastLoaded != null && (TimeUtils.now() - lastLoaded) < 10) { if (lastLoaded != null && (TimeUtils.now() - lastLoaded) < 10) {
Log.d("chessdebug", "[Lobby] refreshGame: SKIPPED game ${startEventId.take(8)} - loaded ${TimeUtils.now() - lastLoaded}s ago") Log.d("chessdebug") { "[Lobby] refreshGame: SKIPPED game ${startEventId.take(8)} - loaded ${TimeUtils.now() - lastLoaded}s ago" }
return return
} }
// Mark immediately to prevent concurrent fetches for the same game // Mark immediately to prevent concurrent fetches for the same game
recentlyLoadedGames[startEventId] = TimeUtils.now() recentlyLoadedGames[startEventId] = TimeUtils.now()
Log.d("chessdebug", "[Lobby] refreshGame: fetching game ${startEventId.take(8)} from relays") Log.d("chessdebug") { "[Lobby] refreshGame: fetching game ${startEventId.take(8)} from relays" }
val events = fetcher.fetchGameEvents(startEventId) val events = fetcher.fetchGameEvents(startEventId)
val result = ChessGameLoader.loadGame(events, userPubkey) val result = ChessGameLoader.loadGame(events, userPubkey)
@@ -696,17 +696,17 @@ class ChessLobbyLogic(
// Check status FIRST to avoid briefly emitting a finished game through activeGames // Check status FIRST to avoid briefly emitting a finished game through activeGames
val gameStatus = result.liveState.gameStatus.value val gameStatus = result.liveState.gameStatus.value
if (gameStatus is GameStatus.Finished) { if (gameStatus is GameStatus.Finished) {
Log.d("chessdebug", "[Lobby] refreshGame: game ${startEventId.take(8)} is FINISHED (${(gameStatus as GameStatus.Finished).result}), moving to completed") Log.d("chessdebug") { "[Lobby] refreshGame: game ${startEventId.take(8)} is FINISHED (${(gameStatus as GameStatus.Finished).result}), moving to completed" }
state.moveToCompleted(startEventId, gameStatus.result.notation, null) state.moveToCompleted(startEventId, gameStatus.result.notation, null)
pollingDelegate.removeGameId(startEventId) pollingDelegate.removeGameId(startEventId)
} else { } else {
Log.d("chessdebug", "[Lobby] refreshGame: game ${startEventId.take(8)} updated, moves=${result.liveState.moveHistory.value.size}, isPlayerTurn=${result.liveState.isPlayerTurn()}") Log.d("chessdebug") { "[Lobby] refreshGame: game ${startEventId.take(8)} updated, moves=${result.liveState.moveHistory.value.size}, isPlayerTurn=${result.liveState.isPlayerTurn()}" }
state.replaceGameState(startEventId, result.liveState) state.replaceGameState(startEventId, result.liveState)
} }
} }
is LoadGameResult.Error -> { is LoadGameResult.Error -> {
Log.d("chessdebug", "[Lobby] refreshGame: ERROR for game ${startEventId.take(8)}: ${result.message}") Log.d("chessdebug") { "[Lobby] refreshGame: ERROR for game ${startEventId.take(8)}: ${result.message}" }
// Don't overwrite error for periodic refresh failures // Don't overwrite error for periodic refresh failures
} }
} }
commons/src/jvmAndroid/kotlin/com/vitorpamplona/amethyst/commons/chess/ChessEventBroadcaster.kt
+4 -4
View File
@@ -68,14 +68,14 @@ class ChessEventBroadcaster(
val targetRelays = ChessConfig.CHESS_RELAYS.map { NormalizedRelayUrl(it) }.toSet() val targetRelays = ChessConfig.CHESS_RELAYS.map { NormalizedRelayUrl(it) }.toSet()
val subId = newSubId() val subId = newSubId()
Log.d("chessdebug", "[Broadcaster] broadcast: event=${event.id.take(8)}, kind=${event.kind}, targetRelays=${targetRelays.map { it.url }}") Log.d("chessdebug") { "[Broadcaster] broadcast: event=${event.id.take(8)}, kind=${event.kind}, targetRelays=${targetRelays.map { it.url }}" }
// Step 1: Check which relays are already connected // Step 1: Check which relays are already connected
val initialConnected = client.connectedRelaysFlow().value val initialConnected = client.connectedRelaysFlow().value
val alreadyConnected = targetRelays.intersect(initialConnected) val alreadyConnected = targetRelays.intersect(initialConnected)
val needsConnection = targetRelays - alreadyConnected val needsConnection = targetRelays - alreadyConnected
Log.d("chessdebug", "[Broadcaster] connected=${alreadyConnected.map { it.url }}, needsConnection=${needsConnection.map { it.url }}") Log.d("chessdebug") { "[Broadcaster] connected=${alreadyConnected.map { it.url }}, needsConnection=${needsConnection.map { it.url }}" }
// Step 2: If some relays need connection, open a subscription to trigger it // Step 2: If some relays need connection, open a subscription to trigger it
if (needsConnection.isNotEmpty()) { if (needsConnection.isNotEmpty()) {
@@ -115,10 +115,10 @@ class ChessEventBroadcaster(
} }
// Step 3: Send the event and wait for OK responses // Step 3: Send the event and wait for OK responses
Log.d("chessdebug", "[Broadcaster] sending event ${event.id.take(8)} and waiting for OK (timeout=${timeoutSeconds}s)") Log.d("chessdebug") { "[Broadcaster] sending event ${event.id.take(8)} and waiting for OK (timeout=${timeoutSeconds}s)" }
val success = client.publishAndConfirm(event, targetRelays, timeoutSeconds) val success = client.publishAndConfirm(event, targetRelays, timeoutSeconds)
Log.d("chessdebug", "[Broadcaster] broadcast result: success=$success for event ${event.id.take(8)}") Log.d("chessdebug") { "[Broadcaster] broadcast result: success=$success for event ${event.id.take(8)}" }
// Note: publishAndConfirm only returns aggregate success (any relay accepted) // Note: publishAndConfirm only returns aggregate success (any relay accepted)
// We don't have per-relay results, so relayResults is empty // We don't have per-relay results, so relayResults is empty