Skip to content

Commit 2c65948

Browse files
detaindetain
committed
Removed redundant hardware acceleration probing calls and fixed Application.php to use container singleton for FfmpegRunner
1 parent bfc5c2f commit 2c65948

12 files changed

Lines changed: 460 additions & 51 deletions

File tree

‎public/index.php‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -107,6 +107,8 @@
107107
* - Body content
108108
*/
109109
$request = Request::fromGlobals();
110+
$requestUid = substr(md5((string)($request->userId ?? '') . $request->path . (string)microtime(true)), 0, 16);
111+
error_log('[DEBUG] ' . date('Y-m-d H:i:s.v') . ' public/index.php START ' . $request->method . ' ' . $request->path . ' [uid=' . $requestUid . '] [userId=' . ($request->userId ?? 'anonymous') . ']');
110112

111113
/**
112114
* C6/B4: Shared request authentication.
@@ -187,8 +189,10 @@
187189
AdminRoutes::register($router, $container);
188190

189191
if (str_starts_with($path, '/api/v1/admin/')) {
192+
error_log('[DEBUG] ' . date('Y-m-d H:i:s.v') . ' public/index.php dispatching admin route [uid=' . $requestUid . ']');
190193
/** @var \Phlix\Server\Http\Response $response */
191194
$response = $router->dispatch($request);
195+
error_log('[DEBUG] ' . date('Y-m-d H:i:s.v') . ' public/index.php admin route completed [uid=' . $requestUid . '] [status=' . $response->statusCode . ']');
192196
$cors->decorate($request, $response)->send();
193197
} elseif (str_starts_with($path, '/api/')) {
194198
/**
@@ -210,7 +214,9 @@
210214
*/
211215
/** @var WebPortalRouter $webPortalRouter */
212216
$webPortalRouter = $container->get(WebPortalRouter::class);
217+
error_log('[DEBUG] ' . date('Y-m-d H:i:s.v') . ' public/index.php dispatching WebPortalRouter [uid=' . $requestUid . ']');
213218
$response = $webPortalRouter->dispatch($request);
219+
error_log('[DEBUG] ' . date('Y-m-d H:i:s.v') . ' public/index.php WebPortalRouter completed [uid=' . $requestUid . '] [status=' . $response->statusCode . ']');
214220
$cors->decorate($request, $response)->send();
215221
} else {
216222
/**

‎src/Common/Database/ConnectionPool.php‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -68,6 +68,8 @@ public static function getConnection(string $name = 'mysql'): Connection
6868
$passStr = is_scalar($password) ? (string)$password : '';
6969
$dbStr = is_scalar($database) ? (string)$database : '';
7070

71+
error_log("[DEBUG] " . date('Y-m-d H:i:s.v') . " ConnectionPool::getConnection Creating NEW connection [name={$name}] [host={$hostStr}] [pool_enabled=" . ($poolEnabled ? 'true' : 'false') . "]");
72+
7173
if ($poolEnabled) {
7274
// Coroutine connection pool: each coroutine leases its own
7375
// connection for true intra-worker DB parallelism. OFF unless
@@ -82,6 +84,7 @@ public static function getConnection(string $name = 'mysql'): Connection
8284
$poolSize,
8385
$charset
8486
);
87+
error_log("[DEBUG] " . date('Y-m-d H:i:s.v') . " ConnectionPool::getConnection Created PooledMySQLConnection [name={$name}] [pool_size={$poolSize}]");
8588
} else {
8689
// Default: the single PhlixMySQLConnection subclass — re-keys
8790
// positional bind arrays (workerman/mysql v1.0.9 bindMore() bug
@@ -98,6 +101,7 @@ public static function getConnection(string $name = 'mysql'): Connection
98101
$dbStr,
99102
$charset
100103
);
104+
error_log("[DEBUG] " . date('Y-m-d H:i:s.v') . " ConnectionPool::getConnection Created PhlixMySQLConnection [name={$name}]");
101105
}
102106
}
103107
return self::$connections[$name];

‎src/Common/Debug/DebugLogger.php‎

Lines changed: 331 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,331 @@
1+
<?php
2+
3+
/**
4+
* Phlix media server component: Debug Logging.
5+
*
6+
* Provides consistent debug logging format for tracing slowdowns.
7+
* Format: [DEBUG] {timestamp} {location} Starting/Completed task: {task_name} in {duration}ms
8+
*
9+
* @copyright 2026 Joe Huss <detain@interserver.net>
10+
* @license MIT
11+
*/
12+
13+
declare(strict_types=1);
14+
15+
namespace Phlix\Common\Debug;
16+
17+
use Psr\Log\LoggerInterface;
18+
use Psr\Log\NullLogger;
19+
20+
/**
21+
* Debug logging utility for tracing task execution and diagnosing slowdowns.
22+
*
23+
* Provides consistent debug logging format:
24+
* - [DEBUG] {timestamp} {location} Starting task: {task_name}
25+
* - [DEBUG] {timestamp} {location} Completed task: {task_name} in {duration}ms
26+
*
27+
* Usage:
28+
* ```php
29+
* $debug = DebugLogger::create('MyService');
30+
* $debug->start('process_item');
31+
* // ... work ...
32+
* $debug->end('process_item');
33+
* ```
34+
*/
35+
class DebugLogger
36+
{
37+
/** @var LoggerInterface Logger instance */
38+
private LoggerInterface $logger;
39+
40+
/** @var string Location identifier (e.g., class name or file) */
41+
private string $location;
42+
43+
/** @var array<string, float> Start times for active tasks */
44+
private array $taskStarts = [];
45+
46+
/** @var array<string, int> Task execution counts */
47+
private array $taskCounts = [];
48+
49+
/** @var array<string, float> Task durations for last N executions */
50+
private array $recentDurations = [];
51+
52+
/** @var int Maximum recent durations to track per task */
53+
private const MAX_RECENT_DURATIONS = 10;
54+
55+
/**
56+
* @param LoggerInterface $logger Logger instance
57+
* @param string $location Location identifier
58+
*/
59+
public function __construct(LoggerInterface $logger, string $location)
60+
{
61+
$this->logger = $logger;
62+
$this->location = $location;
63+
}
64+
65+
/**
66+
* Create a DebugLogger instance.
67+
*
68+
* @param string $location Location identifier
69+
* @param LoggerInterface|null $logger Logger instance (optional, uses NullLogger if not provided)
70+
* @return self
71+
*/
72+
public static function create(string $location, ?LoggerInterface $logger = null): self
73+
{
74+
return new self($logger ?? new NullLogger(), $location);
75+
}
76+
77+
/**
78+
* Start timing a task.
79+
*
80+
* @param string $taskName Name of the task
81+
* @param array<string, mixed> $context Additional context
82+
* @return void
83+
*/
84+
public function start(string $taskName, array $context = []): void
85+
{
86+
$taskId = $this->getTaskId($taskName);
87+
$this->taskStarts[$taskId] = hrtime(true);
88+
$this->taskCounts[$taskId] = ($this->taskCounts[$taskId] ?? 0) + 1;
89+
90+
$this->log('info', "Starting task: {$taskName}", array_merge(
91+
['task' => $taskName, 'uid' => $this->generateUid()],
92+
$context
93+
));
94+
}
95+
96+
/**
97+
* End timing a task and log completion.
98+
*
99+
* @param string $taskName Name of the task
100+
* @param array<string, mixed> $context Additional context
101+
* @return float Duration in milliseconds
102+
*/
103+
public function end(string $taskName, array $context = []): float
104+
{
105+
$taskId = $this->getTaskId($taskName);
106+
$startTime = $this->taskStarts[$taskId] ?? null;
107+
108+
if ($startTime === null) {
109+
$this->logger->warning("[DEBUG] {$this->timestamp()} {$this->location} end() called for unknown task: {$taskName}");
110+
return 0.0;
111+
}
112+
113+
$durationMs = (hrtime(true) - $startTime) / 1_000_000.0;
114+
unset($this->taskStarts[$taskId]);
115+
116+
// Track recent durations for this task
117+
if (!isset($this->recentDurations[$taskId])) {
118+
$this->recentDurations[$taskId] = [];
119+
}
120+
$this->recentDurations[$taskId][] = $durationMs;
121+
if (count($this->recentDurations[$taskId]) > self::MAX_RECENT_DURATIONS) {
122+
array_shift($this->recentDurations[$taskId]);
123+
}
124+
125+
$this->log('info', "Completed task: {$taskName} in " . round($durationMs, 2) . "ms", array_merge(
126+
[
127+
'task' => $taskName,
128+
'duration_ms' => round($durationMs, 2),
129+
'count' => $this->taskCounts[$taskId] ?? 0,
130+
'avg_recent_ms' => $this->getAverageRecentDuration($taskId),
131+
],
132+
$context
133+
));
134+
135+
return $durationMs;
136+
}
137+
138+
/**
139+
* Log a debug message at the start of a loop iteration.
140+
*
141+
* @param string $loopName Name of the loop
142+
* @param int $index Current iteration index
143+
* @param int $total Total iterations
144+
* @param array<string, mixed> $context Additional context
145+
* @return void
146+
*/
147+
public function loopProgress(string $loopName, int $index, int $total, array $context = []): void
148+
{
149+
$this->log('debug', "Loop progress: {$loopName} ({$index}/{$total})", array_merge(
150+
[
151+
'loop' => $loopName,
152+
'index' => $index,
153+
'total' => $total,
154+
'percent' => $total > 0 ? round(($index / $total) * 100, 1) : 0,
155+
],
156+
$context
157+
));
158+
}
159+
160+
/**
161+
* Log the start of a batch operation.
162+
*
163+
* @param string $batchName Name of the batch
164+
* @param int $count Number of items in batch
165+
* @param array<string, mixed> $context Additional context
166+
* @return void
167+
*/
168+
public function startBatch(string $batchName, int $count, array $context = []): void
169+
{
170+
$this->log('info', "Starting batch: {$batchName} ({$count} items)", array_merge(
171+
[
172+
'batch' => $batchName,
173+
'count' => $count,
174+
],
175+
$context
176+
));
177+
}
178+
179+
/**
180+
* Log the completion of a batch operation.
181+
*
182+
* @param string $batchName Name of the batch
183+
* @param float $durationMs Duration in milliseconds
184+
* @param array<string, mixed> $context Additional context
185+
* @return void
186+
*/
187+
public function endBatch(string $batchName, float $durationMs, array $context = []): void
188+
{
189+
$this->log('info', "Completed batch: {$batchName} in " . round($durationMs, 2) . "ms", array_merge(
190+
[
191+
'batch' => $batchName,
192+
'duration_ms' => round($durationMs, 2),
193+
'items_per_sec' => $durationMs > 0 ? round(($context['count'] ?? 0) / ($durationMs / 1000.0), 1) : 0,
194+
],
195+
$context
196+
));
197+
}
198+
199+
/**
200+
* Log an error during task execution.
201+
*
202+
* @param string $taskName Name of the task
203+
* @param string $error Error message
204+
* @param array<string, mixed> $context Additional context
205+
* @return void
206+
*/
207+
public function error(string $taskName, string $error, array $context = []): void
208+
{
209+
$taskId = $this->getTaskId($taskName);
210+
unset($this->taskStarts[$taskId]);
211+
212+
$this->log('error', "Task error: {$taskName} - {$error}", array_merge(
213+
[
214+
'task' => $taskName,
215+
'error' => $error,
216+
'count' => $this->taskCounts[$taskId] ?? 0,
217+
],
218+
$context
219+
));
220+
}
221+
222+
/**
223+
* Log a memory usage snapshot.
224+
*
225+
* @param string $label Label for this snapshot
226+
* @param array<string, mixed> $context Additional context
227+
* @return void
228+
*/
229+
public function memorySnapshot(string $label, array $context = []): void
230+
{
231+
$memoryBytes = memory_get_usage(true);
232+
$peakBytes = memory_get_peak_usage(true);
233+
234+
$this->log('debug', "Memory snapshot: {$label}", array_merge(
235+
[
236+
'label' => $label,
237+
'memory_mb' => round($memoryBytes / 1024 / 1024, 2),
238+
'peak_mb' => round($peakBytes / 1024 / 1024, 2),
239+
],
240+
$context
241+
));
242+
}
243+
244+
/**
245+
* Get task statistics for a given task.
246+
*
247+
* @param string $taskName Name of the task
248+
* @return array{total_count: int, recent_avg_ms: float, recent_min_ms: float, recent_max_ms: float}
249+
*/
250+
public function getTaskStats(string $taskName): array
251+
{
252+
$taskId = $this->getTaskId($taskName);
253+
$durations = $this->recentDurations[$taskId] ?? [];
254+
255+
if (empty($durations)) {
256+
return [
257+
'total_count' => $this->taskCounts[$taskId] ?? 0,
258+
'recent_avg_ms' => 0.0,
259+
'recent_min_ms' => 0.0,
260+
'recent_max_ms' => 0.0,
261+
];
262+
}
263+
264+
return [
265+
'total_count' => $this->taskCounts[$taskId] ?? 0,
266+
'recent_avg_ms' => round(array_sum($durations) / count($durations), 2),
267+
'recent_min_ms' => round(min($durations), 2),
268+
'recent_max_ms' => round(max($durations), 2),
269+
];
270+
}
271+
272+
/**
273+
* Generate a unique ID for this task execution.
274+
*
275+
* @return string
276+
*/
277+
private function generateUid(): string
278+
{
279+
return sprintf('%08x-%04x', mt_rand(0, 0xffffffff), mt_rand(0, 0xffff));
280+
}
281+
282+
/**
283+
* Get current timestamp in ISO format.
284+
*
285+
* @return string
286+
*/
287+
private function timestamp(): string
288+
{
289+
return date('Y-m-d H:i:s.v');
290+
}
291+
292+
/**
293+
* Get task ID from task name.
294+
*
295+
* @param string $taskName
296+
* @return string
297+
*/
298+
private function getTaskId(string $taskName): string
299+
{
300+
return $taskName;
301+
}
302+
303+
/**
304+
* Get average duration from recent executions.
305+
*
306+
* @param string $taskId
307+
* @return float
308+
*/
309+
private function getAverageRecentDuration(string $taskId): float
310+
{
311+
$durations = $this->recentDurations[$taskId] ?? [];
312+
if (empty($durations)) {
313+
return 0.0;
314+
}
315+
return round(array_sum($durations) / count($durations), 2);
316+
}
317+
318+
/**
319+
* Log a message.
320+
*
321+
* @param string $level Log level
322+
* @param string $message Message
323+
* @param array<string, mixed> $context Context
324+
* @return void
325+
*/
326+
private function log(string $level, string $message, array $context = []): void
327+
{
328+
$logMessage = "[DEBUG] {$this->timestamp()} {$this->location} {$message}";
329+
$this->logger->log($level, $logMessage, $context);
330+
}
331+
}

0 commit comments

Comments
 (0)