Merge pull request #1131 from hedgedoc/improve/logging

This commit is contained in:
David Mehren 2021-04-18 22:28:11 +02:00 committed by GitHub
commit 6699e4b0c8
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
12 changed files with 176 additions and 83 deletions

View file

@ -12,6 +12,8 @@ import { Identity } from '../../../users/identity.entity';
import { User } from '../../../users/user.entity'; import { User } from '../../../users/user.entity';
import { AuthToken } from '../../../auth/auth-token.entity'; import { AuthToken } from '../../../auth/auth-token.entity';
import { AuthModule } from '../../../auth/auth.module'; import { AuthModule } from '../../../auth/auth.module';
import { ConfigModule } from '@nestjs/config';
import appConfigMock from '../../../config/mock/app.config.mock';
describe('TokensController', () => { describe('TokensController', () => {
let controller: TokensController; let controller: TokensController;
@ -19,7 +21,14 @@ describe('TokensController', () => {
beforeEach(async () => { beforeEach(async () => {
const module: TestingModule = await Test.createTestingModule({ const module: TestingModule = await Test.createTestingModule({
controllers: [TokensController], controllers: [TokensController],
imports: [LoggerModule, AuthModule], imports: [
ConfigModule.forRoot({
isGlobal: true,
load: [appConfigMock],
}),
LoggerModule,
AuthModule,
],
}) })
.overrideProvider(getRepositoryToken(User)) .overrideProvider(getRepositoryToken(User))
.useValue({}) .useValue({})

View file

@ -15,6 +15,8 @@ import { LoggerModule } from '../logger/logger.module';
import { AuthToken } from './auth-token.entity'; import { AuthToken } from './auth-token.entity';
import { NotInDBError, TokenNotValidError } from '../errors/errors'; import { NotInDBError, TokenNotValidError } from '../errors/errors';
import { Repository } from 'typeorm'; import { Repository } from 'typeorm';
import { ConfigModule } from '@nestjs/config';
import appConfigMock from '../config/mock/app.config.mock';
describe('AuthService', () => { describe('AuthService', () => {
let service: AuthService; let service: AuthService;
@ -32,7 +34,15 @@ describe('AuthService', () => {
useClass: Repository, useClass: Repository,
}, },
], ],
imports: [PassportModule, UsersModule, LoggerModule], imports: [
ConfigModule.forRoot({
isGlobal: true,
load: [appConfigMock],
}),
PassportModule,
UsersModule,
LoggerModule,
],
}) })
.overrideProvider(getRepositoryToken(Identity)) .overrideProvider(getRepositoryToken(Identity))
.useValue({}) .useValue({})

View file

@ -5,9 +5,11 @@
*/ */
import { import {
needToLog,
replaceAuthErrorsWithEnvironmentVariables, replaceAuthErrorsWithEnvironmentVariables,
toArrayConfig, toArrayConfig,
} from './utils'; } from './utils';
import { Loglevel } from './loglevel.enum';
describe('config utils', () => { describe('config utils', () => {
describe('toArrayConfig', () => { describe('toArrayConfig', () => {
@ -40,4 +42,46 @@ describe('config utils', () => {
).toEqual('"HD_AUTH_GITLAB_test_SCOPE'); ).toEqual('"HD_AUTH_GITLAB_test_SCOPE');
}); });
}); });
describe('needToLog', () => {
it('currentLevel ERROR', () => {
const currentLevel = Loglevel.ERROR;
expect(needToLog(currentLevel, Loglevel.ERROR)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.WARN)).toBeFalsy();
expect(needToLog(currentLevel, Loglevel.INFO)).toBeFalsy();
expect(needToLog(currentLevel, Loglevel.DEBUG)).toBeFalsy();
expect(needToLog(currentLevel, Loglevel.TRACE)).toBeFalsy();
});
it('currentLevel WARN', () => {
const currentLevel = Loglevel.WARN;
expect(needToLog(currentLevel, Loglevel.ERROR)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.WARN)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.INFO)).toBeFalsy();
expect(needToLog(currentLevel, Loglevel.DEBUG)).toBeFalsy();
expect(needToLog(currentLevel, Loglevel.TRACE)).toBeFalsy();
});
it('currentLevel INFO', () => {
const currentLevel = Loglevel.INFO;
expect(needToLog(currentLevel, Loglevel.ERROR)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.WARN)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.INFO)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.DEBUG)).toBeFalsy();
expect(needToLog(currentLevel, Loglevel.TRACE)).toBeFalsy();
});
it('currentLevel DEBUG', () => {
const currentLevel = Loglevel.DEBUG;
expect(needToLog(currentLevel, Loglevel.ERROR)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.WARN)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.INFO)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.DEBUG)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.TRACE)).toBeFalsy();
});
it('currentLevel TRACE', () => {
const currentLevel = Loglevel.TRACE;
expect(needToLog(currentLevel, Loglevel.ERROR)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.WARN)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.INFO)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.DEBUG)).toBeTruthy();
expect(needToLog(currentLevel, Loglevel.TRACE)).toBeTruthy();
});
});
}); });

View file

@ -4,6 +4,8 @@
* SPDX-License-Identifier: AGPL-3.0-only * SPDX-License-Identifier: AGPL-3.0-only
*/ */
import { Loglevel } from './loglevel.enum';
export function toArrayConfig(configValue: string, separator = ','): string[] { export function toArrayConfig(configValue: string, separator = ','): string[] {
if (!configValue) { if (!configValue) {
return []; return [];
@ -87,3 +89,27 @@ export function replaceAuthErrorsWithEnvironmentVariables(
message = message.replace('.accessRole', '_ACCESS_ROLE'); message = message.replace('.accessRole', '_ACCESS_ROLE');
return message; return message;
} }
export function needToLog(
currentLoglevel: Loglevel,
requestedLoglevel: Loglevel,
): boolean {
const current = transformLoglevelToInt(currentLoglevel);
const requested = transformLoglevelToInt(requestedLoglevel);
return current >= requested;
}
function transformLoglevelToInt(loglevel: Loglevel): number {
switch (loglevel) {
case Loglevel.TRACE:
return 5;
case Loglevel.DEBUG:
return 4;
case Loglevel.INFO:
return 3;
case Loglevel.WARN:
return 2;
case Loglevel.ERROR:
return 1;
}
}

View file

@ -11,6 +11,8 @@ import { Repository } from 'typeorm';
import { Group } from './group.entity'; import { Group } from './group.entity';
import { NotInDBError } from '../errors/errors'; import { NotInDBError } from '../errors/errors';
import { LoggerModule } from '../logger/logger.module'; import { LoggerModule } from '../logger/logger.module';
import { ConfigModule } from '@nestjs/config';
import appConfigMock from '../config/mock/app.config.mock';
describe('GroupsService', () => { describe('GroupsService', () => {
let service: GroupsService; let service: GroupsService;
@ -26,7 +28,13 @@ describe('GroupsService', () => {
useClass: Repository, useClass: Repository,
}, },
], ],
imports: [LoggerModule], imports: [
ConfigModule.forRoot({
isGlobal: true,
load: [appConfigMock],
}),
LoggerModule,
],
}).compile(); }).compile();
service = module.get<GroupsService>(GroupsService); service = module.get<GroupsService>(GroupsService);

View file

@ -4,17 +4,24 @@
* SPDX-License-Identifier: AGPL-3.0-only * SPDX-License-Identifier: AGPL-3.0-only
*/ */
import { Injectable, Optional, Scope } from '@nestjs/common'; import { Inject, Injectable, Optional, Scope } from '@nestjs/common';
import { isObject } from '@nestjs/common/utils/shared.utils'; import { isObject } from '@nestjs/common/utils/shared.utils';
import clc = require('cli-color'); import clc = require('cli-color');
import DateTimeFormatOptions = Intl.DateTimeFormatOptions; import DateTimeFormatOptions = Intl.DateTimeFormatOptions;
import appConfiguration, { AppConfig } from '../config/app.config';
import { Loglevel } from '../config/loglevel.enum';
import { needToLog } from '../config/utils';
@Injectable({ scope: Scope.TRANSIENT }) @Injectable({ scope: Scope.TRANSIENT })
export class ConsoleLoggerService { export class ConsoleLoggerService {
private classContext: string; private classContext: string;
private lastTimestamp: number; private lastTimestamp: number;
constructor(@Optional() context?: string) { constructor(
@Inject(appConfiguration.KEY)
private appConfig: AppConfig,
@Optional() context?: string,
) {
this.classContext = context; this.classContext = context;
} }
@ -29,47 +36,58 @@ export class ConsoleLoggerService {
this.makeContextString(functionContext), this.makeContextString(functionContext),
false, false,
); );
this.printStackTrace(trace); ConsoleLoggerService.printStackTrace(trace);
} }
log(message: unknown, functionContext?: string): void { log(message: unknown, functionContext?: string): void {
this.printMessage( if (needToLog(this.appConfig.loglevel, Loglevel.INFO)) {
message, this.printMessage(
clc.green, message,
this.makeContextString(functionContext), clc.green,
false, this.makeContextString(functionContext),
); false,
);
}
} }
warn(message: unknown, functionContext?: string): void { warn(message: unknown, functionContext?: string): void {
this.printMessage( if (needToLog(this.appConfig.loglevel, Loglevel.WARN)) {
message, this.printMessage(
clc.yellow, message,
this.makeContextString(functionContext), clc.yellow,
false, this.makeContextString(functionContext),
); false,
);
}
} }
debug(message: unknown, functionContext?: string): void { debug(message: unknown, functionContext?: string): void {
this.printMessage( if (needToLog(this.appConfig.loglevel, Loglevel.DEBUG)) {
message, this.printMessage(
clc.magentaBright, message,
this.makeContextString(functionContext), clc.magentaBright,
false, this.makeContextString(functionContext),
); false,
);
}
} }
verbose(message: unknown, functionContext?: string): void { verbose(message: unknown, functionContext?: string): void {
this.printMessage( if (needToLog(this.appConfig.loglevel, Loglevel.TRACE)) {
message, this.printMessage(
clc.cyanBright, message,
this.makeContextString(functionContext), clc.cyanBright,
false, this.makeContextString(functionContext),
); false,
);
}
} }
private makeContextString(functionContext: string): string { private makeContextString(functionContext: string): string {
let context = this.classContext; let context = this.classContext;
if (!context) {
context = 'HedgeDoc';
}
if (functionContext) { if (functionContext) {
context += '.' + functionContext + '()'; context += '.' + functionContext + '()';
} }
@ -117,7 +135,7 @@ export class ConsoleLoggerService {
return result; return result;
} }
private printStackTrace(trace: string): void { private static printStackTrace(trace: string): void {
if (!trace) { if (!trace) {
return; return;
} }

View file

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

View file

@ -1,39 +0,0 @@
/*
* SPDX-FileCopyrightText: 2021 The HedgeDoc developers (see AUTHORS file)
*
* SPDX-License-Identifier: AGPL-3.0-only
*/
import { Injectable, LoggerService } from '@nestjs/common';
import { ConsoleLoggerService } from './console-logger.service';
Injectable();
export class NestConsoleLoggerService implements LoggerService {
private consoleLoggerService = new ConsoleLoggerService();
debug(message: unknown, context?: string): void {
this.consoleLoggerService.setContext(context);
this.consoleLoggerService.debug(message);
}
error(message: unknown, trace?: string, context?: string): void {
this.consoleLoggerService.setContext(context);
this.consoleLoggerService.error(message, trace);
}
log(message: unknown, context?: string): void {
this.consoleLoggerService.setContext(context);
this.consoleLoggerService.log(message);
}
verbose(message: unknown, context?: string): void {
this.consoleLoggerService.setContext(context);
this.consoleLoggerService.verbose(message);
}
warn(message: unknown, context?: string): void {
this.consoleLoggerService.setContext(context);
this.consoleLoggerService.warn(message);
}
}

View file

@ -4,20 +4,22 @@
* SPDX-License-Identifier: AGPL-3.0-only * SPDX-License-Identifier: AGPL-3.0-only
*/ */
import { ValidationPipe } from '@nestjs/common'; import { LogLevel, ValidationPipe } from '@nestjs/common';
import { ConfigService } from '@nestjs/config'; import { ConfigService } from '@nestjs/config';
import { NestFactory } from '@nestjs/core'; import { NestFactory } from '@nestjs/core';
import { NestExpressApplication } from '@nestjs/platform-express'; import { NestExpressApplication } from '@nestjs/platform-express';
import { AppModule } from './app.module'; import { AppModule } from './app.module';
import { AppConfig } from './config/app.config'; import { AppConfig } from './config/app.config';
import { MediaConfig } from './config/media.config'; import { MediaConfig } from './config/media.config';
import { NestConsoleLoggerService } from './logger/nest-console-logger.service';
import { setupPrivateApiDocs, setupPublicApiDocs } from './utils/swagger'; import { setupPrivateApiDocs, setupPublicApiDocs } from './utils/swagger';
import { BackendType } from './media/backends/backend-type.enum'; import { BackendType } from './media/backends/backend-type.enum';
import { ConsoleLoggerService } from './logger/console-logger.service';
async function bootstrap(): Promise<void> { async function bootstrap(): Promise<void> {
const app = await NestFactory.create<NestExpressApplication>(AppModule); const app = await NestFactory.create<NestExpressApplication>(AppModule, {
const logger = await app.resolve(NestConsoleLoggerService); logger: ['error', 'warn', 'log'] as LogLevel[],
});
const logger = await app.resolve(ConsoleLoggerService);
logger.log('Switching logger', 'AppBootstrap'); logger.log('Switching logger', 'AppBootstrap');
app.useLogger(logger); app.useLogger(logger);
const configService = app.get(ConfigService); const configService = app.get(ConfigService);
@ -25,8 +27,16 @@ async function bootstrap(): Promise<void> {
const mediaConfig = configService.get<MediaConfig>('mediaConfig'); const mediaConfig = configService.get<MediaConfig>('mediaConfig');
setupPublicApiDocs(app); setupPublicApiDocs(app);
logger.log(
`Serving OpenAPI docs for public api under '/apidoc'`,
'AppBootstrap',
);
if (process.env.NODE_ENV === 'development') { if (process.env.NODE_ENV === 'development') {
setupPrivateApiDocs(app); setupPrivateApiDocs(app);
logger.log(
`Serving OpenAPI docs for private api under '/private/apidoc'`,
'AppBootstrap',
);
} }
app.useGlobalPipes( app.useGlobalPipes(
@ -38,7 +48,7 @@ async function bootstrap(): Promise<void> {
); );
if (mediaConfig.backend.use === BackendType.FILESYSTEM) { if (mediaConfig.backend.use === BackendType.FILESYSTEM) {
logger.log( logger.log(
`Serving ${mediaConfig.backend.filesystem.uploadPath} under 'uploads/'`, `Serving the local folder '${mediaConfig.backend.filesystem.uploadPath}' under '/uploads'`,
'AppBootstrap', 'AppBootstrap',
); );
app.useStaticAssets(mediaConfig.backend.filesystem.uploadPath, { app.useStaticAssets(mediaConfig.backend.filesystem.uploadPath, {

View file

@ -9,6 +9,8 @@ import { getRepositoryToken } from '@nestjs/typeorm';
import { LoggerModule } from '../logger/logger.module'; import { LoggerModule } from '../logger/logger.module';
import { User } from './user.entity'; import { User } from './user.entity';
import { UsersService } from './users.service'; import { UsersService } from './users.service';
import { ConfigModule } from '@nestjs/config';
import appConfigMock from '../config/mock/app.config.mock';
describe('UsersService', () => { describe('UsersService', () => {
let service: UsersService; let service: UsersService;
@ -22,7 +24,13 @@ describe('UsersService', () => {
useValue: {}, useValue: {},
}, },
], ],
imports: [LoggerModule], imports: [
ConfigModule.forRoot({
isGlobal: true,
load: [appConfigMock],
}),
LoggerModule,
],
}) })
.overrideProvider(getRepositoryToken(User)) .overrideProvider(getRepositoryToken(User))
.useValue({}) .useValue({})

View file

@ -17,7 +17,6 @@ import customizationConfigMock from '../../src/config/mock/customization.config.
import externalConfigMock from '../../src/config/mock/external-services.config.mock'; import externalConfigMock from '../../src/config/mock/external-services.config.mock';
import { GroupsModule } from '../../src/groups/groups.module'; import { GroupsModule } from '../../src/groups/groups.module';
import { LoggerModule } from '../../src/logger/logger.module'; import { LoggerModule } from '../../src/logger/logger.module';
import { NestConsoleLoggerService } from '../../src/logger/nest-console-logger.service';
import { MediaModule } from '../../src/media/media.module'; import { MediaModule } from '../../src/media/media.module';
import { NotesModule } from '../../src/notes/notes.module'; import { NotesModule } from '../../src/notes/notes.module';
import { NotesService } from '../../src/notes/notes.service'; import { NotesService } from '../../src/notes/notes.service';
@ -26,6 +25,7 @@ import { AuthModule } from '../../src/auth/auth.module';
import { join } from 'path'; import { join } from 'path';
import { PrivateApiModule } from '../../src/api/private/private-api.module'; import { PrivateApiModule } from '../../src/api/private/private-api.module';
import { UsersService } from '../../src/users/users.service'; import { UsersService } from '../../src/users/users.service';
import { ConsoleLoggerService } from '../../src/logger/console-logger.service';
describe('Media', () => { describe('Media', () => {
let app: NestExpressApplication; let app: NestExpressApplication;
@ -67,7 +67,7 @@ describe('Media', () => {
prefix: '/uploads', prefix: '/uploads',
}); });
await app.init(); await app.init();
const logger = await app.resolve(NestConsoleLoggerService); const logger = await app.resolve(ConsoleLoggerService);
logger.log('Switching logger', 'AppBootstrap'); logger.log('Switching logger', 'AppBootstrap');
app.useLogger(logger); app.useLogger(logger);
const notesService: NotesService = moduleRef.get('NotesService'); const notesService: NotesService = moduleRef.get('NotesService');

View file

@ -15,7 +15,6 @@ import mediaConfigMock from '../../src/config/mock/media.config.mock';
import appConfigMock from '../../src/config/mock/app.config.mock'; import appConfigMock from '../../src/config/mock/app.config.mock';
import { GroupsModule } from '../../src/groups/groups.module'; import { GroupsModule } from '../../src/groups/groups.module';
import { LoggerModule } from '../../src/logger/logger.module'; import { LoggerModule } from '../../src/logger/logger.module';
import { NestConsoleLoggerService } from '../../src/logger/nest-console-logger.service';
import { MediaModule } from '../../src/media/media.module'; import { MediaModule } from '../../src/media/media.module';
import { MediaService } from '../../src/media/media.service'; import { MediaService } from '../../src/media/media.service';
import { NotesModule } from '../../src/notes/notes.module'; import { NotesModule } from '../../src/notes/notes.module';
@ -25,6 +24,7 @@ import { AuthModule } from '../../src/auth/auth.module';
import { TokenAuthGuard } from '../../src/auth/token-auth.guard'; import { TokenAuthGuard } from '../../src/auth/token-auth.guard';
import { MockAuthGuard } from '../../src/auth/mock-auth.guard'; import { MockAuthGuard } from '../../src/auth/mock-auth.guard';
import { join } from 'path'; import { join } from 'path';
import { ConsoleLoggerService } from '../../src/logger/console-logger.service';
describe('Media', () => { describe('Media', () => {
let app: NestExpressApplication; let app: NestExpressApplication;
@ -64,7 +64,7 @@ describe('Media', () => {
prefix: '/uploads', prefix: '/uploads',
}); });
await app.init(); await app.init();
const logger = await app.resolve(NestConsoleLoggerService); const logger = await app.resolve(ConsoleLoggerService);
logger.log('Switching logger', 'AppBootstrap'); logger.log('Switching logger', 'AppBootstrap');
app.useLogger(logger); app.useLogger(logger);
const notesService: NotesService = moduleRef.get('NotesService'); const notesService: NotesService = moduleRef.get('NotesService');