Files
zyt/server/tests/DiagnosisAiAssistantTimingTest.php

97 lines
4.8 KiB
PHP
Executable File

<?php
declare(strict_types=1);
require dirname(__DIR__) . '/vendor/autoload.php';
use app\adminapi\service\AssistantSseTiming;
function timingExpect(bool $condition, string $message): void
{
if (!$condition) {
fwrite(STDERR, "FAIL: {$message}\n");
exit(1);
}
}
$one = new AssistantSseTiming();
$two = new AssistantSseTiming();
$first = $one->event('prepare', [
'duration_ms' => 120,
'aggregate_ms' => 75,
'compaction_ms' => 0,
'source_bytes' => 1000,
'query_bytes' => 1100,
'attachment_count' => 2,
'compaction_attempted' => false,
'status' => 'ok',
'patient_name' => '患者姓名',
'query' => '患者正文',
'url' => 'https://private.example/path',
'api_key' => 'secret',
]);
$second = $one->event('upstream_done', [
'duration_ms' => 4300,
'retry_ms' => 1200,
'retry_attempted' => true,
'delta_count' => 4,
'delta_bytes' => 24,
'status' => 'error',
'error_code' => 'UPSTREAM_TIMEOUT',
]);
timingExpect(preg_match('/^[a-f0-9]{32}$/', $first['trace_id']) === 1, 'trace id is random hex only');
timingExpect($first['trace_id'] !== $two->event('prepare')['trace_id'], 'requests use distinct trace ids');
timingExpect($first['trace_id'] === $second['trace_id'], 'all phases share one trace id');
timingExpect(
$first['aggregate_ms'] === 75 && $first['attachment_count'] === 2 && $first['compaction_attempted'] === false,
'prepare phase retains useful numeric metadata'
);
timingExpect(
$second['retry_attempted'] === true && $second['retry_ms'] === 1200
&& $second['error_code'] === 'UPSTREAM_TIMEOUT',
'upstream phase retains retry, duration and safe status'
);
$encoded = json_encode($first, JSON_UNESCAPED_UNICODE);
foreach (['患者姓名', '患者正文', 'private.example', 'secret'] as $sensitive) {
timingExpect(!str_contains($encoded, $sensitive), 'timing log excludes sensitive payload');
}
timingExpect(!isset($one->event('prepare', ['duration_ms' => '患者正文'])['duration_ms']), 'numeric fields reject text');
timingExpect(!isset($one->event('upstream_done', ['error_code' => 'KEY=secret'])['error_code']), 'error code is validated');
timingExpect(!isset($one->event('upstream_done', ['error_code' => 'API_KEY_SECRET'])['error_code']), 'unknown machine codes are not logged');
$startedAt = hrtime(true);
timingExpect(AssistantSseTiming::elapsedMs($startedAt) >= 0, 'monotonic elapsed time is non-negative');
timingExpect(isset($first['request_elapsed_ms']) && is_int($first['request_elapsed_ms']), 'request timing includes the phase before SSE');
timingExpect($one->event('first_delta')['request_elapsed_ms'] >= $first['request_elapsed_ms'], 'full request time remains monotonic across preparation and first text');
timingExpect($one->event('prepare', ['compaction_cache_hit' => true])['compaction_cache_hit'] === true, 'cache hit is safe boolean telemetry');
// Exercise a buffered web-style channel: timing must reach disk before HTTP end/exit.
$app = new \think\App(dirname(__DIR__) . '/');
$directory = sys_get_temp_dir() . '/zyt-ai-timing-' . bin2hex(random_bytes(8));
$app->config->set(['default' => 'timing', 'channels' => ['timing' => [
'type' => 'File', 'path' => $directory, 'single' => 'timing', 'realtime_write' => false,
]]], 'log');
$logger = $app->make('log');
$channel = $logger->channel('timing');
(new ReflectionProperty(\think\log\Channel::class, 'lazy'))->setValue($channel, true);
$logger->info('buffered control');
$logFile = $directory . '/timing.log';
timingExpect(!is_file($logFile), 'control channel really buffers before the SSE timing write');
$one->log('first_delta', ['duration_ms' => 123, 'api_key' => 'must-not-be-logged']);
timingExpect(is_file($logFile), 'SSE timing persists immediately without HTTP-end save');
$logged = file_get_contents($logFile);
timingExpect(str_contains($logged, $one->id()) && !str_contains($logged, 'must-not-be-logged'), 'persisted timing remains patient and credential free');
unlink($logFile);
rmdir($directory);
$controller = file_get_contents(dirname(__DIR__) . '/app/adminapi/controller/tcm/DiagnosisController.php');
$logic = file_get_contents(dirname(__DIR__) . '/app/adminapi/logic/tcm/DiagnosisAiLogic.php');
timingExpect(is_string($controller) && is_string($logic), 'instrumented source is readable');
timingExpect(str_contains($controller, "log('first_delta'") && str_contains($controller, "log('sse_done'"), 'SSE first delta and completion are timed');
timingExpect(str_contains($logic, "log('prepare'") && str_contains($logic, "log('upstream_done'"), 'prepare and upstream are timed');
timingExpect(str_contains($logic, 'compaction_attempted') && str_contains($logic, 'retry_attempted'), 'compression and compatibility retry are recorded');
timingExpect(str_contains($controller, "'trace_id' => \$timing->id()"), 'SSE start exposes only the random trace id for timing correlation');
echo "Diagnosis AI assistant timing: OK\n";