Skip to content

Commit c35a6f4

Browse files
committed
feat: Log outgoing http requests in tests
Assisted-by: ClaudeCode:claude-opus-5 Signed-off-by: Marcel Müller <marcel-mueller@gmx.de>
1 parent fd32555 commit c35a6f4

4 files changed

Lines changed: 202 additions & 0 deletions

File tree

.github/workflows/phpunit-sqlite.yml

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -135,6 +135,16 @@ jobs:
135135
echo '```'
136136
} | tee -a "${GITHUB_STEP_SUMMARY:-/dev/null}"
137137
138+
- name: Outgoing HTTP requests
139+
if: always()
140+
continue-on-error: true
141+
run: |
142+
{
143+
echo '```'
144+
php tests/http-analyzer.php http-requests.log 20
145+
echo '```'
146+
} | tee -a "${GITHUB_STEP_SUMMARY:-/dev/null}"
147+
138148
- name: Print logs
139149
if: always()
140150
run: |

tests/bootstrap.php

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,12 @@
3535
}
3636
}
3737

38+
// Recorded on CI by default; set TEST_LOG_HTTP to a path for a manual run.
39+
$logHttp = getenv('TEST_LOG_HTTP') ?: (getenv('CI') ? OC::$SERVERROOT . '/http-requests.log' : '');
40+
if ($logHttp !== '') {
41+
\Test\HttpRequestLogger::install($logHttp);
42+
}
43+
3844
OC_Hook::clear();
3945

4046
set_include_path(

tests/http-analyzer.php

Lines changed: 80 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,80 @@
1+
<?php
2+
3+
declare(strict_types=1);
4+
/**
5+
* SPDX-FileCopyrightText: 2026 Nextcloud GmbH and Nextcloud contributors
6+
* SPDX-License-Identifier: AGPL-3.0-or-later
7+
*/
8+
9+
/**
10+
* Rank the outgoing HTTP requests recorded by Test\HttpRequestLogger.
11+
*
12+
* Usage: TEST_LOG_HTTP=http-requests.log phpunit ...
13+
* php tests/http-analyzer.php [http-requests.log] [topN]
14+
*
15+
* Tests should not reach the network: anything listed needs either a mocked
16+
* IClientService or a config value that prevents the request.
17+
*/
18+
19+
$file = $argv[1] ?? 'http-requests.log';
20+
$topCount = (int)($argv[2] ?? 20);
21+
22+
if (!is_readable($file)) {
23+
fwrite(STDERR, "cannot read $file\n");
24+
exit(1);
25+
}
26+
27+
/** @var list<array{test: string, method: string, uri: string, outcome: string, duration: float}> $requests */
28+
$requests = [];
29+
foreach (file($file, FILE_IGNORE_NEW_LINES | FILE_SKIP_EMPTY_LINES) ?: [] as $line) {
30+
$request = json_decode($line, true);
31+
if (is_array($request)) {
32+
$requests[] = $request;
33+
}
34+
}
35+
36+
if ($requests === []) {
37+
echo "No outgoing HTTP requests were recorded.\n";
38+
exit(0);
39+
}
40+
41+
$totalDuration = array_sum(array_column($requests, 'duration'));
42+
printf("%d requests, %.1fs total\n", count($requests), $totalDuration);
43+
44+
/** @param callable(array): string $key */
45+
function group(array $requests, callable $key): array {
46+
$groups = [];
47+
foreach ($requests as $request) {
48+
$name = $key($request);
49+
$groups[$name] ??= ['duration' => 0.0, 'requests' => 0];
50+
$groups[$name]['duration'] += $request['duration'];
51+
$groups[$name]['requests']++;
52+
}
53+
uasort($groups, static fn (array $a, array $b): int => $b['duration'] <=> $a['duration']);
54+
return $groups;
55+
}
56+
57+
foreach ([
58+
'host' => static fn (array $r): string => parse_url($r['uri'], PHP_URL_HOST) ?: '(unparsed)',
59+
'test' => static fn (array $r): string => $r['test'],
60+
] as $label => $key) {
61+
$groups = group($requests, $key);
62+
printf("\nRequests by %s\n", $label);
63+
printf(" %9s %9s %s\n", 'sum', 'requests', $label);
64+
foreach (array_slice($groups, 0, $topCount, true) as $name => $stats) {
65+
printf(" %8.2fs %9d %s\n", $stats['duration'], $stats['requests'], $name);
66+
}
67+
}
68+
69+
usort($requests, static fn (array $a, array $b): int => $b['duration'] <=> $a['duration']);
70+
printf("\nTop %d slowest requests\n", $topCount);
71+
foreach (array_slice($requests, 0, $topCount) as $request) {
72+
printf(
73+
" %8.2fs %-6s %-4s %s\n %s\n",
74+
$request['duration'],
75+
$request['method'],
76+
$request['outcome'],
77+
$request['uri'],
78+
$request['test'],
79+
);
80+
}

tests/lib/HttpRequestLogger.php

Lines changed: 106 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,106 @@
1+
<?php
2+
3+
declare(strict_types=1);
4+
/**
5+
* SPDX-FileCopyrightText: 2026 Nextcloud GmbH and Nextcloud contributors
6+
* SPDX-License-Identifier: AGPL-3.0-or-later
7+
*/
8+
9+
namespace Test;
10+
11+
use GuzzleHttp\Handler\CurlHandler;
12+
use GuzzleHttp\Promise\Create;
13+
use GuzzleHttp\Promise\PromiseInterface;
14+
use OC\Http\Client\ClientService;
15+
use OCP\Http\Client\IClient;
16+
use OCP\Http\Client\IClientService;
17+
use OCP\Server;
18+
use Psr\Http\Message\RequestInterface;
19+
use Psr\Http\Message\ResponseInterface;
20+
21+
/**
22+
* Records the outgoing HTTP requests of a test run for tests/http-analyzer.php.
23+
* Enable by setting TEST_LOG_HTTP to the log file path.
24+
*
25+
* Covers IClientService only: a library building its own client or calling curl
26+
* directly stays invisible, as does any test that mocks IClientService.
27+
*/
28+
final class HttpRequestLogger implements IClientService {
29+
private const RUN_MARKER = 'TEST_LOG_HTTP_RUN';
30+
31+
private function __construct(
32+
private IClientService $inner,
33+
private string $logFile,
34+
) {
35+
}
36+
37+
public static function install(string $logFile): void {
38+
// Resolving ClientService rather than IClientService avoids recursing into
39+
// this decorator, and keeps the service lazy.
40+
/** @psalm-suppress InternalMethod */
41+
\OC::$server->registerService(IClientService::class, static fn (): IClientService
42+
=> new self(Server::get(ClientService::class), $logFile));
43+
44+
// A test running in a separate process re-runs the bootstrap, so only the
45+
// process that owns the run may truncate. Children inherit the marker.
46+
if (getenv(self::RUN_MARKER) === false) {
47+
putenv(self::RUN_MARKER . '=' . getmypid());
48+
file_put_contents($logFile, '');
49+
}
50+
}
51+
52+
#[\Override]
53+
public function newClient(?callable $handler = null): IClient {
54+
$next = $handler ?? new CurlHandler();
55+
56+
return $this->inner->newClient(
57+
function (RequestInterface $request, array $options) use ($next): PromiseInterface {
58+
$start = microtime(true);
59+
60+
return $next($request, $options)->then(
61+
function (ResponseInterface $response) use ($request, $start): ResponseInterface {
62+
$this->record($request, $start, (string)$response->getStatusCode());
63+
return $response;
64+
},
65+
function (mixed $reason) use ($request, $start): PromiseInterface {
66+
$this->record($request, $start, 'error');
67+
return Create::rejectionFor($reason);
68+
},
69+
);
70+
},
71+
);
72+
}
73+
74+
private function record(RequestInterface $request, float $start, string $outcome): void {
75+
$line = json_encode([
76+
'test' => self::currentTest(),
77+
'method' => $request->getMethod(),
78+
'uri' => (string)$request->getUri(),
79+
'outcome' => $outcome,
80+
'duration' => round(microtime(true) - $start, 6),
81+
], JSON_INVALID_UTF8_SUBSTITUTE | JSON_UNESCAPED_SLASHES);
82+
83+
if ($line !== false) {
84+
file_put_contents($this->logFile, $line . "\n", FILE_APPEND);
85+
}
86+
}
87+
88+
/** PHPUnit exposes no global for the running test, so walk the stack for it. */
89+
private static function currentTest(): string {
90+
$test = '(unknown)';
91+
92+
foreach (debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS) as $frame) {
93+
$class = $frame['class'] ?? '';
94+
$function = $frame['function'] ?? '';
95+
96+
if ($class !== ''
97+
&& str_starts_with($function, 'test')
98+
&& is_subclass_of($class, \PHPUnit\Framework\TestCase::class)
99+
) {
100+
$test = $class . '::' . $function;
101+
}
102+
}
103+
104+
return $test;
105+
}
106+
}

0 commit comments

Comments
 (0)