chore: Logging (#37956)

apps/meteor/app/api/server/helpers/parseJsonQuery.ts

@@ -43,8 +43,12 @@ export async function parseJsonQuery(api: GenericRouteExecutionContext): Promise
 				}
 			});
 		} catch (e) {
-			logger.warn(`Invalid sort parameter provided "${params.sort}":`, e);
-			throw new Meteor.Error('error-invalid-sort', `Invalid sort parameter provided: "${params.sort}"`, {
+			logger.warn({
+				msg: 'Invalid sort parameter provided',
+				sort: params.sort,
+				err: e,
+			});
+			throw new Meteor.Error('error-invalid-sort', `Invalid sort parameter provided: \"${params.sort}\"`, {
 				helperMethod: 'parseJsonQuery',
 			});
 		}
@@ -67,8 +71,12 @@ export async function parseJsonQuery(api: GenericRouteExecutionContext): Promise
 				}
 			});
 		} catch (e) {
-			logger.warn(`Invalid fields parameter provided "${params.fields}":`, e);
-			throw new Meteor.Error('error-invalid-fields', `Invalid fields parameter provided: "${params.fields}"`, {
+			logger.warn({
+				msg: 'Invalid fields parameter provided',
+				fields: params.fields,
+				err: e,
+			});
+			throw new Meteor.Error('error-invalid-fields', `Invalid fields parameter provided: \"${params.fields}\"`, {
 				helperMethod: 'parseJsonQuery',
 			});
 		}
@@ -111,8 +119,12 @@ export async function parseJsonQuery(api: GenericRouteExecutionContext): Promise
 			query = ejson.parse(params.query);
 			query = clean(query, pathAllowConf.def);
 		} catch (e) {
-			logger.warn(`Invalid query parameter provided "${params.query}":`, e);
-			throw new Meteor.Error('error-invalid-query', `Invalid query parameter provided: "${params.query}"`, {
+			logger.warn({
+				msg: 'Invalid query parameter provided',
+				query: params.query,
+				err: e,
+			});
+			throw new Meteor.Error('error-invalid-query', `Invalid query parameter provided: \"${params.query}\"`, {
 				helperMethod: 'parseJsonQuery',
 			});
 		}

apps/meteor/app/cors/server/cors.ts

@@ -169,11 +169,7 @@ WebApp.httpServer.addListener('request', (req, res, ...args) => {
 	// @ts-expect-error - `pair` is valid, but doesnt exists on types
 	const isSsl = req.connection.pair || (req.headers['x-forwarded-proto'] && req.headers['x-forwarded-proto'].indexOf('https') !== -1);
 
-	logger.debug('req.url', req.url);
-	logger.debug('remoteAddress', remoteAddress);
-	logger.debug('isLocal', isLocal);
-	logger.debug('isSsl', isSsl);
-	logger.debug('req.headers', req.headers);
+	logger.debug({ msg: 'CORS request info', url: req.url, remoteAddress, isLocal, isSsl, headers: req.headers });
 
 	if (!isLocal && !isSsl) {
 		let host = req.headers.host || url.parse(Meteor.absoluteUrl()).hostname || '';

apps/meteor/app/crowd/server/crowd.ts

@@ -25,7 +25,7 @@ function fallbackDefaultAccountSystem(bind: typeof Accounts, username: string |
 		}
 	}
 
-	logger.info('Fallback to default account system', username);
+	logger.info({ msg: 'Fallback to default account system', username });
 
 	const loginRequest = {
 		user: username,
@@ -125,7 +125,7 @@ export class CROWD {
 			if (user) {
 				crowdUsername = user.crowd_username;
 			} else {
-				logger.debug('Could not find a user by email', username);
+				logger.debug({ msg: 'Could not find a user by email', username });
 			}
 		}
 
@@ -143,7 +143,7 @@ export class CROWD {
 			if (user) {
 				crowdUsername = user.crowd_username;
 			} else {
-				logger.debug('Could not find a user with by crowd_username', username);
+				logger.debug({ msg: 'Could not find a user with by crowd_username', username });
 			}
 		}
 
@@ -157,7 +157,7 @@ export class CROWD {
 		if (!user && crowdUsername) {
 			logger.debug('New user. User is not synced yet.');
 		}
-		logger.debug('Going to crowd:', crowdUsername);
+		logger.debug({ msg: 'Going to crowd', crowdUsername });
 
 		return new Promise((resolve, reject) =>
 			this.crowdClient.user.authenticate(crowdUsername, password, async (err: any, res: Record<string, any>) => {
@@ -241,9 +241,9 @@ export class CROWD {
 
 		for await (const user of users) {
 			let crowdUsername = user.hasOwnProperty('crowd_username') ? user.crowd_username : user.username;
-			logger.info('Syncing user', crowdUsername);
+			logger.info({ msg: 'Syncing user', crowdUsername });
 			if (!crowdUsername) {
-				logger.warn('User has no crowd_username', user.username);
+				logger.warn({ msg: 'User has no crowd_username', username: user.username });
 				continue;
 			}
 
@@ -252,28 +252,28 @@ export class CROWD {
 			try {
 				crowdUser = await this.fetchCrowdUser(crowdUsername);
 			} catch (err) {
-				logger.debug({ err });
+				logger.debug({ msg: 'Error while syncing user from CROWD', err });
 				logger.error({ msg: 'Could not sync user with username', crowd_username: crowdUsername });
 
 				const email = user.emails?.[0].address;
-				logger.info('Attempting to find for user by email', email);
+				logger.info({ msg: 'Attempting to find user by email', email });
 
 				const response = await this.searchForCrowdUserByMail(email);
 				if (!response || response.users.length === 0) {
-					logger.warn('Could not find user in CROWD with username or email:', crowdUsername, email);
+					logger.warn({ msg: 'Could not find user in CROWD with username or email', crowd_username: crowdUsername, email });
 					if (settings.get('CROWD_Remove_Orphaned_Users') === true) {
-						logger.info('Removing user:', crowdUsername);
+						logger.info({ msg: 'Removing user', crowd_username: crowdUsername });
 						setImmediate(async () => {
 							await deleteUser(user._id);
-							logger.info('User removed:', crowdUsername);
+							logger.info({ msg: 'User removed', crowd_username: crowdUsername });
 						});
 					}
 					return;
 				}
 				crowdUsername = response.users[0].name;
-				logger.info('User found by email. Syncing user', crowdUsername);
+				logger.info({ msg: 'User found by email. Syncing user', crowd_username: crowdUsername });
 				if (!crowdUsername) {
-					logger.warn('User has no crowd_username', user.username);
+					logger.warn({ msg: 'User has no crowd_username', username: user.username });
 					continue;
 				}
 
@@ -368,7 +368,7 @@ Accounts.registerLoginHandler('crowd', async function (this: typeof Accounts, lo
 		return undefined;
 	}
 
-	logger.info('Init CROWD login', loginRequest.username);
+	logger.info({ msg: 'Init CROWD login', username: loginRequest.username });
 
 	if (settings.get('CROWD_Enable') !== true) {
 		return fallbackDefaultAccountSystem(this, loginRequest.username, loginRequest.crowdPassword);
@@ -379,12 +379,12 @@ Accounts.registerLoginHandler('crowd', async function (this: typeof Accounts, lo
 		const user = await crowd.authenticate(loginRequest.username, loginRequest.crowdPassword);
 
 		if (user && user.crowd === false) {
-			logger.debug(`User ${loginRequest.username} is not a valid crowd user, falling back`);
+			logger.debug({ msg: 'User is not a valid crowd user, falling back', username: loginRequest.username });
 			return fallbackDefaultAccountSystem(this, loginRequest.username, loginRequest.crowdPassword);
 		}
 
 		if (!user) {
-			logger.debug(`User ${loginRequest.username} is not allowed to access Rocket.Chat`);
+			logger.debug({ msg: 'User is not allowed to access Rocket.Chat', username: loginRequest.username });
 			return new Meteor.Error('not-authorized', 'User is not authorized by crowd');
 		}
 

apps/meteor/app/importer-csv/server/CsvImporter.ts

@@ -40,7 +40,7 @@ export class CsvImporter extends Importer {
 					oldRate = rate;
 				}
 			} catch (e) {
-				this.logger.error(e);
+				this.logger.error({ msg: 'Error while increasing CSV import progress', err: e });
 			}
 		};
 
@@ -66,18 +66,18 @@ export class CsvImporter extends Importer {
 		};
 
 		for await (const entry of zip.getEntries()) {
-			this.logger.debug(`Entry: ${entry.entryName}`);
+			this.logger.debug({ msg: 'Entry', entryName: entry.entryName });
 
 			// Ignore anything that has `__MACOSX` in it's name, as sadly these things seem to mess everything up
 			if (entry.entryName.indexOf('__MACOSX') > -1) {
-				this.logger.debug(`Ignoring the file: ${entry.entryName}`);
+				this.logger.debug({ msg: 'Ignoring the file', entryName: entry.entryName });
 				increaseProgressCount();
 				continue;
 			}
 
 			// Directories are ignored, since they are "virtual" in a zip file
 			if (entry.isDirectory) {
-				this.logger.debug(`Ignoring the directory entry: ${entry.entryName}`);
+				this.logger.debug({ msg: 'Ignoring the directory entry', entryName: entry.entryName });
 				increaseProgressCount();
 				continue;
 			}
@@ -168,7 +168,7 @@ export class CsvImporter extends Importer {
 				try {
 					msgs = this.csvParser(entry.getData().toString());
 				} catch (e) {
-					this.logger.warn(`The file ${entry.entryName} contains invalid syntax`, e);
+					this.logger.warn({ msg: 'The file contains invalid syntax', entryName: entry.entryName, err: e });
 					increaseProgressCount();
 					continue;
 				}
@@ -277,7 +277,7 @@ export class CsvImporter extends Importer {
 
 		// Ensure we have at least a single record of any kind
 		if (usersCount === 0 && channelsCount === 0 && messagesCount === 0 && contactsCount === 0) {
-			this.logger.error('No valid record found in the import file.');
+			this.logger.error({ msg: 'No valid record found in the import file.' });
 			await super.updateProgress(ProgressStep.ERROR);
 		}
 

apps/meteor/app/importer-pending-avatars/server/PendingAvatarImporter.ts

@@ -7,7 +7,7 @@ import { setAvatarFromServiceWithValidation } from '../../lib/server/functions/s
 
 export class PendingAvatarImporter extends Importer {
 	async prepareFileCount() {
-		this.logger.debug('start preparing import operation');
+		this.logger.debug({ msg: 'start preparing import operation' });
 		await super.updateProgress(ProgressStep.PREPARING_STARTED);
 
 		const fileCount = await Users.countAllUsersWithPendingAvatar();
@@ -49,13 +49,13 @@ export class PendingAvatarImporter extends Importer {
 							await setAvatarFromServiceWithValidation(_id, url, undefined, 'url');
 							await Users.updateOne({ _id }, { $unset: { _pendingAvatarUrl: '' } });
 						} catch (error) {
-							this.logger.warn(`Failed to set ${name}'s avatar from url ${url}`);
+							this.logger.warn({ msg: 'Failed to set user avatar from pending URL', name, url });
 						}
 					} finally {
 						await this.addCountCompleted(1);
 					}
 				} catch (error) {
-					this.logger.error(error);
+					this.logger.error({ msg: 'Failed to process pending avatar for user', err: error });
 				}
 			}
 		} catch (error) {

apps/meteor/app/importer-slack/server/SlackImporter.ts

@@ -125,7 +125,7 @@ export class SlackImporter extends Importer {
 			(channel): channel is SlackChannel & { creator: string } => 'creator' in channel && channel.creator != null,
 		);
 
-		this.logger.debug(`loaded ${data.length} channels.`);
+		this.logger.debug({ msg: 'loaded channels', count: data.length });
 
 		await this.addCountToTotal(data.length);
 
@@ -155,7 +155,7 @@ export class SlackImporter extends Importer {
 			(channel): channel is SlackChannel & { creator: string } => 'creator' in channel && channel.creator != null,
 		);
 
-		this.logger.debug(`loaded ${data.length} groups.`);
+		this.logger.debug({ msg: 'loaded groups', count: data.length });
 
 		await this.addCountToTotal(data.length);
 
@@ -184,7 +184,7 @@ export class SlackImporter extends Importer {
 			(channel): channel is SlackChannel & { creator: string } => 'creator' in channel && channel.creator != null,
 		);
 
-		this.logger.debug(`loaded ${data.length} mpims.`);
+		this.logger.debug({ msg: 'loaded mpims', count: data.length });
 
 		await this.addCountToTotal(data.length);
 
@@ -213,7 +213,7 @@ export class SlackImporter extends Importer {
 		await super.updateProgress(ProgressStep.PREPARING_CHANNELS);
 		const data = JSON.parse(entry.getData().toString()) as SlackChannel[];
 
-		this.logger.debug(`loaded ${data.length} dms.`);
+		this.logger.debug({ msg: 'loaded dms', count: data.length });
 
 		await this.addCountToTotal(data.length);
 		for await (const channel of data) {
@@ -232,7 +232,7 @@ export class SlackImporter extends Importer {
 		await super.updateProgress(ProgressStep.PREPARING_USERS);
 		const data = JSON.parse(entry.getData().toString()) as SlackUser[];
 
-		this.logger.debug(`loaded ${data.length} users.`);
+		this.logger.debug({ msg: 'loaded users', count: data.length });
 
 		// Insert the users record
 		await this.updateRecord({ 'count.users': data.length });
@@ -352,7 +352,7 @@ export class SlackImporter extends Importer {
 				try {
 					if (entry.entryName.includes('__MACOSX') || entry.entryName.includes('.DS_Store')) {
 						count++;
-						this.logger.debug(`Ignoring the file: ${entry.entryName}`);
+						this.logger.debug({ msg: 'Ignoring the file', entryName: entry.entryName });
 						continue;
 					}
 
@@ -385,7 +385,7 @@ export class SlackImporter extends Importer {
 								}
 							}
 						} catch (error) {
-							this.logger.warn(`${entry.entryName} is not a valid JSON file! Unable to import it.`);
+							this.logger.warn({ msg: 'Entry is not a valid JSON file; unable to import', entryName: entry.entryName, err: error });
 						}
 					}
 				} catch (e) {
@@ -626,7 +626,10 @@ export class SlackImporter extends Importer {
 								newMessage.replies = Array.from(replies);
 							}
 						} else {
-							this.logger.warn(`Failed to import the parent comment, message: ${newMessage._id}. Missing replies/reply_users field`);
+							this.logger.warn({
+								msg: 'Failed to import the parent comment; missing replies/reply_users field',
+								messageId: newMessage._id,
+							});
 						}
 
 						newMessage.tcount = message.reply_count;

apps/meteor/app/importer/server/classes/Importer.ts

@@ -71,7 +71,7 @@ export class Importer {
 		this._lastProgressReportTotal = 0;
 		this.reloadCount();
 
-		this.logger.debug(`Constructed a new ${this.info.name} Importer.`);
+		this.logger.debug({ msg: 'Constructed a new Importer.', importerName: this.info.name });
 	}
 
 	/**
@@ -220,14 +220,14 @@ export class Importer {
 
 				await this.updateProgress(ProgressStep.DONE);
 			} catch (e) {
-				this.logger.error(e);
+				this.logger.error({ msg: 'Importer encountered an error during import', err: e });
 				await this.updateProgress(ProgressStep.ERROR);
 			} finally {
 				await this.applySettingValues(this.oldSettings);
 			}
 
 			const timeTook = Date.now() - started;
-			this.logger.log(`Import took ${timeTook} milliseconds.`);
+			this.logger.log({ msg: 'Import completed', durationMs: timeTook });
 		});
 
 		return this.getProgress();
@@ -279,7 +279,7 @@ export class Importer {
 	async updateProgress(step: IImportProgress['step']): Promise<ImporterProgress> {
 		this.progress.step = step;
 
-		this.logger.debug(`${this.info.name} is now at ${step}.`);
+		this.logger.debug({ msg: 'Importer progress step updated', importerName: this.info.name, step });
 		await this.updateRecord({ status: this.progress.step });
 
 		// Do not send the default progress report during the preparing stage - the classes are sending their own report in a different format.
@@ -343,7 +343,11 @@ export class Importer {
 			}, 250);
 		}
 
-		this.logger.log(`${this.progress.count.completed} records imported, ${this.progress.count.error} failed`);
+		this.logger.log({
+			msg: 'Import progress update',
+			completed: this.progress.count.completed,
+			failed: this.progress.count.error,
+		});
 
 		return this.progress;
 	}

apps/meteor/app/importer/server/classes/converters/RecordConverter.ts

@@ -108,7 +108,11 @@ export class RecordConverter<R extends IImportRecord, T extends RecordConverterO
 	}
 
 	protected async saveError(importId: string, error: Error): Promise<void> {
-		this._logger.error(error);
+		this._logger.error({
+			msg: 'Import record conversion failed',
+			importId,
+			err: error,
+		});
 		this.saveErrorToMemory(importId, error);
 
 		if (!this._converterOptions.workInMemory) {

apps/meteor/app/importer/server/classes/converters/RoomConverter.ts

@@ -98,7 +98,10 @@ export class RoomConverter extends RecordConverter<IImportChannelRecord> {
 
 		if (roomData.t === 'd') {
 			if (members.length < roomData.users.length) {
-				this._logger.warn(`One or more imported users not found: ${roomData.users}`);
+				this._logger.warn({
+					msg: 'One or more imported users not found',
+					users: roomData.users,
+				});
 				throw new Error('importer-channel-missing-users');
 			}
 		}
@@ -125,8 +128,7 @@ export class RoomConverter extends RecordConverter<IImportChannelRecord> {
 
 			roomData._id = roomInfo.rid;
 		} catch (e) {
-			this._logger.warn({ msg: 'Failed to create new room', name: roomData.name, members });
-			this._logger.error(e);
+			this._logger.warn({ msg: 'Failed to create new room', name: roomData.name, members, err: e });
 			throw e;
 		}
 

apps/meteor/app/integrations/server/api/api.ts

@@ -318,7 +318,7 @@ class WebHookAPI extends APIClass<'/hooks'> {
 		const integration = await Integrations.findOneByIdAndToken<IIncomingIntegration>(integrationId, decodeURIComponent(token));
 
 		if (!integration) {
-			incomingLogger.info(`Invalid integration id ${integrationId} or token ${token}`);
+			incomingLogger.info({ msg: 'Invalid integration id or token', integrationId, token });
 
 			throw new Error('Invalid integration id or token provided.');
 		}