Merge pull request #502 from codimd/custom-logger

Use custom logger

src/api/public/me/me.controller.spec.ts

@@ -1,6 +1,7 @@
 import { Test, TestingModule } from '@nestjs/testing';
 import { getRepositoryToken } from '@nestjs/typeorm';
 import { HistoryModule } from '../../../history/history.module';
+import { LoggerModule } from '../../../logger/logger.module';
 import { AuthorColor } from '../../../notes/author-color.entity';
 import { Note } from '../../../notes/note.entity';
 import { NotesModule } from '../../../notes/notes.module';
@@ -18,7 +19,7 @@ describe('Me Controller', () => {
   beforeEach(async () => {
     const module: TestingModule = await Test.createTestingModule({
       controllers: [MeController],
-      imports: [UsersModule, HistoryModule, NotesModule],
+      imports: [UsersModule, HistoryModule, NotesModule, LoggerModule],
     })
       .overrideProvider(getRepositoryToken(User))
       .useValue({})

src/api/public/me/me.controller.ts

@@ -4,7 +4,6 @@ import {
   Delete,
   Get,
   HttpCode,
-  Logger,
   NotFoundException,
   Param,
   Put,
@@ -12,6 +11,7 @@ import {
 import { HistoryEntryUpdateDto } from '../../../history/history-entry-update.dto';
 import { HistoryEntryDto } from '../../../history/history-entry.dto';
 import { HistoryService } from '../../../history/history.service';
+import { ConsoleLoggerService } from '../../../logger/console-logger.service';
 import { NoteMetadataDto } from '../../../notes/note-metadata.dto';
 import { NotesService } from '../../../notes/notes.service';
 import { UserInfoDto } from '../../../users/user-info.dto';
@@ -19,13 +19,14 @@ import { UsersService } from '../../../users/users.service';
 
 @Controller('me')
 export class MeController {
-  private readonly logger = new Logger(MeController.name);
-
   constructor(
+    private readonly logger: ConsoleLoggerService,
     private usersService: UsersService,
     private historyService: HistoryService,
     private notesService: NotesService,
-  ) {}
+  ) {
+    this.logger.setContext(MeController.name);
+  }
 
   @Get()
   getMe(): UserInfoDto {

src/api/public/media/media.controller.spec.ts

@@ -1,4 +1,5 @@
 import { Test, TestingModule } from '@nestjs/testing';
+import { LoggerModule } from '../../../logger/logger.module';
 import { MediaController } from './media.controller';
 
 describe('Media Controller', () => {
@@ -7,6 +8,7 @@ describe('Media Controller', () => {
   beforeEach(async () => {
     const module: TestingModule = await Test.createTestingModule({
       controllers: [MediaController],
+      imports: [LoggerModule],
     }).compile();
 
     controller = module.get<MediaController>(MediaController);

src/api/public/media/media.controller.ts

@@ -1,15 +1,17 @@
 import {
   Controller,
-  Logger,
   Post,
   UploadedFile,
   UseInterceptors,
 } from '@nestjs/common';
 import { FileInterceptor } from '@nestjs/platform-express';
+import { ConsoleLoggerService } from '../../../logger/console-logger.service';
 
 @Controller('media')
 export class MediaController {
-  private readonly logger = new Logger(MediaController.name);
+  constructor(private readonly logger: ConsoleLoggerService) {
+    this.logger.setContext(MediaController.name);
+  }
 
   @Post('upload')
   @UseInterceptors(FileInterceptor('file'))

src/api/public/notes/notes.controller.spec.ts

@@ -1,5 +1,6 @@
 import { Test, TestingModule } from '@nestjs/testing';
 import { getRepositoryToken } from '@nestjs/typeorm';
+import { LoggerModule } from '../../../logger/logger.module';
 import { AuthorColor } from '../../../notes/author-color.entity';
 import { Note } from '../../../notes/note.entity';
 import { NotesService } from '../../../notes/notes.service';
@@ -25,7 +26,7 @@ describe('Notes Controller', () => {
           useValue: {},
         },
       ],
-      imports: [RevisionsModule, UsersModule],
+      imports: [RevisionsModule, UsersModule, LoggerModule],
     })
       .overrideProvider(getRepositoryToken(Note))
       .useValue({})

src/api/public/notes/notes.controller.ts

@@ -5,7 +5,6 @@ import {
   Delete,
   Get,
   Header,
-  Logger,
   Param,
   Post,
   Put,
@@ -13,18 +12,20 @@ import {
 } from '@nestjs/common';
 import { Request } from 'express';
 import * as getRawBody from 'raw-body';
+import { ConsoleLoggerService } from '../../../logger/console-logger.service';
 import { NotePermissionsUpdateDto } from '../../../notes/note-permissions.dto';
 import { NotesService } from '../../../notes/notes.service';
 import { RevisionsService } from '../../../revisions/revisions.service';
 
 @Controller('notes')
 export class NotesController {
-  private readonly logger = new Logger(NotesController.name);
-
   constructor(
+    private readonly logger: ConsoleLoggerService,
     private noteService: NotesService,
     private revisionsService: RevisionsService,
-  ) {}
+  ) {
+    this.logger.setContext(NotesController.name);
+  }
 
   /**
    * Extract the raw markdown from the request body and create a new note with it

src/api/public/public-api.module.ts

@@ -1,5 +1,6 @@
 import { Module } from '@nestjs/common';
 import { HistoryModule } from '../../history/history.module';
+import { LoggerModule } from '../../logger/logger.module';
 import { MonitoringModule } from '../../monitoring/monitoring.module';
 import { NotesModule } from '../../notes/notes.module';
 import { RevisionsModule } from '../../revisions/revisions.module';
@@ -16,6 +17,7 @@ import { MonitoringController } from './monitoring/monitoring.controller';
     NotesModule,
     RevisionsModule,
     MonitoringModule,
+    LoggerModule,
   ],
   controllers: [
     MeController,

src/app.module.ts

@@ -1,14 +1,15 @@
 import { Module } from '@nestjs/common';
 import { TypeOrmModule } from '@nestjs/typeorm';
 import { PublicApiModule } from './api/public/public-api.module';
-import { NotesModule } from './notes/notes.module';
-import { UsersModule } from './users/users.module';
-import { RevisionsModule } from './revisions/revisions.module';
 import { AuthorsModule } from './authors/authors.module';
-import { HistoryModule } from './history/history.module';
-import { MonitoringModule } from './monitoring/monitoring.module';
-import { PermissionsModule } from './permissions/permissions.module';
 import { GroupsModule } from './groups/groups.module';
+import { HistoryModule } from './history/history.module';
+import { LoggerModule } from './logger/logger.module';
+import { MonitoringModule } from './monitoring/monitoring.module';
+import { NotesModule } from './notes/notes.module';
+import { PermissionsModule } from './permissions/permissions.module';
+import { RevisionsModule } from './revisions/revisions.module';
+import { UsersModule } from './users/users.module';
 
 @Module({
   imports: [
@@ -27,6 +28,7 @@ import { GroupsModule } from './groups/groups.module';
     MonitoringModule,
     PermissionsModule,
     GroupsModule,
+    LoggerModule,
   ],
   controllers: [],
   providers: [],

src/history/history.module.ts

@@ -1,8 +1,10 @@
 import { Module } from '@nestjs/common';
+import { LoggerModule } from '../logger/logger.module';
 import { HistoryService } from './history.service';
 
 @Module({
   providers: [HistoryService],
   exports: [HistoryService],
+  imports: [LoggerModule],
 })
 export class HistoryModule {}

src/history/history.service.spec.ts

@@ -1,4 +1,5 @@
 import { Test, TestingModule } from '@nestjs/testing';
+import { LoggerModule } from '../logger/logger.module';
 import { HistoryService } from './history.service';
 
 describe('HistoryService', () => {
@@ -7,6 +8,7 @@ describe('HistoryService', () => {
   beforeEach(async () => {
     const module: TestingModule = await Test.createTestingModule({
       providers: [HistoryService],
+      imports: [LoggerModule],
     }).compile();
 
     service = module.get<HistoryService>(HistoryService);

src/history/history.service.ts

@@ -1,10 +1,13 @@
-import { Injectable, Logger } from '@nestjs/common';
+import { Injectable } from '@nestjs/common';
+import { ConsoleLoggerService } from '../logger/console-logger.service';
 import { HistoryEntryUpdateDto } from './history-entry-update.dto';
 import { HistoryEntryDto } from './history-entry.dto';
 
 @Injectable()
 export class HistoryService {
-  private readonly logger = new Logger(HistoryService.name);
+  constructor(private readonly logger: ConsoleLoggerService) {
+    this.logger.setContext(HistoryService.name);
+  }
 
   getUserHistory(username: string): HistoryEntryDto[] {
     //TODO: Use the database

src/logger/console-logger.service.ts

@@ -0,0 +1,119 @@
+import { Injectable, Optional, Scope } from '@nestjs/common';
+import { isObject } from '@nestjs/common/utils/shared.utils';
+import * as clc from 'cli-color';
+
+@Injectable({ scope: Scope.TRANSIENT })
+export class ConsoleLoggerService {
+  private classContext;
+  private lastTimestamp: number;
+
+  constructor(@Optional() context?: string) {
+    this.classContext = context;
+  }
+
+  setContext(context: string) {
+    this.classContext = context;
+  }
+
+  error(message: any, trace = '', functionContext?: string) {
+    this.printMessage(
+      message,
+      clc.red,
+      this.makeContextString(functionContext),
+      false,
+    );
+    this.printStackTrace(trace);
+  }
+
+  log(message: any, functionContext?: string) {
+    this.printMessage(
+      message,
+      clc.green,
+      this.makeContextString(functionContext),
+      false,
+    );
+  }
+
+  warn(message: any, functionContext?: string) {
+    this.printMessage(
+      message,
+      clc.yellow,
+      this.makeContextString(functionContext),
+      false,
+    );
+  }
+
+  debug(message: any, functionContext?: string) {
+    this.printMessage(
+      message,
+      clc.magentaBright,
+      this.makeContextString(functionContext),
+      false,
+    );
+  }
+
+  verbose(message: any, functionContext?: string) {
+    this.printMessage(
+      message,
+      clc.cyanBright,
+      this.makeContextString(functionContext),
+      false,
+    );
+  }
+
+  private makeContextString(functionContext) {
+    let context = this.classContext;
+    if (functionContext) {
+      context += '.' + functionContext + '()';
+    }
+    return context;
+  }
+
+  private printMessage(
+    message: any,
+    color: (message: string) => string,
+    context = '',
+    isTimeDiffEnabled?: boolean,
+  ) {
+    const output = isObject(message)
+      ? `${color('Object:')}\n${JSON.stringify(message, null, 2)}\n`
+      : color(message);
+
+    const localeStringOptions = {
+      year: 'numeric',
+      hour: 'numeric',
+      minute: 'numeric',
+      second: 'numeric',
+      day: '2-digit',
+      month: '2-digit',
+    };
+    //TODO make timestamp optional
+    const timestamp = new Date(Date.now()).toLocaleString(
+      undefined,
+      localeStringOptions,
+    );
+
+    const contextMessage = context ? clc.blue(`[${context}] `) : '';
+    const timestampDiff = this.updateAndGetTimestampDiff(isTimeDiffEnabled);
+
+    process.stdout.write(
+      `${timestamp} ${contextMessage}${output}${timestampDiff}\n`,
+    );
+  }
+
+  private updateAndGetTimestampDiff(isTimeDiffEnabled?: boolean): string {
+    const includeTimestamp = this.lastTimestamp && isTimeDiffEnabled;
+    const result = includeTimestamp
+      ? clc.yellow(` +${Date.now() - this.lastTimestamp}ms`)
+      : '';
+    this.lastTimestamp = Date.now();
+    return result;
+  }
+
+  private printStackTrace(trace: string) {
+    if (!trace) {
+      return;
+    }
+    process.stdout.write(`${trace}\n`);
+  }
+}

src/logger/logger.module.ts

@@ -0,0 +1,9 @@
+import { Module } from '@nestjs/common';
+import { ConsoleLoggerService } from './console-logger.service';
+import { NestConsoleLoggerService } from './nest-console-logger.service';
+
+@Module({
+  providers: [ConsoleLoggerService, NestConsoleLoggerService],
+  exports: [ConsoleLoggerService, NestConsoleLoggerService],
+})
+export class LoggerModule {}

src/logger/nest-console-logger.service.ts

@@ -0,0 +1,33 @@
+import { Injectable, LoggerService } from '@nestjs/common';
+import { ConsoleLoggerService } from './console-logger.service';
+
+Injectable();
+
+export class NestConsoleLoggerService implements LoggerService {
+  private consoleLoggerService = new ConsoleLoggerService();
+
+  debug(message: any, context?: string): any {
+    this.consoleLoggerService.setContext(context);
+    this.consoleLoggerService.debug(message);
+  }
+
+  error(message: any, trace?: string, context?: string): any {
+    this.consoleLoggerService.setContext(context);
+    this.consoleLoggerService.error(message);
+  }
+
+  log(message: any, context?: string): any {
+    this.consoleLoggerService.setContext(context);
+    this.consoleLoggerService.log(message);
+  }
+
+  verbose(message: any, context?: string): any {
+    this.consoleLoggerService.setContext(context);
+    this.consoleLoggerService.verbose(message);
+  }
+
+  warn(message: any, context?: string): any {
+    this.consoleLoggerService.setContext(context);
+    this.consoleLoggerService.warn(message);
+  }
+}

src/main.ts

@@ -2,9 +2,13 @@ import { ValidationPipe } from '@nestjs/common';
 import { NestFactory } from '@nestjs/core';
 import { DocumentBuilder, SwaggerModule } from '@nestjs/swagger';
 import { AppModule } from './app.module';
+import { NestConsoleLoggerService } from './logger/nest-console-logger.service';
 
 async function bootstrap() {
   const app = await NestFactory.create(AppModule);
+  const logger = await app.resolve(NestConsoleLoggerService);
+  logger.log('Switching logger', 'AppBootstrap');
+  app.useLogger(logger);
 
   const swaggerOptions = new DocumentBuilder()
     .setTitle('HedgeDoc')
@@ -21,6 +25,7 @@ async function bootstrap() {
     }),
   );
   await app.listen(3000);
+  logger.log('Listening on port 3000', 'AppBootstrap');
 }
 
 bootstrap();

src/monitoring/monitoring.module.ts

@@ -1,8 +1,10 @@
 import { Module } from '@nestjs/common';
+import { LoggerModule } from '../logger/logger.module';
 import { MonitoringService } from './monitoring.service';
 
 @Module({
   providers: [MonitoringService],
   exports: [MonitoringService],
+  imports: [LoggerModule],
 })
 export class MonitoringModule {}

src/notes/notes.module.ts

@@ -1,5 +1,6 @@
 import { forwardRef, Module } from '@nestjs/common';
 import { TypeOrmModule } from '@nestjs/typeorm';
+import { LoggerModule } from '../logger/logger.module';
 import { RevisionsModule } from '../revisions/revisions.module';
 import { UsersModule } from '../users/users.module';
 import { AuthorColor } from './author-color.entity';
@@ -11,6 +12,7 @@ import { NotesService } from './notes.service';
     TypeOrmModule.forFeature([Note, AuthorColor]),
     forwardRef(() => RevisionsModule),
     UsersModule,
+    LoggerModule,
   ],
   controllers: [],
   providers: [NotesService],

src/notes/notes.service.spec.ts

@@ -1,5 +1,6 @@
 import { Test, TestingModule } from '@nestjs/testing';
 import { getRepositoryToken } from '@nestjs/typeorm';
+import { LoggerModule } from '../logger/logger.module';
 import { Authorship } from '../revisions/authorship.entity';
 import { Revision } from '../revisions/revision.entity';
 import { RevisionsModule } from '../revisions/revisions.module';
@@ -23,7 +24,7 @@ describe('NotesService', () => {
           useValue: {},
         },
       ],
-      imports: [UsersModule, RevisionsModule],
+      imports: [UsersModule, RevisionsModule, LoggerModule],
     })
       .overrideProvider(getRepositoryToken(User))
       .useValue({})

src/notes/notes.service.ts

@@ -1,6 +1,7 @@
-import { forwardRef, Inject, Injectable, Logger } from '@nestjs/common';
+import { forwardRef, Inject, Injectable } from '@nestjs/common';
 import { InjectRepository } from '@nestjs/typeorm';
 import { Repository } from 'typeorm';
+import { ConsoleLoggerService } from '../logger/console-logger.service';
 import { Revision } from '../revisions/revision.entity';
 import { RevisionsService } from '../revisions/revisions.service';
 import { User } from '../users/user.entity';
@@ -16,14 +17,15 @@ import { NoteUtils } from './note.utils';
 
 @Injectable()
 export class NotesService {
-  private readonly logger = new Logger(NotesService.name);
-
   constructor(
+    private readonly logger: ConsoleLoggerService,
     @InjectRepository(Note) private noteRepository: Repository<Note>,
     @Inject(UsersService) private usersService: UsersService,
     @Inject(forwardRef(() => RevisionsService))
     private revisionsService: RevisionsService,
-  ) {}
+  ) {
+    this.logger.setContext(NotesService.name);
+  }
 
   getUserNotes(username: string): NoteMetadataDto[] {
     this.logger.warn('Using hardcoded data!');

src/permissions/permissions.module.ts

@@ -1,11 +1,13 @@
 import { Module } from '@nestjs/common';
 import { TypeOrmModule } from '@nestjs/typeorm';
+import { LoggerModule } from '../logger/logger.module';
 import { NoteGroupPermission } from './note-group-permission.entity';
 import { NoteUserPermission } from './note-user-permission.entity';
 
 @Module({
   imports: [
     TypeOrmModule.forFeature([NoteUserPermission, NoteGroupPermission]),
+    LoggerModule,
   ],
 })
 export class PermissionsModule {}

src/revisions/revisions.module.ts

@@ -1,5 +1,6 @@
 import { forwardRef, Module } from '@nestjs/common';
 import { TypeOrmModule } from '@nestjs/typeorm';
+import { LoggerModule } from '../logger/logger.module';
 import { NotesModule } from '../notes/notes.module';
 import { Authorship } from './authorship.entity';
 import { Revision } from './revision.entity';
@@ -9,6 +10,7 @@ import { RevisionsService } from './revisions.service';
   imports: [
     TypeOrmModule.forFeature([Revision, Authorship]),
     forwardRef(() => NotesModule),
+    LoggerModule,
   ],
   providers: [RevisionsService],
   exports: [RevisionsService],

src/revisions/revisions.service.spec.ts

@@ -1,5 +1,6 @@
 import { Test, TestingModule } from '@nestjs/testing';
 import { getRepositoryToken } from '@nestjs/typeorm';
+import { LoggerModule } from '../logger/logger.module';
 import { AuthorColor } from '../notes/author-color.entity';
 import { Note } from '../notes/note.entity';
 import { NotesModule } from '../notes/notes.module';
@@ -22,7 +23,7 @@ describe('RevisionsService', () => {
           useValue: {},
         },
       ],
-      imports: [NotesModule],
+      imports: [NotesModule, LoggerModule],
     })
       .overrideProvider(getRepositoryToken(Authorship))
       .useValue({})

src/revisions/revisions.service.ts

@@ -1,6 +1,7 @@
-import { forwardRef, Inject, Injectable, Logger } from '@nestjs/common';
+import { forwardRef, Inject, Injectable } from '@nestjs/common';
 import { InjectRepository } from '@nestjs/typeorm';
 import { Repository } from 'typeorm';
+import { ConsoleLoggerService } from '../logger/console-logger.service';
 import { NotesService } from '../notes/notes.service';
 import { RevisionMetadataDto } from './revision-metadata.dto';
 import { RevisionDto } from './revision.dto';
@@ -8,13 +9,14 @@ import { Revision } from './revision.entity';
 
 @Injectable()
 export class RevisionsService {
-  private readonly logger = new Logger(RevisionsService.name);
-
   constructor(
+    private readonly logger: ConsoleLoggerService,
     @InjectRepository(Revision)
     private revisionRepository: Repository<Revision>,
     @Inject(forwardRef(() => NotesService)) private notesService: NotesService,
-  ) {}
+  ) {
+    this.logger.setContext(RevisionsService.name);
+  }
 
   async getNoteRevisionMetadatas(
     noteIdOrAlias: string,

src/users/users.module.ts

@@ -1,12 +1,16 @@
 import { Module } from '@nestjs/common';
 import { TypeOrmModule } from '@nestjs/typeorm';
+import { LoggerModule } from '../logger/logger.module';
 import { AuthToken } from './auth-token.entity';
 import { Identity } from './identity.entity';
 import { User } from './user.entity';
 import { UsersService } from './users.service';
 
 @Module({
-  imports: [TypeOrmModule.forFeature([User, AuthToken, Identity])],
+  imports: [
+    TypeOrmModule.forFeature([User, AuthToken, Identity]),
+    LoggerModule,
+  ],
   providers: [UsersService],
   exports: [UsersService],
 })

src/users/users.service.spec.ts

@@ -1,4 +1,5 @@
 import { Test, TestingModule } from '@nestjs/testing';
+import { LoggerModule } from '../logger/logger.module';
 import { UsersService } from './users.service';
 
 describe('UsersService', () => {
@@ -7,6 +8,7 @@ describe('UsersService', () => {
   beforeEach(async () => {
     const module: TestingModule = await Test.createTestingModule({
       providers: [UsersService],
+      imports: [LoggerModule],
     }).compile();
 
     service = module.get<UsersService>(UsersService);

src/users/users.service.ts

@@ -1,10 +1,13 @@
-import { Injectable, Logger } from '@nestjs/common';
+import { Injectable } from '@nestjs/common';
+import { ConsoleLoggerService } from '../logger/console-logger.service';
 import { UserInfoDto } from './user-info.dto';
 import { User } from './user.entity';
 
 @Injectable()
 export class UsersService {
-  private readonly logger = new Logger(UsersService.name);
+  constructor(private readonly logger: ConsoleLoggerService) {
+    this.logger.setContext(UsersService.name);
+  }
 
   getUserInfo(): UserInfoDto {
     //TODO: Use the database
@@ -28,7 +31,7 @@ export class UsersService {
 
   toUserDto(user: User | null | undefined): UserInfoDto | null {
     if (!user) {
-      this.logger.warn(`toUserDto recieved ${user} argument!`);
+      this.logger.warn(`Recieved ${user} argument!`, 'toUserDto');
       return null;
     }
     return {

test/public-api/notes.e2e-spec.ts

@@ -4,6 +4,7 @@ import { TypeOrmModule } from '@nestjs/typeorm';
 import * as request from 'supertest';
 import { PublicApiModule } from '../../src/api/public/public-api.module';
 import { GroupsModule } from '../../src/groups/groups.module';
+import { LoggerModule } from '../../src/logger/logger.module';
 import { NotesModule } from '../../src/notes/notes.module';
 import { NotesService } from '../../src/notes/notes.service';
 import { PermissionsModule } from '../../src/permissions/permissions.module';
@@ -25,6 +26,7 @@ describe('Notes', () => {
           autoLoadEntities: true,
           synchronize: true,
         }),
+        LoggerModule,
       ],
     }).compile();