A logging

This commit is contained in:
Fabian @ Blax Software 2026-01-20 18:17:02 +01:00
parent 79afcdeb93
commit 71e0d44e30
2 changed files with 96 additions and 4 deletions

View File

@ -33,21 +33,35 @@ class RestartServer extends Command
*/ */
public function handle() public function handle()
{ {
\Log::channel('websocket')->debug('websockets:restart command started', [
'cache_driver' => $this->option('cache-driver'),
'soft' => $this->option('soft'),
]);
\Log::channel('websocket')->info('WebSocket restart server command called ...'); \Log::channel('websocket')->info('WebSocket restart server command called ...');
config(['cache.default' => $this->option('cache-driver', 'file')]); config(['cache.default' => $this->option('cache-driver', 'file')]);
\Log::channel('websocket')->debug('Cache driver configured', ['driver' => $this->option('cache-driver', 'file')]);
$restartData = [
'time' => $this->currentTime(),
'soft' => $this->option('soft'),
];
\Log::channel('websocket')->debug('Storing restart signal in cache', $restartData);
Cache::forever( Cache::forever(
'blax:websockets:restart', 'blax:websockets:restart',
[ $restartData
'time' => $this->currentTime(),
'soft' => $this->option('soft'),
]
); );
\Log::channel('websocket')->debug('Restart signal stored successfully');
$shutdownType = $this->option('soft') ? 'soft' : 'hard'; $shutdownType = $this->option('soft') ? 'soft' : 'hard';
$this->info( $this->info(
"Broadcasted the {$shutdownType} restart signal to the WebSocket server!" "Broadcasted the {$shutdownType} restart signal to the WebSocket server!"
); );
\Log::channel('websocket')->info('Restart signal broadcasted', ['shutdown_type' => $shutdownType]);
} }
} }

View File

@ -91,6 +91,16 @@ class StartServer extends Command
public function handle() public function handle()
{ {
try { try {
\Log::channel('websocket')->debug('websockets:serve command started', [
'pid' => getmypid(),
'host' => $this->option('host'),
'port' => $this->option('port'),
'cache_driver' => $this->option('cache-driver'),
'disable_statistics' => $this->option('disable-statistics'),
'debug' => $this->option('debug'),
'soft' => $this->option('soft'),
]);
$this->components->info('Handling websocket server with pid ' . getmypid() . '...'); $this->components->info('Handling websocket server with pid ' . getmypid() . '...');
// For is_fork() helper // For is_fork() helper
@ -105,27 +115,43 @@ class StartServer extends Command
// Fixes redis concurrency issues // Fixes redis concurrency issues
config(['cache.default' => $this->option('cache-driver', 'file')]); config(['cache.default' => $this->option('cache-driver', 'file')]);
\Log::channel('websocket')->debug('Cache driver configured', ['driver' => $this->option('cache-driver', 'file')]);
WebsocketService::resetAllTracking(); WebsocketService::resetAllTracking();
\Log::channel('websocket')->debug('WebsocketService tracking reset');
$this->laravel->singleton(LoopInterface::class, function () { $this->laravel->singleton(LoopInterface::class, function () {
return $this->loop; return $this->loop;
}); });
\Log::channel('websocket')->debug('LoopInterface singleton registered');
\Log::channel('websocket')->debug('Configuring loggers...');
$this->configureLoggers(); $this->configureLoggers();
\Log::channel('websocket')->debug('Loggers configured');
\Log::channel('websocket')->debug('Configuring managers...');
$this->configureManagers(); $this->configureManagers();
\Log::channel('websocket')->debug('Managers configured');
\Log::channel('websocket')->debug('Configuring statistics...');
$this->configureStatistics(); $this->configureStatistics();
\Log::channel('websocket')->debug('Statistics configured');
\Log::channel('websocket')->debug('Configuring restart timer...');
$this->configureRestartTimer(); $this->configureRestartTimer();
\Log::channel('websocket')->debug('Restart timer configured');
\Log::channel('websocket')->debug('Configuring routes...');
$this->configureRoutes(); $this->configureRoutes();
\Log::channel('websocket')->debug('Routes configured');
\Log::channel('websocket')->debug('Configuring PCNTL signals...');
$this->configurePcntlSignal(); $this->configurePcntlSignal();
\Log::channel('websocket')->debug('PCNTL signals configured');
// $this->configurePongTracker(); // $this->configurePongTracker();
\Log::channel('websocket')->debug('Starting server...');
$this->startServer(); $this->startServer();
} catch (\Throwable $e) { } catch (\Throwable $e) {
$this->error('Error starting the WebSocket server: ' . $e->getMessage()); $this->error('Error starting the WebSocket server: ' . $e->getMessage());
@ -148,8 +174,11 @@ class StartServer extends Command
*/ */
protected function configureLoggers() protected function configureLoggers()
{ {
\Log::channel('websocket')->debug('Configuring HTTP logger...');
$this->configureHttpLogger(); $this->configureHttpLogger();
\Log::channel('websocket')->debug('Configuring message logger...');
$this->configureMessageLogger(); $this->configureMessageLogger();
\Log::channel('websocket')->debug('Configuring connection logger...');
$this->configureConnectionLogger(); $this->configureConnectionLogger();
} }
@ -167,6 +196,11 @@ class StartServer extends Command
$class = $config['replication']['modes'][$mode]['channel_manager']; $class = $config['replication']['modes'][$mode]['channel_manager'];
\Log::channel('websocket')->debug('Creating ChannelManager', [
'mode' => $mode,
'class' => $class,
]);
return new $class($this->loop); return new $class($this->loop);
}); });
} }
@ -182,11 +216,18 @@ class StartServer extends Command
if (! $this->option('disable-statistics')) { if (! $this->option('disable-statistics')) {
$intervalInSeconds = $this->option('statistics-interval') ?: config('websockets.statistics.interval_in_seconds', 3600); $intervalInSeconds = $this->option('statistics-interval') ?: config('websockets.statistics.interval_in_seconds', 3600);
\Log::channel('websocket')->debug('Statistics enabled', [
'interval_seconds' => $intervalInSeconds,
]);
$this->loop->addPeriodicTimer($intervalInSeconds, function () { $this->loop->addPeriodicTimer($intervalInSeconds, function () {
\Log::channel('websocket')->debug('Statistics timer tick, saving...');
$this->line('Saving statistics...', null, OutputInterface::VERBOSITY_VERBOSE); $this->line('Saving statistics...', null, OutputInterface::VERBOSITY_VERBOSE);
StatisticsCollectorFacade::save(); StatisticsCollectorFacade::save();
}); });
} else {
\Log::channel('websocket')->debug('Statistics disabled');
} }
} }
@ -200,10 +241,19 @@ class StartServer extends Command
$restartData = $this->getLastRestartData(); $restartData = $this->getLastRestartData();
$this->lastRestart = $restartData['time'] ?? null; $this->lastRestart = $restartData['time'] ?? null;
\Log::channel('websocket')->debug('Restart timer configured', [
'initial_restart_time' => $this->lastRestart,
]);
$this->loop->addPeriodicTimer(10, function () { $this->loop->addPeriodicTimer(10, function () {
$restartData = $this->getLastRestartData(); $restartData = $this->getLastRestartData();
$currentRestart = $restartData['time'] ?? null; $currentRestart = $restartData['time'] ?? null;
\Log::channel('websocket')->debug('Restart timer tick', [
'last_restart' => $this->lastRestart,
'current_restart' => $currentRestart,
]);
// Only trigger restart if lastRestart was set and a new restart signal was received // Only trigger restart if lastRestart was set and a new restart signal was received
if ($this->lastRestart !== null && $currentRestart !== null && $currentRestart !== $this->lastRestart) { if ($this->lastRestart !== null && $currentRestart !== null && $currentRestart !== $this->lastRestart) {
$this->restartSoftShutdown = $restartData['soft'] ?? false; $this->restartSoftShutdown = $restartData['soft'] ?? false;
@ -229,7 +279,9 @@ class StartServer extends Command
*/ */
protected function configureRoutes() protected function configureRoutes()
{ {
\Log::channel('websocket')->debug('Registering WebSocket routes...');
WebSocketRouter::registerRoutes(); WebSocketRouter::registerRoutes();
\Log::channel('websocket')->debug('WebSocket routes registered');
} }
/** /**
@ -245,15 +297,19 @@ class StartServer extends Command
// then stopping the loop. // then stopping the loop.
if (! extension_loaded('pcntl')) { if (! extension_loaded('pcntl')) {
\Log::channel('websocket')->error('pcntl extension not loaded');
throw new \RuntimeException('The pcntl extension is required to handle concurrency.'); throw new \RuntimeException('The pcntl extension is required to handle concurrency.');
} }
\Log::channel('websocket')->debug('pcntl extension loaded, registering signal handlers...');
$this->loop->addSignal(SIGTERM, function () { $this->loop->addSignal(SIGTERM, function () {
\Log::channel('websocket')->info('Received SIGTERM, shutting down...'); \Log::channel('websocket')->info('Received SIGTERM, shutting down...');
$this->line('Shutting down server...'); $this->line('Shutting down server...');
$this->triggerShutdown(); $this->triggerShutdown();
}); });
\Log::channel('websocket')->debug('SIGTERM handler registered');
$this->loop->addSignal(SIGINT, function () { $this->loop->addSignal(SIGINT, function () {
\Log::channel('websocket')->info('Received SIGINT, shutting down...'); \Log::channel('websocket')->info('Received SIGINT, shutting down...');
@ -261,6 +317,7 @@ class StartServer extends Command
$this->triggerShutdown(); $this->triggerShutdown();
}); });
\Log::channel('websocket')->debug('SIGINT handler registered');
} }
/** /**
@ -336,9 +393,12 @@ class StartServer extends Command
$this->comment(' <fg=yellow;options=bold>Press Ctrl+C to stop the server</>'); $this->comment(' <fg=yellow;options=bold>Press Ctrl+C to stop the server</>');
$this->newLine(); $this->newLine();
\Log::channel('websocket')->debug('Building server instance...');
$this->buildServer(); $this->buildServer();
\Log::channel('websocket')->debug('Server instance built, starting event loop...');
$this->server->run(); $this->server->run();
\Log::channel('websocket')->debug('Event loop stopped, server shutdown complete');
} }
/** /**
@ -348,20 +408,29 @@ class StartServer extends Command
*/ */
protected function buildServer() protected function buildServer()
{ {
\Log::channel('websocket')->debug('Creating ServerFactory...', [
'host' => $this->option('host'),
'port' => $this->option('port'),
]);
$this->server = new ServerFactory( $this->server = new ServerFactory(
$this->option('host'), $this->option('host'),
$this->option('port') $this->option('port')
); );
if ($loop = $this->option('loop')) { if ($loop = $this->option('loop')) {
\Log::channel('websocket')->debug('Using injected loop');
$this->loop = $loop; $this->loop = $loop;
} }
\Log::channel('websocket')->debug('Configuring server with loop and routes...');
$this->server = $this->server $this->server = $this->server
->setLoop($this->loop) ->setLoop($this->loop)
->withRoutes(WebSocketRouter::getRoutes()) ->withRoutes(WebSocketRouter::getRoutes())
->setConsoleOutput($this->output) ->setConsoleOutput($this->output)
->createServer(); ->createServer();
\Log::channel('websocket')->debug('Server created and ready');
} }
/** /**
@ -391,6 +460,11 @@ class StartServer extends Command
// Check restart signal's soft flag first, then fall back to command option // Check restart signal's soft flag first, then fall back to command option
$useSoftShutdown = $fromRestart ? $this->restartSoftShutdown : $this->option('soft'); $useSoftShutdown = $fromRestart ? $this->restartSoftShutdown : $this->option('soft');
\Log::channel('websocket')->debug('Triggering shutdown', [
'from_restart' => $fromRestart,
'use_soft_shutdown' => $useSoftShutdown,
]);
if ($useSoftShutdown) { if ($useSoftShutdown) {
$this->triggerSoftShutdown(); $this->triggerSoftShutdown();
} else { } else {
@ -426,12 +500,15 @@ class StartServer extends Command
$channelManager = $this->laravel->make(ChannelManager::class); $channelManager = $this->laravel->make(ChannelManager::class);
// Close the new connections allowance on this server. // Close the new connections allowance on this server.
\Log::channel('websocket')->debug('Declining new connections...');
$channelManager->declineNewConnections(); $channelManager->declineNewConnections();
// Get all local connections and close them. They will // Get all local connections and close them. They will
// be automatically be unsubscribed from all channels. // be automatically be unsubscribed from all channels.
\Log::channel('websocket')->debug('Getting local connections to close...');
$channelManager->getLocalConnections() $channelManager->getLocalConnections()
->then(function ($connections) { ->then(function ($connections) {
\Log::channel('websocket')->debug('Closing connections...', ['count' => count($connections)]);
return all(collect($connections)->map(function ($connection) { return all(collect($connections)->map(function ($connection) {
return app('websockets.handler') return app('websockets.handler')
->onClose($connection) ->onClose($connection)
@ -441,6 +518,7 @@ class StartServer extends Command
})->toArray()); })->toArray());
}) })
->then(function () { ->then(function () {
\Log::channel('websocket')->debug('All connections closed, stopping loop...');
$this->loop->stop(); $this->loop->stop();
}); });
} }