diff --git a/server/src/controllers/rest/playbooks/hook.ts b/server/src/controllers/rest/playbooks/hook.ts index dfd465c3..5c10afa8 100644 --- a/server/src/controllers/rest/playbooks/hook.ts +++ b/server/src/controllers/rest/playbooks/hook.ts @@ -22,12 +22,10 @@ export const addTaskStatus = async (req, res) => { }); if (isFinalStatus(status)) { if (ansibleTask.target && ansibleTask.target.length > 0) { - logger.warn('Removing temporary private key'); ansibleTask.target?.map((e) => sshPrivateKeyFileManager.removeAnsibleTemporaryPrivateKey(e, ident), ); } else { - logger.warn('Removing temporary private keys'); sshPrivateKeyFileManager.removeAllAnsibleExecTemporaryPrivateKeys(ident); } } diff --git a/server/src/core/events/EventManager.ts b/server/src/core/events/EventManager.ts index 855fa4b5..ba38e4c8 100644 --- a/server/src/core/events/EventManager.ts +++ b/server/src/core/events/EventManager.ts @@ -25,7 +25,7 @@ abstract class EventManager { protected constructor() { this.eventListeners = {}; - this.logger = log.child({ module: 'EventManager' }, { msgPrefix: '[EVENT-MANAGER] - ' }); + this.logger = log.child({ module: 'EventManager' }, { msgPrefix: '[EVENT_MANAGER] - ' }); } private initializeEventListener(event: string) { diff --git a/server/src/core/startup/index.ts b/server/src/core/startup/index.ts index c4f140c9..72b8a455 100644 --- a/server/src/core/startup/index.ts +++ b/server/src/core/startup/index.ts @@ -21,9 +21,9 @@ import { setAnsibleVersions } from '../system/ansible-versions'; class Startup { private logger = PinoLogger.child({ module: 'Startup' }, { msgPrefix: '[STARTUP] - ' }); - private static readonly MODULE_STARTUP = '[STARTUP]'; async init() { + this.logger.info(`Initializing...`); const schemeVersion = await this.initializeSchemeVersion(); await this.initializeModules(); if (this.isSchemeVersionDifferent(schemeVersion)) { @@ -33,8 +33,7 @@ class Startup { private async initializeSchemeVersion(): Promise { const schemeVersion = await getFromCache(SettingsKeys.GeneralSettingsKeys.SCHEME_VERSION); - this.logger.info(`initialization`); - this.logger.info(`${Startup.MODULE_STARTUP} - Scheme Version: ${schemeVersion}`); + this.logger.info(`initializeSchemeVersion - Saved scheme version: ${schemeVersion}`); return schemeVersion; } @@ -50,7 +49,7 @@ class Startup { } private async updateScheme() { - this.logger.warn(`Scheme version differed, starting writing updates`); + this.logger.warn(`updateScheme- Scheme version differed, starting applying updates...`); await PlaybookModel.syncIndexes(); await DeviceModel.syncIndexes(); await createADefaultLocalUserRepository(); diff --git a/server/src/data/cache/defaults/index.ts b/server/src/data/cache/defaults/index.ts index 2a363eae..cebb58a8 100644 --- a/server/src/data/cache/defaults/index.ts +++ b/server/src/data/cache/defaults/index.ts @@ -1,7 +1,9 @@ import { SettingsKeys } from 'ssm-shared-lib'; -import logger from '../../../logger'; +import pinoLogger from '../../../logger'; import { setToCache } from '../index'; +const logger = pinoLogger.child({ module: 'Cache' }, { msgPrefix: '[CACHE] - ' }); + const REDIS_DEFAULT_VALUES: { key: string; value: string; nx: boolean }[] = [ { key: SettingsKeys.GeneralSettingsKeys.SCHEME_VERSION, @@ -57,9 +59,7 @@ const REDIS_DEFAULT_VALUES: { key: string; value: string; nx: boolean }[] = [ async function initRedisValues(force?: boolean) { for (const value of REDIS_DEFAULT_VALUES) { - logger.info( - `[REDIS] - initRedisValues - Setting default configuration ${value.key} to ${value.value}`, - ); + logger.info(`initRedisValues - Setting default configuration ${value.key} to ${value.value}`); await setToCache(value.key, value.value, { NX: force ? false : value.nx, }); diff --git a/server/src/data/cache/index.ts b/server/src/data/cache/index.ts index 3822342f..d0f00244 100644 --- a/server/src/data/cache/index.ts +++ b/server/src/data/cache/index.ts @@ -6,18 +6,19 @@ let redisClient: RedisClientType; let isReady: boolean = false; export const dbURI = `redis://${redisConf.host}:${redisConf.port}`; -const childLogger = logger.child({ module: 'redis' }, { msgPrefix: '[REDIS] - ' }); +const childLogger = logger.child({ module: 'Cache' }, { msgPrefix: '[CACHE] - ' }); async function createRedisClient(): Promise { + logger.info(`createRedisClient - Connecting to ${dbURI}`); const redisClient = createClient({ url: dbURI, }); redisClient - .on('error', (err) => childLogger.error('Redis Client Error', err)) - .on('connect', () => childLogger.info('Successfully connected to Redis')) + .on('error', (err) => childLogger.error(`createRedisClient- Client error: ${err.message}`)) + .on('connect', () => childLogger.info('createRedisClient - Successfully connected to cache')) .on('ready', () => { isReady = true; - childLogger.info(' Redis ready'); + childLogger.info('createRedisClient - Cache ready'); }); await redisClient.connect(); diff --git a/server/src/data/database/index.ts b/server/src/data/database/index.ts index 6f38e804..b285c46e 100644 --- a/server/src/data/database/index.ts +++ b/server/src/data/database/index.ts @@ -1,8 +1,9 @@ import mongoose from 'mongoose'; import { db } from '../../config'; -import logger from '../../logger'; +import PinoLogger from '../../logger'; export const dbURI = `mongodb://${db.host}:${db.port}/${db.name}`; +const logger = PinoLogger.child({ module: 'Database' }, { msgPrefix: '[DATABASE] - ' }); async function connectMongoDb() { // Build the connection string @@ -15,7 +16,7 @@ async function connectMongoDb() { socketTimeoutMS: 45000, // Close sockets after 45 seconds of inactivity }; - logger.info('[DATABASE] MongoDB - Connecting to ' + dbURI); + logger.info(`connectMongoDb - Connecting to ${dbURI}`); function setRunValidators(this: any) { this.setOptions({ runValidators: true }); @@ -33,34 +34,34 @@ async function connectMongoDb() { }) .connect(dbURI, options) .then(() => { - logger.info('[DATABASE] Mongoose connection done'); + logger.info('connectMongoDb - Connection successful'); }) .catch((e) => { - logger.error('[DATABASE] Mongoose connection error'); + logger.error('connectMongoDb - Connection error'); logger.error(e); }); // CONNECTION EVENTS // When successfully connected mongoose.connection.on('connected', () => { - logger.debug('[DATABASE] Mongoose default connection open to ' + dbURI); + logger.debug(`Connection opened to ${dbURI}`); }); // If the connection throws an error mongoose.connection.on('error', (err) => { - logger.error('[DATABASE] Mongoose default connection error: ' + err); + logger.error('Connection error: ' + err); }); // When the connection is disconnected mongoose.connection.on('disconnected', () => { - logger.info('[DATABASE] Mongoose default connection disconnected'); + logger.info('Connection disconnected'); }); // If the Node process ends, close the Mongoose connection process.on('SIGINT', () => { // @ts-ignore mongoose.connection.close(() => { - logger.info('[DATABASE] Mongoose default connection disconnected through app termination'); + logger.info('Connection disconnected through app termination'); process.exit(0); }); }); diff --git a/server/src/helpers/query/FilterHelper.ts b/server/src/helpers/query/FilterHelper.ts index 58b6b2dd..69aeaebb 100644 --- a/server/src/helpers/query/FilterHelper.ts +++ b/server/src/helpers/query/FilterHelper.ts @@ -1,7 +1,4 @@ // Filtering logic - -import logger from '../../logger'; - export function filterByFields(data: T[], params: any): T[] { if (params.filter) { const filter = JSON.parse(params.filter as any) as { diff --git a/server/src/index.ts b/server/src/index.ts index 1bd958a5..322691ed 100644 --- a/server/src/index.ts +++ b/server/src/index.ts @@ -7,7 +7,16 @@ import Crons from './modules/crons'; import app from './App'; const start = () => { - logger.info(`Starting server...`); + logger.info(` + ,;;:;, + ;;;;; + ,:;;:; ,'=. + ;:;:;' .=" ,'_\\ + ':;:;,/ ,__:=@ + ';;:; =./)_ + \`"=\\_ )_"\` + \`\`'"\` +Starting Squirrel Servers Manager server...`); connection().then(async () => { await Startup.init(); app.setupRoutes(); diff --git a/server/src/logger.ts b/server/src/logger.ts index 6ba10e46..bf519089 100644 --- a/server/src/logger.ts +++ b/server/src/logger.ts @@ -34,17 +34,17 @@ export const httpLoggerOptions = { }, // Define a custom success message customSuccessMessage: function (req, res) { - return `${req.method} completed ${(req as typeof req & { originalUrl: string }).originalUrl}`; + return `Request completed: ${req.method} - ${(req as typeof req & { originalUrl: string }).originalUrl}`; }, // Define a custom receive message customReceivedMessage: function (req, res) { - return `request received: ${req.method} - ${req.url}`; + return `Request received: ${req.method} - ${req.url}`; }, // Define a custom error message customErrorMessage: function (req, res, err) { - return 'request errored with status code: ' + res.statusCode; + return `Request errored with status code: ${res.statusCode}`; }, }; diff --git a/server/src/modules/ansible/extravars/ExtraVars.ts b/server/src/modules/ansible/extravars/ExtraVars.ts index 51ac877e..47844030 100644 --- a/server/src/modules/ansible/extravars/ExtraVars.ts +++ b/server/src/modules/ansible/extravars/ExtraVars.ts @@ -26,7 +26,7 @@ class ExtraVars { if (!value && !emptySubstitute) { this.logger.error(`findValueOfExtraVars - ExtraVar not found : ${e.extraVar}`); if (e.required) { - throw new Error('ExtraVar value not found !'); + throw new Error(`ExtraVar value not found ! (${e.extraVar})`); } } else { substitutedExtraVars.push({ ...e, value: value || undefined }); @@ -62,22 +62,22 @@ class ExtraVars { private getForcedValue(extraVar: API.ExtraVar, forcedValues?: API.ExtraVars) { const forcedValue = forcedValues?.find((e) => e.extraVar === extraVar.extraVar)?.value; - this.logger.debug(`forcedValue found ${forcedValue}`); + this.logger.debug(`forcedValue found: ${forcedValue}`); return forcedValue; } private async getContextExtraVarValue(extraVar: API.ExtraVar, targets?: string[]) { - this.logger.debug(`getContextExtraVarValue '${extraVar.extraVar}'`); + this.logger.debug(`getContextExtraVarValue - '${extraVar.extraVar}'`); if (!targets) { return; } if (targets.length > 1) { - throw new Error('Cannot use CONTEXT variable with multiple targets'); + throw new Error(`Cannot use CONTEXT variable with multiple targets - '${extraVar.extraVar}'`); } const device = await DeviceRepo.findOneByUuid(targets[0]); const user = await UserRepo.findFirst(); if (!device) { - throw new Error('Targeted device not found'); + throw new Error(`Targeted device not found - (device: ${targets?.[0]})`); } switch (extraVar.extraVar) { case SsmAnsible.DefaultContextExtraVarsList.DEVICE_ID: diff --git a/server/src/modules/automations/AutomationComponent.ts b/server/src/modules/automations/AutomationComponent.ts index eca753b8..edc26c33 100644 --- a/server/src/modules/automations/AutomationComponent.ts +++ b/server/src/modules/automations/AutomationComponent.ts @@ -25,7 +25,7 @@ class AutomationComponent { moduleId: `${this.uuid}`, moduleName: `${name}`, }, - { msgPrefix: '[AUTOMATION-COMPONENT] - ' }, + { msgPrefix: '[AUTOMATION] - ' }, ); this.automationChain = automationChain; this.actions = []; @@ -70,14 +70,14 @@ class AutomationComponent { } async onTrigger() { - this.childLogger.info('Triggered'); + this.childLogger.info(`Automation "${this.name}" triggered...`); await this.synchronousExecution(); } async synchronousExecution() { if (this.actions) { for (const action of this.actions) { - this.childLogger.info(`Execution a ${action.type} action`); + this.childLogger.info(`Executing a ${action.type} action...`); await action.executeAction(); } } else { diff --git a/server/src/modules/automations/actions/AbstractActionComponent.ts b/server/src/modules/automations/actions/AbstractActionComponent.ts index a8864874..38e2f5d3 100644 --- a/server/src/modules/automations/actions/AbstractActionComponent.ts +++ b/server/src/modules/automations/actions/AbstractActionComponent.ts @@ -24,7 +24,7 @@ abstract class AbstractActionComponent extends EventManager { moduleName: `${automationName}`, type: type, }, - { msgPrefix: '[ACTION-COMPONENT] - ' }, + { msgPrefix: '[AUTOMATION_ACTION] - ' }, ); } diff --git a/server/src/modules/automations/actions/DockerActionComponent.ts b/server/src/modules/automations/actions/DockerActionComponent.ts index f4fba455..986e12ae 100644 --- a/server/src/modules/automations/actions/DockerActionComponent.ts +++ b/server/src/modules/automations/actions/DockerActionComponent.ts @@ -22,13 +22,13 @@ class DockerActionComponent extends AbstractActionComponent { } async executeAction() { - this.childLogger.info('Docker Action Component execute - started'); + this.childLogger.info('Docker Action Component - executeAction - started'); let success = true; for (const containerId of this.containerIds) { - this.childLogger.info(`Docker Action Component execute - ${containerId}`); + this.childLogger.info(`Docker Action Component - executeAction for: ${containerId}`); const container = await ContainerRepo.findContainerById(containerId); if (!container) { - this.childLogger.error(`Container not found for ${containerId}`); + this.childLogger.error(`Docker Volume Action - Container not found for ${containerId}`); success = false; } else { try { @@ -39,7 +39,9 @@ class DockerActionComponent extends AbstractActionComponent { } } } - this.childLogger.info('Docker Action Component execute - ended'); + this.childLogger.info( + `Docker Action Component - executeAction - ended with ${success ? 'success' : 'failure'}`, + ); if (success) { await this.onSuccess(); } else { diff --git a/server/src/modules/automations/actions/DockerVolumeActionComponent.ts b/server/src/modules/automations/actions/DockerVolumeActionComponent.ts index 6fbb37bd..3ffb279c 100644 --- a/server/src/modules/automations/actions/DockerVolumeActionComponent.ts +++ b/server/src/modules/automations/actions/DockerVolumeActionComponent.ts @@ -22,10 +22,12 @@ class DockerVolumeActionComponent extends AbstractActionComponent { } async executeAction() { - this.childLogger.info('Docker Volume Action Component execute - started'); + this.childLogger.info( + `Docker Volume Action - executeAction (${this.dockerVolumeAction}) - started...`, + ); let success = true; for (const volumeUuid of this.volumeUuids) { - this.childLogger.info(`Docker Volume Action Component execute - ${volumeUuid}`); + this.childLogger.info(`Docker Volume Action - executeAction - for volume: ${volumeUuid}`); const volume = await ContainerVolumeRepo.findByUuid(volumeUuid); if (!volume) { this.childLogger.error(`Volume not found for ${volumeUuid}`); @@ -45,7 +47,9 @@ class DockerVolumeActionComponent extends AbstractActionComponent { } } } - this.childLogger.info('Docker Volume Action Component execute - ended'); + this.childLogger.info( + `Docker Volume Action - executeAction - ${this.dockerVolumeAction} ended with ${success ? 'success' : 'failure'}`, + ); if (success) { await this.onSuccess(); } else { diff --git a/server/src/modules/automations/actions/PlaybookActionComponent.ts b/server/src/modules/automations/actions/PlaybookActionComponent.ts index 580df5af..c2aeefb0 100644 --- a/server/src/modules/automations/actions/PlaybookActionComponent.ts +++ b/server/src/modules/automations/actions/PlaybookActionComponent.ts @@ -28,11 +28,13 @@ class PlaybookActionComponent extends AbstractActionComponent { } async executeAction() { - this.childLogger.info('Playbook Action Component execute - started'); + this.childLogger.info('Playbook Action Component - executeAction - started'); const user = (await UserRepo.findFirst()) as User; const playbook = await PlaybookRepo.findOneByUuid(this.playbookUuid); if (!playbook) { - this.childLogger.error(`Playbook ${this.playbookUuid} does not exist`); + this.childLogger.error( + `Playbook Action Component - Playbook ${this.playbookUuid} does not exist`, + ); return; } try { @@ -60,7 +62,9 @@ class PlaybookActionComponent extends AbstractActionComponent { }; async waitForResult(execId: string, timeoutCount = 0) { - this.childLogger.info(`wait for result ${execId} - (try: ${timeoutCount}/100)`); + this.childLogger.info( + `Playbook Action Component - wait for result ${execId} - (try: ${timeoutCount}/100)`, + ); try { if (timeoutCount > 100) { this.childLogger.error('Timeout reached for task'); @@ -69,13 +73,17 @@ class PlaybookActionComponent extends AbstractActionComponent { } const execStatuses = await AnsibleTaskStatusRepo.findAllByIdent(execId); if (!execStatuses || execStatuses.length === 0) { - this.childLogger.warn(`No execution statuses found (yet) for execId: ${execId}`); + this.childLogger.warn( + `Playbook Action Component - No execution statuses found (yet) for execId: ${execId}`, + ); setTimeout(() => { this.waitForResult(execId, timeoutCount + 1); }, 5000); } else { const lastExecStatus = execStatuses[0]; - this.childLogger.info(`Latest execution status ${lastExecStatus.status}`); + this.childLogger.info( + `Playbook Action Component - Latest execution status ${lastExecStatus.status}`, + ); if (PlaybookActionComponent.isFinalStatus(lastExecStatus.status as string)) { if (lastExecStatus.status === SsmAnsible.AnsibleTaskStatus.SUCCESS) { await this.onSuccess(); @@ -99,7 +107,10 @@ class PlaybookActionComponent extends AbstractActionComponent { try { await this.onError(); } catch (innerError) { - this.childLogger.error('Error during onError handling:', innerError); + this.childLogger.error( + 'Playbook Action Component - Error during onError handling:', + innerError, + ); } } } diff --git a/server/src/modules/docker/core/Component.ts b/server/src/modules/docker/core/Component.ts index 365d148f..932da7a4 100644 --- a/server/src/modules/docker/core/Component.ts +++ b/server/src/modules/docker/core/Component.ts @@ -62,7 +62,7 @@ abstract class Component< { msgPrefix: `[${kind.toUpperCase()}][${type.toUpperCase()}] - ` }, ); this.childLogger.info( - `Register with configuration ${JSON.stringify(this.maskConfiguration())}`, + `Registering ${this.kind?.toLowerCase()} with configuration: ${JSON.stringify(this.maskConfiguration())}`, ); await this.init(); return this; diff --git a/server/src/modules/docker/core/CustomAgent.ts b/server/src/modules/docker/core/CustomAgent.ts index 4736429b..0eb1a5e0 100644 --- a/server/src/modules/docker/core/CustomAgent.ts +++ b/server/src/modules/docker/core/CustomAgent.ts @@ -40,17 +40,17 @@ export const getCustomAgent = (childLogger: any, opt: any) => { .once('ready', () => { conn.exec('docker system dial-stdio', (err, stream) => { if (err) { - this.logger.error('Encountering an exec SSH error'); + this.logger.error(`Encountering an exec SSH error - (host: ${opt.host})`); this.logger.error(err); handleError(err); } stream.addListener('error', (err) => { - this.logger.error('Encountering an stream SSH error'); + this.logger.error(`Encountering an stream SSH error - (host: ${opt.host})`); this.logger.error(err); handleError(err); }); stream.once('close', () => { - this.logger.warn('Stream closed'); + this.logger.warn(`Stream closed - (host: ${opt.host})`); conn.end(); this.destroy(); }); @@ -58,17 +58,17 @@ export const getCustomAgent = (childLogger: any, opt: any) => { }); }) .on('error', (err) => { - this.logger.error(`Error connecting to ${opt.host}`); - this.logger.error(err); + this.logger.error(`Error connecting to ${opt.host} : ${err.message}`); fn(err); }) .once('end', () => { - this.logger.warn('Agent destroy'); + this.logger.warn(`Agent destroy for ${opt.host}`); conn.end(); this.destroy(); }) .connect(opt); } catch (error: any) { + this.logger.error(`Error connecting to ${opt.host} : ${err.message}`); this.logger.error(error); } } diff --git a/server/src/modules/docker/core/WatcherEngine.ts b/server/src/modules/docker/core/WatcherEngine.ts index a3e5d29d..f4f52d7f 100644 --- a/server/src/modules/docker/core/WatcherEngine.ts +++ b/server/src/modules/docker/core/WatcherEngine.ts @@ -100,7 +100,7 @@ async function registerComponent( const providerLowercase = provider.toLowerCase(); const nameLowercase = name.toLowerCase(); try { - logger.info(`Registering "${provider}/${name}" component`); + logger.info(`Registering "${provider}/${name}" component...`); const component = getComponentClass(kind, provider); const componentRegistered = await component.register( _id, diff --git a/server/src/modules/docker/registries/Registry.ts b/server/src/modules/docker/registries/Registry.ts index 4962342e..a8f8a260 100644 --- a/server/src/modules/docker/registries/Registry.ts +++ b/server/src/modules/docker/registries/Registry.ts @@ -29,7 +29,7 @@ abstract class Registry extends Component} */ - // eslint-disable-next-line class-methods-use-this + async authenticate( image: SSMServicesTypes.Image, requestOptions: SSMServicesTypes.RequestOptionsType, @@ -109,7 +109,7 @@ export default class Hub extends Custom { if (requestOptionsWithAuth.headers) { requestOptionsWithAuth.headers.Authorization = `Bearer ${response.data.token}`; } - this.childLogger.info(`Authentication done - ${response.status}`); + this.childLogger.debug(`Authentication done - ${response.status}`); return requestOptionsWithAuth; } catch (e: any) { this.childLogger.error('Authentication failed'); @@ -117,7 +117,6 @@ export default class Hub extends Custom { } } - // eslint-disable-next-line class-methods-use-this getImageFullName(image: SSMServicesTypes.Image, tagOrDigest: string) { let fullName = super.getImageFullName(image, tagOrDigest); fullName = fullName.replace(/registry-1.docker.io\//, ''); diff --git a/server/src/modules/docker/watchers/providers/docker/AbstractDockerImages.ts b/server/src/modules/docker/watchers/providers/docker/AbstractDockerImages.ts index e68da319..ac272cb9 100644 --- a/server/src/modules/docker/watchers/providers/docker/AbstractDockerImages.ts +++ b/server/src/modules/docker/watchers/providers/docker/AbstractDockerImages.ts @@ -8,7 +8,7 @@ export default class DockerImages extends DockerVolumes { dockerApi: Dockerode | undefined = undefined; public async watchImagesFromCron() { - this.childLogger.info('watchImagesFromCron'); + this.childLogger.info(`watchImagesFromCron - (device: ${this.configuration.deviceUuid})`); try { const device = await DeviceRepo.findOneByUuid(this.configuration.deviceUuid); if (!device) { @@ -47,7 +47,9 @@ export default class DockerImages extends DockerVolumes { return imagesInDb?.find((e) => e.id === image?.id) === undefined; }); if (imagesToInsert) { - this.childLogger.info(`insertNewImage - got ${imagesToInsert?.length} images to insert`); + this.childLogger.info( + `insertNewImage - got ${imagesToInsert?.length} images to insert (device: ${this.configuration.deviceUuid})`, + ); await Promise.all( imagesToInsert.map(async (image) => { if (image) { diff --git a/server/src/modules/docker/watchers/providers/docker/AbstractDockerListener.ts b/server/src/modules/docker/watchers/providers/docker/AbstractDockerListener.ts index 49447c94..8943d9b3 100644 --- a/server/src/modules/docker/watchers/providers/docker/AbstractDockerListener.ts +++ b/server/src/modules/docker/watchers/providers/docker/AbstractDockerListener.ts @@ -14,7 +14,9 @@ export default class DockerListener extends Component} */ async listenDockerEvents(): Promise { - this.childLogger.info('Listening to docker events'); + this.childLogger.info( + `Listening to docker events - (device: ${this.configuration.deviceUuid})`, + ); const options: { filters: { type?: @@ -42,7 +44,9 @@ export default class DockerListener extends Component { if (err) { - this.childLogger.warn(`Unable to listen to Docker events [${err.message}]`); + this.childLogger.warn( + `Unable to listen to Docker events [${err.message}] - (device: ${this.configuration.deviceUuid})`, + ); this.childLogger.debug(err); } else { stream?.on('data', (chunk) => this.onDockerEvent(chunk)); @@ -59,11 +63,13 @@ export default class DockerListener extends Component} */ async onDockerEvent(dockerEventChunk: any): Promise { - this.childLogger.info('onDockerEvent'); + this.childLogger.debug('onDockerEvent'); const dockerEvent = JSON.parse(dockerEventChunk.toString()); const action = dockerEvent.Action; const containerId = dockerEvent.id; - this.childLogger.info('onDockerEvent - action: ' + action); + this.childLogger.info( + `onDockerEvent (device: ${this.configuration.deviceUuid} - action received: ${action} - containerId: ${containerId})`, + ); // If the container was created or destroyed => perform a watch if (action === 'destroy' || action === 'create') { @@ -83,7 +89,7 @@ export default class DockerListener extends Component { diff --git a/server/src/modules/docker/watchers/providers/docker/AbstractDockerVolumes.ts b/server/src/modules/docker/watchers/providers/docker/AbstractDockerVolumes.ts index 540860bb..87629fa0 100644 --- a/server/src/modules/docker/watchers/providers/docker/AbstractDockerVolumes.ts +++ b/server/src/modules/docker/watchers/providers/docker/AbstractDockerVolumes.ts @@ -11,7 +11,9 @@ export default class DockerVolumes extends DockerNetworks { dockerApi: Dockerode | undefined = undefined; public async watchVolumesFromCron() { - this.childLogger.info('watchDockerVolumesFromCron'); + this.childLogger.info( + `watchDockerVolumesFromCron - (device: ${this.configuration.deviceUuid})`, + ); try { const device = await DeviceRepo.findOneByUuid(this.configuration.deviceUuid); if (!device) { @@ -86,9 +88,9 @@ export default class DockerVolumes extends DockerNetworks { if (!FileSystemManager.test('-d', backupPath)) { FileSystemManager.createDirectory(backupPath); } - this.childLogger.info(`backupVolume - Backup of volume ${volumeName} started`); + this.childLogger.info(`backupVolume - Backup of volume "${volumeName}" started...`); await this.dockerApi?.pull('alpine'); - this.childLogger.info(`backupVolume - Create container`); + this.childLogger.debug(`backupVolume - Create container`); // Create a temporary container which will mount the volume const container = await this.dockerApi?.createContainer({ Image: 'alpine', @@ -101,11 +103,11 @@ export default class DockerVolumes extends DockerNetworks { if (!container) { throw new Error('Container for backup not created'); } - this.childLogger.info(`backupVolume - Start container`); + this.childLogger.debug(`backupVolume - Start container`); // Start the container await container.start(); - this.childLogger.info(`backupVolume - Wait for container`); + this.childLogger.debug(`backupVolume - Wait for container`); // Create a tar stream // Wait for the container to finish the tar command await container.wait(); @@ -121,7 +123,7 @@ export default class DockerVolumes extends DockerNetworks { const onTarballStreamEnd = async () => { await container .stop({ t: 0 }) - .catch((err) => this.childLogger.warn('Container already stopped:', err)); + .catch((err) => this.childLogger.warn(`Container already stopped: ${err?.message}`)); await container.remove(); this.childLogger.info(`Backup of volume ${volumeName} has been saved to ${backupPath}`); }; diff --git a/server/src/modules/docker/watchers/providers/docker/Docker.ts b/server/src/modules/docker/watchers/providers/docker/Docker.ts index c2abcc26..94b40c2f 100644 --- a/server/src/modules/docker/watchers/providers/docker/Docker.ts +++ b/server/src/modules/docker/watchers/providers/docker/Docker.ts @@ -74,7 +74,9 @@ export default class Docker extends DockerLogs { await DeviceUseCases.updateDockerInfo(this.configuration.deviceUuid, e.ID, e.ServerVersion); }); - this.childLogger.info(`Cron scheduled (${this.configuration.cron})`); + this.childLogger.info( + `Cron scheduled (cron: "${this.configuration.cron}", device: ${this.configuration.deviceUuid})`, + ); this.watchCron = CronJob.schedule(this.configuration.cron, () => { this.watchContainersFromCron(); this.watchNetworksFromCron(); @@ -122,7 +124,7 @@ export default class Docker extends DockerLogs { } const deviceAuth = await DeviceAuthRepo.findOneByDevice(device); if (!deviceAuth) { - throw new Error(`DeviceAuth not found: ${this.configuration.deviceUuid}`); + throw new Error(`DeviceAuth not found for device ${this.configuration.deviceUuid}`); } const options = await SSHCredentialsHelper.getDockerSshConnectionOptions(device, deviceAuth); this.childLogger.debug(options); @@ -171,7 +173,9 @@ export default class Docker extends DockerLogs { * @returns {Promise<*[]>} */ async watchContainersFromCron(): Promise { - this.childLogger.info(`Cron started (${this.configuration.cron})`); + this.childLogger.info( + `watchContainersFromCron - Cron started (cron: "${this.configuration.cron}", device: ${this.configuration.deviceUuid})`, + ); // Get container reports const containerReports = await this.watch(); @@ -190,7 +194,9 @@ export default class Docker extends DockerLogs { ).length; const stats = `${containerReportsCount} containers watched, ${containerErrorsCount} errors, ${containerUpdatesCount} available updates`; - this.childLogger.info(`Cron finished (${stats})`); + this.childLogger.info( + `watchContainersFromCron - Cron finished: ${stats} (device: ${this.configuration.deviceUuid})`, + ); this.emit(Events.UPDATED_CONTAINERS, 'Updated containers'); return containerReports; } @@ -256,12 +262,14 @@ export default class Docker extends DockerLogs { if (this.configuration.watchall) { listContainersOptions.all = true; } - this.childLogger.info('getContainers - dockerApi.listContainers'); + this.childLogger.debug('getContainers - dockerApi.listContainers'); let containers: any[]; try { containers = await this.dockerApi.listContainers(listContainersOptions); } catch (e: any) { - this.childLogger.error(`listContainers - error: ${e.message}`); + this.childLogger.error( + `listContainers - error: ${e.message} - (device: ${this.configuration.deviceUuid})`, + ); await ContainerRepo.updateStatusByWatcher(this.name, SsmStatus.ContainerStatus.UNREACHABLE); return []; } @@ -272,7 +280,9 @@ export default class Docker extends DockerLogs { this.childLogger.debug( `getContainers - filteredContainers: ${JSON.stringify(filteredContainers)}`, ); - this.childLogger.info('getContainers - getImageDetails'); + this.childLogger.info( + `getContainers - getImageDetails for ${filteredContainers?.length} containers... (device: ${this.configuration.deviceUuid})`, + ); const containerPromises = filteredContainers.map((container: ContainerInfo) => this.addImageDetailsToContainer( container, @@ -285,7 +295,9 @@ export default class Docker extends DockerLogs { ), ); const containersWithImage = await Promise.all(containerPromises); - this.childLogger.info('getContainers - getImageDetails - ended'); + this.childLogger.info( + `getContainers - getImageDetails - ended - (device: ${this.configuration.deviceUuid})`, + ); // Return containers to process const containersToReturn = containersWithImage.filter( (imagePromise) => imagePromise !== undefined, @@ -296,11 +308,15 @@ export default class Docker extends DockerLogs { const containersFromTheStore = await ContainerRepo.findContainersByWatcher(this.name); pruneOldContainers(containersToReturn, containersFromTheStore); } catch (e: any) { - this.childLogger.warn(`Error when trying to prune the old containers (${e.message})`); + this.childLogger.warn( + `Error when trying to prune the old containers (message: ${e.message}, device: ${this.configuration.deviceUuid})`, + ); } return containersToReturn; } catch (error: any) { - this.childLogger.error(`getContainers - error: ${error.message}`); + this.childLogger.error( + `getContainers - error: ${error.message} (device: ${this.configuration.deviceUuid})`, + ); this.childLogger.error(error); return []; } @@ -319,7 +335,7 @@ export default class Docker extends DockerLogs { if (!registryProvider) { this.childLogger.error( - `findNewVersion - Unsupported registry (${container.image.registry.name})`, + `findNewVersion - Unsupported registry: ${container.image.registry.name} (image: ${container.image.name})`, ); } else { // Get all available tags @@ -401,16 +417,22 @@ export default class Docker extends DockerLogs { containerInStore.error === undefined ) { this.childLogger.info( - `addImageDetailsToContainer - Container ${container.Image} already in store`, + `addImageDetailsToContainer - Container "${container.Image}" already in store - (containerId: ${containerInStore.id})`, ); return { ...containerInStore, status: container.State, labels: container?.Labels }; } - this.childLogger.info(`addImageDetailsToContainer - getImage: ${container.Image}`); + this.childLogger.info( + `addImageDetailsToContainer - getImage: ${container.Image} - (containerId: ${containerId})`, + ); const img = this.dockerApi.getImage(container.Image); // Get container image details - this.childLogger.info(`addImageDetailsToContainer - inspect: ${container.Image}`); + this.childLogger.info( + `addImageDetailsToContainer - inspect: ${container.Image} - (containerId: ${containerId})`, + ); const image = await img.inspect(); - this.childLogger.info(`addImageDetailsToContainer - distribution: ${container.Image}`); + this.childLogger.info( + `addImageDetailsToContainer - distribution: ${container.Image} - (containerId: ${containerId})`, + ); const distribution = await img.distribution(); // Get useful properties const containerName = getContainerName(container); @@ -427,7 +449,7 @@ export default class Docker extends DockerLogs { if (imageNameToParse.includes('sha256:')) { if (!image.RepoTags || image.RepoTags.length === 0) { this.childLogger.warn( - `addImageDetailsToContainer - Cannot get a reliable tag for this image [${imageNameToParse}]`, + `addImageDetailsToContainer - Cannot get a reliable tag for this image [${imageNameToParse}] - (containerId: ${containerId})`, ); return undefined; } @@ -441,7 +463,7 @@ export default class Docker extends DockerLogs { const watchDigest = isDigestToWatch(container.Labels[Label.wudWatchDigest], isSemver); if (!isSemver && !watchDigest) { this.childLogger.warn( - "addImageDetailsToContainer - Image is not a semver and digest watching is disabled so wud won't report any update. Please review the configuration to enable digest watching for this container or exclude this container from being watched", + `addImageDetailsToContainer - Image "${imageNameToParse}" is not a semver and digest watching is disabled so wud won't report any update. Please review the configuration to enable digest watching for this container or exclude this container from being watched`, ); } return normalizeContainer({ @@ -540,29 +562,33 @@ export default class Docker extends DockerLogs { } async watchContainerStats() { - this.childLogger.info(`[CRON] - watchContainerStats ${this.name}`); + this.childLogger.info( + `watchContainerStats ${this.name} - (device: ${this.configuration.deviceUuid})`, + ); try { const containers = await ContainerRepo.findContainersByWatcher(this.name); if (!containers) { - this.childLogger.warn(`[CRON] - watchContainerStats - No container to watch`); + this.childLogger.warn( + `watchContainerStats - No container to watch - (device: ${this.configuration.deviceUuid})`, + ); return; } this.childLogger.info( - `[CRON] - watchContainerStats - Found ${containers.length} container(s) to watch...`, + `watchContainerStats - Found ${containers.length} container(s) to watch... (device: ${this.configuration.deviceUuid})`, ); for (const container of containers) { - this.childLogger.info(`[CRON] - watchContainerStats ${container.id}`); + this.childLogger.info( + `watchContainerStats ${container.id} - (device: ${this.configuration.deviceUuid})`, + ); try { const dockerContainer = this.dockerApi.getContainer(container.id); - this.childLogger.debug( - `[CRON] - watchContainerStats getContainer - ${dockerContainer.id}`, - ); + this.childLogger.debug(`watchContainerStats getContainer - ${dockerContainer.id}`); const dockerStats = await dockerContainer.stats({ stream: false }); await ContainerStatsRepo.create(container, dockerStats); } catch (error: any) { this.childLogger.error(error); this.childLogger.error( - `[CRON] - Error retrieving stats for ${container.name}/${container.id}}`, + `[CRON] - Error retrieving stats for ${container.name}/${container.id}} - (device: ${this.configuration.deviceUuid})`, ); } } @@ -589,7 +615,9 @@ export default class Docker extends DockerLogs { } async killContainer(container: Container) { - this.childLogger.info(`killContainer ${container.id}`); + this.childLogger.warn( + `killContainer ${container.id} (device: ${this.configuration.deviceUuid})`, + ); await this.dockerApi.getContainer(container.id).kill(); } } diff --git a/server/src/modules/notifications/NotificationComponent.ts b/server/src/modules/notifications/NotificationComponent.ts index 2717f2db..fa3813c0 100644 --- a/server/src/modules/notifications/NotificationComponent.ts +++ b/server/src/modules/notifications/NotificationComponent.ts @@ -7,7 +7,7 @@ import pinoLogger from '../../logger'; class NotificationComponent extends EventManager { private childLogger = pinoLogger.child( { module: `Notification` }, - { msgPrefix: '[NOTIFICATION-COMPONENT] - ' }, + { msgPrefix: '[NOTIFICATION] - ' }, ); private eventsToListen = [ @@ -21,7 +21,7 @@ class NotificationComponent extends EventManager { } async init() { - this.childLogger.info('init'); + this.childLogger.info('Initialization....'); this.subscribeToEvents(); } @@ -34,7 +34,7 @@ class NotificationComponent extends EventManager { private async handleNotificationEvent(event: string, payload: Payload) { try { const { message, severity, module, moduleId } = payload; - this.childLogger.info('Notification received'); + this.childLogger.info(`handleNotificationEvent - Notification received - (event: ${event})`); await InAppNotificationRepo.create({ event, diff --git a/server/src/modules/real-time/RealTime.ts b/server/src/modules/real-time/RealTime.ts index 11b88442..38c74992 100644 --- a/server/src/modules/real-time/RealTime.ts +++ b/server/src/modules/real-time/RealTime.ts @@ -59,7 +59,7 @@ class RealTimeEngine extends EventManager { public init() { try { - this.childLogger.info('init...'); + this.childLogger.info('Init...'); eventsToHandle.forEach(({ event, ssmEvent, logMessage, debounceTime }) => { this.childLogger.debug( diff --git a/server/src/modules/repository/ContainerCustomStacksRepositoryEngine.ts b/server/src/modules/repository/ContainerCustomStacksRepositoryEngine.ts index c67c4b05..ef939c1b 100644 --- a/server/src/modules/repository/ContainerCustomStacksRepositoryEngine.ts +++ b/server/src/modules/repository/ContainerCustomStacksRepositoryEngine.ts @@ -50,7 +50,7 @@ async function registerGitRepository( async function registerRepository(containerCustomStackRepository: ContainerCustomStackRepository) { logger.info( - `Registering ${containerCustomStackRepository.name}/${containerCustomStackRepository.uuid}`, + `Registering: ${containerCustomStackRepository.name}/${containerCustomStackRepository.uuid}`, ); state.stackRepository[containerCustomStackRepository.uuid] = await registerGitRepository( containerCustomStackRepository, @@ -62,7 +62,7 @@ async function registerRepository(containerCustomStackRepository: ContainerCusto async function registerRepositories() { const repos = await ContainerCustomStackRepositoryRepo.findAllActive(); - logger.info(`Found ${repos?.length} active repositories`); + logger.info(`Found ${repos?.length} active repositories in database.`); const repositoriesToRegister: any = []; repos?.map((repo) => { repositoriesToRegister.push(registerRepository(repo)); diff --git a/server/src/modules/shell/AbstractShellCommander.ts b/server/src/modules/shell/AbstractShellCommander.ts index e41ea4fb..791496a0 100644 --- a/server/src/modules/shell/AbstractShellCommander.ts +++ b/server/src/modules/shell/AbstractShellCommander.ts @@ -12,7 +12,7 @@ export abstract class AbstractShellCommander { ...args: Parameters ): ReturnType { try { - this.logger.info(`${this.task} - Starting...`); + this.logger.debug(`${this.task} - Starting...`); return shellCmd(...args); } catch (error) { this.logger.error(`${this.task} - Failed`); diff --git a/server/src/modules/shell/managers/AnsibleShellCommandsManager.ts b/server/src/modules/shell/managers/AnsibleShellCommandsManager.ts index bf260c67..32f5d6ed 100644 --- a/server/src/modules/shell/managers/AnsibleShellCommandsManager.ts +++ b/server/src/modules/shell/managers/AnsibleShellCommandsManager.ts @@ -34,17 +34,19 @@ class AnsibleShellCommandsManager extends AbstractShellCommander { mode: SsmAnsible.ExecutionMode = SsmAnsible.ExecutionMode.APPLY, execUuid?: string, ) { - this.logger.info('executePlaybook - Starting...'); + this.logger.info(`executePlaybook - Starting... (playbook: ${playbookPath})`); execUuid = execUuid || uuidv4(); let inventoryTargets: (Playbooks.All & Playbooks.HostGroups) | undefined; if (target) { - this.logger.info(`executePlaybook - called with target: ${target}`); + this.logger.info( + `executePlaybook - Called with specific device: ${target} - (playbook: ${playbookPath})`, + ); const devicesAuth = await DeviceAuthRepo.findManyByDevicesUuid(target); if (!devicesAuth || devicesAuth.length === 0) { - this.logger.error(`executePlaybook - Target not found (Device Authentication not found)`); + this.logger.error(`executePlaybook - Device Authentication not found (device: ${target})`); throw new Error( - `Exec failed, no matching target (Device Authentication not found for target ${target})`, + `Exec failed, no matching target - (Device Authentication not found for device ${target})`, ); } inventoryTargets = await Inventory.inventoryBuilderForTarget(devicesAuth, execUuid); diff --git a/server/src/modules/shell/managers/SshPrivateKeyFileManager.ts b/server/src/modules/shell/managers/SshPrivateKeyFileManager.ts index 02b4ed45..9e9cac64 100644 --- a/server/src/modules/shell/managers/SshPrivateKeyFileManager.ts +++ b/server/src/modules/shell/managers/SshPrivateKeyFileManager.ts @@ -8,7 +8,13 @@ import FileSystemManager from './FileSystemManager'; class SshPrivateKeyFileManager extends AbstractShellCommander { constructor() { - super(logger.child({ module: 'SshPrivateKeyFileManager' }), 'SshPrivateKey'); + super( + logger.child( + { module: 'SshPrivateKeyFileManager' }, + { msgPrefix: '[SSH_PRIVATE_KEY_FILE_MANAGER - ' }, + ), + 'SshPrivateKey', + ); } getTmpKeyFileName(execUuid: string, deviceUuid: string) { diff --git a/server/src/modules/ssh/SSHTerminalInstance.ts b/server/src/modules/ssh/SSHTerminalInstance.ts index 84ac8c61..82c27dec 100644 --- a/server/src/modules/ssh/SSHTerminalInstance.ts +++ b/server/src/modules/ssh/SSHTerminalInstance.ts @@ -16,16 +16,16 @@ export default class SSHTerminalInstance { this.sshConnectionInstance = new SSHConnectionInstance(deviceUuid); this.socket = socket; this.logger = _logger.child( - { module: 'SSHTerminalInstance' }, + { module: 'SSHTerminalInstance', moduleId: deviceUuid }, { msgPrefix: '[SSH_TERMINAL_INSTANCE] - ' }, ); this.ttyOptions = ttyOptions; } async start() { - this.logger.info('Starting SSHTerminalInstance'); + this.logger.info(`Starting SSHTerminalInstance...`); this.bind(); - this.logger.info('await connect'); + this.logger.debug('Await connect...'); await this.sshConnectionInstance.connect(); } @@ -38,8 +38,7 @@ export default class SSHTerminalInstance { } private bind() { - this.logger.info('bind'); - + this.logger.debug('bind'); this.sshConnectionInstance.ssh.on('banner', this.handleBanner.bind(this)); this.sshConnectionInstance.ssh.on('ready', this.handleReady.bind(this)); this.sshConnectionInstance.ssh.on('end', this.handleEnd.bind(this)); @@ -57,7 +56,7 @@ export default class SSHTerminalInstance { } private handleReady() { - this.logger.info('SSH CONNECTION ESTABLISHED'); + this.logger.info('SSH connection established'); this.socket.emit(SsmEvents.SSH.STATUS, { status: 'OK', message: 'SSH CONNECTION ESTABLISHED' }); this.sshConnectionInstance.ssh.shell( @@ -87,7 +86,7 @@ export default class SSHTerminalInstance { } private handleSocketDisconnect(reason: any) { - this.logger.warn(`CLIENT SOCKET DISCONNECT: ${util.inspect(reason)}`); + this.logger.warn(`Client socket disconnect: ${util.inspect(reason)}`); this.socket.emit(SsmEvents.SSH.STATUS, { status: 'DISCONNECT', message: 'SSH CONNECTION DISCONNECTED', @@ -110,35 +109,35 @@ export default class SSHTerminalInstance { this.ttyOptions.height as number, this.ttyOptions.width as number, ); - this.logger.info(`SOCKET RESIZE: ${JSON.stringify([data.rows, data.cols])}`); + this.logger.info(`Socket resize: ${JSON.stringify([data.rows, data.cols])}`); } private handleSocketData(stream: ClientChannel, data: string) { - this.logger.info(`write on stream: ${data}`); + this.logger.debug(`Write on stream: ${data}`); stream.write(data); } private handleStreamData(data: Buffer) { - this.logger.info(`received on stream: ${data.toString('utf-8')}`); + this.logger.debug(`Received on stream: ${data.toString('utf-8')}`); this.socket.emit(SsmEvents.SSH.NEW_DATA, data.toString('utf-8')); } private handleStreamClose(code: number | null, signal: string | null) { - this.logger.warn(`STREAM CLOSE: ${util.inspect([code, signal])}`); + this.logger.warn(`Stream closed: ${util.inspect([code, signal])}`); if (code !== 0 && code !== null) { - this.logger.error('STREAM CLOSE', util.inspect({ message: [code, signal] })); + this.logger.error('Stream closed', util.inspect({ message: [code, signal] })); } this.socket.disconnect(true); this.sshConnectionInstance.ssh.end(); } private handleEnd() { - this.logger.error('CONN END BY HOST'); + this.logger.error('Connection ended by host'); this.socket.disconnect(true); } private handleClose() { - this.logger.error('CONN CLOSE'); + this.logger.error('Connection closed'); this.socket.disconnect(true); } diff --git a/server/src/modules/update/UpdateChecker.ts b/server/src/modules/update/UpdateChecker.ts index 042f0957..c21c2777 100644 --- a/server/src/modules/update/UpdateChecker.ts +++ b/server/src/modules/update/UpdateChecker.ts @@ -8,7 +8,7 @@ import { version } from '../../../package.json'; class UpdateChecker { private childLogger = pinoLogger.child( { module: `UpdateChecker` }, - { msgPrefix: '[UPDATE_CHECKER] - ' }, + { msgPrefix: '[SSM_UPDATE_CHECKER] - ' }, ); private readonly RELEASE_URL = 'https://raw.githubusercontent.com/SquirrelCorporation/SquirrelServersManager/refs/heads/master/release.json'; @@ -39,16 +39,18 @@ class UpdateChecker { const comparison = this.compareVersions(localVersion, remoteVersion); if (comparison === 0) { - this.childLogger.info('The versions are identical.'); + this.childLogger.info( + 'SSM remote and current versions are identical, no update available.', + ); await setToCache(SettingsKeys.GeneralSettingsKeys.UPDATE_AVAILABLE, ''); } else if (comparison === 1) { this.childLogger.info( - `The local version (${localVersion}) is newer than the remote version (${remoteVersion}).`, + `The SSM local version (${localVersion}) is newer than the remote version (${remoteVersion}).`, ); await setToCache(SettingsKeys.GeneralSettingsKeys.UPDATE_AVAILABLE, ''); } else if (comparison === -1) { this.childLogger.info( - `The local version ${localVersion} is older than the remote version (${remoteVersion}).`, + `The SSM local version ${localVersion} is older than the remote version (${remoteVersion}).`, ); await setToCache(SettingsKeys.GeneralSettingsKeys.UPDATE_AVAILABLE, remoteVersion); } diff --git a/server/src/tests/unit-tests/modules/docker/Registry.test.ts b/server/src/tests/unit-tests/modules/docker/Registry.test.ts index a2287904..014a6fab 100644 --- a/server/src/tests/unit-tests/modules/docker/Registry.test.ts +++ b/server/src/tests/unit-tests/modules/docker/Registry.test.ts @@ -302,7 +302,11 @@ describe('testing Registry', () => { url: 'url', }, }), - ).rejects.toEqual(new Error('getImageManifestDigest - Unexpected error; no manifest found')); + ).rejects.toEqual( + new Error( + 'getImageManifestDigest - Unexpected error; no manifest found for image for image "image"', + ), + ); }); test('callRegistry should call authenticate', async () => {