上一篇介绍了如何使用 JWT 进行单点登录,接下来,要完善一下后端项目的一些基础功能。
首先,一个良好的服务端,应该有较完善的日志收集功能,这样才能在生产环境发生异常时,能够从日志中复盘,找出 Bug 所在。
其次,要针对项目中抛出的异常进行归类,并将信息反映在接口或日志中。
最后,请求接口的参数也应该被记录,以便统计分析(主要用于大数据和恶意攻击分析)。
一、日志系统
这里使用的是 log4js
,已经有大佬总结了 log4js
的用法,就不在赘述了:《Node.js 之 log4js 完全讲解》
1. 配置
先安装依赖包
npm i log4js stacktrace-js -S
在 config 目录下新建一个文件 log4js.ts,用于编写配置文件:
// config/log4js.ts
import * as path from 'path';
const baseLogPath = path.resolve(__dirname, '../../logs'); // 日志要写入哪个目录
const log4jsConfig = {
appenders: {
console: {
type: 'console', // 会打印到控制台
},
access: {
type: 'dateFile', // 会写入文件,并按照日期分类
filename: `${baseLogPath}/access/access.log`, // 日志文件名,会命名为:access.20200320.log
alwaysIncludePattern: true,
pattern: 'yyyyMMdd',
daysToKeep: 60,
numBackups: 3,
category: 'http',
keepFileExt: true, // 是否保留文件后缀
},
app: {
type: 'dateFile',
filename: `${baseLogPath}/app-out/app.log`,
alwaysIncludePattern: true,
layout: {
type: 'pattern',
pattern: '{"date":"%d","level":"%p","category":"%c","host":"%h","pid":"%z","data":\'%m\'}',
},
// 日志文件按日期(天)切割
pattern: 'yyyyMMdd',
daysToKeep: 60,
// maxLogSize: 10485760,
numBackups: 3,
keepFileExt: true,
},
errorFile: {
type: 'dateFile',
filename: `${baseLogPath}/errors/error.log`,
alwaysIncludePattern: true,
layout: {
type: 'pattern',
pattern: '{"date":"%d","level":"%p","category":"%c","host":"%h","pid":"%z","data":\'%m\'}',
},
// 日志文件按日期(天)切割
pattern: 'yyyyMMdd',
daysToKeep: 60,
// maxLogSize: 10485760,
numBackups: 3,
keepFileExt: true,
},
errors: {
type: 'logLevelFilter',
level: 'ERROR',
appender: 'errorFile',
},
},
categories: {
default: {
appenders: ['console', 'app', 'errors'],
level: 'DEBUG',
},
info: { appenders: ['console', 'app', 'errors'], level: 'info' },
access: { appenders: ['console', 'app', 'errors'], level: 'info' },
http: { appenders: ['access'], level: 'DEBUG' },
},
pm2: true, // 使用 pm2 来管理项目时,打开
pm2InstanceVar: 'INSTANCE_ID', // 会根据 pm2 分配的 id 进行区分,以免各进程在写日志时造成冲突
};
export default log4jsConfig;
上面贴出了我的配置,并标注了一些简单的注释,请配合 《Node.js 之 log4js 完全讲解》 一起使用。
2. 实例化
有了配置,就可以着手写 log4js
的实例以及一些工具函数了。
在 src/utils
下新建 log4js.ts
:
// src/utils/log4js.ts
import * as Path from 'path';
import * as Log4js from 'log4js';
import * as Util from 'util';
import * as Moment from 'moment'; // 处理时间的工具
import * as StackTrace from 'stacktrace-js';
import Chalk from 'chalk';
import config from '../../config/log4js';
// 日志级别
export enum LoggerLevel {
ALL = 'ALL',
MARK = 'MARK',
TRACE = 'TRACE',
DEBUG = 'DEBUG',
INFO = 'INFO',
WARN = 'WARN',
ERROR = 'ERROR',
FATAL = 'FATAL',
OFF = 'OFF',
}
// 内容跟踪类
export class ContextTrace {
constructor(
public readonly context: string,
public readonly path?: string,
public readonly lineNumber?: number,
public readonly columnNumber?: number,
) {}
}
Log4js.addLayout('Awesome-nest', (logConfig: any) => {
return (logEvent: Log4js.LoggingEvent): string => {
let moduleName: string = '';
let position: string = '';
// 日志组装
const messageList: string[] = [];
logEvent.data.forEach((value: any) => {
if (value instanceof ContextTrace) {
moduleName = value.context;
// 显示触发日志的坐标(行,列)
if (value.lineNumber && value.columnNumber) {
position = `${value.lineNumber}, ${value.columnNumber}`;
}
return;
}
if (typeof value !== 'string') {
value = Util.inspect(value, false, 3, true);
}
messageList.push(value);
});
// 日志组成部分
const messageOutput: string = messageList.join(' ');
const positionOutput: string = position ? ` [${position}]` : '';
const typeOutput: string = `[${logConfig.type}] ${logEvent.pid.toString()} - `;
const dateOutput: string = `${Moment(logEvent.startTime).format('YYYY-MM-DD HH:mm:ss')}`;
const moduleOutput: string = moduleName ? `[${moduleName}] ` : '[LoggerService] ';
let levelOutput: string = `[${logEvent.level}] ${messageOutput}`;
// 根据日志级别,用不同颜色区分
switch (logEvent.level.toString()) {
case LoggerLevel.DEBUG:
levelOutput = Chalk.green(levelOutput);
break;
case LoggerLevel.INFO:
levelOutput = Chalk.cyan(levelOutput);
break;
case LoggerLevel.WARN:
levelOutput = Chalk.yellow(levelOutput);
break;
case LoggerLevel.ERROR:
levelOutput = Chalk.red(levelOutput);
break;
case LoggerLevel.FATAL:
levelOutput = Chalk.hex('#DD4C35')(levelOutput);
break;
default:
levelOutput = Chalk.grey(levelOutput);
break;
}
return `${Chalk.green(typeOutput)}${dateOutput} ${Chalk.yellow(moduleOutput)}${levelOutput}${positionOutput}`;
};
});
// 注入配置
Log4js.configure(config);
// 实例化
const logger = Log4js.getLogger();
logger.level = LoggerLevel.TRACE;
export class Logger {
static trace(...args) {
logger.trace(Logger.getStackTrace(), ...args);
}
static debug(...args) {
logger.debug(Logger.getStackTrace(), ...args);
}
static log(...args) {
logger.info(Logger.getStackTrace(), ...args);
}
static info(...args) {
logger.info(Logger.getStackTrace(), ...args);
}
static warn(...args) {
logger.warn(Logger.getStackTrace(), ...args);
}
static warning(...args) {
logger.warn(Logger.getStackTrace(), ...args);
}
static error(...args) {
logger.error(Logger.getStackTrace(), ...args);
}
static fatal(...args) {
logger.fatal(Logger.getStackTrace(), ...args);
}
static access(...args) {
const loggerCustom = Log4js.getLogger('http');
loggerCustom.info(Logger.getStackTrace(), ...args);
}
// 日志追踪,可以追溯到哪个文件、第几行第几列
static getStackTrace(deep: number = 2): string {
const stackList: StackTrace.StackFrame[] = StackTrace.getSync();
const stackInfo: StackTrace.StackFrame = stackList[deep];
const lineNumber: number = stackInfo.lineNumber;
const columnNumber: number = stackInfo.columnNumber;
const fileName: string = stackInfo.fileName;
const basename: string = Path.basename(fileName);
return `${basename}(line: ${lineNumber}, column: ${columnNumber}): \n`;
}
}
上面贴出了我实例化 log4js 的过程,主要是处理日志的组成部分(包含了时间、类型,调用文件以及调用的坐标),还可以根据日志的不同级别,在控制台中用不同的颜色显示。
这个文件,不但可以单独调用,也可以做成中间件使用。
3. 制作中间件
我们希望每次用户请求接口的时候,自动记录请求的路由、IP、参数等信息,如果每个路由都写,那就太傻了,所以需要借助中间件来实现。
Nest 中间件实际上等价于 express 中间件。
中间件函数可以执行以下任务:
- 执行任何代码;
- 对请求和响应对象进行更改;
- 结束请求-响应周期;
- 调用堆栈中的下一个中间件函数;
- 如果当前的中间件函数没有【结束请求】或【响应周期】, 它必须调用 next() 将控制传递给下一个中间件函数。否则,请求将被挂起;
执行下列命令,创建中间件文件:
nest g middleware logger middleware
然后,src
目录下,就多出了一个 middleware
的文件夹,里面的 logger.middleware.ts
就是接下来的主角,Nest 预设的中间件模板长这样:
// src/middleware/logger.middleware.ts
import { Injectable, NestMiddleware } from '@nestjs/common';
@Injectable()
export class LoggerMiddleware implements NestMiddleware {
use(req: any, res: any, next: () => void) {
next();
}
}
这里只是实现了 NestMiddleware
接口,它接收 3 个参数:
- req:即 Request,请求信息;
- res:即 Response ,响应信息;
- next:将控制传递到下一个中间件,写过 Vue、Koa 的应该不会陌生;
接下来,我们将日志功能写入中间件:
// src/middleware/logger/logger.middleware.ts
import { Injectable, NestMiddleware } from '@nestjs/common';
import { Request, Response } from 'express';
import { Logger } from '../../utils/log4js';
@Injectable()
export class LoggerMiddleware implements NestMiddleware {
use(req: Request, res: Response, next: () => void) {
const code = res.statusCode; // 响应状态码
next();
// 组装日志信息
const logFormat = `方法:${req.method} \n Request original url:${req.originalUrl} \n 状态码:${code} \n`;
// 根据状态码,进行日志类型区分
if(code>=500){
Logger.error(logFormat);
}else if(code>=400&&code<500){
Logger.warn(logFormat)
}else {
Logger.access(logFormat)
Logger.log(logFormat)
}
}
}
同时,Nest 也支持【函数式中间件】,我们将上面的功能用函数式实现一下:
上面的日志格式进行了一些改动,主要是为了方便查看。
至于使用 Nest 提供的还是函数式中间件,可以视需求决定。当然,Nest 原生的中间件高级玩法会更多一些。
4. 应用中间件
做好中间件后,我们只需要将中间件引入 main.ts
中就好了:
保存代码后,就会发现,项目目录下就多了几个文件:
这就是之前 config/log4js.ts
中配置的成果
接下来,我们试着请求一下登录接口:
发现虽然是打印了,但是没有请求参数信息。
于是,我们还要做一部操作,将请求参数处理一下:
再请求一次,发现参数已经出来了:
再去看看 logs/
文件夹下:
上图可以看到日志已经写入文件了。
5. 初探拦截器
前面已经示范了怎么打印入参,但是光有入参信息,没有出参信息肯定不行的,不然怎么定位 Bug 呢。
Nest 提供了一种叫做 Interceptors
(拦截器) 的东东,你可以理解为关卡,除非遇到关羽这样的可以过五关斩六将,否则所有的参数都会经过这里进行处理,正所谓雁过拔毛。
详细的使用方法会在后面的教程进行讲解,这里只是先大致介绍一下怎么使用:
执行下列指令,创建 transform
文件
nest g interceptor transform interceptor
然后编写出参打印逻辑,intercept
接受两个参数,当前的上下文和传递函数,这里还使用了 pipe
(管道),用于传递响应数据:
// src/interceptor/transform/transform.interceptor.ts
import {
CallHandler,
ExecutionContext,
Injectable,
NestInterceptor,
} from '@nestjs/common';
import { Observable } from 'rxjs';
import { map } from 'rxjs/operators';
import { Logger } from '../../utils/log4js';
@Injectable()
export class TransformInterceptor implements NestInterceptor {
intercept(context: ExecutionContext, next: CallHandler): Observable<any> {
const req = context.getArgByIndex(1).req;
return next.handle().pipe(
map((data) => {
const logFormat = `<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
Request original url: ${req.originalUrl}
Method: ${req.method}
IP: ${req.ip}
User: ${JSON.stringify(req.user)}
Response data:\n ${JSON.stringify(data.data)}
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<`;
Logger.info(logFormat);
Logger.access(logFormat);
return data;
}),
);
}
}
保存文件,然后在 main.ts
中引入,使用 useGlobalInterceptors
调用全局拦截器:
我们再试一次登录接口:
可以看到,出参的日志已经出来了,User
为 undefiend
是因为登录接口没有使用 JWT 守卫,若路由加了 @UseGuards(AuthGuard('jwt'))
,则会把用户信息绑定在 req 上,具体操作可回顾上一篇教程。
二、异常处理
光有入参出参日志还不够,异常的捕获和抛出也需要记录。
接下来,我们先故意写错语法,看看控制台打印什么:
如图,只会记录入参以及控制台默认的报错信息,而默认的报错信息,是不会写入日志文件的。
再看看请求的返回数据:
如图,这里只会看到 “Internal server error”,其他什么信息都没有。
这样就会有隐患了,用户在使用过程中报错了,但是日志没有记录报错的原因,就无法统计影响范围,如果是简单的报错还好,如果涉及数据库各种事务或者并发问题,就很难追踪定位了,总不能一直看着控制台吧。
因此,我们需要捕获代码中未捕获的异常,并记录日志到 logs/errors
里,方便登录线上服务器,对错误日志进行筛选、排查。
1. 初探过滤器
Nest 不光提供了拦截器,也提供了过滤器,就代码结构而言,和拦截器很相似。
内置的异常层负责处理整个应用程序中的所有抛出的异常。当捕获到未处理的异常时,最终用户将收到友好的响应。
我们先新建一个 http-exception.filter
试试:
nest g filter http-exception filter
打开文件,默认代码长这样:
import { ArgumentsHost, Catch, ExceptionFilter } from '@nestjs/common';
@Catch()
export class HttpExceptionFilter<T> implements ExceptionFilter {
catch(exception: T, host: ArgumentsHost) {}
}
可以看到,和拦截器的结构大同小异,也是接收 2 个参数,只不过用了 @Catch()
来修饰。
2. HTTP 错误的捕获
Nest提供了一个内置的 HttpException
类,它从 @nestjs/common
包中导入。对于典型的基于 HTTP REST/GraphQL API
的应用程序,最佳实践是在发生某些错误情况时发送标准 HTTP 响应对象。
HttpException
构造函数有两个必要的参数来决定响应:
- response 参数定义 JSON 响应体。它可以是 string 或 object,如下所述。
- status参数定义HTTP状态代码。
默认情况下,JSON 响应主体包含两个属性:
- statusCode:默认为 status 参数中提供的 HTTP 状态代码
- message:基于状态的 HTTP 错误的简短描述
我们先来编写捕获打印的逻辑:
import { ArgumentsHost, Catch, ExceptionFilter,HttpException } from '@nestjs/common';
import { Request, Response } from 'express';
import { Logger } from '../../utils/log4js';
@Catch(HttpException)
export class HttpExceptionFilter<T> implements ExceptionFilter {
catch(exception: HttpException, host: ArgumentsHost) {
const ctx = host.switchToHttp();
const response = ctx.getResponse<Response>()
const request = ctx.getRequest<Request>()
const status = exception.getStatus()
const logFormat = ` <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
Request original url: ${request.originalUrl}
Method: ${request.method}
IP: ${request.ip}
Status code: ${status}
Response: ${exception.toString()} \n <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
`;
Logger.info(logFormat);
response.status(status).json({
statusCode: status,
error: exception.message,
msg: `${status >= 500 ? '系统错误' : '客户端错误'}`,
});
}
}
上面代码表示如何捕获 HTTP 异常,并组装成更友好的信息返回给用户。
我们测试一下,先把检测接口的 Token 去掉,请求:
上图是还没有加过滤器的请求结果。
我们在 main.ts
中引入 http-exception
:
使用全局过滤器 useGlobalFilters
调用 http-exception
,再请求:
再看控制台
如此一来,就可以看到未带 Token 请求的结果了,具体信息的组装,可以根据个人喜好进行修改。
3. 内置HTTP异常
为了减少样板代码,Nest 提供了一系列继承自核心异常 HttpException
的可用异常。所有这些都可以在 @nestjs/common
包中找到:
- BadRequestException
- UnauthorizedException
- NotFoundException
- ForbiddenException
- NotAcceptableException
- RequestTimeoutException
- ConflictException
- GoneException
- PayloadTooLargeException
- UnsupportedMediaTypeException
- UnprocessableException
- InternalServerErrorException
- NotImplementedException
- BadGatewayException
- ServiceUnavailableException
- GatewayTimeoutException
结合这些,可以自定义抛出的异常类型。
4. 其他错误的捕获
除了 HTTP 相关的异常,还可以捕获项目中出现的所有异常,我们新建 any-exception.filter
:
nest g filter any-exception filter
一样的套路:
/**
* 捕获所有异常
*/
import { ArgumentsHost, Catch, ExceptionFilter,HttpException,HttpStatus } from '@nestjs/common';
import { Logger } from '../../utils/log4js';
import { Request, Response } from 'express';
@Catch()
export class AnyExceptionFilter<T> implements ExceptionFilter {
catch(exception: unknown, host: ArgumentsHost) {
const ctx = host.switchToHttp();
const response = ctx.getResponse<Response>()
const request = ctx.getRequest<Request>()
const status = exception instanceof HttpException ? exception.getStatus() : HttpStatus.INTERNAL_SERVER_ERROR;
const logFormat = ` <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
Request original url: ${request.originalUrl}
Method: ${request.method}
IP: ${request.ip}
Status code: ${status}
Response: ${exception.toString()} \n <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
`;
Logger.error(logFormat);
response.status(status).json({
statusCode: status,
msg: `系统错误: ${exception}`,
});
}
}
和 http-exception
的唯一区别就是 exception
的类型是 unknown
我们将 any-exception
引入 main.ts
:
注意:
AnyExceptionsFilter
要在HttpExceptionFilter
的上面,否则HttpExceptionFilter
就不生效了,全被AnyExceptionsFilter
捕获了。
然后,再请求一次故意抛错的接口:
再看看控制台:
已经有了明显的区别,再看看 errors.log,也写进了日志中:
如此一来,代码中未捕获的错误也能从日志中查到了。
总结
本篇介绍了如何使用 log4js 来管理日志,制作中间件和拦截器对入参出参进行记录,以及使用过滤器对异常进行处理。
文中日志的打印格式可以按照自己喜好进行排版,不一定局限于此。
良好的日志管理能帮我们快速排查 Bug
下一篇将介绍如何使用 DTO 对参数进行验证,解脱各种 if - else。