diff --git a/libs/core/di/src/service-application.ts b/libs/core/di/src/service-application.ts index 01eef56..ef42bac 100644 --- a/libs/core/di/src/service-application.ts +++ b/libs/core/di/src/service-application.ts @@ -3,15 +3,15 @@ * Encapsulates common patterns for Hono-based microservices */ -import type { AwilixContainer } from 'awilix'; -import { Hono } from 'hono'; -import { cors } from 'hono/cors'; import type { BaseAppConfig, UnifiedAppConfig } from '@stock-bot/config'; import { toUnifiedConfig } from '@stock-bot/config'; import type { HandlerRegistry } from '@stock-bot/handler-registry'; import { getLogger, setLoggerConfig, shutdownLoggers, type Logger } from '@stock-bot/logger'; import { Shutdown, SHUTDOWN_DEFAULTS } from '@stock-bot/shutdown'; import type { IServiceContainer } from '@stock-bot/types'; +import type { AwilixContainer } from 'awilix'; +import { Hono } from 'hono'; +import { cors } from 'hono/cors'; import type { ServiceDefinitions } from './container/types'; /** @@ -164,19 +164,30 @@ export class ServiceApplication { * Register graceful shutdown handlers */ private registerShutdownHandlers(): void { + this.logger.info('Registering shutdown handlers', { + service: this.serviceConfig.serviceName, + scheduledJobs: this.serviceConfig.enableScheduledJobs, + timeout: this.serviceConfig.shutdownTimeout + }); + // Priority 1: Queue system (highest priority) if (this.serviceConfig.enableScheduledJobs) { this.shutdown.onShutdown( async () => { this.logger.info('Shutting down queue system...'); + const startTime = Date.now(); try { const queueManager = this.container?.resolve('queueManager'); if (queueManager) { await queueManager.shutdown(); + const duration = Date.now() - startTime; + this.logger.info('Queue system shut down successfully', { duration }); + } else { + this.logger.warn('No queue manager found to shut down'); } - this.logger.info('Queue system shut down'); } catch (error) { - this.logger.error('Error shutting down queue system', { error }); + const duration = Date.now() - startTime; + this.logger.error('Error shutting down queue system', { error, duration }); } }, SHUTDOWN_DEFAULTS.HIGH_PRIORITY, @@ -189,12 +200,17 @@ export class ServiceApplication { async () => { if (this.server) { this.logger.info('Stopping HTTP server...'); + const startTime = Date.now(); try { this.server.stop(); - this.logger.info('HTTP server stopped'); + const duration = Date.now() - startTime; + this.logger.info('HTTP server stopped successfully', { duration }); } catch (error) { - this.logger.error('Error stopping HTTP server', { error }); + const duration = Date.now() - startTime; + this.logger.error('Error stopping HTTP server', { error, duration }); } + } else { + this.logger.warn('No HTTP server to stop'); } }, SHUTDOWN_DEFAULTS.HIGH_PRIORITY, @@ -220,28 +236,62 @@ export class ServiceApplication { this.shutdown.onShutdown( async () => { this.logger.info('Disposing services and connections...'); + const startTime = Date.now(); + const disposed: string[] = []; + const failed: string[] = []; + try { if (this.container) { // Disconnect database clients const mongoClient = this.container.resolve('mongoClient'); if (mongoClient?.disconnect) { - await mongoClient.disconnect(); + try { + const mongoStart = Date.now(); + await mongoClient.disconnect(); + disposed.push(`MongoDB (${Date.now() - mongoStart}ms)`); + } catch (error) { + this.logger.error('Failed to disconnect MongoDB', { error }); + failed.push('MongoDB'); + } } const postgresClient = this.container.resolve('postgresClient'); if (postgresClient?.disconnect) { - await postgresClient.disconnect(); + try { + const pgStart = Date.now(); + await postgresClient.disconnect(); + disposed.push(`PostgreSQL (${Date.now() - pgStart}ms)`); + } catch (error) { + this.logger.error('Failed to disconnect PostgreSQL', { error }); + failed.push('PostgreSQL'); + } } const questdbClient = this.container.resolve('questdbClient'); if (questdbClient?.disconnect) { - await questdbClient.disconnect(); + try { + const questStart = Date.now(); + await questdbClient.disconnect(); + disposed.push(`QuestDB (${Date.now() - questStart}ms)`); + } catch (error) { + this.logger.error('Failed to disconnect QuestDB', { error }); + failed.push('QuestDB'); + } } - this.logger.info('All services disposed successfully'); + const duration = Date.now() - startTime; + this.logger.info('Service disposal completed', { + duration, + disposed, + failed, + success: failed.length === 0 + }); + } else { + this.logger.warn('No container available for service disposal'); } } catch (error) { - this.logger.error('Error disposing services', { error }); + const duration = Date.now() - startTime; + this.logger.error('Error disposing services', { error, duration, disposed, failed }); } }, SHUTDOWN_DEFAULTS.MEDIUM_PRIORITY, @@ -253,15 +303,23 @@ export class ServiceApplication { async () => { try { this.logger.info('Shutting down loggers...'); + // const startTime = Date.now(); await shutdownLoggers(); - // Don't log after shutdown - } catch { - // Silently ignore logger shutdown errors + // Log one final message before shutdown + // console.log(`[${new Date().toISOString()}] Loggers shut down successfully (${Date.now() - startTime}ms)`); + } catch (error) { + // Use console.error since logger might be partially shut down + console.error(`[${new Date().toISOString()}] Error shutting down loggers:`, error); } }, SHUTDOWN_DEFAULTS.LOW_PRIORITY, 'Loggers' ); + + this.logger.info('All shutdown handlers registered', { + service: this.serviceConfig.serviceName, + handlerCount: 3 + (this.serviceConfig.enableScheduledJobs ? 1 : 0) + (this.hooks.onBeforeShutdown ? 1 : 0) + }); } /** diff --git a/libs/core/shutdown/src/shutdown.ts b/libs/core/shutdown/src/shutdown.ts index f2b4cc2..66ce1e9 100644 --- a/libs/core/shutdown/src/shutdown.ts +++ b/libs/core/shutdown/src/shutdown.ts @@ -15,10 +15,13 @@ export class Shutdown { private shutdownTimeout: number; private callbacks: CallbackEntry[] = []; private signalHandlersRegistered = false; + private shutdownPromise: Promise | null = null; + private triggerSignal: string | null = null; constructor(options: ShutdownOptions = {}) { this.shutdownTimeout = options.timeout || SHUTDOWN_DEFAULTS.TIMEOUT; if (options.autoRegister !== false) { + // Register signal handlers immediately in constructor this.setupSignalHandlers(); } } @@ -30,6 +33,17 @@ export class Shutdown { return Shutdown.instance; } + /** + * Get current shutdown status + */ + getStatus(): { isShuttingDown: boolean; signal: string | null; callbackCount: number } { + return { + isShuttingDown: this.isShuttingDown, + signal: this.triggerSignal, + callbackCount: this.callbacks.length + }; + } + /** * Register a cleanup callback */ @@ -47,13 +61,42 @@ export class Shutdown { /** * Initiate graceful shutdown */ - async shutdown(): Promise { + async shutdown(signal?: string): Promise { + // If already shutting down, return the existing promise + if (this.shutdownPromise) { + this.logger.warn('Shutdown already in progress, ignoring additional request', { + originalSignal: this.triggerSignal, + newSignal: signal + }); + return this.shutdownPromise; + } + if (this.isShuttingDown) { - return; + this.logger.warn('Shutdown flag already set but no promise, creating new shutdown'); } this.isShuttingDown = true; + this.triggerSignal = signal || 'manual'; + + this.logger.info('Starting graceful shutdown', { + signal: this.triggerSignal, + timeout: this.shutdownTimeout, + callbackCount: this.callbacks.length + }); + // Create and store the shutdown promise + this.shutdownPromise = this.performShutdown(); + + try { + await this.shutdownPromise; + this.logger.info('Graceful shutdown completed successfully'); + } catch (error) { + this.logger.error('Shutdown failed', { error, signal: this.triggerSignal }); + throw error; + } + } + + private async performShutdown(): Promise { const timeout = new Promise((_, reject) => setTimeout(() => reject(new Error('Shutdown timeout')), this.shutdownTimeout) ); @@ -61,43 +104,86 @@ export class Shutdown { try { await Promise.race([this.executeCallbacks(), timeout]); } catch (error) { - this.logger.error('Shutdown failed', error); throw error; } } private async executeCallbacks(): Promise { const sorted = [...this.callbacks].sort((a, b) => a.priority - b.priority); + + this.logger.debug('Executing shutdown callbacks', { + count: sorted.length, + callbacks: sorted.map(c => ({ name: c.name || 'unnamed', priority: c.priority })) + }); - for (const { callback, name } of sorted) { + let completed = 0; + let failed = 0; + + for (const { callback, name, priority } of sorted) { + const callbackName = name || 'unnamed'; try { + this.logger.debug(`Starting shutdown callback: ${callbackName}`, { priority }); + const startTime = Date.now(); + await callback(); + + const duration = Date.now() - startTime; + completed++; + this.logger.debug(`Completed shutdown callback: ${callbackName}`, { duration, priority }); } catch (error) { - this.logger.error(`Shutdown callback failed: ${name || 'unnamed'}`, error); + failed++; + this.logger.error(`Shutdown callback failed: ${callbackName}`, { error, priority }); } } + + this.logger.info('Shutdown callbacks execution completed', { + total: sorted.length, + completed, + failed + }); } private setupSignalHandlers(): void { if (this.signalHandlersRegistered) { + this.logger.debug('Signal handlers already registered'); return; } const signals: NodeJS.Signals[] = ['SIGTERM', 'SIGINT']; signals.forEach(signal => { - process.once(signal, async () => { - if (!this.isShuttingDown) { - try { - await this.shutdown(); - process.exit(0); - } catch { - process.exit(1); - } + // Use process.on instead of process.once to handle multiple signals + process.on(signal, async () => { + this.logger.info(`Received ${signal} signal`); + + // If already shutting down, ignore the signal + if (this.isShuttingDown || this.shutdownPromise) { + this.logger.info(`Already shutting down, ignoring ${signal}`); + return; + } + + try { + await this.shutdown(signal); + + // Add small delay to ensure logs are flushed + await new Promise(resolve => setTimeout(resolve, 100)); + + this.logger.info('Exiting process with code 0'); + process.exit(0); + } catch (error) { + this.logger.error('Shutdown error, exiting with code 1', { error }); + + // Add small delay to ensure error logs are flushed + await new Promise(resolve => setTimeout(resolve, 100)); + + process.exit(1); } }); + + this.logger.debug(`Registered handler for ${signal}`); }); this.signalHandlersRegistered = true; + this.logger.info('Signal handlers registered for graceful shutdown', { signals }); } }