脚本崩溃时Winston无法写入日志文件的问题排查与解决求助

问题场景 #

我有一个需要日志文件的项目，因此选择使用Winston。但项目运行期间可能会崩溃，于是我进行了测试：

const winston = require('winston');

const logger = winston.createLogger({
    transports: [
        new winston.transports.Console(),
        new winston.transports.File({ filename: 'combined.log' })
    ]
});

let i=100000;
while(i-->0){
    logger.info('Hello world');
}

throw new Error('Error');

该代码会打印100000次Hello world后抛出错误。问题在于只有程序不崩溃时，combined.log才会被写入。为何Winston仅在程序运行结束后才写入日志？如何让它在发生异常时也能写入文件？

补充测试 #

有趣的是，在抛出错误前添加1秒延迟就能正常写入：

const winston = require('winston');
const fsp = require('fs').promises;

let a=async ()=>{

    try{
        await fsp.unlink('combined.log');
    }catch(e){

    }

const logger = winston.createLogger({
    transports: [
        new winston.transports.Console(),
        new winston.transports.File({ filename: 'combined.log' })
    ]
});

    let i=100000;
    while(i-->0){
        logger.info('Hello world');
    }

    //等待1秒
    await new Promise((resolve)=>setTimeout(resolve,1000));
//  await new Promise((resolve,reject)=>{resolve()});

    throw new Error('Error');
}

a()

原因分析 #

Winston的File传输默认采用异步写入机制：它会将日志消息暂存到内存队列中，后台分批执行文件IO操作，以此避免频繁IO阻塞主线程，提升整体性能。

在第一个测试代码中，同步的while循环会持续占用主线程，Node.js事件循环没有机会处理Winston队列中的异步写入任务，紧接着程序就抛出错误崩溃，导致队列里的日志还没来得及写入文件，最终combined.log为空。

而补充测试中的1秒延迟，给了事件循环足够的时间去处理Winston的异步写入任务，所以日志能正常落地到文件。

解决方法 #

1. 手动触发日志刷新 #

利用Winston File传输的flush方法，在崩溃前等待所有待写入的日志完成：

const winston = require('winston');

const logger = winston.createLogger({
    transports: [
        new winston.transports.Console(),
        new winston.transports.File({ filename: 'combined.log' })
    ]
});

async function run() {
    let i=100000;
    while(i-->0){
        logger.info('Hello world');
    }
    // 等待文件传输完成所有日志写入
    await new Promise(resolve => logger.transports[1].flush(resolve));
    throw new Error('Error');
}

run().catch(err => console.error(err));

2. 配置同步写入（不推荐） #

给File传输添加sync: true配置，强制同步写入日志，但会严重降低性能，因为每次日志都会阻塞主线程等待IO完成：

const logger = winston.createLogger({
    transports: [
        new winston.transports.Console(),
        new winston.transports.File({ 
            filename: 'combined.log',
            sync: true // 开启同步写入
        })
    ]
});

3. 监听进程崩溃事件 #

在进程的uncaughtException或unhandledRejection事件中，先完成日志刷新再退出进程：

const winston = require('winston');

const logger = winston.createLogger({
    transports: [
        new winston.transports.Console(),
        new winston.transports.File({ filename: 'combined.log' })
    ]
});

// 处理未捕获的异常
process.on('uncaughtException', async (err) => {
    logger.error('未捕获的异常:', err);
    // 等待日志写入完成后退出
    await new Promise(resolve => logger.transports[1].flush(resolve));
    process.exit(1);
});

let i=100000;
while(i-->0){
    logger.info('Hello world');
}

throw new Error('Error');

内容的提问来源于stack exchange，提问作者user2741831