mahdahar/gdc_cmod
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

debug: add timing info to identify bottlenecks in batch PDF generation

Browse Source 
Add millisecond timing for each step:
- Database check
- Report data fetching (ReportHelper)
- HTML template rendering
- Spooler API call
- Total time per accessnumber
This commit is contained in:
mahdahar 2026-03-11 08:56:53 +07:00
parent 0b569c58d9
commit eb7729478e
1 changed files with 17 additions and 5 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

22
script.php
View File

@ -103,15 +103,19 @@ $stats = [
// Process each accessnumber // Process each accessnumber
foreach ($accessnumbers as $index => $accessnumber) { foreach ($accessnumbers as $index => $accessnumber) {
$current = $index + 1; $current = $index + 1;
$startTime = microtime(true);
echo "[$current/$total] $accessnumber... "; echo "[$current/$total] $accessnumber... ";
flush(); flush();
try { try {
// Check if request exists and get language // Check if request exists and get language
$t1 = microtime(true);
$sql = "SELECT ACCESSNUMBER, ISVAL2, REPORT_LANG $sql = "SELECT ACCESSNUMBER, ISVAL2, REPORT_LANG
FROM GDC_CMOD.dbo.CM_REQUESTS FROM GDC_CMOD.dbo.CM_REQUESTS
WHERE ACCESSNUMBER = ?"; WHERE ACCESSNUMBER = ?";
$row = $db->query($sql, [$accessnumber])->getRowArray(); $row = $db->query($sql, [$accessnumber])->getRowArray();
$t2 = microtime(true);
echo "[DB check: " . round(($t2-$t1)*1000) . "ms] ";
if (!$row) { if (!$row) {
echo "SKIPPED (not found in CM_REQUESTS)\n"; echo "SKIPPED (not found in CM_REQUESTS)\n";
@ -138,24 +142,31 @@ foreach ($accessnumbers as $index => $accessnumber) {
$eng = (int) ($row['REPORT_LANG'] ?? 0); $eng = (int) ($row['REPORT_LANG'] ?? 0);
// Get report data // Get report data
$t3 = microtime(true);
$reportHelper = new \App\Libraries\ReportHelper($db); $reportHelper = new \App\Libraries\ReportHelper($db);
$data = $reportHelper->getReportData($accessnumber, $eng); $data = $reportHelper->getReportData($accessnumber, $eng);
$t4 = microtime(true);
echo "[Report data: " . round(($t4-$t3)*1000) . "ms] ";
flush();
$data['eng'] = $eng; $data['eng'] = $eng;
$data['accessnumber'] = $accessnumber; $data['accessnumber'] = $accessnumber;
$data['ispdf'] = 1; $data['ispdf'] = 1;
// Generate HTML // Generate HTML
echo "generating HTML... "; $t5 = microtime(true);
flush();
$html = view('report/template', $data); $html = view('report/template', $data);
$t6 = microtime(true);
echo "[HTML render: " . round(($t6-$t5)*1000) . "ms] ";
$filename = $accessnumber . ($eng == 1 ? '_eng' : '') . '.pdf'; $filename = $accessnumber . ($eng == 1 ? '_eng' : '') . '.pdf';
$collectionDate = $data['collectionDate'] ?? ''; $collectionDate = $data['collectionDate'] ?? '';
$hostnumber = $data['hostnumber'] ?? ''; $hostnumber = $data['hostnumber'] ?? '';
// Send to PDF spooler // Send to PDF spooler
echo "sending to spooler... "; $t7 = microtime(true);
flush();
$jobId = postToSpooler($html, $filename, $collectionDate, $accessnumber, $hostnumber); $jobId = postToSpooler($html, $filename, $collectionDate, $accessnumber, $hostnumber);
$t8 = microtime(true);
echo "[Spooler: " . round(($t8-$t7)*1000) . "ms] ";
// Log to AUDIT_REQUESTS // Log to AUDIT_REQUESTS
$sqlCheck = "SELECT COUNT(*) as cnt FROM GDC_CMOD.dbo.AUDIT_REQUESTS $sqlCheck = "SELECT COUNT(*) as cnt FROM GDC_CMOD.dbo.AUDIT_REQUESTS
@ -191,7 +202,8 @@ foreach ($accessnumbers as $index => $accessnumber) {
error_log("ORU file creation failed for $accessnumber: " . $e->getMessage()); error_log("ORU file creation failed for $accessnumber: " . $e->getMessage());
} }
echo "QUEUED (job: $jobId, lang: $stepStatus)\n"; $totalTime = round((microtime(true) - $startTime) * 1000);
echo "QUEUED (job: $jobId, lang: $stepStatus, total: {$totalTime}ms)\n";
$stats['success']++; $stats['success']++;
$stats['details'][] = [ $stats['details'][] = [
'accessnumber' => $accessnumber, 'accessnumber' => $accessnumber,