Skip to content

Commit

Permalink
Replace connect* and tls* events with connectionAcquired event
Browse files Browse the repository at this point in the history
Timings are exposed via Connection now.
  • Loading branch information
kelunik committed Aug 28, 2023
1 parent eba31d5 commit 544956b
Show file tree
Hide file tree
Showing 13 changed files with 159 additions and 158 deletions.
10 changes: 10 additions & 0 deletions src/Connection/Connection.php
Original file line number Diff line number Diff line change
Expand Up @@ -28,4 +28,14 @@ public function getLocalAddress(): SocketAddress;
public function getRemoteAddress(): SocketAddress;

public function getTlsInfo(): ?TlsInfo;

/**
* @return float|null Returns the TLS handshake duration if applicable in seconds.
*/
public function getTlsHandshakeDuration(): ?float;

/**
* @return float Returns the total connect duration in seconds, including the TLS handshake.
*/
public function getConnectDuration(): float;
}
7 changes: 7 additions & 0 deletions src/Connection/ConnectionLimitingPool.php
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@
use Amp\Http\Client\Response;
use Revolt\EventLoop;
use function Amp\async;
use function Amp\Http\Client\events;

final class ConnectionLimitingPool implements ConnectionPool
{
Expand Down Expand Up @@ -194,6 +195,8 @@ private function getStreamFor(string $uri, Request $request, Cancellation $cance
continue; // No stream available for the given request.
}

events()->connectionAcquired($request, $connection);

return [$connection, $stream];
}

Expand All @@ -216,6 +219,8 @@ private function getStreamFor(string $uri, Request $request, Cancellation $cance
continue; // Wait for a different connection to become available.
}

events()->connectionAcquired($request, $connection);

return [$connection, $stream];
} while (true);

Expand Down Expand Up @@ -284,6 +289,8 @@ private function getStreamFor(string $uri, Request $request, Cancellation $cance
}
}

events()->connectionAcquired($request, $connection);

return [$connection, $stream];
}

Expand Down
27 changes: 12 additions & 15 deletions src/Connection/DefaultConnectionFactory.php
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@
use Amp\Socket\ClientTlsContext;
use Amp\Socket\ConnectContext;
use Amp\TimeoutCancellation;
use function Amp\Http\Client\events;
use function Amp\now;

final class DefaultConnectionFactory implements ConnectionFactory
{
Expand All @@ -30,7 +30,7 @@ public function __construct(?Socket\SocketConnector $connector = null, ?ConnectC

public function create(Request $request, Cancellation $cancellation): Connection
{
events()->connectStart($request);
$connectStart = now();

$connector = $this->connector ?? Socket\socketConnector();
$connectContext = $this->connectContext ?? new ConnectContext;
Expand Down Expand Up @@ -114,8 +114,10 @@ public function create(Request $request, Cancellation $cancellation): Connection
);
}

$tlsHandshakeDuration = null;

if ($isHttps) {
events()->tlsHandshakeStart($request);
$tlsHandshakeStart = now();

try {
$tlsState = $socket->getTlsState();
Expand Down Expand Up @@ -168,25 +170,24 @@ public function create(Request $request, Cancellation $cancellation): Connection
);
}

events()->tlsHandshakeEnd($request, $tlsInfo);
$tlsHandshakeDuration = now() - $tlsHandshakeStart;
$connectDuration = now() - $connectStart;

if ($tlsInfo->getApplicationLayerProtocol() === 'h2') {
$http2Connection = new Http2Connection($socket);
$http2Connection = new Http2Connection($socket, $connectDuration, $tlsHandshakeDuration);
$http2Connection->initialize($cancellation);

events()->connectEnd($request, $http2Connection);

return $http2Connection;
}
}

$connectDuration = now() - $connectStart;

// Treat the presence of only HTTP/2 as prior knowledge, see https://http2.github.io/http2-spec/#known-http
if ($request->getProtocolVersions() === ['2']) {
$http2Connection = new Http2Connection($socket);
$http2Connection = new Http2Connection($socket, $connectDuration, $tlsHandshakeDuration);
$http2Connection->initialize($cancellation);

events()->connectEnd($request, $http2Connection);

return $http2Connection;
}

Expand All @@ -201,10 +202,6 @@ public function create(Request $request, Cancellation $cancellation): Connection
));
}

$http1Connection = new Http1Connection($socket);

events()->connectEnd($request, $http1Connection);

return $http1Connection;
return new Http1Connection($socket, $connectDuration, $tlsHandshakeDuration);
}
}
18 changes: 16 additions & 2 deletions src/Connection/Http1Connection.php
Original file line number Diff line number Diff line change
Expand Up @@ -80,8 +80,12 @@ final class Http1Connection implements Connection

private ?Future $idleRead = null;

public function __construct(Socket $socket, float $timeoutGracePeriod = 2)
{
public function __construct(
Socket $socket,
private readonly float $connectDuration,
private readonly ?float $tlsHandshakeDuration,
float $timeoutGracePeriod = 2
) {
$this->socket = $socket;
$this->localAddress = $socket->getLocalAddress();
$this->remoteAddress = $socket->getRemoteAddress();
Expand Down Expand Up @@ -137,6 +141,11 @@ public function getTlsInfo(): ?TlsInfo
return $this->tlsInfo;
}

public function getTlsHandshakeDuration(): ?float
{
return $this->tlsHandshakeDuration;
}

public function getProtocolVersions(): array
{
return self::PROTOCOL_VERSIONS;
Expand Down Expand Up @@ -669,4 +678,9 @@ private function watchIdleConnection(): void
return $chunk;
});
}

public function getConnectDuration(): float
{
return $this->connectDuration;
}
}
17 changes: 15 additions & 2 deletions src/Connection/Http2Connection.php
Original file line number Diff line number Diff line change
Expand Up @@ -25,8 +25,11 @@ final class Http2Connection implements Connection

private int $requestCount = 0;

public function __construct(private readonly Socket $socket)
{
public function __construct(
private readonly Socket $socket,
private readonly float $connectDuration,
private readonly ?float $tlsHandshakeDuration
) {
$this->processor = new Http2ConnectionProcessor($socket);
}

Expand Down Expand Up @@ -96,4 +99,14 @@ private function request(Request $request, Cancellation $token, Stream $applicat

return $this->processor->request($request, $token, $applicationStream);
}

public function getTlsHandshakeDuration(): ?float
{
return $this->tlsHandshakeDuration;
}

public function getConnectDuration(): float
{
return $this->connectDuration;
}
}
20 changes: 2 additions & 18 deletions src/EventListener.php
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,6 @@

use Amp\Http\Client\Connection\Connection;
use Amp\Http\Client\Connection\Stream;
use Amp\Socket\TlsInfo;

/**
* Allows listening to more fine granular events than interceptors are able to achieve.
Expand Down Expand Up @@ -50,24 +49,9 @@ public function networkInterceptorStart(Request $request, NetworkInterceptor $in
public function networkInterceptorEnd(Request $request, NetworkInterceptor $interceptor, Response $response): void;

/**
* Called before a new connection is initiated.
* Called after the connection for the request has been selected.
*/
public function connectStart(Request $request): void;

/**
* Called when a new connection is established.
*/
public function connectEnd(Request $request, Connection $connection): void;

/**
* Called before TLS negotiation is started (HTTPS-only).
*/
public function tlsHandshakeStart(Request $request): void;

/**
* Called when TLS negotiation completed (HTTPS-only).
*/
public function tlsHandshakeEnd(Request $request, TlsInfo $tlsInfo): void;
public function connectionAcquired(Request $request, Connection $connection): void;

/**
* Called before the request headers are sent.
Expand Down
110 changes: 61 additions & 49 deletions src/EventListener/LogHttpArchive.php
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,6 @@
use Amp\Http\Client\Response;
use Amp\Http\HttpMessage;
use Amp\Socket\InternetAddress;
use Amp\Socket\TlsInfo;
use Amp\Sync\LocalMutex;
use Revolt\EventLoop;
use function Amp\File\filesystem;
Expand All @@ -30,6 +29,18 @@ final class LogHttpArchive implements EventListener
use ForbidCloning;
use ForbidSerialization;

/**
* @param non-empty-string $attributeName
*/
private static function getDuration(Request $request, string $attributeName): float
{
if (!$request->hasAttribute($attributeName)) {
return -1;
}

return $request->getAttribute($attributeName) ?? -1;
}

/**
* @param non-empty-string $start
* @param non-empty-string ...$ends
Expand Down Expand Up @@ -69,6 +80,40 @@ private static function formatEntry(Response $response): array
{
$request = $response->getRequest();

$connectDuration = self::getDuration(
$request,
HarAttributes::TIME_CONNECT
);

$tlsHandshakeDuration = self::getDuration(
$request,
HarAttributes::TIME_SSL
);

$sendDuration = self::getTime(
$request,
HarAttributes::TIME_SEND,
HarAttributes::TIME_WAIT
);

$waitDuration = self::getTime(
$request,
HarAttributes::TIME_WAIT,
HarAttributes::TIME_RECEIVE
);

$receiveDuration = self::getTime(
$request,
HarAttributes::TIME_RECEIVE,
HarAttributes::TIME_COMPLETE
);

$blockedDuration = self::getTime(
$request,
HarAttributes::TIME_START,
HarAttributes::TIME_COMPLETE
) - $connectDuration - $sendDuration - $receiveDuration;

$data = [
'startedDateTime' => $request->getAttribute(HarAttributes::STARTED_DATE_TIME)->format(\DateTimeInterface::RFC3339_EXTENDED),
'time' => self::getTime($request, HarAttributes::TIME_START, HarAttributes::TIME_COMPLETE),
Expand Down Expand Up @@ -98,38 +143,13 @@ private static function formatEntry(Response $response): array
],
'cache' => [],
'timings' => [
'blocked' => self::getTime(
$request,
HarAttributes::TIME_START,
HarAttributes::TIME_CONNECT,
HarAttributes::TIME_SEND
),
'blocked' => $blockedDuration,
'dns' => -1,
'connect' => self::getTime(
$request,
HarAttributes::TIME_CONNECT,
HarAttributes::TIME_SEND
),
'ssl' => self::getTime(
$request,
HarAttributes::TIME_SSL,
HarAttributes::TIME_SEND
),
'send' => self::getTime(
$request,
HarAttributes::TIME_SEND,
HarAttributes::TIME_WAIT
),
'wait' => self::getTime(
$request,
HarAttributes::TIME_WAIT,
HarAttributes::TIME_RECEIVE
),
'receive' => self::getTime(
$request,
HarAttributes::TIME_RECEIVE,
HarAttributes::TIME_COMPLETE
),
'connect' => $connectDuration,
'ssl' => $tlsHandshakeDuration,
'send' => $sendDuration,
'wait' => $waitDuration,
'receive' => $receiveDuration,
],
];

Expand Down Expand Up @@ -226,9 +246,16 @@ public function requestStart(Request $request): void
$this->addTiming(HarAttributes::TIME_START, $request);
}

public function connectStart(Request $request): void
public function connectionAcquired(Request $request, Connection $connection): void
{
$this->addTiming(HarAttributes::TIME_CONNECT, $request);
$request->setAttribute(HarAttributes::TIME_CONNECT, (int) ($connection->getConnectDuration() * 1000));

$tlsHandshakeDuration = $connection->getTlsHandshakeDuration();
if ($tlsHandshakeDuration !== null) {
$request->setAttribute(HarAttributes::TIME_SSL, (int) ($tlsHandshakeDuration * 1000));
} else {
$request->setAttribute(HarAttributes::TIME_SSL, -1);
}
}

public function requestHeaderStart(Request $request, Stream $stream): void
Expand Down Expand Up @@ -278,21 +305,6 @@ public function requestFailed(Request $request, HttpException $exception): void
// TODO: Log error to archive
}

public function connectEnd(Request $request, Connection $connection): void
{
// nothing to do
}

public function tlsHandshakeStart(Request $request): void
{
$this->addTiming(HarAttributes::TIME_SSL, $request);
}

public function tlsHandshakeEnd(Request $request, TlsInfo $tlsInfo): void
{
// nothing to do
}

public function requestHeaderEnd(Request $request, Stream $stream): void
{
// nothing to do
Expand Down
Loading

0 comments on commit 544956b

Please sign in to comment.