chore: add logs to recurring omnichannel cron jobs (#29392)

apps/meteor/ee/app/livechat-enterprise/server/lib/AutoCloseOnHoldScheduler.ts

@@ -6,6 +6,8 @@ import { LivechatRooms, Users } from '@rocket.chat/models';
 import type { IUser } from '@rocket.chat/core-typings';
 
 import { Livechat } from '../../../../../app/livechat/server/lib/LivechatTyped';
+import { schedulerLogger } from './logger';
+import type { MainLogger } from '../../../../../server/lib/logger/getPino';
 
 const SCHEDULER_NAME = 'omnichannel_auto_close_on_hold_scheduler';
 
@@ -16,8 +18,15 @@ class AutoCloseOnHoldSchedulerClass {
 
 	running: boolean;
 
+	logger: MainLogger;
+
+	constructor() {
+		this.logger = schedulerLogger.section('AutoCloseOnHoldScheduler');
+	}
+
 	public async init(): Promise<void> {
 		if (this.running) {
+			this.logger.debug('Already running');
 			return;
 		}
 
@@ -29,9 +38,11 @@ class AutoCloseOnHoldSchedulerClass {
 
 		await this.scheduler.start();
 		this.running = true;
+		this.logger.debug('Started');
 	}
 
 	public async scheduleRoom(roomId: string, timeout: number, comment: string): Promise<void> {
+		this.logger.debug(`Scheduling room ${roomId} to be closed in ${timeout} seconds`);
 		await this.unscheduleRoom(roomId);
 
 		const jobName = `${SCHEDULER_NAME}-${roomId}`;
@@ -42,11 +53,13 @@ class AutoCloseOnHoldSchedulerClass {
 	}
 
 	public async unscheduleRoom(roomId: string): Promise<void> {
+		this.logger.debug(`Unscheduling room ${roomId}`);
 		const jobName = `${SCHEDULER_NAME}-${roomId}`;
 		await this.scheduler.cancel({ name: jobName });
 	}
 
 	private async executeJob({ attrs: { data } }: any = {}): Promise<void> {
+		this.logger.debug(`Executing job for room ${data.roomId}`);
 		const { roomId, comment } = data;
 
 		const [room, user] = await Promise.all([LivechatRooms.findOneById(roomId), this.getSchedulerUser()]);
@@ -62,6 +75,7 @@ class AutoCloseOnHoldSchedulerClass {
 			comment,
 		};
 
+		this.logger.debug(`Closing room ${roomId}`);
 		await Livechat.closeRoom(payload);
 	}
 

apps/meteor/ee/app/livechat-enterprise/server/lib/AutoTransferChatScheduler.ts

@@ -8,6 +8,8 @@ import { Livechat } from '../../../../../app/livechat/server';
 import { RoutingManager } from '../../../../../app/livechat/server/lib/RoutingManager';
 import { forwardRoomToAgent } from '../../../../../app/livechat/server/lib/Helper';
 import { settings } from '../../../../../app/settings/server';
+import { schedulerLogger } from './logger';
+import type { MainLogger } from '../../../../../server/lib/logger/getPino';
 
 const SCHEDULER_NAME = 'omnichannel_scheduler';
 
@@ -18,8 +20,15 @@ class AutoTransferChatSchedulerClass {
 
 	user: IUser;
 
+	logger: MainLogger;
+
+	constructor() {
+		this.logger = schedulerLogger.section('AutoTransferChatScheduler');
+	}
+
 	public async init(): Promise<void> {
 		if (this.running) {
+			this.logger.debug('Already running');
 			return;
 		}
 
@@ -31,6 +40,7 @@ class AutoTransferChatSchedulerClass {
 
 		await this.scheduler.start();
 		this.running = true;
+		this.logger.debug('Started');
 	}
 
 	private async getSchedulerUser(): Promise<IUser | null> {
@@ -38,6 +48,7 @@ class AutoTransferChatSchedulerClass {
 	}
 
 	public async scheduleRoom(roomId: string, timeout: number): Promise<void> {
+		this.logger.debug(`Scheduling room ${roomId} to be transferred in ${timeout} seconds`);
 		await this.unscheduleRoom(roomId);
 
 		const jobName = `${SCHEDULER_NAME}-${roomId}`;
@@ -47,9 +58,11 @@ class AutoTransferChatSchedulerClass {
 		this.scheduler.define(jobName, this.executeJob.bind(this));
 		await this.scheduler.schedule(when, jobName, { roomId });
 		await LivechatRooms.setAutoTransferOngoingById(roomId);
+		this.logger.debug(`Scheduled room ${roomId} to be transferred in ${timeout} seconds`);
 	}
 
 	public async unscheduleRoom(roomId: string): Promise<void> {
+		this.logger.debug(`Unscheduling room ${roomId}`);
 		const jobName = `${SCHEDULER_NAME}-${roomId}`;
 
 		await LivechatRooms.unsetAutoTransferOngoingById(roomId);
@@ -57,6 +70,7 @@ class AutoTransferChatSchedulerClass {
 	}
 
 	private async transferRoom(roomId: string): Promise<boolean> {
+		this.logger.debug(`Transferring room ${roomId}`);
 		const room = await LivechatRooms.findOneById(roomId, {
 			_id: 1,
 			v: 1,
@@ -76,6 +90,7 @@ class AutoTransferChatSchedulerClass {
 		const timeoutDuration = settings.get<number>('Livechat_auto_transfer_chat_timeout').toString();
 
 		if (!RoutingManager.getConfig().autoAssignAgent) {
+			this.logger.debug(`Auto-assign agent is disabled, returning room ${roomId} as inquiry`);
 			return Livechat.returnRoomAsInquiry(room._id, departmentId, {
 				scope: 'autoTransferUnansweredChatsToQueue',
 				comment: timeoutDuration,
@@ -85,6 +100,7 @@ class AutoTransferChatSchedulerClass {
 
 		const agent = await RoutingManager.getNextAgent(departmentId, ignoreAgentId);
 		if (agent) {
+			this.logger.debug(`Transferring room ${roomId} to agent ${agent.agentId}`);
 			return forwardRoomToAgent(room, {
 				userId: agent.agentId,
 				transferredBy: await this.getSchedulerUser(),
@@ -94,6 +110,7 @@ class AutoTransferChatSchedulerClass {
 			});
 		}
 
+		this.logger.debug(`No agent found to transfer room ${roomId}`);
 		return false;
 	}
 

apps/meteor/ee/app/livechat-enterprise/server/lib/QueueInactivityMonitor.ts

@@ -6,9 +6,10 @@ import type { IUser, IOmnichannelRoom } from '@rocket.chat/core-typings';
 import { LivechatRooms, LivechatInquiry as LivechatInquiryRaw, Users } from '@rocket.chat/models';
 
 import { settings } from '../../../../../app/settings/server';
-import { Logger } from '../../../../../app/logger/server';
 import { Livechat } from '../../../../../app/livechat/server/lib/LivechatTyped';
 import { i18n } from '../../../../../server/lib/i18n';
+import { schedulerLogger } from './logger';
+import type { MainLogger } from '../../../../../server/lib/logger/getPino';
 
 const SCHEDULER_NAME = 'omnichannel_queue_inactivity_monitor';
 
@@ -17,7 +18,7 @@ class OmnichannelQueueInactivityMonitorClass {
 
 	running: boolean;
 
-	logger: Logger;
+	logger: MainLogger;
 
 	_name: string;
 
@@ -33,7 +34,7 @@ class OmnichannelQueueInactivityMonitorClass {
 		this._db = MongoInternals.defaultRemoteCollectionDriver().mongo.db;
 		this.running = false;
 		this._name = 'Omnichannel-Queue-Inactivity-Monitor';
-		this.logger = new Logger('QueueInactivityMonitor');
+		this.logger = schedulerLogger.section(this._name);
 		this.scheduler = new Agenda({
 			mongo: (MongoInternals.defaultRemoteCollectionDriver().mongo as any).client.db(),
 			db: { collection: SCHEDULER_NAME },

apps/meteor/ee/app/livechat-enterprise/server/lib/VisitorInactivityMonitor.ts

@@ -5,8 +5,9 @@ import { cronJobs } from '@rocket.chat/cron';
 import { settings } from '../../../../../app/settings/server';
 import { Livechat } from '../../../../../app/livechat/server/lib/LivechatTyped';
 import { LivechatEnterprise } from './LivechatEnterprise';
-import { logger } from './logger';
 import { i18n } from '../../../../../server/lib/i18n';
+import { schedulerLogger } from './logger';
+import type { MainLogger } from '../../../../../server/lib/logger/getPino';
 
 const isPromiseRejectedResult = (result: any): result is PromiseRejectedResult => result && result.status === 'rejected';
 
@@ -19,15 +20,19 @@ export class VisitorInactivityMonitor {
 
 	user: IUser;
 
+	logger: MainLogger;
+
 	private scheduler = cronJobs;
 
 	constructor() {
 		this._started = false;
 		this._name = 'Omnichannel Visitor Inactivity Monitor';
 		this.messageCache = new Map();
+		this.logger = schedulerLogger.section(this._name);
 	}
 
 	async start() {
+		this.logger.debug('Starting');
 		await this._startMonitoring();
 		this._initializeMessageCache();
 		const cat = await Users.findOneById('rocket.cat');
@@ -38,20 +43,24 @@ export class VisitorInactivityMonitor {
 
 	private async _startMonitoring() {
 		if (this.isRunning()) {
+			this.logger.debug('Already running');
 			return;
 		}
 		const everyMinute = '* * * * *';
 		await this.scheduler.add(this._name, everyMinute, async () => this.handleAbandonedRooms());
 		this._started = true;
+		this.logger.debug('Started');
 	}
 
 	async stop() {
 		if (!this.isRunning()) {
+			this.logger.debug('Not running');
 			return;
 		}
 		await this.scheduler.remove(this._name);
 
 		this._started = false;
+		this.logger.debug('Stopped');
 	}
 
 	isRunning() {
@@ -64,18 +73,23 @@ export class VisitorInactivityMonitor {
 	}
 
 	async _getDepartmentAbandonedCustomMessage(departmentId: string) {
+		this.logger.debug(`Getting department abandoned custom message for department ${departmentId}`);
 		if (this.messageCache.has('departmentId')) {
+			this.logger.debug(`Using cached department abandoned custom message for department ${departmentId}`);
 			return this.messageCache.get('departmentId');
 		}
 		const department = await LivechatDepartment.findOneById(departmentId);
 		if (!department) {
+			this.logger.debug(`Department ${departmentId} not found`);
 			return;
 		}
+		this.logger.debug(`Setting department abandoned custom message for department ${departmentId}`);
 		this.messageCache.set(department._id, department.abandonedRoomsCloseCustomMessage);
 		return department.abandonedRoomsCloseCustomMessage;
 	}
 
 	async closeRooms(room: IOmnichannelRoom) {
+		this.logger.debug(`Closing room ${room._id}`);
 		let comment = this.messageCache.get('default');
 		if (room.departmentId) {
 			comment = (await this._getDepartmentAbandonedCustomMessage(room.departmentId)) || comment;
@@ -85,18 +99,22 @@ export class VisitorInactivityMonitor {
 			room,
 			user: this.user,
 		});
+		this.logger.debug(`Room ${room._id} closed`);
 	}
 
 	async placeRoomOnHold(room: IOmnichannelRoom) {
+		this.logger.debug(`Placing room ${room._id} on hold`);
 		const timeout = settings.get<number>('Livechat_visitor_inactivity_timeout');
 
 		const { v: { _id: visitorId } = {} } = room;
 		if (!visitorId) {
+			this.logger.debug(`Room ${room._id} does not have a visitor`);
 			throw new Error('error-invalid_visitor');
 		}
 
 		const visitor = await LivechatVisitors.findOneById(visitorId);
 		if (!visitor) {
+			this.logger.debug(`Room ${room._id} does not have a visitor`);
 			throw new Error('error-invalid_visitor');
 		}
 
@@ -107,15 +125,17 @@ export class VisitorInactivityMonitor {
 			LivechatEnterprise.placeRoomOnHold(room, comment, this.user),
 			LivechatRooms.unsetPredictedVisitorAbandonmentByRoomId(room._id),
 		]);
+		this.logger.debug(`Room ${room._id} placed on hold`);
 		const rejected = result.filter(isPromiseRejectedResult).map((r) => r.reason);
 		if (rejected.length) {
-			logger.error({ msg: 'Error placing room on hold', error: rejected });
+			this.logger.error({ msg: 'Error placing room on hold', error: rejected });
 
 			throw new Error('Error placing room on hold. Please check logs for more details.');
 		}
 	}
 
 	async handleAbandonedRooms() {
+		this.logger.debug('Handling abandoned rooms');
 		const action = settings.get<string>('Livechat_abandoned_rooms_action');
 		if (!action || action === 'none') {
 			return;
@@ -125,10 +145,12 @@ export class VisitorInactivityMonitor {
 		await LivechatRooms.findAbandonedOpenRooms(new Date()).forEach((room) => {
 			switch (action) {
 				case 'close': {
+					this.logger.debug(`Closing room ${room._id}`);
 					promises.push(this.closeRooms(room));
 					break;
 				}
 				case 'on-hold': {
+					this.logger.debug(`Placing room ${room._id} on hold`);
 					promises.push(this.placeRoomOnHold(room));
 					break;
 				}
@@ -140,8 +162,8 @@ export class VisitorInactivityMonitor {
 		const errors = result.filter(isPromiseRejectedResult).map((r) => r.reason);
 
 		if (errors.length) {
-			logger.error({ msg: `Error while removing priority from ${errors.length} rooms`, reason: errors[0] });
-			logger.debug({ msg: 'Rejection results', errors });
+			this.logger.error({ msg: `Error while removing priority from ${errors.length} rooms`, reason: errors[0] });
+			this.logger.debug({ msg: 'Rejection results', errors });
 		}
 
 		this._initializeMessageCache();

apps/meteor/ee/app/livechat-enterprise/server/lib/logger.ts

@@ -7,3 +7,5 @@ export const queueLogger = logger.section('Queue');
 export const helperLogger = logger.section('Helper');
 export const cbLogger = logger.section('Callbacks');
 export const bhLogger = logger.section('Business-Hours');
+
+export const schedulerLogger = new Logger('Scheduler');