klevze
fb560fb7dd
Parse rotated nginx JSON access logs into host/route timings so production hotspots can be measured without ad-hoc one-off scripts.
565 lines
20 KiB
PHP
565 lines
20 KiB
PHP
<?php
|
|
|
|
declare(strict_types=1);
|
|
|
|
namespace App\Support\Http;
|
|
|
|
/**
|
|
* Read-only parser for nginx skinbase_perf JSON lines.
|
|
*
|
|
* Multi-value upstream timings (retries): use the **sum** of numeric parts
|
|
* as the upstream total for that request. "-" and empty → null.
|
|
* Percentiles use nearest-rank (ceil(p * n), 1-indexed).
|
|
*
|
|
* Exact --status=404 means HTTP 404 only (not 4xx). Classes are 4xx/5xx.
|
|
*/
|
|
final class HttpPerformanceLogAnalyzer
|
|
{
|
|
/** Ignore gaps shorter than this when judging 24h source coverage. */
|
|
public const COVERAGE_TOLERANCE_SECONDS = 900;
|
|
|
|
public function __construct(private readonly HttpUriNormalizer $uris)
|
|
{
|
|
}
|
|
|
|
/**
|
|
* @param string|list<string> $input
|
|
* @param array{
|
|
* since?: ?string,
|
|
* until?: ?string,
|
|
* min_requests?: int,
|
|
* top?: int,
|
|
* status?: ?string,
|
|
* uri?: ?string,
|
|
* host?: ?string,
|
|
* slow_ms?: ?float,
|
|
* now?: ?\DateTimeImmutable
|
|
* } $options
|
|
* @return array<string, mixed>
|
|
*/
|
|
public function analyze(string|array $input, array $options = []): array
|
|
{
|
|
$files = $this->normalizeInputList($input);
|
|
$now = $options['now'] ?? new \DateTimeImmutable('now');
|
|
$requestedStart = $this->sinceCutoff($options['since'] ?? null, $now);
|
|
$requestedEnd = $this->untilInstant($options['until'] ?? null, $now);
|
|
$minRequests = max(1, (int) ($options['min_requests'] ?? 1));
|
|
$top = max(1, (int) ($options['top'] ?? 20));
|
|
$statusFilter = $this->parseStatusFilter($options['status'] ?? null);
|
|
$uriFilter = $options['uri'] ?? null;
|
|
$hostFilter = isset($options['host']) ? (string) $options['host'] : '';
|
|
$slowMs = isset($options['slow_ms']) && $options['slow_ms'] !== null
|
|
? (float) $options['slow_ms'] / 1000
|
|
: null;
|
|
|
|
$skipped = 0;
|
|
$linesScanned = 0;
|
|
$parseable = 0;
|
|
$families = [];
|
|
$slowest = [];
|
|
$statusCounts = ['4xx' => 0, '5xx' => 0, '499' => 0, 'total' => 0];
|
|
$sources = [];
|
|
$earliestParseable = null;
|
|
$latestParseable = null;
|
|
$earliestMatching = null;
|
|
$latestMatching = null;
|
|
|
|
foreach ($files as $file) {
|
|
$source = [
|
|
'path' => $file,
|
|
'gzip' => str_ends_with(strtolower($file), '.gz'),
|
|
'lines_scanned' => 0,
|
|
'parseable' => 0,
|
|
'in_window' => 0,
|
|
'error' => null,
|
|
];
|
|
|
|
$handle = $this->openStream($file);
|
|
if ($handle === false) {
|
|
$source['error'] = 'unreadable';
|
|
$sources[] = $source;
|
|
continue;
|
|
}
|
|
|
|
try {
|
|
while (($line = fgets($handle)) !== false) {
|
|
$linesScanned++;
|
|
$source['lines_scanned']++;
|
|
$line = trim($line);
|
|
if ($line === '') {
|
|
continue;
|
|
}
|
|
|
|
$row = json_decode($line, true);
|
|
if (! is_array($row)) {
|
|
$skipped++;
|
|
continue;
|
|
}
|
|
|
|
$time = $this->parseTime((string) ($row['time'] ?? ''));
|
|
$requestTime = $this->parseFloat($row['request_time'] ?? null);
|
|
if ($requestTime === null) {
|
|
$skipped++;
|
|
continue;
|
|
}
|
|
|
|
$parseable++;
|
|
$source['parseable']++;
|
|
if ($time instanceof \DateTimeImmutable) {
|
|
$earliestParseable = $this->minTime($earliestParseable, $time);
|
|
$latestParseable = $this->maxTime($latestParseable, $time);
|
|
}
|
|
|
|
if ($requestedStart !== null && ($time === null || $time < $requestedStart)) {
|
|
continue;
|
|
}
|
|
if ($requestedEnd !== null && ($time === null || $time > $requestedEnd)) {
|
|
continue;
|
|
}
|
|
|
|
$status = (int) ($row['status'] ?? 0);
|
|
if (! $this->statusMatches($status, $statusFilter)) {
|
|
continue;
|
|
}
|
|
|
|
$host = (string) ($row['host'] ?? '');
|
|
if ($hostFilter !== '' && $host !== $hostFilter) {
|
|
continue;
|
|
}
|
|
|
|
$uri = $this->uris->normalize((string) ($row['uri'] ?? '/'));
|
|
if (is_string($uriFilter) && $uriFilter !== '' && ! str_starts_with($uri, $uriFilter)) {
|
|
continue;
|
|
}
|
|
|
|
if ($slowMs !== null && $requestTime < $slowMs) {
|
|
continue;
|
|
}
|
|
|
|
$source['in_window']++;
|
|
if ($time instanceof \DateTimeImmutable) {
|
|
$earliestMatching = $this->minTime($earliestMatching, $time);
|
|
$latestMatching = $this->maxTime($latestMatching, $time);
|
|
}
|
|
|
|
$upstreamResponse = $this->parseUpstream($row['upstream_response_time'] ?? null);
|
|
$upstreamHeader = $this->parseUpstream($row['upstream_header_time'] ?? null);
|
|
$bytes = (int) ($row['bytes'] ?? 0);
|
|
$method = (string) ($row['method'] ?? '');
|
|
|
|
$statusCounts['total']++;
|
|
if ($status === 499) {
|
|
$statusCounts['499']++;
|
|
} elseif ($status >= 500) {
|
|
$statusCounts['5xx']++;
|
|
} elseif ($status >= 400) {
|
|
$statusCounts['4xx']++;
|
|
}
|
|
|
|
$familyKey = $host."\n".$uri;
|
|
$families[$familyKey] ??= [
|
|
'host' => $host,
|
|
'uri' => $uri,
|
|
'count' => 0,
|
|
'times' => [],
|
|
'upstream_sum' => 0.0,
|
|
'upstream_n' => 0,
|
|
'header_sum' => 0.0,
|
|
'header_n' => 0,
|
|
'bytes_sum' => 0,
|
|
'4xx' => 0,
|
|
'5xx' => 0,
|
|
'499' => 0,
|
|
'404' => 0,
|
|
];
|
|
$families[$familyKey]['count']++;
|
|
$families[$familyKey]['times'][] = $requestTime;
|
|
$families[$familyKey]['bytes_sum'] += $bytes;
|
|
if ($upstreamResponse !== null) {
|
|
$families[$familyKey]['upstream_sum'] += $upstreamResponse;
|
|
$families[$familyKey]['upstream_n']++;
|
|
}
|
|
if ($upstreamHeader !== null) {
|
|
$families[$familyKey]['header_sum'] += $upstreamHeader;
|
|
$families[$familyKey]['header_n']++;
|
|
}
|
|
if ($status === 499) {
|
|
$families[$familyKey]['499']++;
|
|
} elseif ($status >= 500) {
|
|
$families[$familyKey]['5xx']++;
|
|
} elseif ($status >= 400) {
|
|
$families[$familyKey]['4xx']++;
|
|
if ($status === 404) {
|
|
$families[$familyKey]['404']++;
|
|
}
|
|
}
|
|
|
|
$slowest[] = [
|
|
'time' => $row['time'] ?? null,
|
|
'host' => $host,
|
|
'uri' => $uri,
|
|
'method' => $method,
|
|
'status' => $status,
|
|
'request_time' => $requestTime,
|
|
];
|
|
$slowest[array_key_last($slowest)]['upstream_response_time'] = $upstreamResponse;
|
|
}
|
|
} finally {
|
|
fclose($handle);
|
|
}
|
|
|
|
$sources[] = $source;
|
|
}
|
|
|
|
usort($slowest, static fn (array $a, array $b): int => $b['request_time'] <=> $a['request_time']);
|
|
$slowest = array_slice($slowest, 0, $top);
|
|
|
|
$summaries = [];
|
|
foreach ($families as $family) {
|
|
if ($family['count'] < $minRequests) {
|
|
continue;
|
|
}
|
|
$times = $family['times'];
|
|
sort($times, SORT_NUMERIC);
|
|
$avg = array_sum($times) / $family['count'];
|
|
$summaries[] = [
|
|
'host' => $family['host'],
|
|
'uri' => $family['uri'],
|
|
'count' => $family['count'],
|
|
'p50' => $this->percentile($times, 0.50),
|
|
'p95' => $this->percentile($times, 0.95),
|
|
'p99' => $this->percentile($times, 0.99),
|
|
'max' => $times[array_key_last($times)],
|
|
'avg' => round($avg, 4),
|
|
'total' => round(array_sum($times), 4),
|
|
'avg_upstream_response' => $family['upstream_n'] > 0 ? round($family['upstream_sum'] / $family['upstream_n'], 4) : null,
|
|
'avg_upstream_header' => $family['header_n'] > 0 ? round($family['header_sum'] / $family['header_n'], 4) : null,
|
|
'avg_bytes' => (int) round($family['bytes_sum'] / $family['count']),
|
|
'4xx' => $family['4xx'],
|
|
'4xx_rate' => round($family['4xx'] / $family['count'], 4),
|
|
'404' => $family['404'],
|
|
'5xx' => $family['5xx'],
|
|
'5xx_rate' => round($family['5xx'] / $family['count'], 4),
|
|
'499' => $family['499'],
|
|
];
|
|
}
|
|
|
|
$byP95 = $summaries;
|
|
usort($byP95, static fn (array $a, array $b): int => ($b['p95'] ?? 0) <=> ($a['p95'] ?? 0));
|
|
$byP99 = $summaries;
|
|
usort($byP99, static fn (array $a, array $b): int => ($b['p99'] ?? 0) <=> ($a['p99'] ?? 0));
|
|
$byTotal = $summaries;
|
|
usort($byTotal, static fn (array $a, array $b): int => $b['total'] <=> $a['total']);
|
|
$byCount = $summaries;
|
|
usort($byCount, static fn (array $a, array $b): int => $b['count'] <=> $a['count']);
|
|
$byCost = $summaries;
|
|
usort($byCost, static fn (array $a, array $b): int => ($b['count'] * $b['avg']) <=> ($a['count'] * $a['avg']));
|
|
$by5xx = array_values(array_filter($summaries, static fn (array $row): bool => $row['5xx'] > 0));
|
|
usort($by5xx, static fn (array $a, array $b): int => $b['5xx'] <=> $a['5xx']);
|
|
$by404 = array_values(array_filter($summaries, static fn (array $row): bool => ($row['404'] ?? 0) > 0));
|
|
usort($by404, static fn (array $a, array $b): int => $b['404'] <=> $a['404']);
|
|
|
|
$coverage = $this->coverageReport(
|
|
$requestedStart,
|
|
$requestedEnd,
|
|
$earliestParseable,
|
|
$latestParseable,
|
|
$earliestMatching,
|
|
$latestMatching,
|
|
);
|
|
|
|
return [
|
|
'skipped' => $skipped,
|
|
'lines_scanned' => $linesScanned,
|
|
'parseable' => $parseable,
|
|
'source_files' => count($files),
|
|
'sources' => $sources,
|
|
'coverage' => $coverage,
|
|
'warnings' => $coverage['warnings'],
|
|
'sample_empty' => $statusCounts['total'] === 0,
|
|
'totals' => $statusCounts,
|
|
'by_p95' => array_slice($byP95, 0, $top),
|
|
'by_p99' => array_slice($byP99, 0, $top),
|
|
'by_total_time' => array_slice($byTotal, 0, $top),
|
|
'by_count' => array_slice($byCount, 0, $top),
|
|
'by_cost' => array_slice($byCost, 0, $top),
|
|
'by_5xx' => array_slice($by5xx, 0, $top),
|
|
'by_4xx' => array_slice($by404, 0, $top),
|
|
'slowest' => $slowest,
|
|
'percentile_method' => 'nearest-rank (ceil(p * n), 1-indexed)',
|
|
'upstream_aggregation' => 'sum of numeric comma-separated upstream timings; "-" is null',
|
|
];
|
|
}
|
|
|
|
/**
|
|
* @param list<string> $paths
|
|
* @return list<string>
|
|
*/
|
|
public function deduplicatePaths(array $paths): array
|
|
{
|
|
$seen = [];
|
|
$out = [];
|
|
foreach ($paths as $path) {
|
|
$path = str_replace('\\', '/', (string) $path);
|
|
if ($path === '') {
|
|
continue;
|
|
}
|
|
$resolved = realpath($path) ?: $path;
|
|
$key = strtolower($resolved);
|
|
if (isset($seen[$key])) {
|
|
continue;
|
|
}
|
|
$seen[$key] = true;
|
|
$out[] = $path;
|
|
}
|
|
|
|
return array_values($out);
|
|
}
|
|
|
|
/**
|
|
* @return list<string>
|
|
*/
|
|
public function expandGlob(string $pattern): array
|
|
{
|
|
$matches = glob($pattern, GLOB_NOSORT) ?: [];
|
|
$files = [];
|
|
foreach ($matches as $match) {
|
|
if (is_file($match)) {
|
|
$files[] = $match;
|
|
}
|
|
}
|
|
natsort($files);
|
|
|
|
return array_values($files);
|
|
}
|
|
|
|
/**
|
|
* Nearest-rank: rank = ceil(p * n), 1-indexed.
|
|
*
|
|
* @param list<float> $sorted
|
|
*/
|
|
public function percentile(array $sorted, float $p): ?float
|
|
{
|
|
$n = count($sorted);
|
|
if ($n === 0) {
|
|
return null;
|
|
}
|
|
|
|
$rank = (int) ceil($p * $n);
|
|
$index = max(0, min($n - 1, $rank - 1));
|
|
|
|
return round($sorted[$index], 4);
|
|
}
|
|
|
|
public function parseUpstream(mixed $value): ?float
|
|
{
|
|
if ($value === null || $value === '' || $value === '-') {
|
|
return null;
|
|
}
|
|
|
|
if (is_int($value) || is_float($value)) {
|
|
return (float) $value;
|
|
}
|
|
|
|
$parts = preg_split('/\s*,\s*/', (string) $value) ?: [];
|
|
$sum = 0.0;
|
|
$found = false;
|
|
foreach ($parts as $part) {
|
|
if ($part === '' || $part === '-') {
|
|
continue;
|
|
}
|
|
if (! is_numeric($part)) {
|
|
continue;
|
|
}
|
|
$sum += (float) $part;
|
|
$found = true;
|
|
}
|
|
|
|
return $found ? $sum : null;
|
|
}
|
|
|
|
/**
|
|
* @param string|list<string> $input
|
|
* @return list<string>
|
|
*/
|
|
private function normalizeInputList(string|array $input): array
|
|
{
|
|
$files = is_array($input) ? $input : [$input];
|
|
$files = $this->deduplicatePaths(array_map('strval', $files));
|
|
if ($files === []) {
|
|
throw new \InvalidArgumentException('No performance log files were provided.');
|
|
}
|
|
|
|
return $files;
|
|
}
|
|
|
|
/**
|
|
* @return resource|false
|
|
*/
|
|
private function openStream(string $file)
|
|
{
|
|
if (str_ends_with(strtolower($file), '.gz')) {
|
|
return @gzopen($file, 'rb');
|
|
}
|
|
|
|
return @fopen($file, 'r');
|
|
}
|
|
|
|
/**
|
|
* @return array{type: string, code?: int, class?: string}
|
|
*/
|
|
public function parseStatusFilter(?string $raw): array
|
|
{
|
|
if ($raw === null || $raw === '') {
|
|
return ['type' => 'none'];
|
|
}
|
|
|
|
$value = strtolower(trim($raw));
|
|
if ($value === '4xx') {
|
|
return ['type' => 'class', 'class' => '4xx'];
|
|
}
|
|
if ($value === '5xx') {
|
|
return ['type' => 'class', 'class' => '5xx'];
|
|
}
|
|
if (preg_match('/^[1-5][0-9]{2}$/', $value) === 1) {
|
|
return ['type' => 'exact', 'code' => (int) $value];
|
|
}
|
|
|
|
throw new \InvalidArgumentException('Invalid --status value: '.$raw);
|
|
}
|
|
|
|
/**
|
|
* @param array{type: string, code?: int, class?: string} $filter
|
|
*/
|
|
private function statusMatches(int $status, array $filter): bool
|
|
{
|
|
return match ($filter['type']) {
|
|
'none' => true,
|
|
'exact' => $status === (int) ($filter['code'] ?? 0),
|
|
'class' => ($filter['class'] ?? '') === '5xx'
|
|
? ($status >= 500 && $status <= 599)
|
|
: ($status >= 400 && $status <= 499),
|
|
default => true,
|
|
};
|
|
}
|
|
|
|
/**
|
|
* @return array<string, mixed>
|
|
*/
|
|
private function coverageReport(
|
|
?\DateTimeImmutable $requestedStart,
|
|
?\DateTimeImmutable $requestedEnd,
|
|
?\DateTimeImmutable $earliestParseable,
|
|
?\DateTimeImmutable $latestParseable,
|
|
?\DateTimeImmutable $earliestMatching,
|
|
?\DateTimeImmutable $latestMatching,
|
|
): array {
|
|
$warnings = [];
|
|
$complete = true;
|
|
if ($requestedStart instanceof \DateTimeImmutable && $requestedEnd instanceof \DateTimeImmutable) {
|
|
if (! $earliestParseable instanceof \DateTimeImmutable || ! $latestParseable instanceof \DateTimeImmutable) {
|
|
$complete = false;
|
|
$warnings[] = 'Observed records do not demonstrate full requested coverage.';
|
|
} else {
|
|
$startGap = $earliestParseable->getTimestamp() - $requestedStart->getTimestamp();
|
|
$endGap = $requestedEnd->getTimestamp() - $latestParseable->getTimestamp();
|
|
if ($startGap > self::COVERAGE_TOLERANCE_SECONDS || $endGap > self::COVERAGE_TOLERANCE_SECONDS) {
|
|
$complete = false;
|
|
$warnings[] = sprintf(
|
|
'WARNING: Requested window is not fully covered by supplied logs. Requested: %s → %s Observed: %s → %s',
|
|
$requestedStart->format(\DateTimeInterface::ATOM),
|
|
$requestedEnd->format(\DateTimeInterface::ATOM),
|
|
$earliestParseable->format(\DateTimeInterface::ATOM),
|
|
$latestParseable->format(\DateTimeInterface::ATOM),
|
|
);
|
|
}
|
|
}
|
|
}
|
|
|
|
return [
|
|
'requested_start' => $requestedStart?->format(\DateTimeInterface::ATOM),
|
|
'requested_end' => $requestedEnd?->format(\DateTimeInterface::ATOM),
|
|
'observed_earliest_parseable' => $earliestParseable?->format(\DateTimeInterface::ATOM),
|
|
'observed_latest_parseable' => $latestParseable?->format(\DateTimeInterface::ATOM),
|
|
'observed_earliest_matching' => $earliestMatching?->format(\DateTimeInterface::ATOM),
|
|
'observed_latest_matching' => $latestMatching?->format(\DateTimeInterface::ATOM),
|
|
'tolerance_seconds' => self::COVERAGE_TOLERANCE_SECONDS,
|
|
'complete' => $complete,
|
|
'warnings' => $warnings,
|
|
];
|
|
}
|
|
|
|
private function minTime(?\DateTimeImmutable $current, \DateTimeImmutable $candidate): \DateTimeImmutable
|
|
{
|
|
if ($current === null || $candidate < $current) {
|
|
return $candidate;
|
|
}
|
|
|
|
return $current;
|
|
}
|
|
|
|
private function maxTime(?\DateTimeImmutable $current, \DateTimeImmutable $candidate): \DateTimeImmutable
|
|
{
|
|
if ($current === null || $candidate > $current) {
|
|
return $candidate;
|
|
}
|
|
|
|
return $current;
|
|
}
|
|
|
|
private function parseFloat(mixed $value): ?float
|
|
{
|
|
if ($value === null || $value === '' || $value === '-') {
|
|
return null;
|
|
}
|
|
if (! is_numeric($value)) {
|
|
return null;
|
|
}
|
|
|
|
return (float) $value;
|
|
}
|
|
|
|
private function parseTime(string $value): ?\DateTimeImmutable
|
|
{
|
|
if ($value === '') {
|
|
return null;
|
|
}
|
|
|
|
try {
|
|
return new \DateTimeImmutable($value);
|
|
} catch (\Exception) {
|
|
return null;
|
|
}
|
|
}
|
|
|
|
private function sinceCutoff(?string $since, \DateTimeImmutable $now): ?\DateTimeImmutable
|
|
{
|
|
if ($since === null || $since === '') {
|
|
return null;
|
|
}
|
|
|
|
if (preg_match('/^(\d+)(h|d|m)$/', strtolower($since), $matches) !== 1) {
|
|
return $this->parseTime($since);
|
|
}
|
|
|
|
$n = (int) $matches[1];
|
|
$unit = $matches[2];
|
|
$interval = match ($unit) {
|
|
'm' => new \DateInterval('PT'.$n.'M'),
|
|
'h' => new \DateInterval('PT'.$n.'H'),
|
|
'd' => new \DateInterval('P'.$n.'D'),
|
|
};
|
|
|
|
return $now->sub($interval);
|
|
}
|
|
|
|
private function untilInstant(?string $until, \DateTimeImmutable $now): \DateTimeImmutable
|
|
{
|
|
if ($until === null || $until === '') {
|
|
return $now;
|
|
}
|
|
|
|
return $this->parseTime($until) ?? $now;
|
|
}
|
|
}
|