diff --git a/composer.json b/composer.json index 1bc85063..29693707 100644 --- a/composer.json +++ b/composer.json @@ -17,7 +17,7 @@ "require": { "php": ">=8.2", "freedsx/asn1": "dev-main#b57a38f", - "freedsx/socket": "dev-main#610bf80", + "freedsx/socket": "dev-main#287974b", "freedsx/sasl": "dev-main#85e1ef9", "psr/log": "^3" }, diff --git a/docs/Server/Monitoring.md b/docs/Server/Monitoring.md index e7e2fec4..30f3aeaa 100644 --- a/docs/Server/Monitoring.md +++ b/docs/Server/Monitoring.md @@ -53,9 +53,17 @@ off rather than returned empty. | `connectionsTotal` | Connections accepted since start. | | `connectionsRejected` | Connections turned away at the connection limit. | | `connectionsWriteTimeouts`, `connectionsIdleTimeouts` | Connections closed by the write or idle timeout. | +| `connectionsRequestSizeExceeded` | Connections dropped because a request exceeded `setMaxRequestSize`. | | `connectionsMax` | The configured connection limit (`0` is unlimited). | | `operationsCompleted`, `operationsFailed` | Total operations and the failed subset. | | `operationsByType` | Per-type counts, e.g. `search=1402, bind=210, add=8`. | +| `operationsByResultCode` | Per-result-code counts, e.g. `0=1610, 49=3, 32=5`. | +| `operationsAvgLatencyMsByType` | Mean latency in milliseconds per type, e.g. `search=1.83, bind=0.42`. | +| `bindsByMethod` | Bind counts split by method, e.g. `anonymous=12, simple=200, sasl=8`. | +| `searchesByScope` | Search counts split by scope, e.g. `base=4, one=10, sub=1388`. | +| `operationsInProgressByType` | Operations currently executing, per type. Coroutine runner only (see [Runner Differences](#runner-differences)). | +| `trafficBytesSent`, `trafficBytesReceived` | LDAP protocol bytes written to and read from clients. | +| `trafficEntriesReturned` | Search-result entries returned to clients. | Counters are monotonic since start and are never reset, so sample and diff them to get rates. A restart starts them over. @@ -67,13 +75,17 @@ authenticated-only. To restrict it further, add `RuleBasedAccessControl` rules t ## Runner Differences -* **Swoole** runs in one process, so `cn=monitor` is fully live. -* **PCNTL** forks per connection. Connection gauges are authoritative, and operation counts stay current to within about - one accept cycle (`setSocketAcceptTimeout`), including on long-lived connections. They are best-effort: a forcibly - killed worker may lose its most recent operations. +**Swoole** (single process): -Under PCNTL the monitor data is published to a JSON file, by default under the system temp directory keyed by port. Set -`setMonitorSnapshotPath()` to relocate it or to avoid collisions when running several instances on one host. +* `cn=monitor` is fully live. +* `operationsInProgressByType` is reported. + +**PCNTL** (forks per connection): + +* Connection gauges are authoritative. +* Operation counts, traffic totals, and breakdowns are best-effort and current to within about one accept cycle. +* `operationsInProgressByType` is omitted: it is a per-child gauge the parent serving `cn=monitor` cannot aggregate. +* Monitor data is published to a JSON file, by default under the system temp directory keyed by port; set `setMonitorSnapshotPath()` to relocate it or avoid collisions across instances. For per-operation aggregation that survives saturation or spans instances, prefer a push exporter. @@ -85,8 +97,9 @@ Provide any `MetricsRecorderInterface` to receive events out-of-band: $options->setMetricsRecorder($myRecorder); ``` -It is notified of each operation (`operationObserved`), connection lifecycle event (`connectionObserved`), server start, -and config reload. The recorder and `cn=monitor` are independent, so the two options compose: +It is notified of each operation start (`operationStarted`) and completion (`operationObserved`), transport traffic +(`trafficObserved`), connection lifecycle event (`connectionObserved`), server start, and config reload. The recorder and +`cn=monitor` are independent, so the two options compose: | `setMonitorEnabled` | `setMetricsRecorder` | Result | | --- | --- | --- | diff --git a/src/FreeDSx/Ldap/Protocol/LdapQueue.php b/src/FreeDSx/Ldap/Protocol/LdapQueue.php index 306a10ae..b9772894 100644 --- a/src/FreeDSx/Ldap/Protocol/LdapQueue.php +++ b/src/FreeDSx/Ldap/Protocol/LdapQueue.php @@ -127,13 +127,16 @@ protected function unwrap(string $bytes): Buffer protected function decode(string $bytes): Message { try { - return parent::decode($bytes); + $message = parent::decode($bytes); } catch (PduLengthException $e) { throw new RequestSizeExceededException( $e->getMessage(), previous: $e, ); } + $this->onMessageDecoded($message); + + return $message; } /** @@ -152,6 +155,7 @@ protected function sendLdapMessage(iterable $messages): static foreach ($messages as $message) { $encoded = $this->encoder->encode($message->toAsn1()); + $this->onMessageEncoded($encoded); $buffer .= $this->messageWrapper !== null ? $this->messageWrapper->wrap($encoded) : $encoded; $bufferLen = strlen($buffer); if ($bufferLen >= self::BUFFER_SIZE) { @@ -166,6 +170,16 @@ protected function sendLdapMessage(iterable $messages): static return $this; } + /** + * Extension point invoked with each message's encoded bytes as it is sent. + */ + protected function onMessageEncoded(string $encoded): void {} + + /** + * Extension point invoked with each message decoded off the socket. + */ + protected function onMessageDecoded(Message $message): void {} + public function isConnected(): bool { return $this->socket->isConnected(); diff --git a/src/FreeDSx/Ldap/Protocol/Queue/Response/MetricsResponseInterceptor.php b/src/FreeDSx/Ldap/Protocol/Queue/Response/MetricsResponseInterceptor.php new file mode 100644 index 00000000..df335f75 --- /dev/null +++ b/src/FreeDSx/Ldap/Protocol/Queue/Response/MetricsResponseInterceptor.php @@ -0,0 +1,38 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace FreeDSx\Ldap\Protocol\Queue\Response; + +use FreeDSx\Ldap\Operation\Response\SearchResultEntry; +use FreeDSx\Ldap\Protocol\LdapMessageResponse; +use FreeDSx\Ldap\Server\Metrics\MetricsRecorderInterface; +use FreeDSx\Ldap\Server\Metrics\Observation\TrafficObservation; + +/** + * Counts search-result entries as they stream out to the client. + * + * @author Chad Sikorra + */ +final readonly class MetricsResponseInterceptor implements ResponseInterceptor +{ + public function __construct(private MetricsRecorderInterface $recorder) {} + + public function intercept(LdapMessageResponse $response): LdapMessageResponse + { + if ($response->getResponse() instanceof SearchResultEntry) { + $this->recorder->trafficObserved(new TrafficObservation(entriesReturned: 1)); + } + + return $response; + } +} diff --git a/src/FreeDSx/Ldap/Protocol/Queue/ServerQueue.php b/src/FreeDSx/Ldap/Protocol/Queue/ServerQueue.php index 3cb3fa50..e3c8e50e 100644 --- a/src/FreeDSx/Ldap/Protocol/Queue/ServerQueue.php +++ b/src/FreeDSx/Ldap/Protocol/Queue/ServerQueue.php @@ -27,11 +27,16 @@ use FreeDSx\Ldap\Protocol\LdapMessageResponse; use FreeDSx\Ldap\Protocol\LdapQueue; use FreeDSx\Ldap\Protocol\Queue\Response\ResponseInterceptor; +use FreeDSx\Ldap\Server\Metrics\MetricsRecorderInterface; +use FreeDSx\Ldap\Server\Metrics\Observation\TrafficObservation; +use FreeDSx\Ldap\Server\Metrics\Recorder\NullMetricsRecorder; use FreeDSx\Socket\Exception\ConnectionException; use FreeDSx\Socket\Queue\Message; use FreeDSx\Socket\Socket; use Generator; +use function strlen; + /** * The LDAP Queue class for sending and receiving messages for servers. * @@ -57,6 +62,7 @@ public function __construct( ?EncoderInterface $encoder = null, int $maxReceiveSize = 0, array $interceptors = [], + private readonly MetricsRecorderInterface $metricsRecorder = new NullMetricsRecorder(), ) { parent::__construct( $socket, @@ -66,6 +72,32 @@ public function __construct( $this->interceptors = $interceptors; } + /** + * Count the LDAP bytes received for a decoded request. + * + * @throws ProtocolException + */ + protected function decode(string $bytes): Message + { + $message = parent::decode($bytes); + + $this->metricsRecorder->trafficObserved(new TrafficObservation( + bytesReceived: (int) $message->getLastPosition(), + )); + + return $message; + } + + /** + * Count the LDAP bytes sent for each outgoing response. + */ + protected function onMessageEncoded(string $encoded): void + { + $this->metricsRecorder->trafficObserved(new TrafficObservation( + bytesSent: strlen($encoded), + )); + } + /** * @throws ProtocolException * @throws UnsolicitedNotificationException diff --git a/src/FreeDSx/Ldap/Protocol/ServerProtocolHandler.php b/src/FreeDSx/Ldap/Protocol/ServerProtocolHandler.php index 24417d96..1c783ced 100644 --- a/src/FreeDSx/Ldap/Protocol/ServerProtocolHandler.php +++ b/src/FreeDSx/Ldap/Protocol/ServerProtocolHandler.php @@ -16,6 +16,7 @@ use FreeDSx\Asn1\Exception\EncoderException; use FreeDSx\Ldap\Exception\OperationException; use FreeDSx\Ldap\Exception\ProtocolException; +use FreeDSx\Ldap\Exception\RequestSizeExceededException; use FreeDSx\Ldap\Exception\RequestValidationException; use FreeDSx\Ldap\Exception\ResponseAlreadySentException; use FreeDSx\Ldap\Operation\Response\ExtendedResponse; @@ -26,9 +27,11 @@ use FreeDSx\Ldap\Server\Logging\EventContext; use FreeDSx\Ldap\Server\Logging\EventLogger; use FreeDSx\Ldap\Server\Logging\ServerEvent; +use FreeDSx\Ldap\Server\Metrics\Observation\ConnectionObservation; use FreeDSx\Ldap\Server\Middleware\Pipeline\MiddlewareHandlerInterface; use FreeDSx\Ldap\Server\Middleware\Pipeline\ServerRequestContext; use FreeDSx\Socket\Exception\ConnectionException; +use FreeDSx\Socket\Exception\IdleTimeoutException; use FreeDSx\Socket\Exception\WriteTimeoutException; use Throwable; @@ -50,10 +53,14 @@ public function __construct( /** * Listens for messages from the socket and handles the responses/actions needed. * + * @return ?ConnectionObservation The connection-timeout that ended the session, or null for a normal close. + * * @throws EncoderException */ - public function handle(): void + public function handle(): ?ConnectionObservation { + $closeReason = null; + try { while ($message = $this->queue->getMessage()) { $this->dispatchRequest($message); @@ -72,12 +79,27 @@ public function handle(): void ServerEvent::WriteTimeout, [EventContext::REASON_MESSAGE => $e->getMessage()], ); + $closeReason = ConnectionObservation::WriteTimeout; + } catch (IdleTimeoutException $e) { + # The client sent nothing within the read timeout. Record it and close; there is nothing to send back. + $this->eventLogger->record( + ServerEvent::IdleTimeout, + [EventContext::REASON_MESSAGE => $e->getMessage()], + ); + $closeReason = ConnectionObservation::IdleTimeout; } catch (ConnectionException) { # Connection closure is recorded by the runner's lifecycle logging; no audit event for normal client disconnects. + } catch (RequestSizeExceededException $e) { + # The client sent a PDU larger than the configured maximum. Per RFC 4511 §4.1.1 answer with a Notice of + # Disconnection, passing the cause so the log identifies the size violation, then record it and close. + $this->sendNoticeOfDisconnect( + $e->getMessage(), + cause: $e, + ); + $closeReason = ConnectionObservation::RequestSizeExceeded; } catch (EncoderException|ProtocolException) { - # Per RFC 4511 §4.1.1, a PDU that cannot be processed — malformed, or rejected for exceeding the configured - # size cap (RequestSizeExceededException) — warrants a disconnect with a protocol error. The - # NoticeOfDisconnectSent event records the specific reason. + # Per RFC 4511 §4.1.1, a PDU that cannot be processed (malformed) warrants a disconnect with a protocol + # error. The NoticeOfDisconnectSent event records the specific reason. $this->sendNoticeOfDisconnect('The message could not be processed.'); } catch (Throwable $e) { if ($this->queue->isConnected()) { @@ -88,6 +110,8 @@ public function handle(): void $this->queue->close(); } } + + return $closeReason; } /** diff --git a/src/FreeDSx/Ldap/Protocol/ServerProtocolHandler/ServerMonitorHandler.php b/src/FreeDSx/Ldap/Protocol/ServerProtocolHandler/ServerMonitorHandler.php index 9717b3f3..4d43f807 100644 --- a/src/FreeDSx/Ldap/Protocol/ServerProtocolHandler/ServerMonitorHandler.php +++ b/src/FreeDSx/Ldap/Protocol/ServerProtocolHandler/ServerMonitorHandler.php @@ -24,6 +24,7 @@ use FreeDSx\Ldap\Server\Metrics\Snapshot\MetricsSnapshot; use FreeDSx\Ldap\Server\Operation\OperationOutcomeResult; use FreeDSx\Ldap\Server\Operation\OperationResult; +use FreeDSx\Ldap\Server\ServerRunner\CoroutineServerRunnerInterface; use FreeDSx\Ldap\Server\ServerRunner\PcntlServerRunner; use FreeDSx\Ldap\Server\ServerRunner\SwooleServerRunner; use FreeDSx\Ldap\Server\Token\TokenInterface; @@ -81,6 +82,7 @@ private function attributes(MetricsSnapshot $snapshot): array $lifecycle = $snapshot->lifecycle; $connections = $snapshot->connections; $operations = $snapshot->operations; + $traffic = $snapshot->traffic; return array_filter([ 'objectClass' => ['top', 'extensibleObject'], @@ -97,13 +99,79 @@ private function attributes(MetricsSnapshot $snapshot): array 'connectionsRejected' => [(string) $connections->rejected], 'connectionsWriteTimeouts' => [(string) $connections->writeTimeouts], 'connectionsIdleTimeouts' => [(string) $connections->idleTimeouts], + 'connectionsRequestSizeExceeded' => [(string) $connections->requestSizeExceeded], 'connectionsMax' => [(string) $this->options->getMaxConnections()], 'operationsCompleted' => [(string) $operations->total()], 'operationsFailed' => [(string) $operations->totalErrors()], - 'operationsByType' => $this->operationsByType($operations->counts), + 'operationsByType' => $this->formatCounts($operations->counts), + 'operationsByResultCode' => $this->formatCounts($operations->resultCodeCounts), + 'bindsByMethod' => $this->formatCounts($operations->bindCounts), + 'searchesByScope' => $this->formatCounts($operations->searchScopeCounts), + 'operationsAvgLatencyMsByType' => $this->avgLatencyMsByType( + $operations->counts, + $operations->durationSeconds, + ), + 'operationsInProgressByType' => $this->operationsInProgress($snapshot->operationsInProgress), + 'trafficBytesSent' => [(string) $traffic->bytesSent], + 'trafficBytesReceived' => [(string) $traffic->bytesReceived], + 'trafficEntriesReturned' => [(string) $traffic->entriesReturned], ]); } + /** + * The in-flight gauge is only meaningful under the single-process Swoole runner. + * + * @param array $inProgress + * @return list + */ + private function operationsInProgress(array $inProgress): array + { + if (!$this->isCoroutineRunner()) { + return []; + } + + return $this->formatCounts($inProgress); + } + + private function isCoroutineRunner(): bool + { + $runner = $this->options->getServerRunner(); + + if ($runner !== null) { + return $runner instanceof CoroutineServerRunnerInterface; + } + + return $this->options->getUseSwooleRunner(); + } + + /** + * Mean latency per operation type in milliseconds, derived from the summed duration and count. + * + * @param array $counts + * @param array $durationSeconds + * @return list + */ + private function avgLatencyMsByType( + array $counts, + array $durationSeconds, + ): array { + $values = []; + + foreach ($counts as $operation => $count) { + if ($count <= 0) { + continue; + } + + $averageMs = (($durationSeconds[$operation] ?? 0.0) / $count) * 1000; + $values[] = $operation . '=' . (string) round( + $averageMs, + 2, + ); + } + + return $values; + } + /** * @return list */ @@ -135,15 +203,17 @@ private function runnerClass(): string } /** - * @param array $counts + * Render a count map as multivalue "key=count" strings. + * + * @param array $counts * @return list */ - private function operationsByType(array $counts): array + private function formatCounts(array $counts): array { $values = []; - foreach ($counts as $operation => $count) { - $values[] = $operation . '=' . $count; + foreach ($counts as $key => $count) { + $values[] = $key . '=' . $count; } return $values; diff --git a/src/FreeDSx/Ldap/Server/Logging/EventLogPolicy.php b/src/FreeDSx/Ldap/Server/Logging/EventLogPolicy.php index 961a5baf..c1fa2775 100644 --- a/src/FreeDSx/Ldap/Server/Logging/EventLogPolicy.php +++ b/src/FreeDSx/Ldap/Server/Logging/EventLogPolicy.php @@ -59,6 +59,7 @@ public static function default(): self ServerEvent::SchemaViolation, ServerEvent::NoticeOfDisconnectSent, ServerEvent::WriteTimeout, + ServerEvent::IdleTimeout, ServerEvent::PasswordPolicyAccountLocked, ServerEvent::PasswordPolicyAccountUnlocked, ServerEvent::PasswordPolicyExpired, diff --git a/src/FreeDSx/Ldap/Server/Logging/ServerEvent.php b/src/FreeDSx/Ldap/Server/Logging/ServerEvent.php index 2996a33f..8a31befd 100644 --- a/src/FreeDSx/Ldap/Server/Logging/ServerEvent.php +++ b/src/FreeDSx/Ldap/Server/Logging/ServerEvent.php @@ -45,6 +45,7 @@ enum ServerEvent: string case SchemaViolation = 'schema.violation'; case NoticeOfDisconnectSent = 'session.disconnect_notice'; case WriteTimeout = 'session.write_timeout'; + case IdleTimeout = 'session.idle_timeout'; case PasswordPolicyAccountLocked = 'password_policy.account_locked'; case PasswordPolicyAccountUnlocked = 'password_policy.account_unlocked'; case PasswordPolicyExpired = 'password_policy.expired'; @@ -66,6 +67,7 @@ public function level(): string self::SchemaViolation, self::NoticeOfDisconnectSent, self::WriteTimeout, + self::IdleTimeout, self::PasswordPolicyExpired, self::PasswordPolicyChangeRejected => LogLevel::NOTICE, default => LogLevel::INFO, diff --git a/src/FreeDSx/Ldap/Server/Metrics/MetricsRecorderInterface.php b/src/FreeDSx/Ldap/Server/Metrics/MetricsRecorderInterface.php index e42ee7e2..849f482e 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/MetricsRecorderInterface.php +++ b/src/FreeDSx/Ldap/Server/Metrics/MetricsRecorderInterface.php @@ -13,8 +13,10 @@ namespace FreeDSx\Ldap\Server\Metrics; +use FreeDSx\Ldap\Operation\OperationType; use FreeDSx\Ldap\Server\Metrics\Observation\ConnectionObservation; use FreeDSx\Ldap\Server\Metrics\Observation\OperationObservation; +use FreeDSx\Ldap\Server\Metrics\Observation\TrafficObservation; /** * Sink that server components push metric observations to. @@ -23,8 +25,21 @@ */ interface MetricsRecorderInterface { + /** + * Records a completed operation, also clearing the in-light counter. + */ public function operationObserved(OperationObservation $observation): void; + /** + * Marks an operation as entering the handler. + */ + public function operationStarted(OperationType $operation): void; + + /** + * Records a unit of transport traffic. + */ + public function trafficObserved(TrafficObservation $observation): void; + public function connectionObserved(ConnectionObservation $observation): void; /** diff --git a/src/FreeDSx/Ldap/Server/Metrics/Observation/ConnectionObservation.php b/src/FreeDSx/Ldap/Server/Metrics/Observation/ConnectionObservation.php index 2fe5f3ef..74c7d4c7 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Observation/ConnectionObservation.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Observation/ConnectionObservation.php @@ -29,4 +29,6 @@ enum ConnectionObservation: string case WriteTimeout = 'write_timeout'; case IdleTimeout = 'idle_timeout'; + + case RequestSizeExceeded = 'request_size_exceeded'; } diff --git a/src/FreeDSx/Ldap/Server/Metrics/Observation/OperationObservation.php b/src/FreeDSx/Ldap/Server/Metrics/Observation/OperationObservation.php index 1da2c249..fb26d076 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Observation/OperationObservation.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Observation/OperationObservation.php @@ -24,11 +24,15 @@ { /** * @param int $resultCode The LDAP result code the operation produced. + * @param string|null $bindMethod The bind sub-type (anonymous/simple/sasl) for binds, null otherwise. + * @param string|null $searchScope The search scope (base/one/sub) for searches, null otherwise. */ public function __construct( public OperationType $operation, public bool $succeeded, public float $durationSeconds, public int $resultCode, + public ?string $bindMethod = null, + public ?string $searchScope = null, ) {} } diff --git a/src/FreeDSx/Ldap/Server/Metrics/Observation/TrafficObservation.php b/src/FreeDSx/Ldap/Server/Metrics/Observation/TrafficObservation.php new file mode 100644 index 00000000..85dcda9a --- /dev/null +++ b/src/FreeDSx/Ldap/Server/Metrics/Observation/TrafficObservation.php @@ -0,0 +1,28 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace FreeDSx\Ldap\Server\Metrics\Observation; + +/** + * A unit of transport traffic. + * + * @author Chad Sikorra + */ +final readonly class TrafficObservation +{ + public function __construct( + public int $bytesSent = 0, + public int $bytesReceived = 0, + public int $entriesReturned = 0, + ) {} +} diff --git a/src/FreeDSx/Ldap/Server/Metrics/Recorder/InMemoryMetricsRecorder.php b/src/FreeDSx/Ldap/Server/Metrics/Recorder/InMemoryMetricsRecorder.php index 11e533b3..7b2e6ff9 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Recorder/InMemoryMetricsRecorder.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Recorder/InMemoryMetricsRecorder.php @@ -13,15 +13,19 @@ namespace FreeDSx\Ldap\Server\Metrics\Recorder; +use FreeDSx\Ldap\Operation\OperationType; use FreeDSx\Ldap\Server\Metrics\Observation\ConnectionObservation; use FreeDSx\Ldap\Server\Metrics\MetricsRecorderInterface; use FreeDSx\Ldap\Server\Metrics\MetricsSnapshotProvider; use FreeDSx\Ldap\Server\Metrics\Observation\OperationObservation; -use FreeDSx\Ldap\Server\Metrics\Rollup\OperationRollupInterface; +use FreeDSx\Ldap\Server\Metrics\Observation\TrafficObservation; +use FreeDSx\Ldap\Server\Metrics\Rollup\MetricsDelta; +use FreeDSx\Ldap\Server\Metrics\Rollup\MetricsRollupInterface; use FreeDSx\Ldap\Server\Metrics\Snapshot\ConnectionMetrics; use FreeDSx\Ldap\Server\Metrics\Snapshot\LifecycleMetrics; use FreeDSx\Ldap\Server\Metrics\Snapshot\MetricsSnapshot; use FreeDSx\Ldap\Server\Metrics\Snapshot\OperationMetrics; +use FreeDSx\Ldap\Server\Metrics\Snapshot\TrafficMetrics; use function max; @@ -30,7 +34,7 @@ * * @author Chad Sikorra */ -final class InMemoryMetricsRecorder implements MetricsRecorderInterface, MetricsSnapshotProvider, OperationRollupInterface +final class InMemoryMetricsRecorder implements MetricsRecorderInterface, MetricsSnapshotProvider, MetricsRollupInterface { private int $startedAt = 0; @@ -66,6 +70,11 @@ final class InMemoryMetricsRecorder implements MetricsRecorderInterface, Metrics */ private int $idleTimeouts = 0; + /** + * @var int<0, max> + */ + private int $requestSizeExceeded = 0; + /** * @var array> */ @@ -86,8 +95,60 @@ final class InMemoryMetricsRecorder implements MetricsRecorderInterface, Metrics */ private array $resultCodeCounts = []; + /** + * @var array> + */ + private array $bindCounts = []; + + /** + * @var array> + */ + private array $searchScopeCounts = []; + + /** + * @var array> In-flight count per operation type; entries are pruned when they reach zero. + */ + private array $operationsInProgress = []; + + /** + * @var int<0, max> + */ + private int $bytesSent = 0; + + /** + * @var int<0, max> + */ + private int $bytesReceived = 0; + + /** + * @var int<0, max> + */ + private int $entriesReturned = 0; + + public function trafficObserved(TrafficObservation $observation): void + { + $this->bytesSent = max( + 0, + $this->bytesSent + $observation->bytesSent, + ); + $this->bytesReceived = max( + 0, + $this->bytesReceived + $observation->bytesReceived, + ); + $this->entriesReturned = max( + 0, + $this->entriesReturned + $observation->entriesReturned, + ); + } + + public function operationStarted(OperationType $operation): void + { + $this->operationsInProgress[$operation->value] = ($this->operationsInProgress[$operation->value] ?? 0) + 1; + } + public function operationObserved(OperationObservation $observation): void { + $this->clearInProgress($observation->operation); $operation = $observation->operation->value; $this->operationCounts[$operation] = ($this->operationCounts[$operation] ?? 0) + 1; $this->operationDurationSeconds[$operation] = ($this->operationDurationSeconds[$operation] ?? 0.0) @@ -97,6 +158,14 @@ public function operationObserved(OperationObservation $observation): void if (!$observation->succeeded) { $this->operationErrors[$operation] = ($this->operationErrors[$operation] ?? 0) + 1; } + + if ($observation->bindMethod !== null) { + $this->bindCounts[$observation->bindMethod] = ($this->bindCounts[$observation->bindMethod] ?? 0) + 1; + } + + if ($observation->searchScope !== null) { + $this->searchScopeCounts[$observation->searchScope] = ($this->searchScopeCounts[$observation->searchScope] ?? 0) + 1; + } } public function connectionObserved(ConnectionObservation $observation): void @@ -107,6 +176,7 @@ public function connectionObserved(ConnectionObservation $observation): void ConnectionObservation::Rejected => $this->rejectedConnections++, ConnectionObservation::WriteTimeout => $this->writeTimeouts++, ConnectionObservation::IdleTimeout => $this->idleTimeouts++, + ConnectionObservation::RequestSizeExceeded => $this->requestSizeExceeded++, }; } @@ -135,46 +205,102 @@ public function snapshot(): MetricsSnapshot $this->rejectedConnections, $this->writeTimeouts, $this->idleTimeouts, + $this->requestSizeExceeded, ), - new OperationMetrics( - $this->operationCounts, - $this->operationErrors, - $this->operationDurationSeconds, - $this->resultCodeCounts, - ), + $this->operationMetrics(), + $this->operationsInProgress, + $this->trafficMetrics(), ); } - public function takeOperationDelta(): OperationMetrics + private function operationMetrics(): OperationMetrics { - $delta = new OperationMetrics( + return new OperationMetrics( $this->operationCounts, $this->operationErrors, $this->operationDurationSeconds, $this->resultCodeCounts, + $this->bindCounts, + $this->searchScopeCounts, ); + } - $this->resetOperations(); + private function trafficMetrics(): TrafficMetrics + { + return new TrafficMetrics( + $this->bytesSent, + $this->bytesReceived, + $this->entriesReturned, + ); + } + + /** + * Decrement, and prune at zero, the in-flight gauge for a completed operation type. + */ + private function clearInProgress(OperationType $operation): void + { + $key = $operation->value; + + if (!isset($this->operationsInProgress[$key])) { + return; + } + + $remaining = $this->operationsInProgress[$key] - 1; + + if ($remaining <= 0) { + unset($this->operationsInProgress[$key]); + + return; + } + + $this->operationsInProgress[$key] = $remaining; + } + + public function takeDelta(): MetricsDelta + { + $delta = new MetricsDelta( + $this->operationMetrics(), + $this->trafficMetrics(), + ); + + $this->resetDelta(); return $delta; } - public function resetOperations(): void + public function resetDelta(): void { $this->operationCounts = []; $this->operationErrors = []; $this->operationDurationSeconds = []; $this->resultCodeCounts = []; + $this->bindCounts = []; + $this->searchScopeCounts = []; + $this->bytesSent = 0; + $this->bytesReceived = 0; + $this->entriesReturned = 0; } - public function mergeOperations(OperationMetrics $delta): void + public function mergeDelta(MetricsDelta $delta): void + { + $this->mergeOperations($delta->operations); + $this->mergeTraffic($delta->traffic); + } + + private function mergeOperations(OperationMetrics $delta): void { foreach ($delta->counts as $operation => $count) { - $this->operationCounts[$operation] = max(0, ($this->operationCounts[$operation] ?? 0) + $count); + $this->operationCounts[$operation] = max( + 0, + ($this->operationCounts[$operation] ?? 0) + $count, + ); } foreach ($delta->errors as $operation => $count) { - $this->operationErrors[$operation] = max(0, ($this->operationErrors[$operation] ?? 0) + $count); + $this->operationErrors[$operation] = max( + 0, + ($this->operationErrors[$operation] ?? 0) + $count, + ); } foreach ($delta->durationSeconds as $operation => $seconds) { @@ -182,10 +308,43 @@ public function mergeOperations(OperationMetrics $delta): void } foreach ($delta->resultCodeCounts as $code => $count) { - $this->resultCodeCounts[$code] = max(0, ($this->resultCodeCounts[$code] ?? 0) + $count); + $this->resultCodeCounts[$code] = max( + 0, + ($this->resultCodeCounts[$code] ?? 0) + $count, + ); + } + + foreach ($delta->bindCounts as $method => $count) { + $this->bindCounts[$method] = max( + 0, + ($this->bindCounts[$method] ?? 0) + $count, + ); + } + + foreach ($delta->searchScopeCounts as $scope => $count) { + $this->searchScopeCounts[$scope] = max( + 0, + ($this->searchScopeCounts[$scope] ?? 0) + $count, + ); } } + private function mergeTraffic(TrafficMetrics $delta): void + { + $this->bytesSent = max( + 0, + $this->bytesSent + $delta->bytesSent, + ); + $this->bytesReceived = max( + 0, + $this->bytesReceived + $delta->bytesReceived, + ); + $this->entriesReturned = max( + 0, + $this->entriesReturned + $delta->entriesReturned, + ); + } + private function onOpened(): void { $this->activeConnections++; diff --git a/src/FreeDSx/Ldap/Server/Metrics/Recorder/MetricsRecorderChain.php b/src/FreeDSx/Ldap/Server/Metrics/Recorder/MetricsRecorderChain.php index 4dde2e25..4b508d59 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Recorder/MetricsRecorderChain.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Recorder/MetricsRecorderChain.php @@ -13,9 +13,11 @@ namespace FreeDSx\Ldap\Server\Metrics\Recorder; +use FreeDSx\Ldap\Operation\OperationType; use FreeDSx\Ldap\Server\Metrics\Observation\ConnectionObservation; use FreeDSx\Ldap\Server\Metrics\MetricsRecorderInterface; use FreeDSx\Ldap\Server\Metrics\Observation\OperationObservation; +use FreeDSx\Ldap\Server\Metrics\Observation\TrafficObservation; use function array_values; @@ -43,6 +45,20 @@ public function operationObserved(OperationObservation $observation): void } } + public function operationStarted(OperationType $operation): void + { + foreach ($this->recorders as $recorder) { + $recorder->operationStarted($operation); + } + } + + public function trafficObserved(TrafficObservation $observation): void + { + foreach ($this->recorders as $recorder) { + $recorder->trafficObserved($observation); + } + } + public function connectionObserved(ConnectionObservation $observation): void { foreach ($this->recorders as $recorder) { diff --git a/src/FreeDSx/Ldap/Server/Metrics/Recorder/NullMetricsRecorder.php b/src/FreeDSx/Ldap/Server/Metrics/Recorder/NullMetricsRecorder.php index 60a939fd..dd09a844 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Recorder/NullMetricsRecorder.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Recorder/NullMetricsRecorder.php @@ -13,9 +13,11 @@ namespace FreeDSx\Ldap\Server\Metrics\Recorder; +use FreeDSx\Ldap\Operation\OperationType; use FreeDSx\Ldap\Server\Metrics\Observation\ConnectionObservation; use FreeDSx\Ldap\Server\Metrics\MetricsRecorderInterface; use FreeDSx\Ldap\Server\Metrics\Observation\OperationObservation; +use FreeDSx\Ldap\Server\Metrics\Observation\TrafficObservation; /** * The default recorder; discards every observation for zero overhead when metrics are unconfigured. @@ -26,6 +28,10 @@ final class NullMetricsRecorder implements MetricsRecorderInterface { public function operationObserved(OperationObservation $observation): void {} + public function operationStarted(OperationType $operation): void {} + + public function trafficObserved(TrafficObservation $observation): void {} + public function connectionObserved(ConnectionObservation $observation): void {} public function serverStarted(int $startedAt): void {} diff --git a/src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsDelta.php b/src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsDelta.php new file mode 100644 index 00000000..726013ef --- /dev/null +++ b/src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsDelta.php @@ -0,0 +1,30 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace FreeDSx\Ldap\Server\Metrics\Rollup; + +use FreeDSx\Ldap\Server\Metrics\Snapshot\OperationMetrics; +use FreeDSx\Ldap\Server\Metrics\Snapshot\TrafficMetrics; + +/** + * The additive metrics a child process reports to the parent in one rollup flush. + * + * @author Chad Sikorra + */ +final readonly class MetricsDelta +{ + public function __construct( + public OperationMetrics $operations = new OperationMetrics(), + public TrafficMetrics $traffic = new TrafficMetrics(), + ) {} +} diff --git a/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationDeltaMessage.php b/src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsDeltaMessage.php similarity index 55% rename from src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationDeltaMessage.php rename to src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsDeltaMessage.php index 919e9853..63d24cd8 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationDeltaMessage.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsDeltaMessage.php @@ -13,21 +13,20 @@ namespace FreeDSx\Ldap\Server\Metrics\Rollup; -use FreeDSx\Ldap\Server\Metrics\Snapshot\OperationMetrics; use FreeDSx\Ldap\Server\Process\ChannelMessage; /** - * Carries a child process's operation-metrics delta to the parent over a ChildChannel. + * Carries a child process's metrics delta to the parent over a ChildChannel. * * @author Chad Sikorra */ -final readonly class OperationDeltaMessage implements ChannelMessage +final readonly class MetricsDeltaMessage implements ChannelMessage { - public function __construct(private OperationMetrics $operations) {} + public function __construct(private MetricsDelta $delta) {} - public function operations(): OperationMetrics + public function delta(): MetricsDelta { - return $this->operations; + return $this->delta; } /** @@ -35,6 +34,9 @@ public function operations(): OperationMetrics */ public function toArray(): array { - return $this->operations->toArray(); + return [ + 'operations' => $this->delta->operations->toArray(), + 'traffic' => $this->delta->traffic->toArray(), + ]; } } diff --git a/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationDeltaMessageFactory.php b/src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsDeltaMessageFactory.php similarity index 54% rename from src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationDeltaMessageFactory.php rename to src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsDeltaMessageFactory.php index cf60bfbd..36c0e6cd 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationDeltaMessageFactory.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsDeltaMessageFactory.php @@ -14,21 +14,30 @@ namespace FreeDSx\Ldap\Server\Metrics\Rollup; use FreeDSx\Ldap\Server\Metrics\Snapshot\OperationMetrics; +use FreeDSx\Ldap\Server\Metrics\Snapshot\TrafficMetrics; use FreeDSx\Ldap\Server\Process\ChannelMessage; use FreeDSx\Ldap\Server\Process\ChannelMessageFactory; +use function is_array; + /** - * Rebuilds an OperationDeltaMessage from its wire form on the parent's end of a ChildChannel. + * Rebuilds a MetricsDeltaMessage from its wire form on the parent's end of a ChildChannel. * * @author Chad Sikorra */ -final class OperationDeltaMessageFactory implements ChannelMessageFactory +final class MetricsDeltaMessageFactory implements ChannelMessageFactory { /** * @param array $data */ public function fromArray(array $data): ChannelMessage { - return new OperationDeltaMessage(OperationMetrics::fromArray($data)); + $operations = $data['operations'] ?? null; + $traffic = $data['traffic'] ?? null; + + return new MetricsDeltaMessage(new MetricsDelta( + OperationMetrics::fromArray(is_array($operations) ? $operations : []), + TrafficMetrics::fromArray(is_array($traffic) ? $traffic : []), + )); } } diff --git a/src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsRollupInterface.php b/src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsRollupInterface.php new file mode 100644 index 00000000..b2d66146 --- /dev/null +++ b/src/FreeDSx/Ldap/Server/Metrics/Rollup/MetricsRollupInterface.php @@ -0,0 +1,37 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace FreeDSx\Ldap\Server\Metrics\Rollup; + +/** + * Moves additive metrics between a child and the parent's authoritative totals. + * + * @author Chad Sikorra + */ +interface MetricsRollupInterface +{ + /** + * Return the additive metrics accumulated since the last call and reset them to zero. + */ + public function takeDelta(): MetricsDelta; + + /** + * Clear the additive accumulators without reporting them. + */ + public function resetDelta(): void; + + /** + * Fold a delta reported by a child process into the totals. + */ + public function mergeDelta(MetricsDelta $delta): void; +} diff --git a/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationRollupCoordinator.php b/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationRollupCoordinator.php index 215e7cad..c0264da2 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationRollupCoordinator.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationRollupCoordinator.php @@ -26,8 +26,8 @@ final class OperationRollupCoordinator private ?ChildChannel $boundChannel = null; public function __construct( - private readonly OperationRollupInterface $recorder, - private readonly ChannelMessageFactory $messageFactory = new OperationDeltaMessageFactory(), + private readonly MetricsRollupInterface $recorder, + private readonly ChannelMessageFactory $messageFactory = new MetricsDeltaMessageFactory(), ) {} public function openChannel(): ChildChannel @@ -36,20 +36,20 @@ public function openChannel(): ChildChannel } /** - * In the child: clear operations inherited from the parent and bind the channel this child reports on. + * In the child: clear metrics inherited from the parent and bind the channel this child reports on. */ public function enterChild(ChildChannel $channel): void { - $this->recorder->resetOperations(); + $this->recorder->resetDelta(); $this->boundChannel = $channel; } /** - * In the child: report the operations recorded since the last flush. + * In the child: report the metrics recorded since the last flush. */ public function flush(): void { - $this->boundChannel?->send(new OperationDeltaMessage($this->recorder->takeOperationDelta())); + $this->boundChannel?->send(new MetricsDeltaMessage($this->recorder->takeDelta())); } /** @@ -62,13 +62,13 @@ public function finish(): void } /** - * In the parent: fold any operation deltas available on a child's channel into the totals. + * In the parent: fold any metrics deltas available on a child's channel into the totals. */ public function collect(ChildChannel $channel): void { foreach ($channel->receive() as $message) { - if ($message instanceof OperationDeltaMessage) { - $this->recorder->mergeOperations($message->operations()); + if ($message instanceof MetricsDeltaMessage) { + $this->recorder->mergeDelta($message->delta()); } } } diff --git a/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationRollupInterface.php b/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationRollupInterface.php deleted file mode 100644 index 2187a15d..00000000 --- a/src/FreeDSx/Ldap/Server/Metrics/Rollup/OperationRollupInterface.php +++ /dev/null @@ -1,39 +0,0 @@ - - * - * For the full copyright and license information, please view the LICENSE - * file that was distributed with this source code. - */ - -namespace FreeDSx\Ldap\Server\Metrics\Rollup; - -use FreeDSx\Ldap\Server\Metrics\Snapshot\OperationMetrics; - -/** - * Moves operation metrics between a child and the parent's authoritative totals. - * - * @author Chad Sikorra - */ -interface OperationRollupInterface -{ - /** - * Return the operation metrics accumulated since the last call and reset them to zero. - */ - public function takeOperationDelta(): OperationMetrics; - - /** - * Clear the operation accumulators. - */ - public function resetOperations(): void; - - /** - * Fold an operation-metrics delta reported by a child process into the totals. - */ - public function mergeOperations(OperationMetrics $delta): void; -} diff --git a/src/FreeDSx/Ldap/Server/Metrics/Snapshot/ConnectionMetrics.php b/src/FreeDSx/Ldap/Server/Metrics/Snapshot/ConnectionMetrics.php index 5f3aa37e..ee7c73d2 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Snapshot/ConnectionMetrics.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Snapshot/ConnectionMetrics.php @@ -26,6 +26,7 @@ public function __construct( public int $rejected = 0, public int $writeTimeouts = 0, public int $idleTimeouts = 0, + public int $requestSizeExceeded = 0, ) {} /** @@ -39,6 +40,7 @@ public function toArray(): array 'rejected' => $this->rejected, 'write_timeouts' => $this->writeTimeouts, 'idle_timeouts' => $this->idleTimeouts, + 'request_size_exceeded' => $this->requestSizeExceeded, ]; } @@ -53,6 +55,7 @@ public static function fromArray(array $data): self rejected: SnapshotValue::toInt($data['rejected'] ?? null), writeTimeouts: SnapshotValue::toInt($data['write_timeouts'] ?? null), idleTimeouts: SnapshotValue::toInt($data['idle_timeouts'] ?? null), + requestSizeExceeded: SnapshotValue::toInt($data['request_size_exceeded'] ?? null), ); } } diff --git a/src/FreeDSx/Ldap/Server/Metrics/Snapshot/MetricsSnapshot.php b/src/FreeDSx/Ldap/Server/Metrics/Snapshot/MetricsSnapshot.php index 2da154af..1aa8edb4 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Snapshot/MetricsSnapshot.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Snapshot/MetricsSnapshot.php @@ -20,10 +20,15 @@ */ final readonly class MetricsSnapshot { + /** + * @param array $operationsInProgress In-flight count per operation type (a live gauge, not a counter). + */ public function __construct( public LifecycleMetrics $lifecycle = new LifecycleMetrics(), public ConnectionMetrics $connections = new ConnectionMetrics(), public OperationMetrics $operations = new OperationMetrics(), + public array $operationsInProgress = [], + public TrafficMetrics $traffic = new TrafficMetrics(), ) {} /** @@ -35,6 +40,8 @@ public function toArray(): array 'lifecycle' => $this->lifecycle->toArray(), 'connections' => $this->connections->toArray(), 'operations' => $this->operations->toArray(), + 'operations_in_progress' => $this->operationsInProgress, + 'traffic' => $this->traffic->toArray(), ]; } @@ -56,6 +63,11 @@ public static function fromArray(array $data): self $data, 'operations', )), + operationsInProgress: SnapshotValue::toIntMap($data['operations_in_progress'] ?? null), + traffic: TrafficMetrics::fromArray(self::section( + $data, + 'traffic', + )), ); } diff --git a/src/FreeDSx/Ldap/Server/Metrics/Snapshot/OperationMetrics.php b/src/FreeDSx/Ldap/Server/Metrics/Snapshot/OperationMetrics.php index f4e1e38a..71eaa2f1 100644 --- a/src/FreeDSx/Ldap/Server/Metrics/Snapshot/OperationMetrics.php +++ b/src/FreeDSx/Ldap/Server/Metrics/Snapshot/OperationMetrics.php @@ -27,12 +27,16 @@ * @param array $errors Operation label to failed count. * @param array $durationSeconds Operation label to summed duration. * @param array $resultCodeCounts LDAP result code to count. + * @param array $bindCounts Bind sub-type (anonymous/simple/sasl) to count. + * @param array $searchScopeCounts Search scope (base/one/sub) to count. */ public function __construct( public array $counts = [], public array $errors = [], public array $durationSeconds = [], public array $resultCodeCounts = [], + public array $bindCounts = [], + public array $searchScopeCounts = [], ) {} public function total(): int @@ -55,6 +59,8 @@ public function toArray(): array 'errors' => $this->errors, 'duration_seconds' => $this->durationSeconds, 'result_code_counts' => $this->resultCodeCounts, + 'bind_counts' => $this->bindCounts, + 'search_scope_counts' => $this->searchScopeCounts, ]; } @@ -68,6 +74,8 @@ public static function fromArray(array $data): self errors: SnapshotValue::toIntMap($data['errors'] ?? null), durationSeconds: SnapshotValue::toFloatMap($data['duration_seconds'] ?? null), resultCodeCounts: SnapshotValue::toIntKeyedIntMap($data['result_code_counts'] ?? null), + bindCounts: SnapshotValue::toIntMap($data['bind_counts'] ?? null), + searchScopeCounts: SnapshotValue::toIntMap($data['search_scope_counts'] ?? null), ); } } diff --git a/src/FreeDSx/Ldap/Server/Metrics/Snapshot/TrafficMetrics.php b/src/FreeDSx/Ldap/Server/Metrics/Snapshot/TrafficMetrics.php new file mode 100644 index 00000000..ea36704a --- /dev/null +++ b/src/FreeDSx/Ldap/Server/Metrics/Snapshot/TrafficMetrics.php @@ -0,0 +1,52 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace FreeDSx\Ldap\Server\Metrics\Snapshot; + +/** + * Transport-level traffic totals. + * + * @author Chad Sikorra + */ +final readonly class TrafficMetrics +{ + public function __construct( + public int $bytesSent = 0, + public int $bytesReceived = 0, + public int $entriesReturned = 0, + ) {} + + /** + * @return array + */ + public function toArray(): array + { + return [ + 'bytes_sent' => $this->bytesSent, + 'bytes_received' => $this->bytesReceived, + 'entries_returned' => $this->entriesReturned, + ]; + } + + /** + * @param array $data + */ + public static function fromArray(array $data): self + { + return new self( + bytesSent: SnapshotValue::toInt($data['bytes_sent'] ?? null), + bytesReceived: SnapshotValue::toInt($data['bytes_received'] ?? null), + entriesReturned: SnapshotValue::toInt($data['entries_returned'] ?? null), + ); + } +} diff --git a/src/FreeDSx/Ldap/Server/Middleware/MetricsMiddleware.php b/src/FreeDSx/Ldap/Server/Middleware/MetricsMiddleware.php index 797e6119..6b7716f3 100644 --- a/src/FreeDSx/Ldap/Server/Middleware/MetricsMiddleware.php +++ b/src/FreeDSx/Ldap/Server/Middleware/MetricsMiddleware.php @@ -15,6 +15,12 @@ use FreeDSx\Ldap\Exception\OperationException; use FreeDSx\Ldap\Operation\OperationType; +use FreeDSx\Ldap\Operation\Request\AnonBindRequest; +use FreeDSx\Ldap\Operation\Request\RequestInterface; +use FreeDSx\Ldap\Operation\Request\SaslBindRequest; +use FreeDSx\Ldap\Operation\Request\SearchRequest; +use FreeDSx\Ldap\Operation\Request\SimpleBindRequest; +use FreeDSx\Ldap\Operation\ResultCode; use FreeDSx\Ldap\Server\Metrics\MetricsRecorderInterface; use FreeDSx\Ldap\Server\Metrics\Observation\OperationObservation; use FreeDSx\Ldap\Server\Metrics\Rollup\OperationRollupCoordinator; @@ -23,6 +29,7 @@ use FreeDSx\Ldap\Server\Middleware\Pipeline\ServerRequestContext; use FreeDSx\Ldap\Server\Operation\OperationOutcome; use FreeDSx\Ldap\Server\Operation\OperationResult; +use Throwable; use function microtime; @@ -47,23 +54,38 @@ public function process( ServerRequestContext $context, MiddlewareHandlerInterface $next, ): OperationResult { - $operation = OperationType::classify($context->message->getRequest()); + $request = $context->message->getRequest(); + $operation = OperationType::classify($request); + $this->recorder->operationStarted($operation); $startedAt = microtime(true); try { $result = $next->handle($context); } catch (OperationException $e) { $this->record( + $request, $operation, false, microtime(true) - $startedAt, $e->getCode(), ); + throw $e; + } catch (Throwable $e) { + // An unexpected failure still has to clear the in-flight gauge and be counted as a failed op. + $this->record( + $request, + $operation, + false, + microtime(true) - $startedAt, + ResultCode::OPERATIONS_ERROR, + ); + throw $e; } $this->record( + $request, $operation, $result->outcome() === OperationOutcome::Succeeded, microtime(true) - $startedAt, @@ -74,6 +96,7 @@ public function process( } private function record( + RequestInterface $request, OperationType $operation, bool $succeeded, float $durationSeconds, @@ -84,7 +107,33 @@ private function record( $succeeded, $durationSeconds, $resultCode, + $this->bindMethod($request), + $this->searchScope($request), )); $this->rollup?->flush(); } + + private function bindMethod(RequestInterface $request): ?string + { + return match (true) { + $request instanceof AnonBindRequest => 'anonymous', + $request instanceof SaslBindRequest => 'sasl', + $request instanceof SimpleBindRequest => 'simple', + default => null, + }; + } + + private function searchScope(RequestInterface $request): ?string + { + if (!$request instanceof SearchRequest) { + return null; + } + + return match ($request->getScope()) { + SearchRequest::SCOPE_BASE_OBJECT => 'base', + SearchRequest::SCOPE_SINGLE_LEVEL => 'one', + SearchRequest::SCOPE_WHOLE_SUBTREE => 'sub', + default => null, + }; + } } diff --git a/src/FreeDSx/Ldap/Server/ServerConnectionScaffoldingTrait.php b/src/FreeDSx/Ldap/Server/ServerConnectionScaffoldingTrait.php index ecadfc05..6bcd57a1 100644 --- a/src/FreeDSx/Ldap/Server/ServerConnectionScaffoldingTrait.php +++ b/src/FreeDSx/Ldap/Server/ServerConnectionScaffoldingTrait.php @@ -18,6 +18,8 @@ use FreeDSx\Ldap\Protocol\Queue\ServerQueue; use FreeDSx\Ldap\Server\Logging\ConnectionContext; use FreeDSx\Ldap\Server\Logging\EventLogger; +use FreeDSx\Ldap\Server\Metrics\MetricsRecorderInterface; +use FreeDSx\Ldap\Server\Metrics\Recorder\NullMetricsRecorder; use FreeDSx\Ldap\ServerOptions; use FreeDSx\Socket\Socket; @@ -36,11 +38,13 @@ abstract protected function serverOptions(): ServerOptions; private function makeServerQueue( Socket $socket, array $interceptors = [], + MetricsRecorderInterface $metricsRecorder = new NullMetricsRecorder(), ): ServerQueue { return new ServerQueue( $socket, maxReceiveSize: $this->serverOptions()->getMaxRequestSize(), interceptors: $interceptors, + metricsRecorder: $metricsRecorder, ); } diff --git a/src/FreeDSx/Ldap/Server/ServerProtocolFactory.php b/src/FreeDSx/Ldap/Server/ServerProtocolFactory.php index 1bc4ac37..b6ce0100 100644 --- a/src/FreeDSx/Ldap/Server/ServerProtocolFactory.php +++ b/src/FreeDSx/Ldap/Server/ServerProtocolFactory.php @@ -58,6 +58,7 @@ use FreeDSx\Ldap\Server\Middleware\Pipeline\HandlerInvoker; use FreeDSx\Ldap\Server\Middleware\Pipeline\MiddlewareChain; use FreeDSx\Ldap\Server\PasswordPolicy\Guard\PasswordPolicyBindGuard; +use FreeDSx\Ldap\Protocol\Queue\Response\MetricsResponseInterceptor; use FreeDSx\Ldap\Protocol\Queue\Response\PasswordPolicyResponseInterceptor; use FreeDSx\Ldap\Server\PasswordPolicy\PasswordPolicyContext; use FreeDSx\Ldap\Server\PasswordPolicy\PasswordPolicyEngine; @@ -111,9 +112,14 @@ public function make( ); } + if (!$this->metricsRecorder instanceof NullMetricsRecorder) { + $interceptors[] = new MetricsResponseInterceptor($this->metricsRecorder); + } + $serverQueue = $this->makeServerQueue( $socket, $interceptors, + $this->metricsRecorder, ); $authenticators = [ diff --git a/src/FreeDSx/Ldap/Server/ServerRunner/CoroutineServerRunnerInterface.php b/src/FreeDSx/Ldap/Server/ServerRunner/CoroutineServerRunnerInterface.php new file mode 100644 index 00000000..654a5fa4 --- /dev/null +++ b/src/FreeDSx/Ldap/Server/ServerRunner/CoroutineServerRunnerInterface.php @@ -0,0 +1,21 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace FreeDSx\Ldap\Server\ServerRunner; + +/** + * Marks a runner that handles connections concurrently within a single process. + * + * @author Chad Sikorra + */ +interface CoroutineServerRunnerInterface extends ServerRunnerInterface {} diff --git a/src/FreeDSx/Ldap/Server/ServerRunner/PcntlServerRunner.php b/src/FreeDSx/Ldap/Server/ServerRunner/PcntlServerRunner.php index 126f47f3..044688f9 100644 --- a/src/FreeDSx/Ldap/Server/ServerRunner/PcntlServerRunner.php +++ b/src/FreeDSx/Ldap/Server/ServerRunner/PcntlServerRunner.php @@ -45,6 +45,15 @@ class PcntlServerRunner implements ServerRunnerInterface use ServerRunnerLoggerTrait; use ReloadsConfigurationTrait; + /** + * Child exit codes that tell the parent why a connection ended, so it can record the metric. + */ + private const EXIT_CODE_WRITE_TIMEOUT = 10; + + private const EXIT_CODE_IDLE_TIMEOUT = 11; + + private const EXIT_CODE_REQUEST_SIZE_EXCEEDED = 12; + private SocketServer $server; /** @@ -131,8 +140,7 @@ public function run(): void private function cleanUpChildProcesses(): void { foreach ($this->childProcesses as $index => $childProcess) { - // No use for this at the moment, but define it anyway. - $status = null; + $status = 0; $result = pcntl_waitpid( $childProcess->getPid(), @@ -147,6 +155,10 @@ private function cleanUpChildProcesses(): void $this->server->removeClient($socket); $socket->close(); $this->metricsRecorder->connectionObserved(ConnectionObservation::Closed); + $this->recordChildCloseReason( + $result, + $status, + ); $this->logInfo( 'The child process has ended.', array_merge( @@ -193,6 +205,42 @@ private function drainOperationDelta(ChildProcess $childProcess): void $childProcess->getChannel()?->close(); } + /** + * The exit code a child uses to tell the parent which close reason, if any, ended the connection. + */ + private function childExitCodeFor(?ConnectionObservation $closeReason): int + { + return match ($closeReason) { + ConnectionObservation::WriteTimeout => self::EXIT_CODE_WRITE_TIMEOUT, + ConnectionObservation::IdleTimeout => self::EXIT_CODE_IDLE_TIMEOUT, + ConnectionObservation::RequestSizeExceeded => self::EXIT_CODE_REQUEST_SIZE_EXCEEDED, + default => 0, + }; + } + + /** + * Record a reaped child's close reason from its exit status, alongside the connection-closed gauge update. + */ + private function recordChildCloseReason( + int $result, + int $status, + ): void { + if ($result <= 0 || !pcntl_wifexited($status)) { + return; + } + + $observation = match (pcntl_wexitstatus($status)) { + self::EXIT_CODE_WRITE_TIMEOUT => ConnectionObservation::WriteTimeout, + self::EXIT_CODE_IDLE_TIMEOUT => ConnectionObservation::IdleTimeout, + self::EXIT_CODE_REQUEST_SIZE_EXCEEDED => ConnectionObservation::RequestSizeExceeded, + default => null, + }; + + if ($observation !== null) { + $this->metricsRecorder->connectionObserved($observation); + } + } + /** * Accept clients from the socket server in a loop with a timeout. This lets us to periodically check existing * children processes as we listen for new ones. @@ -452,8 +500,9 @@ private function runChildProcessThenExit( $context, ); + $closeReason = null; try { - $serverProtocolHandler->handle(); + $closeReason = $serverProtocolHandler->handle(); } finally { $this->operationRollup?->finish(); } @@ -463,7 +512,8 @@ private function runChildProcessThenExit( $context, ); - exit(0); + // Convey a timeout close to the parent through the exit code. + exit($this->childExitCodeFor($closeReason)); } /** diff --git a/src/FreeDSx/Ldap/Server/ServerRunner/SwooleServerRunner.php b/src/FreeDSx/Ldap/Server/ServerRunner/SwooleServerRunner.php index 62a7acde..be0fdd80 100644 --- a/src/FreeDSx/Ldap/Server/ServerRunner/SwooleServerRunner.php +++ b/src/FreeDSx/Ldap/Server/ServerRunner/SwooleServerRunner.php @@ -48,7 +48,7 @@ * * @author Chad Sikorra */ -class SwooleServerRunner implements ServerRunnerInterface +class SwooleServerRunner implements CoroutineServerRunnerInterface { use ServerRunnerLoggerTrait; use ReloadsConfigurationTrait; @@ -235,7 +235,11 @@ private function handleClient( ); $this->activeHandlers[$socketId] = $handler; $this->logClientConnected(); - $handler->handle(); + $closeReason = $handler->handle(); + + if ($closeReason !== null) { + $this->metricsRecorder->connectionObserved($closeReason); + } } catch (Throwable $e) { $this->logClientError($e); } finally { diff --git a/tests/performance/LoadTestCommand.php b/tests/performance/LoadTestCommand.php index 9ae18899..434b78ee 100644 --- a/tests/performance/LoadTestCommand.php +++ b/tests/performance/LoadTestCommand.php @@ -349,6 +349,13 @@ private function renderMonitorEntry( 'operationsCompleted', 'operationsFailed', 'operationsByType', + 'operationsByResultCode', + 'bindsByMethod', + 'searchesByScope', + 'operationsInProgressByType', + 'trafficBytesSent', + 'trafficBytesReceived', + 'trafficEntriesReturned', ]; foreach ($attributes as $name) { if (!isset($entry[$name])) { diff --git a/tests/support/Middleware/CallbackMiddlewareHandler.php b/tests/support/Middleware/CallbackMiddlewareHandler.php new file mode 100644 index 00000000..16b2a1e0 --- /dev/null +++ b/tests/support/Middleware/CallbackMiddlewareHandler.php @@ -0,0 +1,37 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace Tests\Support\FreeDSx\Ldap\Middleware; + +use Closure; +use FreeDSx\Ldap\Server\Middleware\Pipeline\MiddlewareHandlerInterface; +use FreeDSx\Ldap\Server\Middleware\Pipeline\ServerRequestContext; +use FreeDSx\Ldap\Server\Operation\OperationResult; + +/** + * Terminal handler that defers to a callback, letting a test observe state while the operation is in flight. + * + * @author Chad Sikorra + */ +final readonly class CallbackMiddlewareHandler implements MiddlewareHandlerInterface +{ + /** + * @param Closure(ServerRequestContext): OperationResult $callback + */ + public function __construct(private Closure $callback) {} + + public function handle(ServerRequestContext $context): OperationResult + { + return ($this->callback)($context); + } +} diff --git a/tests/unit/Protocol/Queue/Response/MetricsResponseInterceptorTest.php b/tests/unit/Protocol/Queue/Response/MetricsResponseInterceptorTest.php new file mode 100644 index 00000000..cdf4f8f4 --- /dev/null +++ b/tests/unit/Protocol/Queue/Response/MetricsResponseInterceptorTest.php @@ -0,0 +1,68 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace Tests\Unit\FreeDSx\Ldap\Protocol\Queue\Response; + +use FreeDSx\Ldap\Entry\Entry; +use FreeDSx\Ldap\Operation\Response\SearchResultDone; +use FreeDSx\Ldap\Operation\Response\SearchResultEntry; +use FreeDSx\Ldap\Operation\ResultCode; +use FreeDSx\Ldap\Protocol\LdapMessageResponse; +use FreeDSx\Ldap\Protocol\Queue\Response\MetricsResponseInterceptor; +use FreeDSx\Ldap\Server\Metrics\Recorder\InMemoryMetricsRecorder; +use PHPUnit\Framework\TestCase; + +final class MetricsResponseInterceptorTest extends TestCase +{ + private InMemoryMetricsRecorder $recorder; + + private MetricsResponseInterceptor $subject; + + protected function setUp(): void + { + $this->recorder = new InMemoryMetricsRecorder(); + $this->subject = new MetricsResponseInterceptor($this->recorder); + } + + public function test_it_counts_a_search_result_entry(): void + { + $response = new LdapMessageResponse( + 1, + new SearchResultEntry(new Entry('cn=foo,dc=bar')), + ); + + $returned = $this->subject->intercept($response); + + self::assertSame( + $response, + $returned, + ); + self::assertSame( + 1, + $this->recorder->snapshot()->traffic->entriesReturned, + ); + } + + public function test_it_does_not_count_a_non_entry_response(): void + { + $this->subject->intercept(new LdapMessageResponse( + 1, + new SearchResultDone(ResultCode::SUCCESS), + )); + + self::assertSame( + 0, + $this->recorder->snapshot()->traffic->entriesReturned, + ); + } +} diff --git a/tests/unit/Protocol/Queue/ServerQueueTest.php b/tests/unit/Protocol/Queue/ServerQueueTest.php index 6c4e7d4f..a40f6c95 100644 --- a/tests/unit/Protocol/Queue/ServerQueueTest.php +++ b/tests/unit/Protocol/Queue/ServerQueueTest.php @@ -27,6 +27,7 @@ use FreeDSx\Ldap\Exception\RequestSizeExceededException; use FreeDSx\Ldap\Protocol\Queue\MessageWrapperInterface; use FreeDSx\Ldap\Protocol\Queue\ServerQueue; +use FreeDSx\Ldap\Server\Metrics\Recorder\InMemoryMetricsRecorder; use FreeDSx\Socket\Queue\Buffer; use FreeDSx\Socket\Socket; use PHPUnit\Framework\MockObject\MockObject; @@ -113,6 +114,60 @@ public function test_it_should_send_multiple_messages_with_write_and_respect_the } + public function test_it_records_bytes_sent_for_each_outgoing_message(): void + { + $recorder = new InMemoryMetricsRecorder(); + $encoder = $this->createMock(EncoderInterface::class); + $encoder->method('encode')->willReturn('abcdef'); + $socket = $this->createMock(Socket::class); + + $queue = new ServerQueue( + $socket, + $encoder, + metricsRecorder: $recorder, + ); + $queue->sendMessage(new LdapMessageResponse( + 1, + new DeleteResponse(0), + )); + + self::assertSame( + 6, + $recorder->snapshot()->traffic->bytesSent, + ); + } + + public function test_it_records_bytes_received_for_each_decoded_request(): void + { + $recorder = new InMemoryMetricsRecorder(); + $encoder = $this->createMock(EncoderInterface::class); + $encoder->method('getLastPosition')->willReturn(42); + $encoder->expects($this->once()) + ->method('decode') + ->willReturn(Asn1::sequence( + Asn1::integer(1), + Asn1::application(10, Asn1::octetString('dc=foo,dc=bar')), + new IncompleteType((new LdapEncoder())->encode(Asn1::context(0, Asn1::sequenceOf((new Control('foo'))->toAsn1())))), + )); + $socket = $this->createMock(Socket::class); + $socket->method('read')->willReturnOnConsecutiveCalls( + 'foo', + false, + ); + + $queue = new ServerQueue( + $socket, + $encoder, + metricsRecorder: $recorder, + ); + $queue->getMessage(); + + self::assertSame( + 42, + $recorder->snapshot()->traffic->bytesReceived, + ); + } + public function test_it_should_set_a_message_wrapper_and_use_it_when_sending_messages(): void { $this->mockEncoder diff --git a/tests/unit/Protocol/ServerProtocolHandler/ServerMonitorHandlerTest.php b/tests/unit/Protocol/ServerProtocolHandler/ServerMonitorHandlerTest.php index 19149aad..28adf04c 100644 --- a/tests/unit/Protocol/ServerProtocolHandler/ServerMonitorHandlerTest.php +++ b/tests/unit/Protocol/ServerProtocolHandler/ServerMonitorHandlerTest.php @@ -26,6 +26,7 @@ use FreeDSx\Ldap\Search\Filters; use FreeDSx\Ldap\Server\Metrics\Observation\ConnectionObservation; use FreeDSx\Ldap\Server\Metrics\Observation\OperationObservation; +use FreeDSx\Ldap\Server\Metrics\Observation\TrafficObservation; use FreeDSx\Ldap\Server\Metrics\Recorder\InMemoryMetricsRecorder; use FreeDSx\Ldap\Server\ServerRunner\PcntlServerRunner; use FreeDSx\Ldap\Server\Token\TokenInterface; @@ -131,6 +132,85 @@ public function test_it_reports_operation_totals_and_a_per_type_breakdown(): voi ); } + public function test_it_reports_a_result_code_breakdown(): void + { + $this->metrics->operationObserved(new OperationObservation( + OperationType::Search, + true, + 0.1, + ResultCode::SUCCESS, + )); + $this->metrics->operationObserved(new OperationObservation( + OperationType::Add, + false, + 0.1, + ResultCode::NO_SUCH_OBJECT, + )); + + $entry = $this->handleAndCaptureEntry(); + + self::assertEqualsCanonicalizing( + [ + ResultCode::SUCCESS . '=1', + ResultCode::NO_SUCH_OBJECT . '=1', + ], + $entry->get('operationsByResultCode')?->getValues(), + ); + } + + public function test_it_reports_bind_method_and_search_scope_breakdowns(): void + { + $this->metrics->operationObserved(new OperationObservation( + OperationType::Bind, + true, + 0.1, + ResultCode::SUCCESS, + bindMethod: 'anonymous', + )); + $this->metrics->operationObserved(new OperationObservation( + OperationType::Search, + true, + 0.1, + ResultCode::SUCCESS, + searchScope: 'sub', + )); + + $entry = $this->handleAndCaptureEntry(); + + self::assertSame( + ['anonymous=1'], + $entry->get('bindsByMethod')?->getValues(), + ); + self::assertSame( + ['sub=1'], + $entry->get('searchesByScope')?->getValues(), + ); + } + + public function test_it_reports_the_average_latency_per_type_in_milliseconds(): void + { + $this->metrics->operationObserved(new OperationObservation( + OperationType::Search, + true, + 0.1, + ResultCode::SUCCESS, + )); + $this->metrics->operationObserved(new OperationObservation( + OperationType::Search, + true, + 0.3, + ResultCode::SUCCESS, + )); + + $entry = $this->handleAndCaptureEntry(); + + // (0.1 + 0.3) / 2 = 0.2s = 200ms + self::assertSame( + ['search=200'], + $entry->get('operationsAvgLatencyMsByType')?->getValues(), + ); + } + public function test_it_reports_the_server_host(): void { $host = gethostname(); @@ -165,6 +245,70 @@ public function test_it_omits_the_start_time_when_unknown(): void self::assertNull($entry->get('serverUptimeSeconds')); } + public function test_it_reports_connections_closed_by_an_oversized_request(): void + { + $this->metrics->connectionObserved(ConnectionObservation::RequestSizeExceeded); + $this->metrics->connectionObserved(ConnectionObservation::RequestSizeExceeded); + + $entry = $this->handleAndCaptureEntry(); + + self::assertSame( + ['2'], + $entry->get('connectionsRequestSizeExceeded')?->getValues(), + ); + } + + public function test_it_reports_traffic_totals(): void + { + $this->metrics->trafficObserved(new TrafficObservation( + bytesSent: 2048, + bytesReceived: 256, + entriesReturned: 7, + )); + + $entry = $this->handleAndCaptureEntry(); + + self::assertSame( + ['2048'], + $entry->get('trafficBytesSent')?->getValues(), + ); + self::assertSame( + ['256'], + $entry->get('trafficBytesReceived')?->getValues(), + ); + self::assertSame( + ['7'], + $entry->get('trafficEntriesReturned')?->getValues(), + ); + } + + public function test_it_omits_in_flight_operations_under_the_forking_runner(): void + { + $this->metrics->operationStarted(OperationType::Search); + + $entry = $this->handleAndCaptureEntry(); + + self::assertNull($entry->get('operationsInProgressByType')); + } + + public function test_it_reports_in_flight_operations_under_a_coroutine_runner(): void + { + $this->metrics->operationStarted(OperationType::Search); + + $subject = new ServerMonitorHandler( + options: (new ServerOptions())->setUseSwooleRunner(true), + queue: $this->mockQueue, + snapshots: $this->metrics, + ); + + $entry = $this->handleAndCaptureEntry($subject); + + self::assertSame( + ['search=1'], + $entry->get('operationsInProgressByType')?->getValues(), + ); + } + private function makeMessage(): LdapMessageRequest { return new LdapMessageRequest( @@ -175,7 +319,7 @@ private function makeMessage(): LdapMessageRequest ); } - private function handleAndCaptureEntry(): Entry + private function handleAndCaptureEntry(?ServerMonitorHandler $subject = null): Entry { $captured = null; @@ -193,7 +337,7 @@ private function handleAndCaptureEntry(): Entry self::anything(), ); - $this->subject->handleRequest( + ($subject ?? $this->subject)->handleRequest( $this->makeMessage(), $this->mockToken, ); diff --git a/tests/unit/Protocol/ServerProtocolHandlerTest.php b/tests/unit/Protocol/ServerProtocolHandlerTest.php index 69bbd42d..4ef3a9e7 100644 --- a/tests/unit/Protocol/ServerProtocolHandlerTest.php +++ b/tests/unit/Protocol/ServerProtocolHandlerTest.php @@ -31,9 +31,11 @@ use FreeDSx\Ldap\Server\Logging\EventContext; use FreeDSx\Ldap\Server\Logging\EventLogger; use FreeDSx\Ldap\Server\Logging\EventLogPolicy; +use FreeDSx\Ldap\Server\Metrics\Observation\ConnectionObservation; use FreeDSx\Ldap\Server\Middleware\Pipeline\MiddlewareHandlerInterface; use FreeDSx\Ldap\Server\Operation\OperationOutcomeResult; use FreeDSx\Socket\Exception\ConnectionException; +use FreeDSx\Socket\Exception\IdleTimeoutException; use FreeDSx\Socket\Exception\WriteTimeoutException; use PHPUnit\Framework\MockObject\MockObject; use PHPUnit\Framework\TestCase; @@ -161,16 +163,29 @@ public function test_it_sends_a_notice_of_disconnect_on_a_protocol_exception_fro ->handle(); } - public function test_it_sends_a_notice_of_disconnect_when_a_request_exceeds_the_max_size(): void + public function test_a_request_size_exceeded_is_recorded_and_sends_a_notice_of_disconnect(): void { + $recordingLogger = new RecordingLogger(); $this->mockQueue ->method('getMessage') ->willThrowException(new RequestSizeExceededException('too big')); - $this->expectNoticeOfDisconnect('The message could not be processed.'); + $this->expectNoticeOfDisconnect('too big'); - $this->handlerWith(new StubMiddlewareHandler(OperationOutcomeResult::succeeded())) - ->handle(); + $closeReason = $this->handlerWith( + new StubMiddlewareHandler(OperationOutcomeResult::succeeded()), + new EventLogger($recordingLogger, EventLogPolicy::default()), + )->handle(); + + self::assertSame( + ConnectionObservation::RequestSizeExceeded, + $closeReason, + ); + $record = $this->findRecord($recordingLogger, 'session.disconnect_notice'); + self::assertSame( + RequestSizeExceededException::class, + $record['context']['exception_class'], + ); } public function test_it_sends_a_notice_of_disconnect_on_an_encoder_exception_from_the_message_queue(): void @@ -213,11 +228,15 @@ public function test_a_write_timeout_is_recorded_and_closes_without_a_notice_of_ ->expects(self::once()) ->method('close'); - $this->handlerWith( + $closeReason = $this->handlerWith( new ThrowingMiddlewareHandler(new WriteTimeoutException('The write operation timed out after 600 seconds.')), new EventLogger($recordingLogger, EventLogPolicy::default()), )->handle(); + self::assertSame( + ConnectionObservation::WriteTimeout, + $closeReason, + ); $record = $this->findRecord($recordingLogger, 'session.write_timeout'); self::assertSame( 'The write operation timed out after 600 seconds.', @@ -225,6 +244,43 @@ public function test_a_write_timeout_is_recorded_and_closes_without_a_notice_of_ ); } + public function test_an_idle_timeout_is_recorded_and_closes_without_a_notice_of_disconnect(): void + { + $recordingLogger = new RecordingLogger(); + $this->mockQueue + ->method('getMessage') + ->willThrowException(new IdleTimeoutException('The connection was idle for longer than the read timeout of 600 seconds.')); + $this->mockQueue + ->expects(self::never()) + ->method('sendMessage'); + $this->mockQueue + ->expects(self::once()) + ->method('close'); + + $closeReason = $this->handlerWith( + new StubMiddlewareHandler(OperationOutcomeResult::succeeded()), + new EventLogger($recordingLogger, EventLogPolicy::default()), + )->handle(); + + self::assertSame( + ConnectionObservation::IdleTimeout, + $closeReason, + ); + $record = $this->findRecord($recordingLogger, 'session.idle_timeout'); + self::assertSame( + 'The connection was idle for longer than the read timeout of 600 seconds.', + $record['context'][EventContext::REASON_MESSAGE], + ); + + foreach ($recordingLogger->records as $logged) { + self::assertNotSame( + 'session.disconnect_notice', + $logged['message'], + 'An idle client must not be sent a Notice of Disconnection.', + ); + } + } + public function test_it_sends_a_notice_of_disconnect_and_closes_the_queue_on_shutdown(): void { $this->mockQueue diff --git a/tests/unit/Server/Metrics/Recorder/InMemoryMetricsRecorderTest.php b/tests/unit/Server/Metrics/Recorder/InMemoryMetricsRecorderTest.php index 3bd535f6..8bad9511 100644 --- a/tests/unit/Server/Metrics/Recorder/InMemoryMetricsRecorderTest.php +++ b/tests/unit/Server/Metrics/Recorder/InMemoryMetricsRecorderTest.php @@ -17,8 +17,11 @@ use FreeDSx\Ldap\Operation\ResultCode; use FreeDSx\Ldap\Server\Metrics\Observation\ConnectionObservation; use FreeDSx\Ldap\Server\Metrics\Observation\OperationObservation; +use FreeDSx\Ldap\Server\Metrics\Observation\TrafficObservation; use FreeDSx\Ldap\Server\Metrics\Recorder\InMemoryMetricsRecorder; +use FreeDSx\Ldap\Server\Metrics\Rollup\MetricsDelta; use FreeDSx\Ldap\Server\Metrics\Snapshot\OperationMetrics; +use FreeDSx\Ldap\Server\Metrics\Snapshot\TrafficMetrics; use PHPUnit\Framework\TestCase; final class InMemoryMetricsRecorderTest extends TestCase @@ -68,6 +71,87 @@ public function test_it_records_operations_with_counts_errors_and_durations(): v ); } + public function test_it_records_bind_method_and_search_scope_breakdowns(): void + { + $this->subject->operationObserved(new OperationObservation( + OperationType::Bind, + true, + 0.1, + ResultCode::SUCCESS, + bindMethod: 'anonymous', + )); + $this->subject->operationObserved(new OperationObservation( + OperationType::Bind, + true, + 0.1, + ResultCode::SUCCESS, + bindMethod: 'simple', + )); + $this->subject->operationObserved(new OperationObservation( + OperationType::Search, + true, + 0.1, + ResultCode::SUCCESS, + searchScope: 'sub', + )); + + $operations = $this->subject->snapshot()->operations; + + self::assertSame( + ['anonymous' => 1, 'simple' => 1], + $operations->bindCounts, + ); + self::assertSame( + ['sub' => 1], + $operations->searchScopeCounts, + ); + } + + public function test_it_tracks_in_flight_operations_per_type_and_prunes_at_zero(): void + { + $this->subject->operationStarted(OperationType::Search); + $this->subject->operationStarted(OperationType::Search); + $this->subject->operationStarted(OperationType::Bind); + + self::assertSame( + ['search' => 2, 'bind' => 1], + $this->subject->snapshot()->operationsInProgress, + ); + + $this->subject->operationObserved(new OperationObservation( + OperationType::Search, + true, + 0.1, + ResultCode::SUCCESS, + )); + $this->subject->operationObserved(new OperationObservation( + OperationType::Search, + true, + 0.1, + ResultCode::SUCCESS, + )); + + self::assertSame( + ['bind' => 1], + $this->subject->snapshot()->operationsInProgress, + ); + } + + public function test_observing_more_than_started_floors_the_in_flight_gauge(): void + { + $this->subject->operationObserved(new OperationObservation( + OperationType::Search, + true, + 0.1, + ResultCode::SUCCESS, + )); + + self::assertSame( + [], + $this->subject->snapshot()->operationsInProgress, + ); + } + public function test_the_active_connection_gauge_rises_on_open_and_falls_on_close(): void { $this->subject->connectionObserved(ConnectionObservation::Opened); @@ -102,6 +186,7 @@ public function test_it_counts_rejected_and_timed_out_connections(): void $this->subject->connectionObserved(ConnectionObservation::WriteTimeout); $this->subject->connectionObserved(ConnectionObservation::WriteTimeout); $this->subject->connectionObserved(ConnectionObservation::IdleTimeout); + $this->subject->connectionObserved(ConnectionObservation::RequestSizeExceeded); $connections = $this->subject->snapshot()->connections; @@ -117,34 +202,67 @@ public function test_it_counts_rejected_and_timed_out_connections(): void 1, $connections->idleTimeouts, ); + self::assertSame( + 1, + $connections->requestSizeExceeded, + ); } - public function test_taking_the_operation_delta_returns_the_metrics_and_resets_them(): void + public function test_taking_the_delta_returns_the_metrics_and_resets_them(): void { $this->subject->operationObserved(new OperationObservation( OperationType::Search, true, 0.5, ResultCode::SUCCESS, + searchScope: 'sub', + )); + $this->subject->operationObserved(new OperationObservation( + OperationType::Bind, + true, + 0.1, + ResultCode::SUCCESS, + bindMethod: 'simple', + )); + $this->subject->trafficObserved(new TrafficObservation( + bytesSent: 120, + bytesReceived: 30, + entriesReturned: 4, )); - $delta = $this->subject->takeOperationDelta(); + $delta = $this->subject->takeDelta(); self::assertSame( - ['search' => 1], - $delta->counts, + ['search' => 1, 'bind' => 1], + $delta->operations->counts, ); self::assertSame( - [ResultCode::SUCCESS => 1], - $delta->resultCodeCounts, + [ResultCode::SUCCESS => 2], + $delta->operations->resultCodeCounts, + ); + self::assertSame( + ['simple' => 1], + $delta->operations->bindCounts, + ); + self::assertSame( + ['sub' => 1], + $delta->operations->searchScopeCounts, + ); + self::assertSame( + 120, + $delta->traffic->bytesSent, + ); + self::assertSame( + 4, + $delta->traffic->entriesReturned, ); self::assertSame( [], - $this->subject->takeOperationDelta()->counts, + $this->subject->takeDelta()->operations->counts, ); } - public function test_resetting_operations_clears_the_accumulators_but_keeps_connections(): void + public function test_resetting_the_delta_clears_the_accumulators_but_keeps_connections(): void { $this->subject->operationObserved(new OperationObservation( OperationType::Search, @@ -152,22 +270,27 @@ public function test_resetting_operations_clears_the_accumulators_but_keeps_conn 0.5, ResultCode::SUCCESS, )); + $this->subject->trafficObserved(new TrafficObservation(bytesSent: 50)); $this->subject->connectionObserved(ConnectionObservation::Opened); - $this->subject->resetOperations(); + $this->subject->resetDelta(); $snapshot = $this->subject->snapshot(); self::assertSame( [], $snapshot->operations->counts, ); + self::assertSame( + 0, + $snapshot->traffic->bytesSent, + ); self::assertSame( 1, $snapshot->connections->active, ); } - public function test_merging_an_operation_delta_sums_into_the_totals(): void + public function test_merging_a_delta_sums_into_the_totals(): void { $this->subject->operationObserved(new OperationObservation( OperationType::Search, @@ -175,15 +298,29 @@ public function test_merging_an_operation_delta_sums_into_the_totals(): void 0.5, ResultCode::SUCCESS, )); + $this->subject->trafficObserved(new TrafficObservation( + bytesSent: 10, + entriesReturned: 1, + )); - $this->subject->mergeOperations(new OperationMetrics( - counts: ['search' => 2, 'bind' => 1], - errors: ['search' => 1], - durationSeconds: ['search' => 0.25], - resultCodeCounts: [ResultCode::SUCCESS => 2], + $this->subject->mergeDelta(new MetricsDelta( + new OperationMetrics( + counts: ['search' => 2, 'bind' => 1], + errors: ['search' => 1], + durationSeconds: ['search' => 0.25], + resultCodeCounts: [ResultCode::SUCCESS => 2], + bindCounts: ['anonymous' => 1], + searchScopeCounts: ['sub' => 2], + ), + new TrafficMetrics( + bytesSent: 90, + bytesReceived: 5, + entriesReturned: 3, + ), )); - $operations = $this->subject->snapshot()->operations; + $snapshot = $this->subject->snapshot(); + $operations = $snapshot->operations; self::assertSame( ['search' => 3, 'bind' => 1], @@ -201,6 +338,22 @@ public function test_merging_an_operation_delta_sums_into_the_totals(): void [ResultCode::SUCCESS => 3], $operations->resultCodeCounts, ); + self::assertSame( + ['anonymous' => 1], + $operations->bindCounts, + ); + self::assertSame( + ['sub' => 2], + $operations->searchScopeCounts, + ); + self::assertSame( + 100, + $snapshot->traffic->bytesSent, + ); + self::assertSame( + 4, + $snapshot->traffic->entriesReturned, + ); } public function test_it_records_the_start_time_and_counts_reloads(): void diff --git a/tests/unit/Server/Metrics/Rollup/MetricsDeltaMessageTest.php b/tests/unit/Server/Metrics/Rollup/MetricsDeltaMessageTest.php new file mode 100644 index 00000000..2ca30a4b --- /dev/null +++ b/tests/unit/Server/Metrics/Rollup/MetricsDeltaMessageTest.php @@ -0,0 +1,76 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace Tests\Unit\FreeDSx\Ldap\Server\Metrics\Rollup; + +use FreeDSx\Ldap\Operation\ResultCode; +use FreeDSx\Ldap\Server\Metrics\Rollup\MetricsDelta; +use FreeDSx\Ldap\Server\Metrics\Rollup\MetricsDeltaMessage; +use FreeDSx\Ldap\Server\Metrics\Rollup\MetricsDeltaMessageFactory; +use FreeDSx\Ldap\Server\Metrics\Snapshot\OperationMetrics; +use FreeDSx\Ldap\Server\Metrics\Snapshot\TrafficMetrics; +use PHPUnit\Framework\TestCase; + +final class MetricsDeltaMessageTest extends TestCase +{ + public function test_it_round_trips_a_delta_through_the_wire_form(): void + { + $delta = new MetricsDelta( + new OperationMetrics( + counts: ['search' => 4, 'bind' => 1], + errors: ['search' => 1], + durationSeconds: ['search' => 0.5], + resultCodeCounts: [ResultCode::SUCCESS => 4], + bindCounts: ['simple' => 1], + searchScopeCounts: ['sub' => 4], + ), + new TrafficMetrics( + bytesSent: 4096, + bytesReceived: 256, + entriesReturned: 4, + ), + ); + + $message = new MetricsDeltaMessage($delta); + $rebuilt = (new MetricsDeltaMessageFactory())->fromArray($message->toArray()); + + self::assertInstanceOf( + MetricsDeltaMessage::class, + $rebuilt, + ); + self::assertSame( + $delta->operations->counts, + $rebuilt->delta()->operations->counts, + ); + self::assertSame( + $delta->operations->bindCounts, + $rebuilt->delta()->operations->bindCounts, + ); + self::assertSame( + $delta->operations->searchScopeCounts, + $rebuilt->delta()->operations->searchScopeCounts, + ); + self::assertSame( + $delta->traffic->bytesSent, + $rebuilt->delta()->traffic->bytesSent, + ); + self::assertSame( + $delta->traffic->bytesReceived, + $rebuilt->delta()->traffic->bytesReceived, + ); + self::assertSame( + $delta->traffic->entriesReturned, + $rebuilt->delta()->traffic->entriesReturned, + ); + } +} diff --git a/tests/unit/Server/Metrics/Rollup/OperationDeltaMessageTest.php b/tests/unit/Server/Metrics/Rollup/OperationDeltaMessageTest.php deleted file mode 100644 index 0a59b7eb..00000000 --- a/tests/unit/Server/Metrics/Rollup/OperationDeltaMessageTest.php +++ /dev/null @@ -1,57 +0,0 @@ - - * - * For the full copyright and license information, please view the LICENSE - * file that was distributed with this source code. - */ - -namespace Tests\Unit\FreeDSx\Ldap\Server\Metrics\Rollup; - -use FreeDSx\Ldap\Operation\ResultCode; -use FreeDSx\Ldap\Server\Metrics\Rollup\OperationDeltaMessage; -use FreeDSx\Ldap\Server\Metrics\Rollup\OperationDeltaMessageFactory; -use FreeDSx\Ldap\Server\Metrics\Snapshot\OperationMetrics; -use PHPUnit\Framework\TestCase; - -final class OperationDeltaMessageTest extends TestCase -{ - public function test_it_round_trips_operation_metrics_through_the_wire_form(): void - { - $operations = new OperationMetrics( - counts: ['search' => 4, 'bind' => 1], - errors: ['search' => 1], - durationSeconds: ['search' => 0.5], - resultCodeCounts: [ResultCode::SUCCESS => 4], - ); - - $message = new OperationDeltaMessage($operations); - $rebuilt = (new OperationDeltaMessageFactory())->fromArray($message->toArray()); - - self::assertInstanceOf( - OperationDeltaMessage::class, - $rebuilt, - ); - self::assertSame( - $operations->counts, - $rebuilt->operations()->counts, - ); - self::assertSame( - $operations->errors, - $rebuilt->operations()->errors, - ); - self::assertSame( - $operations->durationSeconds, - $rebuilt->operations()->durationSeconds, - ); - self::assertSame( - $operations->resultCodeCounts, - $rebuilt->operations()->resultCodeCounts, - ); - } -} diff --git a/tests/unit/Server/Middleware/MetricsMiddlewareTest.php b/tests/unit/Server/Middleware/MetricsMiddlewareTest.php index 54edd1b4..25cbe0e6 100644 --- a/tests/unit/Server/Middleware/MetricsMiddlewareTest.php +++ b/tests/unit/Server/Middleware/MetricsMiddlewareTest.php @@ -14,6 +14,7 @@ namespace Tests\Unit\FreeDSx\Ldap\Server\Middleware; use FreeDSx\Ldap\Exception\OperationException; +use FreeDSx\Ldap\Operation\Request\AnonBindRequest; use FreeDSx\Ldap\Operation\Request\RequestInterface; use FreeDSx\Ldap\Operation\Request\SearchRequest; use FreeDSx\Ldap\Operation\Request\SimpleBindRequest; @@ -26,6 +27,8 @@ use FreeDSx\Ldap\Server\Middleware\Pipeline\ServerRequestContext; use FreeDSx\Ldap\Server\Operation\OperationOutcomeResult; use PHPUnit\Framework\TestCase; +use RuntimeException; +use Tests\Support\FreeDSx\Ldap\Middleware\CallbackMiddlewareHandler; use Tests\Support\FreeDSx\Ldap\Middleware\StubMiddlewareHandler; use Tests\Support\FreeDSx\Ldap\Middleware\ThrowingMiddlewareHandler; @@ -116,6 +119,93 @@ public function test_a_thrown_operation_exception_is_recorded_and_rethrown(): vo ); } + public function test_it_raises_the_in_flight_gauge_during_handling_and_clears_it_after(): void + { + $inFlightDuring = []; + + $this->subject->process( + $this->contextFor(new SearchRequest(Filters::present('objectClass'))), + new CallbackMiddlewareHandler(function () use (&$inFlightDuring) { + $inFlightDuring = $this->recorder->snapshot()->operationsInProgress; + + return OperationOutcomeResult::succeeded(); + }), + ); + + self::assertSame( + ['search' => 1], + $inFlightDuring, + ); + self::assertSame( + [], + $this->recorder->snapshot()->operationsInProgress, + ); + } + + public function test_an_unexpected_throwable_is_recorded_and_clears_the_in_flight_gauge(): void + { + $caught = null; + + try { + $this->subject->process( + $this->contextFor(new SearchRequest(Filters::present('objectClass'))), + new ThrowingMiddlewareHandler(new RuntimeException('boom')), + ); + } catch (RuntimeException $e) { + $caught = $e; + } + + self::assertInstanceOf( + RuntimeException::class, + $caught, + ); + + $operations = $this->recorder->snapshot()->operations; + + self::assertSame( + ['search' => 1], + $operations->errors, + ); + self::assertSame( + [ResultCode::OPERATIONS_ERROR => 1], + $operations->resultCodeCounts, + ); + self::assertSame( + [], + $this->recorder->snapshot()->operationsInProgress, + ); + } + + public function test_it_records_the_bind_method_dimension(): void + { + $this->subject->process( + $this->contextFor(new AnonBindRequest()), + new StubMiddlewareHandler(OperationOutcomeResult::succeeded()), + ); + $this->subject->process( + $this->contextFor(new SimpleBindRequest('cn=user,dc=foo,dc=bar', 'secret')), + new StubMiddlewareHandler(OperationOutcomeResult::succeeded()), + ); + + self::assertSame( + ['anonymous' => 1, 'simple' => 1], + $this->recorder->snapshot()->operations->bindCounts, + ); + } + + public function test_it_records_the_search_scope_dimension(): void + { + $this->subject->process( + $this->contextFor((new SearchRequest(Filters::present('objectClass')))->useBaseScope()), + new StubMiddlewareHandler(OperationOutcomeResult::succeeded()), + ); + + self::assertSame( + ['base' => 1], + $this->recorder->snapshot()->operations->searchScopeCounts, + ); + } + public function test_it_streams_each_recorded_operation_to_the_rollup_coordinator(): void { if (str_starts_with(strtoupper(PHP_OS), 'WIN')) {