如何用log4j或winston编写大量的日志? 内存不足

loggingNodeJS

作为nodejs的开端,我写了如下的testing代码。 但内存越来越大,有时甚至没有输出(通过多种方式改变它)。

有2个着名的日志模块, log4js和winston 。 以log4js为例。

1. main.js

(function(){ "use strict"; let log4js = require("./log4js-config.js"); let logger = log4js.getLogger("log4js_main"); for(let i = 0; i < 10000000 ; i++){ logger.log("info", "info message " + i + "."); } })(); 

2. log4js-config.js

 module.exports = (function(){ "use strict"; let Log4js = require("log4js"); Log4js.configure( { "appenders" : [ { "type" : "logLevelFilter" ,"level" : "ALL" ,"appender" : { "type" : "console" } } ,{ "type" : "logLevelFilter" ,"level" : "ALL" ,"appender" : { "type" : "dateFile" ,"filename" : "./logs/log4js_date" ,"pattern" : "-yyyyMMdd.log" ,"alwaysIncludePattern" : false ,"maxLogSize" : 209715200 ,"_maxLogSize" : "200M = 200 * 1024 * 1024 = 209715200" ,"category" : "log4js.dateFile" } } ,{ "type" : "logLevelFilter" ,"level" : "ALL" ,"appender" : { "type" : "file" ,"filename" : "./logs/log4js_size.log" ,"maxLogSize" : 209715200 ,"_maxLogSize" : "200M = 200 * 1024 * 1024 = 209715200" ,"alwaysIncludePattern" : false ,"backups" : 10 ,"category" : "log4js.file" } } ] ,"replaceConsole" : true } ); return Log4js; })(); 

循环次数less的时候,虽然记忆力增加了,从来没有倒下过,但效果很好。 但是,如果时间超过1000万,就会失败,提示如下:

 ... [2015-12-14 11:23:12.480] [INFO] log4js_main - info message 2525074. [2015-12-14 11:23:12.480] [INFO] log4js_main - info message 2525075. [2015-12-14 11:23:12.480] [INFO] log4js_main - info message 2525076. [2015-12-14 11:23:12.480] [INFO] log4js_main - info message 2525077. [2015-12-14 11:23:12.480] [INFO] log4js_main - info message 2525078. [2015-12-14 11:23:12.480] [INFO] log4js_main - info message 2525079. [2015-12-14 11:23:12.480] [INFO] log4js_main - info message 2525080. [2015-12-14 11:23:12.480] [INFO] log4js_main - info message 2525081. [2015-12-14 11:23:12.480] [INFO] log4js_main - info message 2525082. <--- Last few GCs ---> 420299 ms: Scavenge 1399.0 (1457.4) -> 1399.0 (1457.4) MB, 2.3 / 0 ms (+ 0.0 ms in 1 steps since l ast GC) [allocation failure] [incremental marking delaying mark-sweep]. 421110 ms: Mark-sweep 1399.0 (1457.4) -> 1399.0 (1457.4) MB, 814.3 / 0 ms (+ 15.0 ms in 2 steps si nce start of marking, biggest step 15.0 ms) [last resort gc]. 421937 ms: Mark-sweep 1399.0 (1457.4) -> 1399.0 (1457.4) MB, 828.6 / 0 ms [last resort gc]. <--- JS stacktrace ---> ==== JS stack trace ========================================= Security context: 0000019446CE3AD1 <JS Object> 1: nextTick [node.js:~491] [pc=0000037DBBD17738] (this=0000012811B14929 <a process with map 0000 02F23C011991>,callback=0000017AB4E49C01 <JS Function afterWrite (SharedFunctionInfo 000002DC70230AF1 )>) 2: arguments adaptor frame: 5->1 3: onwrite(aka onwrite) [_stream_writable.js:~315] [pc=0000037DBB93CC17] (this=0000019446C04189 <undefined>,stream=000000727BB2BEE1 <a WriteStream wit... FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - process out of memory 

PS

作为我在stackoverflow.com中的第一个问题,我想分享一些困扰我很久的事情。 所以来到这个问题。

TL;博士

有必要让logging器有机会通过setImmediate()完成I / O工作,并使用事件而不是“for”来执行循环,否则会将内容保留在内存中,并因为内存不足而死亡。

根本原因

这是由nodejs的事件循环机制引起的 , bool ev_run(loop,int flags) ,它每次按照这个顺序从观察者那里接受一个任务:

 空闲 - > I / O  - >检查 

' for '和' process.nextTick() '是空闲的观察者,所以logging器没有机会做底层的I / O工作。 这会导致内存不足。

所以,我们需要给logging员一个机会去做下面的工作。

main.js for log4js

 (function(){ "use strict"; const WORK_DONE_EVENT_NAME = "work-done"; const WORK_TIMES = 100 * 1000 * 1000; let evem = new (require("events").EventEmitter)(); // Explicitly listening on the event. evem.on(WORK_DONE_EVENT_NAME, function(){ // setImmediate: after I/O operations setImmediate(doWork); }); let log4js = require("./log4js-config.js"); let logger = log4js.getLogger("log4js_main"); let idx = 0; function doWork(){ idx++; if(idx >= WORK_TIMES){ console.timeEnd(WORK_DONE_EVENT_NAME); return; } logger.info(idx); setImmediate(function(){ evem.emit(WORK_DONE_EVENT_NAME); }); } console.time(WORK_DONE_EVENT_NAME); doWork(); })(); 

log4js-config.js(保持不变)

winston的main.js

 (function(){ "use strict"; const WORK_DONE_EVENT_NAME = "work-done"; const WORK_TIMES = 100 * 1000 * 1000; let evem = new (require("events").EventEmitter)(); let logger = require("./winston-config"); // Explicitly listening on the event. evem.on(WORK_DONE_EVENT_NAME, function(){ // setImmediate: after I/O operations setImmediate(doWork); }); let idx = 0; function doWork(){ idx++; if(idx >= WORK_TIMES){ console.timeEnd(WORK_TIMES); return; } logger.silly(idx, function(err, level, msg, meta){ if(err){ throw err; } evem.emit(WORK_DONE_EVENT_NAME); }); } console.time(WORK_TIMES); doWork(); })(); 

温斯顿- config.js

 module.exports = (function(){ "use strict"; let Winston = require("winston"); let WinstonDailyRotateFile = require("winston-daily-rotate-file"); let transports = [ new (Winston.transports.Console)({ "colorize" : true ,"timestamp" : true ,"showLevel": true ,"level" : "silly" }) ,new (Winston.transports.File)({ "name" : "winston-file" ,"filename" : "./logs/winston_size.log" ,"maxsize" : 209715200 , "_maxsize" : "200M = 200 * 1024 * 1024 = 209715200" ,"maxFiles" : 1024 ,"timestamp" : true ,"showLevel": true ,"level": "silly" }) ,new (WinstonDailyRotateFile)({ "name" : "winston-daily-file" ,"filename" : "./logs/winston_date" ,"datePattern" : "-yyyyMMdd.log" ,"maxsize" : 209715200 , "_maxsize" : "200M = 200 * 1024 * 1024 = 209715200" ,"maxFiles" : 10 ,"timestamp" : true ,"level": "silly" }) ]; let logger = new (Winston.Logger)({ "transports" : transports }); return logger; })();