feat(logger): add dailyRotateFile to default transport & add trace level (#4429)

packages/core/database/src/collection.ts

@@ -332,7 +332,7 @@ export class Collection<
 
     const { database } = this.context;
 
-    database.logger.debug(`beforeSetField: ${safeJsonStringify(options)}`, {
+    database.logger.trace(`beforeSetField: ${safeJsonStringify(options)}`, {
       databaseInstanceId: database.instanceId,
       collectionName: this.name,
       fieldName: name,

packages/core/database/src/database.ts

@@ -530,7 +530,7 @@ export class Database extends EventEmitter implements AsyncEmitter {
       options.underscored = true;
     }
 
-    this.logger.debug(`beforeDefineCollection: ${safeJsonStringify(options)}`, {
+    this.logger.trace(`beforeDefineCollection: ${safeJsonStringify(options)}`, {
       databaseInstanceId: this.instanceId,
     });
 

packages/core/logger/src/config.ts

@@ -17,10 +17,7 @@ export const getLoggerFilePath = (...paths: string[]): string => {
 };
 
 export const getLoggerTransport = (): ('console' | 'file' | 'dailyRotateFile')[] =>
-  (
-    (process.env.LOGGER_TRANSPORT as any) ||
-    (process.env.APP_ENV === 'development' ? 'console' : 'console,dailyRotateFile')
-  ).split(',');
+  ((process.env.LOGGER_TRANSPORT as any) || 'console,dailyRotateFile').split(',');
 
 export const getLoggerFormat = (): 'logfmt' | 'json' | 'delimiter' | 'console' =>
   (process.env.LOGGER_FORMAT as any) || (process.env.APP_ENV === 'development' ? 'console' : 'json');

packages/core/logger/src/format.ts

@@ -124,7 +124,7 @@ export const consoleFormat: winston.Logform.Format = winston.format.printf((info
     .map(([k, v]) => `${k}=${v}`)
     .join(' ');
 
-  const level = info.level.padEnd(5, ' ');
+  const level = `[${info.level}]`.padEnd(7, ' ');
   const message = info.message.padEnd(44, ' ');
   const color =
     {
@@ -132,10 +132,11 @@ export const consoleFormat: winston.Logform.Format = winston.format.printf((info
       warn: chalk.yellow,
       info: chalk.green,
       debug: chalk.blue,
+      trace: chalk.cyan,
     }[info.level] || chalk.white;
   const colorized = message.startsWith('Executing')
-    ? color(`${info.timestamp} [${level}]`) + ` ${message}`
-    : color(`${info.timestamp} [${level}] ${message}`);
+    ? color(`${info.timestamp} ${level}`) + ` ${message}`
+    : color(`${info.timestamp} ${level} ${message}`);
   return `${colorized} ${tags}`;
 });
 

packages/core/logger/src/logger.ts

@@ -7,12 +7,16 @@
  * For more information, please refer to: https://www.nocobase.com/agreement.
  */
 
-import winston, { Logger } from 'winston';
+import winston, { LeveledLogMethod, Logger as WinstonLogger } from 'winston';
 import 'winston-daily-rotate-file';
 import { getLoggerLevel } from './config';
 import { getTransports } from './transports';
 import { consoleFormat } from './format';
 
+interface Logger extends WinstonLogger {
+  trace: LeveledLogMethod;
+}
+
 interface LoggerOptions extends Omit<winston.LoggerOptions, 'transports' | 'format'> {
   dirname?: string;
   filename?: string;
@@ -20,17 +24,26 @@ interface LoggerOptions extends Omit<winston.LoggerOptions, 'transports' | 'form
   transports?: ('console' | 'file' | 'dailyRotateFile' | winston.transport)[];
 }
 
+export const levels = {
+  trace: 4,
+  debug: 3,
+  info: 2,
+  warn: 1,
+  error: 0,
+};
+
 export const createLogger = (options: LoggerOptions) => {
   if (process.env.GITHUB_ACTIONS) {
     return createConsoleLogger();
   }
   const { format, ...rest } = options;
   const winstonOptions = {
+    levels,
     level: getLoggerLevel(),
     ...rest,
     transports: getTransports(options),
   };
-  return winston.createLogger(winstonOptions);
+  return winston.createLogger(winstonOptions) as Logger;
 };
 
 /**
@@ -39,6 +52,7 @@ export const createLogger = (options: LoggerOptions) => {
 export const createConsoleLogger = (options?: winston.LoggerOptions) => {
   const { format, ...rest } = options || {};
   return winston.createLogger({
+    levels,
     level: getLoggerLevel(),
     format: winston.format.combine(
       winston.format.timestamp({
@@ -48,7 +62,7 @@ export const createConsoleLogger = (options?: winston.LoggerOptions) => {
     ),
     ...(rest || {}),
     transports: [new winston.transports.Console()],
-  });
+  }) as Logger;
 };
 
 export { Logger, LoggerOptions };

packages/core/logger/src/system-logger.ts

@@ -7,8 +7,8 @@
  * For more information, please refer to: https://www.nocobase.com/agreement.
  */
 
-import winston, { format, Logger } from 'winston';
-import { createLogger, LoggerOptions } from './logger';
+import winston, { format } from 'winston';
+import { createLogger, Logger, LoggerOptions, levels } from './logger';
 import Transport from 'winston-transport';
 import { SPLAT } from 'triple-beam';
 import { getFormat } from './format';
@@ -27,11 +27,12 @@ export type logMethod = (
   },
 ) => SystemLogger;
 
-export interface SystemLogger extends Omit<Logger, 'info' | 'warn' | 'error' | 'debug'> {
+export interface SystemLogger extends Omit<Logger, 'info' | 'warn' | 'error' | 'debug' | 'trace'> {
   info: logMethod;
   warn: logMethod;
   error: logMethod;
   debug: logMethod;
+  trace: logMethod;
 }
 
 class SystemLoggerTransport extends Transport {
@@ -120,8 +121,11 @@ export const createSystemLogger = (options: SystemLoggerOptions): SystemLogger =
     transport.close();
   });
   const logger = winston.createLogger({
+    levels,
     transports: [transport],
-  });
+    // Due to the use of custom log levels,
+    // we have to use the any type until Winston updates the type definitions.
+  }) as any;
 
   // Since error.cause is not supported by child logger of winston
   // we have to use a proxy to rewrite child method

packages/core/server/src/application.ts

@@ -550,9 +550,11 @@ export class Application<StateT = DefaultState, ContextT = DefaultContext> exten
 
     this._cacheManager = await createCacheManager(this, this.options.cacheManager);
 
+    this.log.debug('init plugins');
     this.setMaintainingMessage('init plugins');
     await this.pm.initPlugins();
 
+    this.log.debug('loading app...');
     this.setMaintainingMessage('start load');
     this.setMaintainingMessage('emit beforeLoad');
 
@@ -697,7 +699,7 @@ export class Application<StateT = DefaultState, ContextT = DefaultContext> exten
     }
     if (options?.reqId) {
       this.context.reqId = options.reqId;
-      this._logger = this._logger.child({ reqId: this.context.reqId });
+      this._logger = this._logger.child({ reqId: this.context.reqId }) as any;
     }
     this._maintainingStatusBeforeCommand = this._maintainingCommandStatus;
 
@@ -761,6 +763,7 @@ export class Application<StateT = DefaultState, ContextT = DefaultContext> exten
       );
     }
 
+    this.log.debug(`starting app...`);
     this.setMaintainingMessage('starting app...');
 
     if (this.db.closed()) {
@@ -1065,7 +1068,9 @@ export class Application<StateT = DefaultState, ContextT = DefaultContext> exten
       reqId: this.context.reqId,
       app: this.name,
       module: 'application',
-    });
+      // Due to the use of custom log levels,
+      // we have to use any type here until Winston updates the type definitions.
+    }) as any;
     this.requestLogger = createLogger({
       dirname: getLoggerFilePath(this.name),
       filename: 'request',

packages/core/server/src/locale/locale.ts

@@ -24,7 +24,7 @@ export class Locale {
   constructor(app: Application) {
     this.app = app;
     this.app.on('afterLoad', async () => {
-      this.app.log.debug('load locale resource', { submodule: 'locale', method: 'onAfterLoad' });
+      this.app.log.debug('loading locale resource...', { submodule: 'locale', method: 'onAfterLoad' });
       this.app.setMaintainingMessage('load locale resource');
       await this.load();
       this.app.log.debug('locale resource loaded', { submodule: 'locale', method: 'onAfterLoad' });

packages/core/server/src/plugin-manager/plugin-manager.ts

@@ -351,7 +351,7 @@ export class PluginManager {
       console.error(error);
       // empty
     }
-    this.app.log.debug(`add plugin [${options.name}]`, {
+    this.app.log.trace(`add plugin [${options.name}]`, {
       method: 'add',
       submodule: 'plugin-manager',
       name: options.name,
@@ -429,6 +429,7 @@ export class PluginManager {
   }
 
   async load(options: any = {}) {
+    this.app.log.debug('loading plugins...');
     this.app.setMaintainingMessage('loading plugins...');
     const total = this.pluginInstances.size;
 
@@ -446,7 +447,7 @@ export class PluginManager {
       if (!plugin.enabled) {
         continue;
       }
-      this.app.logger.debug(`before load plugin [${name}]`, { submodule: 'plugin-manager', method: 'load', name });
+      this.app.logger.trace(`before load plugin [${name}]`, { submodule: 'plugin-manager', method: 'load', name });
       await plugin.beforeLoad();
     }
 
@@ -465,14 +466,15 @@ export class PluginManager {
       }
 
       await this.app.emitAsync('beforeLoadPlugin', plugin, options);
-      this.app.logger.debug(`load plugin [${name}] `, { submodule: 'plugin-manager', method: 'load', name });
+      this.app.logger.trace(`load plugin [${name}] `, { submodule: 'plugin-manager', method: 'load', name });
       await plugin.loadCollections();
       await plugin.load();
       plugin.state.loaded = true;
       await this.app.emitAsync('afterLoadPlugin', plugin, options);
     }
 
-    this.app.setMaintainingMessage('loaded plugins');
+    this.app.log.debug('plugins loaded');
+    this.app.setMaintainingMessage('plugins loaded');
   }
 
   async install(options: InstallOptions = {}) {

packages/plugins/@nocobase/plugin-data-source-main/src/server/repositories/collection-repository.ts

@@ -26,6 +26,8 @@ export class CollectionRepository extends Repository {
   }
 
   async load(options: LoadOptions = {}) {
+    this.database.logger.debug('loading collections...');
+
     const { filter, skipExist } = options;
     const instances = (await this.find({ filter, appends: ['fields'] })) as CollectionModel[];
 
@@ -95,8 +97,7 @@ export class CollectionRepository extends Repository {
         lazyCollectionFields.set(instanceName, skipField);
       }
 
-      this.database.logger.debug(`load collection`, {
-        instanceName,
+      this.database.logger.trace(`load ${instanceName} collection`, {
         submodule: 'CollectionRepository',
         method: 'load',
       });
@@ -110,7 +111,7 @@ export class CollectionRepository extends Repository {
 
     // load view fields
     for (const viewCollectionName of viewCollections) {
-      this.database.logger.debug(`load collection fields`, {
+      this.database.logger.trace(`load collection fields`, {
         submodule: 'CollectionRepository',
         method: 'load',
         viewCollectionName,
@@ -141,7 +142,7 @@ export class CollectionRepository extends Repository {
 
     // load lazy collection field
     for (const [collectionName, skipField] of lazyCollectionFields) {
-      this.database.logger.debug(`load collection fields`, {
+      this.database.logger.trace(`load collection fields`, {
         submodule: 'CollectionRepository',
         method: 'load',
         collectionName,
@@ -152,7 +153,7 @@ export class CollectionRepository extends Repository {
 
     // load source attribute fields
     for (const [collectionName, skipField] of fieldWithSourceAttributes) {
-      this.database.logger.debug(`load collection fields`, {
+      this.database.logger.trace(`load collection fields`, {
         submodule: 'CollectionRepository',
         method: 'load',
         collectionName,
@@ -161,6 +162,8 @@ export class CollectionRepository extends Repository {
       this.app.setMaintainingMessage(`load ${collectionName} collection fields`);
       await nameMap[collectionName].loadFields({ includeFields: skipField });
     }
+
+    this.database.logger.debug('collections loaded');
   }
 
   async db2cm(collectionName: string) {