added logs

app/http.php

@@ -447,6 +447,24 @@ $http->on(Constant::EVENT_REQUEST, function (SwooleRequest $swooleRequest, Swool
     $request = new Request($swooleRequest);
     $response = new Response($swooleResponse);
 
+    // Debug incoming Origin header for HTTP requests
+    $origin = $request->getOrigin();
+    if ($origin !== '') {
+        $originHost = \parse_url($origin, PHP_URL_HOST) ?: '';
+        Console::warning(
+            '[HTTP][Origin] Incoming origin: ' . $origin .
+            ' (originHost=' . $originHost .
+            ', requestHost=' . $request->getHostname() .
+            ', uri=' . $request->getURI() . ')'
+        );
+    } else {
+        Console::warning(
+            '[HTTP][Origin] No Origin header ' .
+            '(requestHost=' . $request->getHostname() .
+            ', uri=' . $request->getURI() . ')'
+        );
+    }
+
     if (Files::isFileLoaded($request->getURI())) {
         $time = (60 * 60 * 24 * 365 * 2); // 45 days cache
 

app/realtime.php

@@ -418,8 +418,9 @@ $server->onWorkerStart(function (int $workerId) use ($server, $register, $stats,
          * Sending test message for SDK E2E tests every 5 seconds.
          */
         if ($realtime->hasSubscriber('console', Role::guests()->toString(), 'tests')) {
+            $time = (new \DateTimeImmutable())->format('Y-m-d H:i:s.v');
             $payload = ['response' => 'WS:/v1/realtime:passed'];
-
+            
             $event = [
                 'project' => 'console',
                 'roles' => [Role::guests()->toString()],
@@ -438,7 +439,7 @@ $server->onWorkerStart(function (int $workerId) use ($server, $register, $stats,
                 $data = $event['data'];
                 // Send matched subscription IDs
                 $data['subscriptions'] = array_keys($matchedSubscriptions);
-
+                Console::log("[Debug][Worker test endpoint sending time". "to connection :". $connectionId . " is" . $time);
                 $server->send([$connectionId], json_encode([
                     'type' => 'event',
                     'data' => $data
@@ -490,6 +491,7 @@ $server->onWorkerStart(function (int $workerId) use ($server, $register, $stats,
 
                         foreach ($subscriptionMetadata as $subscriptionId => $metadata) {
                             $queries = Query::parseQueries($metadata['queries'] ?? []);
+
                             $realtime->subscribe(
                                 $projectId,
                                 $connection,
@@ -498,6 +500,29 @@ $server->onWorkerStart(function (int $workerId) use ($server, $register, $stats,
                                 $metadata['channels'] ?? [],
                                 $queries
                             );
+
+                            $createdAt = new \DateTimeImmutable();
+                            $createdAtFormatted = $createdAt->format('Y-m-d H:i:s.v');
+
+                            if (!isset($realtime->connections[$connection]['subscriptionCreatedAt'])) {
+                                $realtime->connections[$connection]['subscriptionCreatedAt'] = [];
+                            }
+
+                            $realtime->connections[$connection]['subscriptionCreatedAt'][$subscriptionId] = [
+                                'timestamp' => $createdAtFormatted,
+                                'createdAtMs' => microtime(true),
+                                'channels' => $metadata['channels'] ?? [],
+                                'queries' => $metadata['queries'] ?? [],
+                            ];
+
+                            Console::info('[Realtime][Resubscribe][PermissionsChanged] '
+                                . 'time=' . $createdAtFormatted
+                                . ' projectId=' . $projectId
+                                . ' connectionId=' . $connection
+                                . ' subscriptionId=' . $subscriptionId
+                                . ' channels=' . json_encode($metadata['channels'] ?? [])
+                                . ' queries=' . json_encode($metadata['queries'] ?? [])
+                            );
                         }
 
                         // Restore authorization after subscribe
@@ -509,12 +534,21 @@ $server->onWorkerStart(function (int $workerId) use ($server, $register, $stats,
 
                 $receivers = $realtime->getSubscribers($event); // [connectionId => [subId => queries]]
 
-                if (Http::isDevelopment() && !empty($receivers)) {
-                    Console::log("[Debug][Worker {$workerId}] Receivers: " . count($receivers));
-                    Console::log("[Debug][Worker {$workerId}] Receivers Connection IDs: " . json_encode(array_keys($receivers)));
-                    Console::log("[Debug][Worker {$workerId}] Event Query: " . json_encode(array_values($receivers)));
-                    Console::log("[Debug][Worker {$workerId}] Event: " . $payload);
-                }
+                $deliveryTime = new \DateTimeImmutable();
+                $deliveryTimeFormatted = $deliveryTime->format('Y-m-d H:i:s.v');
+
+                Console::log('[Realtime][Event] '
+                    . 'workerId=' . $workerId
+                    . ' time=' . $deliveryTimeFormatted
+                    . ' projectId=' . ($event['project'] ?? '')
+                    . ' channels=' . json_encode($event['data']['channels'] ?? [])
+                    . ' events=' . json_encode($event['data']['events'] ?? [])
+                    . ' receiversCount=' . count($receivers)
+                );
+
+                Console::log('[Realtime][EventDebug] ReceiversConnectionIds=' . json_encode(array_keys($receivers)));
+                Console::log('[Realtime][EventDebug] MatchedSubscriptions=' . json_encode($receivers));
+                Console::log('[Realtime][EventDebug] RawEventPayload=' . $payload);
 
                 $totalMessages = 0;
 
@@ -523,6 +557,31 @@ $server->onWorkerStart(function (int $workerId) use ($server, $register, $stats,
                     // Send matched subscription IDs
                     $data['subscriptions'] = array_keys($matchedSubscriptions);
 
+                    // Per-subscription logging for latency & query visibility
+                    foreach ($matchedSubscriptions as $subscriptionId => $subscriptionQueries) {
+                        $subscriptionMeta = $realtime->connections[$connectionId]['subscriptionCreatedAt'][$subscriptionId] ?? null;
+                        $createdAt = $subscriptionMeta['timestamp'] ?? null;
+                        $createdAtMs = $subscriptionMeta['createdAtMs'] ?? null;
+
+                        $latencyMs = null;
+                        if ($createdAtMs !== null) {
+                            $latencyMs = (int) ((microtime(true) - $createdAtMs) * 1000);
+                        }
+
+                        Console::log('[Realtime][Delivery] '
+                            . 'time=' . $deliveryTimeFormatted
+                            . ' projectId=' . ($event['project'] ?? '')
+                            . ' connectionId=' . $connectionId
+                            . ' subscriptionId=' . $subscriptionId
+                            . ' eventChannels=' . json_encode($event['data']['channels'] ?? [])
+                            . ' eventEvents=' . json_encode($event['data']['events'] ?? [])
+                            . ' subscriptionChannels=' . json_encode($subscriptionMeta['channels'] ?? [])
+                            . ' subscriptionQueries=' . json_encode($subscriptionQueries)
+                            . ' subscriptionCreatedAt=' . ($createdAt ?? 'null')
+                            . ' subscriptionAgeMs=' . ($latencyMs !== null ? $latencyMs : 'null')
+                        );
+                    }
+
                     $server->send(
                         [$connectionId],
                         json_encode([
@@ -607,9 +666,20 @@ $server->onOpen(function (int $connection, SwooleRequest $request) use ($server,
          * Skip this check for non-web platforms which are not required to send an origin header.
          */
         $origin = $request->getOrigin();
+        $originHost = \parse_url($origin, PHP_URL_HOST) ?: '';
+        Console::warning(
+            '[Realtime][Origin] Incoming origin: ' . $origin .
+            ' (originHost=' . $originHost .
+            ', requestHost=' . $request->getHostname() .
+            ', projectId=' . $project->getId() . ')'
+        );
         $originValidator = $app->getResource('originValidator');
 
         if (!empty($origin) && !$originValidator->isValid($origin) && $project->getId() !== 'console') {
+            Console::warning(
+                '[Realtime][Origin] Origin failed validation: ' . $origin .
+                ' | reason="' . $originValidator->getDescription() . '"'
+            );
             throw new Exception(Exception::REALTIME_POLICY_VIOLATION, $originValidator->getDescription());
         }
 
@@ -641,15 +711,50 @@ $server->onOpen(function (int $connection, SwooleRequest $request) use ($server,
         foreach ($subscriptionsByIndex as $index => $subscription) {
             $subscriptionId = ID::unique();
 
+            $subscriptionChannels = $subscription['channels'];
+            $subscriptionQueriesObjects = $subscription['queries']; // array<Query>
+            $subscriptionQueries = [];
+
+            foreach ($subscriptionQueriesObjects as $queryObject) {
+                if ($queryObject instanceof Query) {
+                    $subscriptionQueries[] = $queryObject->toString();
+                }
+            }
+
+            $createdAt = new \DateTimeImmutable();
+            $createdAtFormatted = $createdAt->format('Y-m-d H:i:s.v');
+
+            Console::info('[Realtime][Subscribe] '
+                . 'time=' . $createdAtFormatted
+                . ' projectId=' . $project->getId()
+                . ' connectionId=' . $connection
+                . ' subscriptionIndex=' . $index
+                . ' subscriptionId=' . $subscriptionId
+                . ' channels=' . json_encode($subscriptionChannels)
+                . ' queries=' . json_encode($subscriptionQueries)
+            );
+
             $realtime->subscribe(
                 $project->getId(),
                 $connection,
                 $subscriptionId,
                 $roles,
-                $subscription['channels'],
+                $subscriptionChannels,
                 $subscription['queries'] // Query objects
             );
 
+            // Track subscription timing & metadata for latency / perf debugging
+            if (!isset($realtime->connections[$connection]['subscriptionCreatedAt'])) {
+                $realtime->connections[$connection]['subscriptionCreatedAt'] = [];
+            }
+
+            $realtime->connections[$connection]['subscriptionCreatedAt'][$subscriptionId] = [
+                'timestamp' => $createdAtFormatted,
+                'createdAtMs' => microtime(true),
+                'channels' => $subscriptionChannels,
+                'queries' => $subscriptionQueries,
+            ];
+
             $subscriptionMapping[$index] = $subscriptionId;
         }
 
@@ -756,6 +861,15 @@ $server->onMessage(function (int $connection, string $message) use ($server, $re
 
         switch ($message['type']) {
             case 'ping':
+                $heartbeatTime = new \DateTimeImmutable();
+                $heartbeatTimeFormatted = $heartbeatTime->format('Y-m-d H:i:s.v');
+
+                Console::log('[Realtime][Heartbeat] '
+                    . 'time=' . $heartbeatTimeFormatted
+                    . ' connectionId=' . $connection
+                    . ' projectId=' . ($projectId ?? 'unknown')
+                );
+
                 $server->send([$connection], json_encode([
                     'type' => 'pong'
                 ]));
@@ -813,6 +927,29 @@ $server->onMessage(function (int $connection, string $message) use ($server, $re
                             $metadata['channels'] ?? [],
                             $queries
                         );
+
+                        $createdAt = new \DateTimeImmutable();
+                        $createdAtFormatted = $createdAt->format('Y-m-d H:i:s.v');
+
+                        if (!isset($realtime->connections[$connection]['subscriptionCreatedAt'])) {
+                            $realtime->connections[$connection]['subscriptionCreatedAt'] = [];
+                        }
+
+                        $realtime->connections[$connection]['subscriptionCreatedAt'][$subscriptionId] = [
+                            'timestamp' => $createdAtFormatted,
+                            'createdAtMs' => microtime(true),
+                            'channels' => $metadata['channels'] ?? [],
+                            'queries' => $metadata['queries'] ?? [],
+                        ];
+
+                        Console::info('[Realtime][Resubscribe][Authentication] '
+                            . 'time=' . $createdAtFormatted
+                            . ' projectId=' . $projectId
+                            . ' connectionId=' . $connection
+                            . ' subscriptionId=' . $subscriptionId
+                            . ' channels=' . json_encode($metadata['channels'] ?? [])
+                            . ' queries=' . json_encode($metadata['queries'] ?? [])
+                        );
                     }
                 }