diff --git a/src/Database/Adapter.php b/src/Database/Adapter.php index ef0598341..d4cbeafdc 100644 --- a/src/Database/Adapter.php +++ b/src/Database/Adapter.php @@ -40,6 +40,22 @@ abstract class Adapter */ protected array $debug = []; + /** + * @var ?array> + */ + protected ?array $explainBuffer = null; + + /** + * @var array + */ + protected const EXPLAIN_COLUMN_RENAMES = [ + '_uid' => '$id', + '_createdAt' => '$createdAt', + '_updatedAt' => '$updatedAt', + '_permissions' => '$permissions', + '_tenant' => '$tenant', + ]; + /** * @var array> */ @@ -104,6 +120,176 @@ public function resetDebug(): static return $this; } + /** + * @throws DatabaseException when called inside an already-active scope — + * the buffer is a single shared array, so silently clobbering the outer + * scope would lose every previously-captured entry. + */ + public function startExplainCapture(): void + { + if ($this->explainBuffer !== null) { + throw new DatabaseException('withExplain cannot be nested — finish the outer scope first.'); + } + $this->explainBuffer = []; + } + + /** + * @return array> + */ + public function stopExplainCapture(): array + { + $captured = $this->explainBuffer ?? []; + $this->explainBuffer = null; + return $captured; + } + + public function isExplainCapturing(): bool + { + return $this->explainBuffer !== null; + } + + /** + * @param string $sql + * @param array $binds + * @param string $purpose + * @param array $context + */ + protected function capturePlan(string $sql, array $binds = [], string $purpose = 'find', array $context = []): void + { + try { + $plan = $this->explainSQL($sql, $binds); + $plan = $this->sanitizePlan($plan); + } catch (\Throwable $e) { + $plan = ['error' => $e->getMessage()]; + } + + $this->explainBuffer[] = [ + 'purpose' => $purpose, + 'context' => $context, + 'plan' => $plan, + ]; + } + + /** + * Attach real execution stats to the most recently captured plan entry. + * + * Avoids a second EXPLAIN ANALYZE pass by measuring the read that already + * runs inside the explain scope. + * + * @param int|null $rowsReturned actual rows the statement returned (null when not meaningful, e.g. an aggregate) + * @param float|null $executionTime actual wall time of the statement in milliseconds + */ + protected function recordPlanActuals(?int $rowsReturned, ?float $executionTime): void + { + if ($this->explainBuffer === null || $this->explainBuffer === []) { + return; + } + $last = \array_key_last($this->explainBuffer); + $plan = $this->explainBuffer[$last]['plan'] ?? null; + // capturePlan() stores the entry just before the real statement runs; + // only fill actuals when the captured plan is a well-formed array. A + // failed EXPLAIN is stored as ['error' => ...] — leave it untouched so + // an error entry never masquerades as a real plan with stats. + if (! \is_array($plan) || isset($plan['error'])) { + return; + } + $this->explainBuffer[$last]['plan']['rowsReturned'] = $rowsReturned; + $this->explainBuffer[$last]['plan']['executionTime'] = $executionTime; + } + + /** + * @param array $plan + * @return array + */ + protected function sanitizePlan(array $plan): array + { + return $this->sanitizePlanNode($plan); + } + + private function sanitizePlanNode(mixed $node): mixed + { + if (\is_array($node)) { + $result = []; + foreach ($node as $key => $value) { + $newKey = \is_string($key) ? $this->renameInternalIdentifier($key) : $key; + $result[$newKey] = $this->sanitizePlanNode($value); + } + return $result; + } + + if (\is_string($node)) { + return $this->renameInternalIdentifier($node); + } + + return $node; + } + + private function renameInternalIdentifier(string $name): string + { + if (\str_ends_with($name, '__metadata')) { + return ''; + } + if (\str_ends_with($name, '_perms')) { + return ''; + } + if (isset(self::EXPLAIN_COLUMN_RENAMES[$name])) { + return self::EXPLAIN_COLUMN_RENAMES[$name]; + } + // The permission/metadata tables also appear embedded inside plan + // strings — e.g. a MariaDB attached_condition like + // "`db_x_collection_y_perms`.`_permission` in (...)". The suffix checks + // above only catch standalone identifiers, so rewrite the embedded + // physical-table tokens here too. Match the longest run of + // identifier/backtick chars ending in the internal suffix. + $name = \preg_replace('/[`\w]*__metadata/', '', $name) ?? $name; + $name = \preg_replace('/[`\w]*_perms/', '', $name) ?? $name; + + // SQL plans qualify columns with the schema name (e.g. a MariaDB + // condition "`appwrite`.`main`.`status` = '...'"). Drop the leading + // schema qualifier so the internal database name is not exposed. + $database = $this->getDatabase(); + if ($database !== '') { + $name = \str_replace('`'.$database.'`.', '', $name); + } + + // Plan strings embed internal column identifiers (e.g. index_condition: + // "main.`_uid` = '...'"). Best-effort, display-only substring rewrite: + // a user column containing "_uid"/"_tenant"/etc. is rewritten too, which + // is fine since this is for reading the plan, not round-tripping names. + if (\str_contains($name, '_')) { + foreach (self::EXPLAIN_COLUMN_RENAMES as $internal => $public) { + if (\str_contains($name, $internal)) { + $name = \str_replace($internal, $public, $name); + } + } + } + return $name; + } + + /** + * Produce a normalized query plan for a single statement. + * + * Every adapter returns the same fixed shape (engine, rowsScanned, + * indexUsed, estimatedCost, rowsReturned, executionTime, tree) so the + * public DTO stays typed regardless of engine. + * + * @param string $sql + * @param array $binds + * @return array + */ + protected function explainSQL(string $sql, array $binds = []): array + { + return [ + 'engine' => 'unsupported', + 'rowsScanned' => null, + 'indexUsed' => null, + 'estimatedCost' => null, + 'rowsReturned' => null, + 'executionTime' => null, + 'tree' => null, + ]; + } + /** * Set Namespace. * @@ -347,6 +533,8 @@ public function getTimeout(): int */ public function clearTimeout(string $event): void { + $this->timeout = 0; + // Clear existing callback $this->before($event, 'timeout'); } @@ -1610,6 +1798,16 @@ public function getSupportForTTLIndexes(): bool return false; } + /** + * Is query explain (plan capture via withExplain) supported? + * + * @return bool + */ + public function getSupportForExplain(): bool + { + return false; + } + /** * Does the adapter support transaction retries? * diff --git a/src/Database/Adapter/MariaDB.php b/src/Database/Adapter/MariaDB.php index 599da878e..7f5adda7c 100644 --- a/src/Database/Adapter/MariaDB.php +++ b/src/Database/Adapter/MariaDB.php @@ -1957,6 +1957,24 @@ public function getConnectionId(): string return $stmt->fetchColumn(); } + /** + * @param string $sql + * @param array $binds + * @return array + */ + protected function explainSQL(string $sql, array $binds = []): array + { + // setTimeout() wraps statements with `SET STATEMENT ... FOR `, + // which is illegal inside EXPLAIN. Strip the wrapper before delegating. + $stripped = \preg_replace('/^\s*SET\s+STATEMENT\s+[^;]*?\s+FOR\s+/is', '', $sql, 1); + return parent::explainSQL($stripped ?? $sql, $binds); + } + + protected function getExplainEngine(): string + { + return 'mariadb'; + } + public function getInternalIndexesKeys(): array { return ['primary', '_created_at', '_updated_at', '_tenant_id']; diff --git a/src/Database/Adapter/Mongo.php b/src/Database/Adapter/Mongo.php index bc6d79638..6c828439f 100644 --- a/src/Database/Adapter/Mongo.php +++ b/src/Database/Adapter/Mongo.php @@ -2196,6 +2196,17 @@ public function find(Document $collection, array $queries = [], ?int $limit = 25 $found = []; $cursorId = null; + if ($this->explainBuffer !== null) { + $this->capturePlan( + \json_encode(['find' => $name, 'filter' => $filters, 'options' => $options]) ?: '', + [], + 'find', + ['collection' => $collection->getId()], + ); + } + + $explainStart = $this->explainBuffer !== null ? \microtime(true) : null; + try { // Use proper cursor iteration with reasonable batch size $options['batchSize'] = self::DEFAULT_BATCH_SIZE; @@ -2254,6 +2265,12 @@ public function find(Document $collection, array $queries = [], ?int $limit = 25 } } + if ($explainStart !== null) { + // Real stats from the read that actually ran (queryPlanner explain + // above does not execute), mirroring the SQL adapter. + $this->recordPlanActuals(\count($found), (\microtime(true) - $explainStart) * 1000); + } + return $found; } @@ -2404,8 +2421,18 @@ public function count(Document $collection, array $queries = [], ?int $max = nul ]; } - try { + if ($this->explainBuffer !== null) { + $this->capturePlan( + \json_encode(['aggregate' => $name, 'pipeline' => $pipeline]) ?: '', + [], + 'count', + ['collection' => $collection->getId()], + ); + } + + $explainStart = $this->explainBuffer !== null ? \microtime(true) : null; + try { $result = $this->client->aggregate($name, $pipeline, $options); // Aggregation returns stdClass with cursor property containing firstBatch @@ -2421,6 +2448,11 @@ public function count(Document $collection, array $queries = [], ?int $max = nul return 0; } catch (MongoException $e) { return 0; + } finally { + if ($explainStart !== null) { + // Aggregate: one row out, so rowsReturned is not meaningful — record time only. + $this->recordPlanActuals(null, (\microtime(true) - $explainStart) * 1000); + } } } @@ -2478,7 +2510,26 @@ public function sum(Document $collection, string $attribute, array $queries = [] ]; $options = $this->getTransactionOptions(); - return $this->client->aggregate($name, $pipeline, $options)->cursor->firstBatch[0]->total ?? 0; + + if ($this->explainBuffer !== null) { + $this->capturePlan( + \json_encode(['aggregate' => $name, 'pipeline' => $pipeline]) ?: '', + [], + 'sum', + ['collection' => $collection->getId(), 'attribute' => $attribute], + ); + } + + $explainStart = $this->explainBuffer !== null ? \microtime(true) : null; + + try { + return $this->client->aggregate($name, $pipeline, $options)->cursor->firstBatch[0]->total ?? 0; + } finally { + if ($explainStart !== null) { + // Aggregate: one row out, so rowsReturned is not meaningful — record time only. + $this->recordPlanActuals(null, (\microtime(true) - $explainStart) * 1000); + } + } } /** @@ -3592,6 +3643,146 @@ public function getKeywords(): array return []; } + /** + * @param string $sql + * @param array $binds + * @return array + */ + protected function explainSQL(string $sql, array $binds = []): array + { + $captured = $sql !== '' ? \json_decode($sql, true) : null; + + // Without a captured command (or invalid JSON) we can't ask Mongo for a plan. + if (! \is_array($captured)) { + return [ + 'engine' => 'mongo', + 'rowsScanned' => null, + 'indexUsed' => null, + 'estimatedCost' => null, + 'rowsReturned' => null, + 'executionTime' => null, + 'tree' => $captured, + ]; + } + + // Capture stores find as { find, filter, options } and aggregate as + // { aggregate, pipeline }. Mongo's explain command wants the options + // hoisted to top level, and aggregate needs a cursor field. + $command = $captured; + if (isset($command['options']) && \is_array($command['options'])) { + $command = \array_merge($command, $command['options']); + unset($command['options']); + } + // Mongo's explain rejects `filter: []`; coerce to an empty object. + if (isset($command['filter']) && \is_array($command['filter']) && empty($command['filter'])) { + $command['filter'] = (object) []; + } + if (isset($command['aggregate']) && ! isset($command['cursor'])) { + $command['cursor'] = (object) []; + } + + $tree = null; + $indexUsed = null; + try { + // queryPlanner, NOT executionStats: executionStats re-runs the + // query, double-executing every captured read. Actuals come from + // timing the real find/count/sum via recordPlanActuals(). + $raw = $this->client->query([ + 'explain' => (object) $command, + 'verbosity' => 'queryPlanner', + ]); + $tree = \json_decode(\json_encode($raw) ?: 'null', true); + $indexUsed = $this->extractMongoIndexUsed($tree); + } catch (\Throwable $e) { + // Fall back to the captured command on any explain failure so callers + // still see what was attempted. + $tree = ['command' => $captured, 'explainError' => $e->getMessage()]; + } + + return [ + 'engine' => 'mongo', + // rowsScanned is an execution stat Mongo only emits under + // executionStats; queryPlanner gives the plan shape, not counts. + 'rowsScanned' => null, + 'indexUsed' => $indexUsed, + 'estimatedCost' => null, + 'rowsReturned' => null, + 'executionTime' => null, + 'tree' => $tree, + ]; + } + + /** + * Find the IXSCAN indexName from the WINNING plan of a Mongo explain tree. + * + * Only descends into `winningPlan` branches — never `rejectedPlans`, which + * can hold IXSCAN stages even when the winning plan is a COLLSCAN, so a + * blind walk would report an index that the query does not actually use. + * + * @param array|null $tree + */ + private function extractMongoIndexUsed(?array $tree): ?string + { + if (! \is_array($tree)) { + return null; + } + + foreach ($this->findWinningPlans($tree) as $winningPlan) { + $found = $this->findIxscanIndex($winningPlan); + if ($found !== null) { + return $found; + } + } + + return null; + } + + /** + * Collect every `winningPlan` subtree, skipping rejectedPlans branches. + * + * @param array $tree + * @return array> + */ + private function findWinningPlans(array $tree): array + { + $plans = []; + foreach ($tree as $key => $value) { + if (! \is_array($value)) { + continue; + } + if ($key === 'winningPlan') { + $plans[] = $value; + continue; + } + if ($key === 'rejectedPlans') { + continue; + } + $plans = \array_merge($plans, $this->findWinningPlans($value)); + } + return $plans; + } + + /** + * First IXSCAN indexName within a single (winning) plan subtree. + * + * @param array $plan + */ + private function findIxscanIndex(array $plan): ?string + { + if (($plan['stage'] ?? null) === 'IXSCAN' && isset($plan['indexName']) && \is_string($plan['indexName'])) { + return $plan['indexName']; + } + foreach ($plan as $value) { + if (\is_array($value)) { + $found = $this->findIxscanIndex($value); + if ($found !== null) { + return $found; + } + } + } + return null; + } + protected function processException(\Throwable $e): \Throwable { // Timeout @@ -3792,6 +3983,11 @@ public function getSupportForTTLIndexes(): bool return true; } + public function getSupportForExplain(): bool + { + return true; + } + public function getSupportForTransactionRetries(): bool { return false; diff --git a/src/Database/Adapter/MySQL.php b/src/Database/Adapter/MySQL.php index 5aaa28107..0ea4c9dee 100644 --- a/src/Database/Adapter/MySQL.php +++ b/src/Database/Adapter/MySQL.php @@ -324,4 +324,9 @@ public function getSupportForTTLIndexes(): bool { return false; } + + protected function getExplainEngine(): string + { + return 'mysql'; + } } diff --git a/src/Database/Adapter/Pool.php b/src/Database/Adapter/Pool.php index a08832088..a9e7b0c03 100644 --- a/src/Database/Adapter/Pool.php +++ b/src/Database/Adapter/Pool.php @@ -42,16 +42,41 @@ public function __construct(UtopiaPool $pool) */ public function delegate(string $method, array $args): mixed { - if ($this->pinnedAdapter !== null) { - if ($this->skipDuplicates) { - return $this->pinnedAdapter->skipDuplicates( - fn () => $this->pinnedAdapter->{$method}(...$args) - ); + // Wrap any inner-adapter call so withExplain scope propagates and its + // captures aggregate back into the pool buffer — needed for both the + // pinned-transaction and pooled paths. + $invoke = function (Adapter $adapter) use ($method, $args): mixed { + // Only start (and own the stop/drain of) capture when the adapter + // isn't already capturing. A pinned adapter is reused across nested + // delegate() calls — e.g. a before()-listener firing its own query + // inside the read — so re-starting would wrongly throw "cannot be + // nested". Nested calls just let their plans accumulate into the + // same buffer, drained once by the outermost call. + $startedCapture = $this->isExplainCapturing() && ! $adapter->isExplainCapturing(); + if ($startedCapture) { + $adapter->startExplainCapture(); } - return $this->pinnedAdapter->{$method}(...$args); + try { + if ($this->skipDuplicates) { + return $adapter->skipDuplicates( + fn () => $adapter->{$method}(...$args) + ); + } + return $adapter->{$method}(...$args); + } finally { + if ($startedCapture) { + foreach ($adapter->stopExplainCapture() as $entry) { + $this->explainBuffer[] = $entry; + } + } + } + }; + + if ($this->pinnedAdapter !== null) { + return $invoke($this->pinnedAdapter); } - return $this->pool->use(function (Adapter $adapter) use ($method, $args) { + return $this->pool->use(function (Adapter $adapter) use ($invoke) { // Run setters in case config changed since this connection was last used $adapter->setDatabase($this->getDatabase()); $adapter->setNamespace($this->getNamespace()); @@ -59,8 +84,11 @@ public function delegate(string $method, array $args): mixed $adapter->setTenant($this->getTenant()); $adapter->setAuthorization($this->authorization); - if ($this->getTimeout() > 0) { - $adapter->setTimeout($this->getTimeout()); + $timeout = $this->getTimeout(); + if ($timeout > 0) { + $adapter->setTimeout($timeout); + } else { + $adapter->clearTimeout(Database::EVENT_ALL); } $adapter->resetDebug(); foreach ($this->getDebug() as $key => $value) { @@ -71,12 +99,7 @@ public function delegate(string $method, array $args): mixed $adapter->setMetadata($key, $value); } - if ($this->skipDuplicates) { - return $adapter->skipDuplicates( - fn () => $adapter->{$method}(...$args) - ); - } - return $adapter->{$method}(...$args); + return $invoke($adapter); }); } @@ -99,6 +122,9 @@ protected function trigger(string $event, mixed $query): mixed public function setTimeout(int $milliseconds, string $event = Database::EVENT_ALL): void { + // Record on Pool first so delegate()'s borrow logic re-applies the timeout + // (instead of clearing it as stale) on this and every subsequent call. + $this->timeout = $milliseconds; $this->delegate(__FUNCTION__, \func_get_args()); } @@ -147,8 +173,11 @@ public function withTransaction(callable $callback): mixed $adapter->setTenant($this->getTenant()); $adapter->setAuthorization($this->authorization); - if ($this->getTimeout() > 0) { - $adapter->setTimeout($this->getTimeout()); + $timeout = $this->getTimeout(); + if ($timeout > 0) { + $adapter->setTimeout($timeout); + } else { + $adapter->clearTimeout(Database::EVENT_ALL); } $adapter->resetDebug(); foreach ($this->getDebug() as $key => $value) { @@ -323,6 +352,17 @@ public function find(Document $collection, array $queries = [], ?int $limit = 25 return $this->delegate(__FUNCTION__, \func_get_args()); } + /** + * @param string $sql + * @param array $binds + * @return array + */ + protected function explainSQL(string $sql, array $binds = []): array + { + // Explain runs on the inner adapter via delegate(), not on the pool itself. + throw new DatabaseException('Pool::explainSQL must not be invoked directly'); + } + public function sum(Document $collection, string $attribute, array $queries = [], ?int $max = null): float|int { return $this->delegate(__FUNCTION__, \func_get_args()); @@ -398,6 +438,11 @@ public function getSupportForSchemas(): bool return $this->delegate(__FUNCTION__, \func_get_args()); } + public function getSupportForExplain(): bool + { + return $this->delegate(__FUNCTION__, \func_get_args()); + } + public function getSupportForAttributes(): bool { return $this->delegate(__FUNCTION__, \func_get_args()); diff --git a/src/Database/Adapter/Postgres.php b/src/Database/Adapter/Postgres.php index d81cdec0b..d8f352fba 100644 --- a/src/Database/Adapter/Postgres.php +++ b/src/Database/Adapter/Postgres.php @@ -1578,6 +1578,137 @@ public function getConnectionId(): string return $stmt->fetchColumn(); } + /** + * @param string $sql + * @param array $binds + * @return array + */ + protected function explainSQL(string $sql, array $binds = []): array + { + $explainSql = 'EXPLAIN (FORMAT JSON) ' . \ltrim($sql); + + $stmt = $this->getPDO()->prepare($explainSql); + + foreach ($binds as $key => $value) { + if (\gettype($value) === 'double') { + $stmt->bindValue($key, $this->getFloatPrecision($value), \PDO::PARAM_STR); + } else { + $stmt->bindValue($key, $value, $this->getPDOType($value)); + } + } + + // Route through execute() so the EXPLAIN inherits statement_timeout and + // the same PDO error handling as the real read it mirrors. + try { + $this->execute($stmt); + $raw = $stmt->fetchColumn(); + } catch (PDOException $e) { + throw $this->processException($e); + } finally { + $stmt->closeCursor(); + } + + $decoded = \is_string($raw) ? \json_decode($raw, true) : null; + // Postgres wraps the plan in a one-element array. + $tree = (\is_array($decoded) && isset($decoded[0]) && \is_array($decoded[0])) + ? $decoded[0] + : null; + + $rootPlan = (\is_array($tree) && isset($tree['Plan']) && \is_array($tree['Plan'])) + ? $tree['Plan'] + : null; + + // Postgres nests the real work under the root node's `Plans`. A vector + // query (`ORDER BY emb <-> $1 LIMIT k`) plans as Limit → Index Scan, so + // the index name and scanned rows live on a CHILD, not the root. Walk + // the whole tree for those; cost is cumulative so the root carries it. + return [ + 'engine' => $this->getExplainEngine(), + 'rowsScanned' => $this->extractPgPlanRows($rootPlan), + 'indexUsed' => $this->extractPgIndexUsed($rootPlan), + 'estimatedCost' => (\is_array($rootPlan) && isset($rootPlan['Total Cost']) && \is_numeric($rootPlan['Total Cost'])) + ? (float) $rootPlan['Total Cost'] + : null, + 'rowsReturned' => null, + 'executionTime' => null, + 'tree' => $tree, + ]; + } + + protected function getExplainEngine(): string + { + return 'postgres'; + } + + /** + * Estimated rows examined by the deepest scan node — the leaf the access + * path actually reads, not the root (which for a Limit reports just `k`). + * + * @param array|null $plan + */ + private function extractPgPlanRows(?array $plan): ?int + { + $found = null; + $this->walkPgPlan($plan, function (array $node) use (&$found): void { + // Scan nodes touch storage; their `Plan Rows` is the meaningful + // "rows examined" figure. Prefer the first one encountered. + if ($found === null + && isset($node['Node Type']) + && \is_string($node['Node Type']) + && \str_contains($node['Node Type'], 'Scan') + && isset($node['Plan Rows']) + && \is_numeric($node['Plan Rows']) + ) { + $found = (int) $node['Plan Rows']; + } + }); + + // No scan node (e.g. Result/Values plan) — fall back to the root estimate. + if ($found === null && isset($plan['Plan Rows']) && \is_numeric($plan['Plan Rows'])) { + $found = (int) $plan['Plan Rows']; + } + + return $found; + } + + /** + * First index name in the plan tree (e.g. an HNSW/IVFFlat index on a + * pgvector `<->` scan), searched depth-first from the root. + * + * @param array|null $plan + */ + private function extractPgIndexUsed(?array $plan): ?string + { + $found = null; + $this->walkPgPlan($plan, function (array $node) use (&$found): void { + if ($found === null && isset($node['Index Name']) && \is_string($node['Index Name'])) { + $found = $node['Index Name']; + } + }); + return $found; + } + + /** + * Depth-first walk over a Postgres plan node and its nested `Plans`. + * + * @param array|null $node + * @param callable(array): void $visitor + */ + private function walkPgPlan(?array $node, callable $visitor): void + { + if (! \is_array($node)) { + return; + } + $visitor($node); + if (isset($node['Plans']) && \is_array($node['Plans'])) { + foreach ($node['Plans'] as $child) { + if (\is_array($child)) { + $this->walkPgPlan($child, $visitor); + } + } + } + } + /** * Handle distance spatial queries * diff --git a/src/Database/Adapter/SQL.php b/src/Database/Adapter/SQL.php index e56678f8e..ab3d9d585 100644 --- a/src/Database/Adapter/SQL.php +++ b/src/Database/Adapter/SQL.php @@ -2528,6 +2528,144 @@ protected function execute(mixed $stmt): bool return $stmt->execute(); } + /** + * @param string $sql + * @param array $binds + * @return array + */ + protected function explainSQL(string $sql, array $binds = []): array + { + $explainSql = 'EXPLAIN FORMAT=JSON ' . \ltrim($sql); + + $stmt = $this->getPDO()->prepare($explainSql); + + foreach ($binds as $key => $value) { + if (\gettype($value) === 'double') { + $stmt->bindValue($key, $this->getFloatPrecision($value), \PDO::PARAM_STR); + } else { + $stmt->bindValue($key, $value, $this->getPDOType($value)); + } + } + + // Route through execute() so the EXPLAIN inherits the same timeout and + // PDO error handling as the real read it mirrors. + try { + $this->execute($stmt); + $raw = $stmt->fetchColumn(); + } catch (PDOException $e) { + throw $this->processException($e); + } finally { + $stmt->closeCursor(); + } + + $tree = \is_string($raw) ? \json_decode($raw, true) : null; + $tree = \is_array($tree) ? $tree : null; + + return [ + 'engine' => $this->getExplainEngine(), + 'rowsScanned' => $this->extractRowsScanned($tree), + 'indexUsed' => $this->extractIndexUsed($tree), + 'estimatedCost' => $this->extractEstimatedCost($tree), + 'rowsReturned' => null, + 'executionTime' => null, + 'tree' => $tree, + ]; + } + + /** + * Precise engine label for the normalized plan (e.g. mysql, mariadb, + * postgres). Lets each surface report its real backend instead of a + * generic 'sql'. + */ + abstract protected function getExplainEngine(): string; + + public function getSupportForExplain(): bool + { + return true; + } + + /** + * @param array|null $tree + */ + private function extractRowsScanned(?array $tree): ?int + { + if ($tree === null) { + return null; + } + $total = null; + $this->walkExplainTables($tree, function (array $table) use (&$total) { + // MySQL exposes 'rows_examined_per_scan', MariaDB exposes 'rows'. + $rows = $table['rows_examined_per_scan'] ?? $table['rows'] ?? null; + if (\is_numeric($rows)) { + $total = ($total ?? 0) + (int) $rows; + } + }); + return $total; + } + + /** + * @param array|null $tree + */ + private function extractIndexUsed(?array $tree): ?string + { + if ($tree === null) { + return null; + } + $found = null; + // Only the outer table — inner permission subquery indexes are not user-facing. + $this->walkExplainTables($tree, function (array $table) use (&$found) { + if ($found === null && isset($table['key']) && \is_string($table['key'])) { + $found = $table['key']; + } + }, depthLimit: 1); + return $found; + } + + /** + * @param array|null $tree + */ + private function extractEstimatedCost(?array $tree): ?float + { + if ($tree === null) { + return null; + } + $cost = $tree['query_block']['cost_info']['query_cost'] ?? null; + return \is_numeric($cost) ? (float) $cost : null; + } + + /** + * @param array $node + * @param callable(array): void $visitor + * @param int|null $depthLimit + * @param int $depth + */ + private function walkExplainTables(array $node, callable $visitor, ?int $depthLimit = null, int $depth = 0): void + { + if ($depthLimit !== null && $depth > $depthLimit) { + return; + } + + foreach ($node as $key => $value) { + if ($key === 'table' && \is_array($value)) { + $visitor($value); + if (isset($value['attached_subqueries']) && \is_array($value['attached_subqueries'])) { + foreach ($value['attached_subqueries'] as $sub) { + if (\is_array($sub)) { + $this->walkExplainTables($sub, $visitor, $depthLimit, $depth + 1); + } + } + } + if (isset($value['materialized_from_subquery']) && \is_array($value['materialized_from_subquery'])) { + $this->walkExplainTables($value['materialized_from_subquery'], $visitor, $depthLimit, $depth + 1); + } + continue; + } + if (\is_array($value)) { + $this->walkExplainTables($value, $visitor, $depthLimit, $depth); + } + } + } + /** * Create Documents in batches * @@ -3240,6 +3378,12 @@ public function find(Document $collection, array $queries = [], ?int $limit = 25 $sql = $this->trigger(Database::EVENT_DOCUMENT_FIND, $sql); + if ($this->explainBuffer !== null) { + $this->capturePlan($sql, $binds, 'find', ['collection' => $collection]); + } + + $explainStart = $this->explainBuffer !== null ? \microtime(true) : null; + try { $stmt = $this->getPDO()->prepare($sql); @@ -3259,6 +3403,11 @@ public function find(Document $collection, array $queries = [], ?int $limit = 25 $results = $stmt->fetchAll(); $stmt->closeCursor(); + if ($explainStart !== null) { + // Real stats from the read that actually ran — no second pass. + $this->recordPlanActuals(\count($results), (\microtime(true) - $explainStart) * 1000); + } + foreach ($results as $index => $document) { if (\array_key_exists('_uid', $document)) { $results[$index]['$id'] = $document['_uid']; @@ -3366,6 +3515,13 @@ public function count(Document $collection, array $queries = [], ?int $max = nul $sql = $this->trigger(Database::EVENT_DOCUMENT_COUNT, $sql); + if ($this->explainBuffer !== null) { + // $collection was reassigned to the string id at the top of this method. + $this->capturePlan($sql, $binds, 'count', ['collection' => $collection]); + } + + $explainStart = $this->explainBuffer !== null ? \microtime(true) : null; + $stmt = $this->getPDO()->prepare($sql); foreach ($binds as $key => $value) { @@ -3384,6 +3540,11 @@ public function count(Document $collection, array $queries = [], ?int $max = nul $result = $result[0]; } + if ($explainStart !== null) { + // Aggregate: one row out, so rowsReturned is not meaningful — record time only. + $this->recordPlanActuals(null, (\microtime(true) - $explainStart) * 1000); + } + return $result['sum'] ?? 0; } @@ -3461,6 +3622,13 @@ public function sum(Document $collection, string $attribute, array $queries = [] $sql = $this->trigger(Database::EVENT_DOCUMENT_SUM, $sql); + if ($this->explainBuffer !== null) { + // $collection was reassigned to the string id at the top of this method. + $this->capturePlan($sql, $binds, 'sum', ['collection' => $collection, 'attribute' => $attribute]); + } + + $explainStart = $this->explainBuffer !== null ? \microtime(true) : null; + $stmt = $this->getPDO()->prepare($sql); foreach ($binds as $key => $value) { @@ -3479,6 +3647,11 @@ public function sum(Document $collection, string $attribute, array $queries = [] $result = $result[0]; } + if ($explainStart !== null) { + // Aggregate: one row out, so rowsReturned is not meaningful — record time only. + $this->recordPlanActuals(null, (\microtime(true) - $explainStart) * 1000); + } + return $result['sum'] ?? 0; } diff --git a/src/Database/Adapter/SQLite.php b/src/Database/Adapter/SQLite.php index 5b07ce3b7..4cf28ea77 100644 --- a/src/Database/Adapter/SQLite.php +++ b/src/Database/Adapter/SQLite.php @@ -88,6 +88,50 @@ public function __construct(mixed $pdo) $this->registerUserFunctions(); } + /** + * @param string $sql + * @param array $binds + * @return array + */ + protected function explainSQL(string $sql, array $binds = []): array + { + $explainSql = 'EXPLAIN QUERY PLAN ' . \ltrim($sql); + + $stmt = $this->getPDO()->prepare($explainSql); + + foreach ($binds as $key => $value) { + if (\gettype($value) === 'double') { + $stmt->bindValue($key, $this->getFloatPrecision($value), \PDO::PARAM_STR); + } else { + $stmt->bindValue($key, $value, $this->getPDOType($value)); + } + } + + try { + $this->execute($stmt); + $rows = $stmt->fetchAll(\PDO::FETCH_ASSOC); + } catch (PDOException $e) { + throw $this->processException($e); + } finally { + $stmt->closeCursor(); + } + + return [ + 'engine' => $this->getExplainEngine(), + 'rowsScanned' => null, + 'indexUsed' => null, + 'estimatedCost' => null, + 'rowsReturned' => null, + 'executionTime' => null, + 'tree' => ['steps' => \is_array($rows) ? $rows : []], + ]; + } + + protected function getExplainEngine(): string + { + return 'sqlite'; + } + /** * Toggle MariaDB/MySQL emulation. See $emulateMySQL for what this * actually changes. diff --git a/src/Database/Database.php b/src/Database/Database.php index f9fad6808..3e70765f2 100644 --- a/src/Database/Database.php +++ b/src/Database/Database.php @@ -1454,6 +1454,32 @@ public function withPreserveDates(callable $callback): mixed } } + /** + * Run $callback with explain capture enabled. + * + * Returns the callback's own result (like withPreserveSequence/withTenant), + * so callers get their query output normally. The captured query plan is + * written to the by-reference $plan Document (`{ queries: [...] }`), letting + * one call yield both the rows and their plan. + * + * @template T + * @param callable(): T $callback + * @param Document|null $plan out-param: receives the captured plan document + * @return T the callback's return value + * @throws \Throwable rethrown from $callback; capture is always stopped first + */ + public function withExplain(callable $callback, ?Document &$plan = null): mixed + { + $this->adapter->startExplainCapture(); + try { + return $callback(); + } finally { + $plan = new Document([ + 'queries' => $this->adapter->stopExplainCapture(), + ]); + } + } + public function getPreserveSequence(): bool { return $this->preserveSequence; diff --git a/tests/e2e/Adapter/Base.php b/tests/e2e/Adapter/Base.php index 4baeba35b..f944d8a2a 100644 --- a/tests/e2e/Adapter/Base.php +++ b/tests/e2e/Adapter/Base.php @@ -7,6 +7,7 @@ use Tests\E2E\Adapter\Scopes\CollectionTests; use Tests\E2E\Adapter\Scopes\CustomDocumentTypeTests; use Tests\E2E\Adapter\Scopes\DocumentTests; +use Tests\E2E\Adapter\Scopes\ExplainTests; use Tests\E2E\Adapter\Scopes\GeneralTests; use Tests\E2E\Adapter\Scopes\IndexTests; use Tests\E2E\Adapter\Scopes\ObjectAttributeTests; @@ -27,6 +28,7 @@ abstract class Base extends TestCase use CustomDocumentTypeTests; use DocumentTests; use AttributeTests; + use ExplainTests; use IndexTests; use OperatorTests; use PermissionTests; diff --git a/tests/e2e/Adapter/Scopes/ExplainTests.php b/tests/e2e/Adapter/Scopes/ExplainTests.php new file mode 100644 index 000000000..77fe33cd0 --- /dev/null +++ b/tests/e2e/Adapter/Scopes/ExplainTests.php @@ -0,0 +1,249 @@ +getDatabase(); + + // SQL-only: asserts the precise engine label and a non-null plan tree. + if (! $database->getAdapter() instanceof SQL) { + $this->markTestSkipped('Engine label and plan tree assertions are SQL-specific.'); + } + + $database->getAuthorization()->addRole(Role::any()->toString()); + + $collection = 'explain_test_' . \uniqid(); + + $database->createCollection($collection, permissions: [ + Permission::create(Role::any()), + Permission::read(Role::any()), + ]); + $database->createAttribute($collection, 'title', Database::VAR_STRING, 128, true); + $database->createAttribute($collection, 'status', Database::VAR_STRING, 32, true); + + $database->createDocument($collection, new Document([ + '$id' => ID::unique(), + '$permissions' => [Permission::read(Role::any())], + 'title' => 'first', + 'status' => 'published', + ])); + $database->createDocument($collection, new Document([ + '$id' => ID::unique(), + '$permissions' => [Permission::read(Role::any())], + 'title' => 'second', + 'status' => 'draft', + ])); + + $plan = null; + $rows = $database->withExplain(fn () => $database->find($collection, [ + Query::equal('status', ['published']), + Query::limit(10), + ]), $plan); + + $this->assertIsArray($rows); + $this->assertInstanceOf(Document::class, $plan); + + $entries = $plan->getAttribute('queries'); + $this->assertIsArray($entries); + $this->assertNotEmpty($entries); + + $entry = $entries[0]; + $this->assertSame('find', $entry['purpose']); + $this->assertArrayHasKey('context', $entry); + $this->assertArrayHasKey('collection', $entry['context']); + $this->assertSame($collection, $entry['context']['collection']); + + $this->assertArrayHasKey('plan', $entry); + // Engine label is precise per adapter (mysql/mariadb/postgres/sqlite). + $this->assertContains($entry['plan']['engine'], ['mysql', 'mariadb', 'postgres', 'sqlite']); + $this->assertArrayHasKey('tree', $entry['plan']); + $this->assertNotNull($entry['plan']['tree']); + + $this->assertArrayHasKey('rowsScanned', $entry['plan']); + $this->assertArrayHasKey('indexUsed', $entry['plan']); + $this->assertArrayHasKey('estimatedCost', $entry['plan']); + + // Actual execution stats from the real find() that ran under explain. + $this->assertArrayHasKey('rowsReturned', $entry['plan']); + $this->assertArrayHasKey('executionTime', $entry['plan']); + // One document matches status=published, and find() rows are measured directly. + $this->assertSame(1, $entry['plan']['rowsReturned']); + $this->assertIsFloat($entry['plan']['executionTime']); + + $rawTree = \json_encode($entry['plan']['tree']) ?: ''; + $this->assertStringNotContainsString('_perms', $rawTree); + + $database->deleteCollection($collection); + } + + public function testWithExplainBufferIsClearedAfterScope(): void + { + /** @var Database $database */ + $database = $this->getDatabase(); + + if (! $database->getAdapter()->getSupportForExplain()) { + $this->markTestSkipped('Adapter does not support explain.'); + } + + $this->assertFalse($database->getAdapter()->isExplainCapturing()); + + $database->withExplain(function () use ($database) { + $this->assertTrue($database->getAdapter()->isExplainCapturing()); + }); + + $this->assertFalse($database->getAdapter()->isExplainCapturing()); + } + + public function testWithExplainExceptionDoesNotLeaveBufferOpen(): void + { + /** @var Database $database */ + $database = $this->getDatabase(); + + if (! $database->getAdapter()->getSupportForExplain()) { + $this->markTestSkipped('Adapter does not support explain.'); + } + + $propagated = false; + try { + $database->withExplain(function () { + throw new \RuntimeException('boom'); + }); + } catch (\RuntimeException) { + $propagated = true; + } + + $this->assertTrue($propagated, 'Expected RuntimeException to propagate'); + $this->assertFalse($database->getAdapter()->isExplainCapturing()); + } + + public function testWithExplainCapturesCountAndSum(): void + { + /** @var Database $database */ + $database = $this->getDatabase(); + + if (! $database->getAdapter()->getSupportForExplain()) { + $this->markTestSkipped('Adapter does not support explain.'); + } + + $database->getAuthorization()->addRole(Role::any()->toString()); + + $collection = 'explain_count_sum_' . \uniqid(); + $database->createCollection($collection, permissions: [ + Permission::create(Role::any()), + Permission::read(Role::any()), + ]); + $database->createAttribute($collection, 'score', Database::VAR_INTEGER, 0, true); + + for ($i = 0; $i < 3; $i++) { + $database->createDocument($collection, new Document([ + '$id' => ID::unique(), + '$permissions' => [Permission::read(Role::any())], + 'score' => $i + 1, + ])); + } + + // Regression guard: count() used to crash inside withExplain because + // the context array called ->getId() on a string. + $plan = null; + $database->withExplain(function () use ($database, $collection): void { + $database->count($collection); + $database->sum($collection, 'score'); + }, $plan); + + $entries = $plan->getAttribute('queries'); + $this->assertIsArray($entries); + $this->assertGreaterThanOrEqual(2, \count($entries)); + + $purposes = \array_column($entries, 'purpose'); + $this->assertContains('count', $purposes); + $this->assertContains('sum', $purposes); + + foreach ($entries as $entry) { + $this->assertSame($collection, $entry['context']['collection']); + if ($entry['purpose'] === 'sum') { + $this->assertSame('score', $entry['context']['attribute']); + } + } + + $database->deleteCollection($collection); + } + + public function testWithExplainWorksInsideTransactionOnPooledAdapter(): void + { + /** @var Database $database */ + $database = $this->getDatabase(); + + if (! $database->getAdapter() instanceof Pool) { + $this->markTestSkipped('Transaction-pinned adapter only matters when running through the Pool adapter.'); + } + + $database->getAuthorization()->addRole(Role::any()->toString()); + + $collection = 'explain_txn_' . \uniqid(); + $database->createCollection($collection, permissions: [ + Permission::create(Role::any()), + Permission::read(Role::any()), + ]); + $database->createAttribute($collection, 'title', Database::VAR_STRING, 32, true); + $database->createDocument($collection, new Document([ + '$id' => ID::unique(), + '$permissions' => [Permission::read(Role::any())], + 'title' => 'one', + ])); + + // Pin a connection by running inside a transaction, then capture + // explain on the *same* pinned connection. Regression guard: this used + // to silently return [] because the pinned-adapter early return + // bypassed the start/stop/drain logic. + $plan = null; + $rows = $database->withExplain(function () use ($database, $collection) { + return $database->withTransaction(fn () => $database->find($collection, [ + Query::limit(5), + ])); + }, $plan); + + $this->assertIsArray($rows); + + $entries = $plan->getAttribute('queries'); + $this->assertIsArray($entries); + $this->assertNotEmpty($entries, 'pinned-adapter explain capture must reach the pool buffer'); + $this->assertSame('find', $entries[0]['purpose']); + + $database->deleteCollection($collection); + } + + public function testNestedWithExplainThrows(): void + { + /** @var Database $database */ + $database = $this->getDatabase(); + + if (! $database->getAdapter()->getSupportForExplain()) { + $this->markTestSkipped('Adapter does not support explain.'); + } + + $this->expectException(DatabaseException::class); + $this->expectExceptionMessageMatches('/cannot be nested/i'); + + $database->withExplain(function () use ($database): void { + $database->withExplain(fn () => null); + }); + + // Even though the inner call threw, the outer scope's finally still + // runs and clears the buffer — verified separately to keep this test + // focused on the nesting guard itself. + } +} diff --git a/tests/unit/ExplainTest.php b/tests/unit/ExplainTest.php new file mode 100644 index 000000000..3e849cc74 --- /dev/null +++ b/tests/unit/ExplainTest.php @@ -0,0 +1,286 @@ +createMock(Adapter::class); + + $adapter->expects($this->once())->method('startExplainCapture'); + $adapter + ->expects($this->once()) + ->method('stopExplainCapture') + ->willReturn([ + [ + 'purpose' => 'find', + 'context' => ['collection' => 'movies'], + 'plan' => [ + 'engine' => 'sql', + 'rowsScanned' => 25, + 'indexUsed' => '_idx_status', + 'estimatedCost' => 4.5, + 'tree' => null, + ], + ], + ]); + + $db = new Database($adapter, new Cache(new None())); + + // The callback result must propagate; the plan comes via the out-param. + $plan = null; + $result = $db->withExplain(fn () => 'callback-result', $plan); + + $this->assertSame('callback-result', $result); + $this->assertInstanceOf(Document::class, $plan); + + $entries = $plan->getAttribute('queries'); + $this->assertIsArray($entries); + $this->assertCount(1, $entries); + $this->assertSame('find', $entries[0]['purpose']); + $this->assertSame('movies', $entries[0]['context']['collection']); + $this->assertSame(25, $entries[0]['plan']['rowsScanned']); + } + + public function testStopExplainCaptureIsCalledEvenWhenCallbackThrows(): void + { + $adapter = $this->createMock(Adapter::class); + + $adapter->expects($this->once())->method('startExplainCapture'); + $adapter->expects($this->once())->method('stopExplainCapture')->willReturn([]); + + $db = new Database($adapter, new Cache(new None())); + + $this->expectException(\RuntimeException::class); + $db->withExplain(function () { + throw new \RuntimeException('boom'); + }); + } + + public function testSanitizePlanHidesInternalTablesAndRenamesColumns(): void + { + $adapter = $this->createMock(Adapter::class); + $adapter->method('getDatabase')->willReturn('appwrite'); + $sanitize = (new \ReflectionMethod(Adapter::class, 'sanitizePlan')) + ->getClosure($adapter); + + $sanitized = $sanitize([ + 'table_name' => 'project_1_collection_5_perms', + 'meta_table' => 'appwrite__metadata', + 'projection' => ['_uid', '_createdAt', '_updatedAt', '_permissions', 'title'], + 'tenant_col' => '_tenant', + // The perms/metadata tables also appear embedded in condition strings. + 'attached_condition' => "_45_abc123_perms._permission = 'read' and project_1__metadata._uid = '1'", + // SQL plans qualify columns with the schema name. + 'index_condition' => "(`appwrite`.`main`.`status` = 'published')", + 'nested' => [ + 'inner_table' => 'project_1__metadata', + 'cols' => ['_uid', '_id'], + ], + ]); + + $this->assertSame('', $sanitized['table_name']); + $this->assertSame('', $sanitized['meta_table']); + $this->assertSame('', $sanitized['nested']['inner_table']); + + $this->assertSame(['$id', '$createdAt', '$updatedAt', '$permissions', 'title'], $sanitized['projection']); + $this->assertSame('$tenant', $sanitized['tenant_col']); + + // Embedded physical table tokens inside a condition string are rewritten too. + $this->assertStringNotContainsString('_perms', $sanitized['attached_condition']); + $this->assertStringNotContainsString('__metadata', $sanitized['attached_condition']); + + // The internal schema name is stripped from qualified column references. + $this->assertStringNotContainsString('`appwrite`', $sanitized['index_condition']); + $this->assertSame("(`main`.`status` = 'published')", $sanitized['index_condition']); + + // _id is MySQL's auto-increment column; not renamed. + $this->assertSame(['$id', '_id'], $sanitized['nested']['cols']); + } + + public function testRecordPlanActualsFillsLastEntry(): void + { + $adapter = $this->getMockBuilder(Adapter::class) + ->onlyMethods([]) + ->getMockForAbstractClass(); + + $buffer = new \ReflectionProperty(Adapter::class, 'explainBuffer'); + $buffer->setValue($adapter, [[ + 'purpose' => 'find', + 'context' => ['collection' => 'movies'], + 'plan' => ['engine' => 'mariadb', 'rowsScanned' => 10], + ]]); + + (new \ReflectionMethod(Adapter::class, 'recordPlanActuals')) + ->invoke($adapter, 7, 1.5); + + $captured = $buffer->getValue($adapter); + $this->assertSame(7, $captured[0]['plan']['rowsReturned']); + $this->assertSame(1.5, $captured[0]['plan']['executionTime']); + } + + public function testRecordPlanActualsIgnoresFailedPlans(): void + { + $adapter = $this->getMockForAbstractClass(Adapter::class); + + $buffer = new \ReflectionProperty(Adapter::class, 'explainBuffer'); + // A failed EXPLAIN is stored as ['error' => ...]; actuals must not be + // grafted onto an error entry as if it were a real plan. + $buffer->setValue($adapter, [[ + 'purpose' => 'find', + 'context' => [], + 'plan' => ['error' => 'boom'], + ]]); + + (new \ReflectionMethod(Adapter::class, 'recordPlanActuals')) + ->invoke($adapter, 7, 1.5); + + $captured = $buffer->getValue($adapter); + $this->assertArrayNotHasKey('rowsReturned', $captured[0]['plan']); + $this->assertSame(['error' => 'boom'], $captured[0]['plan']); + } + + public function testRecordPlanActualsNoopWhenNotCapturing(): void + { + $adapter = $this->getMockForAbstractClass(Adapter::class); + + // explainBuffer defaults to null (not capturing) — must be a safe no-op. + (new \ReflectionMethod(Adapter::class, 'recordPlanActuals')) + ->invoke($adapter, 7, 1.5); + + $buffer = new \ReflectionProperty(Adapter::class, 'explainBuffer'); + $this->assertNull($buffer->getValue($adapter)); + } + + public function testPostgresExtractionRecursesIntoChildPlans(): void + { + // Canonical pgvector plan: Limit -> Index Scan. The index name and the + // scanned rows live on the CHILD; the root Limit only knows `k`. + $tree = [ + 'Plan' => [ + 'Node Type' => 'Limit', + 'Plan Rows' => 5, + 'Total Cost' => 42.7, + 'Plans' => [ + [ + 'Node Type' => 'Index Scan', + 'Index Name' => 'movies_embedding_hnsw', + 'Plan Rows' => 950, + 'Total Cost' => 41.0, + ], + ], + ], + ]; + + $adapter = (new \ReflectionClass(Postgres::class))->newInstanceWithoutConstructor(); + $root = $tree['Plan']; + + $rows = (new \ReflectionMethod(Postgres::class, 'extractPgPlanRows'))->invoke($adapter, $root); + $index = (new \ReflectionMethod(Postgres::class, 'extractPgIndexUsed'))->invoke($adapter, $root); + + // rowsScanned comes from the scan leaf (950), NOT the Limit's 5. + $this->assertSame(950, $rows); + $this->assertSame('movies_embedding_hnsw', $index); + } + + public function testPostgresExtractionFallsBackToRootRowsWithoutScan(): void + { + $adapter = (new \ReflectionClass(Postgres::class))->newInstanceWithoutConstructor(); + $root = [ + 'Node Type' => 'Result', + 'Plan Rows' => 1, + ]; + + $rows = (new \ReflectionMethod(Postgres::class, 'extractPgPlanRows'))->invoke($adapter, $root); + $index = (new \ReflectionMethod(Postgres::class, 'extractPgIndexUsed'))->invoke($adapter, $root); + + $this->assertSame(1, $rows); + $this->assertNull($index); + } + + public function testPoolDoesNotRestartCaptureOnAlreadyCapturingPinnedAdapter(): void + { + // Reproduces the re-entrancy bug: while the pool is capturing, a nested + // delegate() on the pinned (transaction) adapter — e.g. a before(find) + // transformation issuing its own query — must NOT call + // startExplainCapture() again, which would throw "cannot be nested". + $inner = $this->getMockBuilder(Adapter::class) + ->onlyMethods(['startExplainCapture', 'isExplainCapturing', 'ping']) + ->getMockForAbstractClass(); + + // The inner adapter is already mid-capture from the outer find(). + $inner->method('isExplainCapturing')->willReturn(true); + $inner->method('ping')->willReturn(true); + // The guard must prevent any re-start on the already-capturing adapter. + $inner->expects($this->never())->method('startExplainCapture'); + + $pool = (new \ReflectionClass(Pool::class))->newInstanceWithoutConstructor(); + + // Pin the inner adapter (as withTransaction does) and turn on pool-level + // capture so delegate() takes the capturing branch. + (new \ReflectionProperty(Pool::class, 'pinnedAdapter'))->setValue($pool, $inner); + (new \ReflectionProperty(Adapter::class, 'explainBuffer'))->setValue($pool, []); + + $result = $pool->delegate('ping', []); + + $this->assertTrue($result); + } + + public function testPoolClearsStaleTimeoutOnBorrowedAdapters(): void + { + $inner = $this->getMockBuilder(Adapter::class) + ->onlyMethods(['clearTimeout', 'ping']) + ->getMockForAbstractClass(); + + $inner + ->expects($this->once()) + ->method('clearTimeout') + ->with(Database::EVENT_ALL); + $inner->method('ping')->willReturn(true); + + $pool = new UtopiaPool(new Stack(), 'mock', 1, fn () => $inner); + $adapter = new Pool($pool); + $adapter->setAuthorization(new Authorization()); + + $this->assertTrue($adapter->ping()); + } + + public function testPoolReappliesTimeoutAcrossDelegatedCalls(): void + { + // Regression: after setTimeout() on the Pool, a subsequent delegated call + // (e.g. find) must re-apply the timeout to whatever adapter is borrowed + // — not clear it because the Pool itself forgot the timeout was set. + $inner = $this->getMockBuilder(Adapter::class) + ->onlyMethods(['setTimeout', 'clearTimeout', 'ping']) + ->getMockForAbstractClass(); + + // Every setTimeout invocation must carry the live timeout, never clear it. + $inner + ->method('setTimeout') + ->with(1000, Database::EVENT_ALL); + // clearTimeout must NOT be called while the Pool still has a positive timeout. + $inner->expects($this->never())->method('clearTimeout'); + $inner->method('ping')->willReturn(true); + + $pool = new UtopiaPool(new Stack(), 'mock', 1, fn () => $inner); + $adapter = new Pool($pool); + $adapter->setAuthorization(new Authorization()); + + $adapter->setTimeout(1000); + $this->assertSame(1000, $adapter->getTimeout()); + $this->assertTrue($adapter->ping()); + } +}