Increase operation timeout, add diagnostic logs, and enhance gateway stream summarization

This commit is contained in:
Jeppe Bundgaard
2026-04-23 21:36:25 +02:00
parent 0813bfc0f0
commit b98cef0caa
4 changed files with 182 additions and 23 deletions
+66 -8
View File
@@ -309,6 +309,35 @@ function collectMessages(rows) {
: []; : [];
} }
function summarizeStreamMessages(messages, limit = 12) {
return messages
.slice(-limit)
.map((message) => {
if (!message || typeof message !== "object") {
return null;
}
const summary = {
type: message.type || "unknown",
};
if (message.operationId !== undefined) {
summary.operationId = Number(message.operationId || 0);
}
if (message.operation && typeof message.operation === "object") {
summary.operationStatus = message.operation.status || null;
}
if (message.gateway && typeof message.gateway === "object") {
summary.gatewayStatus = message.gateway.status || null;
}
return summary;
})
.filter(Boolean);
}
async function main() { async function main() {
const scriptPath = fileURLToPath(import.meta.url); const scriptPath = fileURLToPath(import.meta.url);
const rootDir = await resolveRootDir(scriptPath); const rootDir = await resolveRootDir(scriptPath);
@@ -481,11 +510,32 @@ async function main() {
const operationId = Number(operationResponse?.data?.operation?.id || 0); const operationId = Number(operationResponse?.data?.operation?.id || 0);
assert.ok(operationId > 0, "Operation creation did not return an operation id."); assert.ok(operationId > 0, "Operation creation did not return an operation id.");
await waitForSocketMessage( try {
streamMessages, await waitForSocketMessage(
(message) => message?.type === "task.updated" && Number(message?.operationId || 0) === operationId, streamMessages,
{ timeoutMs: 30_000, message: "Live gateway stream never emitted task.updated for the queued operation." } (message) => message?.type === "task.updated" && Number(message?.operationId || 0) === operationId,
); { timeoutMs: 180_000, message: "Live gateway stream never emitted task.updated for the queued operation." }
);
} catch (error) {
let operationSnapshot = null;
try {
const operations = await apiRequest(baseUrl, "GET", `/edge-gateways/${gatewayId}/operations`, {
token: authToken,
});
operationSnapshot = Array.isArray(operations?.data)
? operations.data.find((item) => Number(item?.id || 0) === operationId) || null
: null;
} catch {
operationSnapshot = null;
}
const diagnostic = [
error instanceof Error ? error.message : String(error),
`Recent stream messages: ${JSON.stringify(summarizeStreamMessages(streamMessages))}`,
`Operation snapshot: ${JSON.stringify(operationSnapshot)}`,
].join("\n");
throw new Error(diagnostic);
}
await waitForCondition( await waitForCondition(
async () => { async () => {
@@ -499,7 +549,7 @@ async function main() {
return operation?.status === "COMPLETED"; return operation?.status === "COMPLETED";
}, },
{ timeoutMs: 30_000, message: "Gateway operation never completed through the live agent." } { timeoutMs: 180_000, message: "Gateway operation never completed through the live agent." }
); );
await waitForSocketMessage( await waitForSocketMessage(
@@ -514,9 +564,17 @@ async function main() {
token: authToken, token: authToken,
}); });
return Array.isArray(logs?.data?.log_entries) && logs.data.log_entries.length > 0; const timeline = Array.isArray(logs?.data?.entries) ? logs.data.entries : [];
return timeline.some((entry) => {
const nestedEntry = entry?.entry && typeof entry.entry === "object" ? entry.entry : null;
const directOperationId = Number(nestedEntry?.operation_id || 0);
const contextualOperationId = Number(nestedEntry?.context?.operation_id || 0);
return directOperationId === operationId || contextualOperationId === operationId;
});
}, },
{ timeoutMs: 20_000, message: "Gateway logs page never received live log entries from the running agent." } { timeoutMs: 30_000, message: "Gateway logs page never reflected the live operation timeline." }
); );
const statistics = await apiRequest(baseUrl, "GET", `/edge-gateways/${gatewayId}/statistics`, { const statistics = await apiRequest(baseUrl, "GET", `/edge-gateways/${gatewayId}/statistics`, {
File diff suppressed because one or more lines are too long
@@ -11784,3 +11784,87 @@
[Thu Apr 23 19:00:02 2026] 127.0.0.1:47412 Closing [Thu Apr 23 19:00:02 2026] 127.0.0.1:47412 Closing
[Thu Apr 23 19:00:03 2026] 127.0.0.1:47422 Accepted [Thu Apr 23 19:00:03 2026] 127.0.0.1:47422 Accepted
[Thu Apr 23 19:00:14 2026] 127.0.0.1:47422 Closing [Thu Apr 23 19:00:14 2026] 127.0.0.1:47422 Closing
[Thu Apr 23 19:23:38 2026] PHP 8.2.15 Development Server (http://127.0.0.1:41635) started
[Thu Apr 23 19:23:38 2026] PHP 8.2.15 Development Server (http://127.0.0.1:34429) started
[Thu Apr 23 19:23:38 2026] 127.0.0.1:53904 Accepted
[Thu Apr 23 19:23:38 2026] 127.0.0.1:41596 Accepted
[Thu Apr 23 19:23:39 2026] 127.0.0.1:53904 Closing
[Thu Apr 23 19:23:39 2026] 127.0.0.1:41898 Accepted
[Thu Apr 23 19:23:39 2026] 127.0.0.1:41596 Closing
[Thu Apr 23 19:23:39 2026] 127.0.0.1:33838 Accepted
[Thu Apr 23 19:23:46 2026] 127.0.0.1:33838 Closing
[Thu Apr 23 19:23:46 2026] 127.0.0.1:33852 Accepted
[Thu Apr 23 19:23:49 2026] 127.0.0.1:41898 Closing
[Thu Apr 23 19:23:49 2026] 127.0.0.1:40306 Accepted
[Thu Apr 23 19:23:56 2026] 127.0.0.1:40306 Closing
[Thu Apr 23 19:23:56 2026] 127.0.0.1:40322 Accepted
[Thu Apr 23 19:24:02 2026] 127.0.0.1:33852 Closing
[Thu Apr 23 19:24:02 2026] 127.0.0.1:47950 Accepted
[Thu Apr 23 19:24:03 2026] 127.0.0.1:40322 Closing
[Thu Apr 23 19:24:03 2026] 127.0.0.1:42110 Accepted
[Thu Apr 23 19:24:19 2026] 127.0.0.1:47950 Closing
[Thu Apr 23 19:24:19 2026] 127.0.0.1:37590 Accepted
[Thu Apr 23 19:24:23 2026] 127.0.0.1:42110 Closing
[Thu Apr 23 19:24:24 2026] 127.0.0.1:53044 Accepted
[Thu Apr 23 19:24:33 2026] 127.0.0.1:37590 Closing
[Thu Apr 23 19:24:33 2026] 127.0.0.1:45346 Accepted
[Thu Apr 23 19:24:37 2026] 127.0.0.1:53044 Closing
[Thu Apr 23 19:24:38 2026] 127.0.0.1:44010 Accepted
[Thu Apr 23 19:24:47 2026] 127.0.0.1:45346 Closing
[Thu Apr 23 19:24:47 2026] 127.0.0.1:47316 Accepted
[Thu Apr 23 19:24:51 2026] 127.0.0.1:44010 Closing
[Thu Apr 23 19:24:51 2026] 127.0.0.1:40232 Accepted
[Thu Apr 23 19:24:52 2026] 127.0.0.1:47316 Closing
[Thu Apr 23 19:24:52 2026] 127.0.0.1:40934 Accepted
[Thu Apr 23 19:25:11 2026] 127.0.0.1:40232 Closing
[Thu Apr 23 19:25:11 2026] 127.0.0.1:47766 Accepted
[Thu Apr 23 19:25:13 2026] 127.0.0.1:40934 Closing
[Thu Apr 23 19:25:13 2026] 127.0.0.1:51356 Accepted
[Thu Apr 23 19:25:19 2026] 127.0.0.1:51356 Closing
[Thu Apr 23 19:25:19 2026] 127.0.0.1:52100 Accepted
[Thu Apr 23 19:25:24 2026] 127.0.0.1:47766 Closing
[Thu Apr 23 19:25:28 2026] 127.0.0.1:52100 Closing
[Thu Apr 23 19:25:28 2026] 127.0.0.1:52112 Accepted
[Thu Apr 23 19:25:32 2026] 127.0.0.1:43250 Accepted
[Thu Apr 23 19:25:51 2026] 127.0.0.1:52112 Closing
[Thu Apr 23 19:25:51 2026] 127.0.0.1:34940 Accepted
[Thu Apr 23 19:26:25 2026] 127.0.0.1:34940 Closing
[Thu Apr 23 19:26:25 2026] 127.0.0.1:52990 Accepted
[Thu Apr 23 19:26:27 2026] 127.0.0.1:43250 Closing
[Thu Apr 23 19:26:27 2026] 127.0.0.1:53240 Accepted
[Thu Apr 23 19:26:39 2026] 127.0.0.1:53240 Closing
[Thu Apr 23 19:26:39 2026] 127.0.0.1:37316 Accepted
[Thu Apr 23 19:26:49 2026] 127.0.0.1:52990 Closing
[Thu Apr 23 19:26:51 2026] 127.0.0.1:37316 Closing
[Thu Apr 23 19:26:51 2026] 127.0.0.1:39238 Accepted
[Thu Apr 23 19:26:57 2026] 127.0.0.1:53744 Accepted
[Thu Apr 23 19:27:07 2026] 127.0.0.1:39238 Closing
[Thu Apr 23 19:27:07 2026] 127.0.0.1:44008 Accepted
[Thu Apr 23 19:27:14 2026] 127.0.0.1:44008 Closing
[Thu Apr 23 19:27:14 2026] 127.0.0.1:60690 Accepted
[Thu Apr 23 19:27:44 2026] 127.0.0.1:60690 Closing
[Thu Apr 23 19:27:44 2026] 127.0.0.1:42122 Accepted
[Thu Apr 23 19:27:46 2026] 127.0.0.1:53744 Closing
[Thu Apr 23 19:27:46 2026] 127.0.0.1:45324 Accepted
[Thu Apr 23 19:27:58 2026] 127.0.0.1:45324 Closing
[Thu Apr 23 19:27:58 2026] 127.0.0.1:55480 Accepted
[Thu Apr 23 19:28:04 2026] 127.0.0.1:42122 Closing
[Thu Apr 23 19:28:04 2026] 127.0.0.1:37980 Accepted
[Thu Apr 23 19:28:11 2026] 127.0.0.1:55480 Closing
[Thu Apr 23 19:28:11 2026] 127.0.0.1:33676 Accepted
[Thu Apr 23 19:28:28 2026] 127.0.0.1:33676 Closing
[Thu Apr 23 19:28:28 2026] 127.0.0.1:51506 Accepted
[Thu Apr 23 19:28:46 2026] 127.0.0.1:37980 Closing
[Thu Apr 23 19:28:57 2026] 127.0.0.1:37352 Accepted
[Thu Apr 23 19:28:58 2026] 127.0.0.1:51506 Closing
[Thu Apr 23 19:28:58 2026] 127.0.0.1:50856 Accepted
[Thu Apr 23 19:28:58 2026] 127.0.0.1:37352 Closing
[Thu Apr 23 19:28:58 2026] 127.0.0.1:37358 Accepted
[Thu Apr 23 19:29:04 2026] 127.0.0.1:37358 Closing
[Thu Apr 23 19:29:04 2026] 127.0.0.1:45058 Accepted
[Thu Apr 23 19:29:10 2026] 127.0.0.1:45058 Closing
[Thu Apr 23 19:29:22 2026] 127.0.0.1:50856 Closing
[Thu Apr 23 19:29:22 2026] 127.0.0.1:38996 Accepted
[Thu Apr 23 19:30:02 2026] 127.0.0.1:38996 Closing
[Thu Apr 23 19:30:10 2026] 127.0.0.1:59878 Accepted
[Thu Apr 23 19:30:16 2026] 127.0.0.1:59878 Closing
@@ -414,7 +414,7 @@ class edge_gateway_operation_service
self::STATUS_CANCEL_REQUESTED, self::STATUS_CANCEL_REQUESTED,
self::STATUS_CANCELLED, self::STATUS_CANCELLED,
], true)) { ], true)) {
return $this->serializeOperation($operation, true); return $this->serializePersistedOperation($operationId, true);
} }
$level = strtoupper(trim((string)($payload['level'] ?? self::LEVEL_INFO))); $level = strtoupper(trim((string)($payload['level'] ?? self::LEVEL_INFO)));
@@ -447,9 +447,10 @@ class edge_gateway_operation_service
$this->markOperationFailedFromEvent($gatewayId, $operation, $code, $message, $context); $this->markOperationFailedFromEvent($gatewayId, $operation, $code, $message, $context);
} }
$this->refreshGatewayViewCache($gatewayId); $this->clearObjectPropertyCache('edge_gateway_operations', $operationId);
$this->clearGatewayViewCache($gatewayId);
return $this->serializeOperation($operation, true); return $this->serializePersistedOperation($operationId, true);
} }
/** /**
@@ -478,7 +479,7 @@ class edge_gateway_operation_service
self::STATUS_FAILED, self::STATUS_FAILED,
self::STATUS_CANCELLED, self::STATUS_CANCELLED,
], true)) { ], true)) {
return $this->serializeOperation($operation, true); return $this->serializePersistedOperation($operationId, true);
} }
$ok = (bool)($payload['ok'] ?? false); $ok = (bool)($payload['ok'] ?? false);
@@ -550,10 +551,11 @@ class edge_gateway_operation_service
$errorMessage $errorMessage
); );
} }
$this->refreshGatewayViewCache($gatewayId); $this->clearObjectPropertyCache('edge_gateway_operations', $operationId);
$this->clearGatewayViewCache($gatewayId);
$this->manager()->notifyBrokerGatewaySync($gatewayId); $this->manager()->notifyBrokerGatewaySync($gatewayId);
return $this->serializeOperation($operation, true); return $this->serializePersistedOperation($operationId, true);
} }
/** /**
@@ -962,8 +964,8 @@ class edge_gateway_operation_service
): array { ): array {
$stage = trim((string)($context['stage'] ?? '')); $stage = trim((string)($context['stage'] ?? ''));
if ($stage === '') { if ($stage === '') {
$operation = (new edge_gateway_operations_o())->select($operationId); $operationRecord = $this->fetchOperationRecord($operationId);
$stage = trim((string)($operation->status->value() ?? '')); $stage = trim((string)($operationRecord['status'] ?? ''));
} }
if ($stage === '') { if ($stage === '') {
$stage = 'RECORDED'; $stage = 'RECORDED';
@@ -1053,6 +1055,19 @@ class edge_gateway_operation_service
return is_array($row) ? $row : null; return is_array($row) ? $row : null;
} }
/**
* @return array<string,mixed>
*/
private function serializePersistedOperation(int $operationId, bool $includeEvents = true): array
{
$operation = $this->fetchOperationRecord($operationId);
if ($operation === null) {
throw new RuntimeException('Edge gateway operation could not be reloaded');
}
return $this->serializeOperationRecord($operation, $includeEvents);
}
/** /**
* @param array<string,mixed> $operation * @param array<string,mixed> $operation
* @return array<string,mixed> * @return array<string,mixed>
@@ -1228,7 +1243,7 @@ class edge_gateway_operation_service
self::STATUS_CANCEL_REQUESTED, self::STATUS_CANCEL_REQUESTED,
self::STATUS_CANCELLED, self::STATUS_CANCELLED,
], true)) { ], true)) {
return $this->serializeOperation($operation, true); return $this->serializePersistedOperation($operationId, true);
} }
$level = strtoupper(trim((string)($payload['level'] ?? self::LEVEL_INFO))); $level = strtoupper(trim((string)($payload['level'] ?? self::LEVEL_INFO)));
@@ -1261,9 +1276,10 @@ class edge_gateway_operation_service
$this->markOperationFailedFromEvent($gatewayId, $operation, $code, $message, $context); $this->markOperationFailedFromEvent($gatewayId, $operation, $code, $message, $context);
} }
$this->refreshGatewayViewCache($gatewayId); $this->clearObjectPropertyCache('edge_gateway_operations', $operationId);
$this->clearGatewayViewCache($gatewayId);
return $this->serializeOperation($operation, true); return $this->serializePersistedOperation($operationId, true);
} }
/** /**
@@ -1277,7 +1293,7 @@ class edge_gateway_operation_service
self::STATUS_FAILED, self::STATUS_FAILED,
self::STATUS_CANCELLED, self::STATUS_CANCELLED,
], true)) { ], true)) {
return $this->serializeOperation($operation, true); return $this->serializePersistedOperation($operationId, true);
} }
$ok = (bool)($payload['ok'] ?? false); $ok = (bool)($payload['ok'] ?? false);
@@ -1349,9 +1365,10 @@ class edge_gateway_operation_service
$errorMessage $errorMessage
); );
} }
$this->refreshGatewayViewCache($gatewayId); $this->clearObjectPropertyCache('edge_gateway_operations', $operationId);
$this->clearGatewayViewCache($gatewayId);
$this->manager()->notifyBrokerGatewaySync($gatewayId); $this->manager()->notifyBrokerGatewaySync($gatewayId);
return $this->serializeOperation($operation, true); return $this->serializePersistedOperation($operationId, true);
} }
} }