fix: draw offer race condition + add multiplayer logging

Root cause: draw offers stored in game_state were lost when a
concurrent move write did read→merge→write (non-atomic). Now uses
PostgreSQL jsonb || operator via merge_game_state() RPC for atomic
merges.

Also adds:
- mp_log table for server-side multiplayer event logging
- Frontend sessionStorage logging (sessionStorage.mp_log) for
  debugging draw offers, moves, and poll events
- Logging on match_created, move, resign, draw_accepted, game_state_merge
Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>

api/game.php

@@ -120,30 +120,44 @@ function handleGameMove($db, string $userId, array $input): void {
     if (isset($input['white_time_remaining_ms'])) $update['white_time_remaining_ms'] = intval($input['white_time_remaining_ms']);
     if (isset($input['black_time_remaining_ms'])) $update['black_time_remaining_ms'] = intval($input['black_time_remaining_ms']);
 
-    // Merge game_state instead of overwriting — preserves emotes, draw offers, etc.
+    // game_state: use atomic merge via DB function (prevents race conditions with draw offers, emotes)
+    $gameStatePatch = null;
     if (!empty($input['game_state'])) {
-        $newState = is_string($input['game_state']) ? (json_decode($input['game_state'], true) ?: []) : $input['game_state'];
-        $matches = $sdb->get('matches', ['id' => 'eq.' . $matchId, 'select' => 'game_state', 'limit' => 1]);
-        $existing = [];
-        if (is_array($matches) && !empty($matches) && !isset($matches['error'])) {
-            $raw = $matches[0]['game_state'] ?? null;
-            if ($raw) {
-                if (is_string($raw)) {
-                    $existing = json_decode($raw, true) ?: [];
-                } elseif (is_array($raw) && !array_is_list($raw)) {
-                    $existing = $raw;
-                } else {
-                    $existing = [];
-                }
-            }
-        }
-        $merged = array_merge($existing, $newState);
-        $update['game_state'] = $merged;
+        $gameStatePatch = is_string($input['game_state']) ? (json_decode($input['game_state'], true) ?: []) : $input['game_state'];
+    }
+
+    // If we only have game_state (no board columns), use atomic merge only
+    $hasBoardUpdate = isset($update['current_fen']) || isset($update['moves']) || isset($update['move_count']);
+
+    if ($gameStatePatch && !$hasBoardUpdate) {
+        // Pure game_state update (draw offer, emote, etc.) — use atomic merge
+        supabaseRpc('merge_game_state', [
+            'p_table' => 'matches',
+            'p_match_id' => $matchId,
+            'p_patch' => $gameStatePatch
+        ]);
+        mpLog($matchId, 'chess', $userId, 'game_state_merge', $gameStatePatch);
+        jsonResponse(['success' => true]);
+        return;
+    }
+
+    if ($gameStatePatch && $hasBoardUpdate) {
+        // Move + game_state: atomic merge game_state first, then update board columns
+        supabaseRpc('merge_game_state', [
+            'p_table' => 'matches',
+            'p_match_id' => $matchId,
+            'p_patch' => $gameStatePatch
+        ]);
     }
 
     $result = $sdb->update('matches', $update, ['id' => 'eq.' . $matchId]);
 
     if (isset($result['error'])) jsonError($result['error']);
+
+    mpLog($matchId, 'chess', $userId, 'move', [
+        'move_count' => $input['move_count'] ?? null,
+        'fen_short' => substr($input['fen'] ?? '', 0, 30)
+    ]);
     jsonResponse(['success' => true]);
 }
 
@@ -167,6 +181,7 @@ function handleResign($db, string $userId, array $input): void {
         'updated_at' => date('c')
     ], ['id' => 'eq.' . $matchId]);
 
+    mpLog($matchId, 'chess', $userId, 'resign', ['result' => $result]);
     jsonResponse(['result' => $result]);
 }
 
@@ -188,6 +203,7 @@ function handleDraw($db, string $userId, array $input): void {
         'game_state' => ['draw_accepted' => true]
     ], ['id' => 'eq.' . $matchId]);
 
+    mpLog($matchId, 'chess', $userId, 'draw_accepted', []);
     jsonResponse(['result' => 'draw']);
 }
 
@@ -444,3 +460,13 @@ function handleFindActiveMatch(string $userId, array $input): void {
 
     jsonResponse(['match_id' => null]);
 }
+
+function mpLog(string $matchId, string $gameKey, string $playerId, string $event, $payload = []): void {
+    supabaseRpc('log_mp_event', [
+        'p_match_id' => $matchId,
+        'p_game_key' => $gameKey,
+        'p_player_id' => $playerId,
+        'p_event' => $event,
+        'p_payload' => json_encode(is_array($payload) ? $payload : [])
+    ]);
+}

api/matchmaking.php

@@ -156,6 +156,10 @@ function handleQueue($db, string $userId, array $input): void {
                 'match_id' => $matchId
             ], ['id' => 'eq.' . $opponent['id']]);
 
+            mpLog($matchId, $gameKey, $userId, 'match_created', [
+                'white' => $whiteId, 'black' => $blackId, 'time_control' => $timeControl
+            ]);
+
             $myColor = $isWhite ? 'w' : 'b';
             jsonResponse(['match_id' => $matchId, 'color' => $myColor, 'opponent_id' => $opponent['player_id']]);
             return;
@@ -208,3 +212,13 @@ function handleDequeue($db, string $userId, array $input): void {
     $sdb->delete('matchmaking_queue', ['player_id' => 'eq.' . $userId]);
     jsonResponse(['success' => true]);
 }
+
+function mpLog(string $matchId, string $gameKey, string $playerId, string $event, $payload = []): void {
+    supabaseRpc('log_mp_event', [
+        'p_match_id' => $matchId,
+        'p_game_key' => $gameKey,
+        'p_player_id' => $playerId,
+        'p_event' => $event,
+        'p_payload' => is_array($payload) ? $payload : []
+    ]);
+}

public/js/modules/chess/scenes/game.js

@@ -243,10 +243,12 @@ export function mountGame(el, params) {
       }
     } else if (gameState.mode === 'live' && gameState.matchId) {
       const userId = store.get('auth.userId');
+      const drawT = Date.now();
+      mpLogFront('draw_offer_sent', { to: 'opponent', draw_offer_t: drawT });
       net.post('game.php', {
         action: 'move',
         match_id: gameState.matchId,
-        game_state: JSON.stringify({ draw_offer: userId, draw_offer_t: Date.now() })
+        game_state: JSON.stringify({ draw_offer: userId, draw_offer_t: drawT })
       });
       const msg = document.createElement('div');
       msg.textContent = 'تم إرسال عرض التعادل...';
@@ -585,10 +587,20 @@ function getEndReason() {
 // ===== LIVE MULTIPLAYER =====
 let lastKnownMoveCount = 0;
 
+function mpLogFront(event, data) {
+  try {
+    const logs = JSON.parse(sessionStorage.getItem('mp_log') || '[]');
+    logs.push({ t: Date.now(), e: event, ...data });
+    if (logs.length > 100) logs.splice(0, logs.length - 100);
+    sessionStorage.setItem('mp_log', JSON.stringify(logs));
+  } catch(e) {}
+}
+
 async function sendLiveMove(el) {
   if (!gameState.matchId) return;
   lastKnownMoveCount = gameState.moveCount;
   const lastMove = gameState.moveHistory[gameState.moveHistory.length - 1];
+  mpLogFront('move_sent', { mc: gameState.moveCount, san: lastMove?.san });
   try {
     await net.post('game.php', {
       action: 'move',
@@ -602,7 +614,9 @@ async function sendLiveMove(el) {
         last_move: lastMove ? { from: lastMove.from, to: lastMove.to, san: lastMove.san, promotion: lastMove.promotion || null } : null
       })
     });
-  } catch (e) {}
+  } catch (e) {
+    mpLogFront('move_send_error', { error: e.message });
+  }
 }
 
 function handleLivePollData(el, data) {
@@ -626,6 +640,9 @@ function handleLivePollData(el, data) {
   checkDrawOffer(el, data.game_state, myId);
   checkDrawResponse(el, data.game_state, myId);
 
+  // Multiplayer event logging (stored in sessionStorage for debugging)
+  mpLogFront('poll', { mc: data.move_count, gs_keys: data.game_state ? Object.keys(typeof data.game_state === 'string' ? JSON.parse(data.game_state) : data.game_state) : [] });
+
   // New move arrived — only process when waiting for opponent
   if (!gameState.isPlayerTurn && data.move_count > lastKnownMoveCount) {
     lastKnownMoveCount = data.move_count;
@@ -797,10 +814,15 @@ let lastDrawOfferHandled = 0;
 function checkDrawOffer(el, rawGameState, myId) {
   if (!rawGameState || gameState.gameOver) return;
   const gs = typeof rawGameState === 'string' ? JSON.parse(rawGameState) : rawGameState;
-  if (!gs || !gs.draw_offer || gs.draw_offer === myId) return;
+  if (!gs || !gs.draw_offer) return;
+  if (gs.draw_offer === myId) {
+    mpLogFront('draw_offer_skip_own', { draw_offer: gs.draw_offer });
+    return;
+  }
   const offerTime = gs.draw_offer_t || 0;
   if (offerTime <= lastDrawOfferHandled) return;
   lastDrawOfferHandled = offerTime;
+  mpLogFront('draw_offer_received', { from: gs.draw_offer, draw_offer_t: offerTime });
 
   // Show accept/deny UI
   const existing = el.querySelector('#draw-offer-dialog');