const fs = require('fs'); const os = require("os"); const path = require("path"); let rfs = require('rotating-file-stream'); const mkdirp = require('mkdirp'); const onHeaders = require('on-headers'); const dateFMT = 'yyyymmdd HH:MM:ss.l'; const dateFMT_SQL = 'yyyy-mm-dd HH:MM:ss.l'; const fileFMT = 'yyyymmddHHMMss'; const dateFormat = require('dateformat'); const sqlite3 = require('sqlite3').verbose(); process.env.pm_id = process.env.pm_id | '0'; let db; //const db = new sqlite3.Database( path.resolve(__dirname, `statDB/stat_${process.env.pm_id}.db`) ); const cron = require('node-cron'); // import cron from 'node-cron'; let conf = {}; conf.projectName = 'PROJECT_NAME'; conf.log = {}; conf.log.time = null; //min conf.log.size = null; //maxsize per file, k conf.log.path = './appLogPath/'; conf.log.level = 'debug'; //debug,info,warn,error conf.log.console = false; conf.log.file = true; conf.summary = {}; conf.summary.time = 15; conf.summary.size = null; conf.summary.path = './summaryPath/'; conf.summary.console = false; conf.summary.file = true; conf.detail = {}; conf.detail.time = 15; conf.detail.size = null; conf.detail.path = './detailPath/'; conf.detail.console = false; conf.detail.file = true; conf.stat = {}; conf.stat.time = 15; conf.stat.size = 15; conf.stat.path = './statPath/'; conf.stat.mode = 0; //0 == file, 1== :memory: conf.stat.pathDB = undefined; //optional, folder path DB conf.stat.statInterval = 15; conf.stat.console = false; conf.stat.file = true; // conf.stat.process = [{ // name:'stat_name_1', // threshold: 10 // },{ // name:'stat_name_2', // threshold: 10 // }]; // conf.alarm = {}; // conf.alarm.time = 15; // conf.alarm.size = 15; // conf.alarm.path = './alarmPath/'; // conf.alarm.console = false; // conf.alarm.file = true; let log = { initLog: false } function getLogFileName(date, index) { return os.hostname() + '_' + conf.projectName + (date ? ('_' + dateFormat(date, fileFMT) + '.' + index) : '') + '.log'; } function getStatFileName(date, index) { return os.hostname() + '_' + conf.projectName + (date ? ('_' + dateFormat(date, fileFMT) + '.' + index) : '') + '.' + process.env.pm_id + '.stat'; } function getSummaryFileName(date, index) { return os.hostname() + '_' + conf.projectName + (date ? ('_' + dateFormat(date, fileFMT) + '.' + index) : '') + '.summary'; } function getDetailFileName(date, index) { return os.hostname() + '_' + conf.projectName + (date ? ('_' + dateFormat(date, fileFMT) + '.' + index) : '') + '.detail'; } function getConf(type) { if (type === 'app') return conf['log']; else if (type === 'stt') return conf['stat']; else if (type === 'smr') return conf['summary']; else if (type === 'dtl') return conf['detail']; } function generator(type) { return (time, index) => { if (type === 'app') return getLogFileName(time, index); else if (type === 'stt') return getStatFileName(time, index); else if (type === 'smr') return getSummaryFileName(time, index); else if (type === 'dtl') return getDetailFileName(time, index); } } function createOpts(conf) { let o = { path: conf.path }; if (conf.size) o.size = conf.size + 'K'; if (conf.time) o.interval = conf.time + 'm'; return o; } function createStream(type) { let conf = getConf(type); let stream = rfs(generator(type), createOpts(conf)); return stream; } var streamTask = { app: [], stt: [], smr: [], dtl: [] }; function toStr(txt) { // console.log(txt + 'txt instanceof Object ' + (txt instanceof Object)); // console.log(txt + 'txt instanceof Array ' + (txt instanceof Array)); if ( txt instanceof Error ) { return txt.message + ', ' + txt.stack; } else if ( txt instanceof Object ) { return JSON.stringify(txt); } else { return txt; } } function printTxtOrError( _txt ){ if (_txt instanceof Error) { return _txt; }else{ return _txt; } } function processApplog(lvlAppLog, ..._txt) { let session; let rtxt = ''; if (_txt instanceof Array) { if (_txt.length > 1) { //index0 == session, index1 == text session = _txt[0]; rtxt = toStr(_txt[1]) for (let i = 2; i < _txt.length; i++) { rtxt += ' ' + toStr(_txt[i]); } } else { session = ''; rtxt = _txt[0]; } } else { session = ''; rtxt = toStr(_txt); } return `${getDateTimeLogFormat(new Date())}|${session}|${lvlAppLog}|${rtxt}`; } function write(type, txt) { for (const stream of streamTask[type]) { stream.write(txt + '\r\n'); } } function getDateTimeLogFormat(currentDates) { var years = currentDates.getFullYear(); var months = currentDates.getMonth() + 1; var day = currentDates.getDate(); var hours = currentDates.getHours(); var minutes = currentDates.getMinutes(); var second = currentDates.getSeconds(); var millisecs = currentDates.getMilliseconds(); var monthFormatted = months < 10 ? "0" + months : months; var dayFormatted = day < 10 ? "0" + day : day; var hourFormatted = hours < 10 ? "0" + hours : hours; var minFormatted = minutes < 10 ? "0" + minutes : minutes; var secFormatted = second < 10 ? "0" + second : second; var milliFormatted = null; if (millisecs < 10) { milliFormatted = "00" + millisecs; } else if (millisecs < 100) { milliFormatted = "0" + millisecs; } else { milliFormatted = millisecs; } var detail = '' + years + monthFormatted + dayFormatted + ' ' + hourFormatted + ':' + minFormatted + ':' + secFormatted + '.' + milliFormatted + '|' + os.hostname() + '|' + conf.projectName; return detail; } function initDB() { if (conf.stat.mode === 0) { db = new sqlite3.cached.Database(':memory:'); } else if (conf.stat.mode === 1) { if (!conf.stat.pathDB) { conf.stat.pathDB = path.resolve(__dirname, 'statDB'); } if (!fs.existsSync(conf.stat.pathDB)) { fs.mkdirSync(conf.stat.pathDB); } db = new sqlite3.cached.Database(`${conf.stat.pathDB}/stat_${process.env.pm_id}.db`); } db.serialize(function () { db.run("CREATE TABLE IF NOT EXISTS stat (stat_time TEXT, stat_name TEXT);"); }); } function initLog() { if (conf.log) { if (conf.log.file) { if (!fs.existsSync(conf.log.path)) { //fs.mkdirSync(conf.log.path); mkdirp.sync(conf.log.path); } streamTask['app'].push(createStream('app')); } if (conf.log.console) streamTask['app'].push(process.stdout); } if (conf.stat) { if (conf.log.file){ if (!fs.existsSync(conf.stat.path)) { //fs.mkdirSync(conf.stat.path); mkdirp.sync(conf.stat.path); } streamTask['stt'].push(createStream('stt')); } if (conf.log.console) streamTask['stt'].push(process.stdout); } if (conf.summary) { if (conf.log.file){ if (!fs.existsSync(conf.summary.path)) { // fs.mkdirSync(conf.summary.path); mkdirp.sync(conf.summary.path); } streamTask['smr'].push(createStream('smr')); } if (conf.log.console) streamTask['smr'].push(process.stdout); } if (conf.detail) { if (conf.log.file){ if (!fs.existsSync(conf.detail.path)) { // fs.mkdirSync(conf.detail.path); mkdirp.sync(conf.detail.path); } streamTask['dtl'].push(createStream('dtl')); } if (conf.log.console) streamTask['dtl'].push(process.stdout); } } function addStat(stat_name) { db.serialize(function () { //db.run("CREATE TABLE lorem (info TEXT, xx TEXT)"); /*var stmt = db.prepare("INSERT INTO lorem VALUES (?)"); for (var i = 0; i < 10; i++) { stmt.run("Ipsum " + i); } stmt.finalize(); db.run("INSERT INTO stat(stat_time, stat_name) VALUES (?)", ['xx',stat_name], function() { console.log( 'x' ); getStat(); });*/ /*db.run("INSERT INTO stat VALUES (?,?)", [dateFormat(new Date(), dateFMT_SQL), stat_name], function() { getStat(); });*/ db.run("INSERT INTO stat VALUES (?,?)", [dateFormat(new Date(), dateFMT_SQL), stat_name]); /*db.run("INSERT INTO stat VALUES (DATETIME('now'), '"+stat_name+"')", function() { console.log( 'x' ); getStat(); });*/ }); } //var prevStatDateRange; function fushStat() { var end = new Date(); end.setMilliseconds(0); //var start = new Date(end.getTime()); //start.setMinutes(end.getMinutes() - conf.log.statTime); var en = dateFormat(end, dateFMT_SQL); //var st = dateFormat(prevStatDateRange, dateFMT_SQL); //prevStatDateRange = end; //assign for next loop //console.log(st + '|' + en); //var path = getStatFileName(end); db.serialize(function () { //var stream = fs.createWriteStream(path, { 'flags': 'a' }); write('stt', en); db.each("SELECT stat_name, count(stat_name) as count FROM stat WHERE stat_time < ? group by stat_name order by stat_time", [en], function (err, row) { if (err) { console.log(err); return; } //console.log(path+' '+ row.stat_name + ' ' + row.count ); write('stt', row.stat_name + ' ' + row.count); }); db.run("DELETE FROM stat WHERE stat_time < ?", [en]); /*db.each("SELECT stat_name, count(stat_name) as count FROM stat WHERE stat_time BETWEEN ? AND ? group by stat_name order by stat_name", [st, en], function (err, row) { if (err) { console.log(err); return; } //console.log(path+' '+ row.stat_name + ' ' + row.count ); write(end, 'stt', row.stat_name + ' ' + row.count, false); }); db.run("DELETE FROM stat WHERE stat_time BETWEEN ? AND ?", [st, en]);*/ }); } function getIntervalTime(type) { if (type === 'app') { return conf.log.time; } else if (type === 'stt') { return conf.stat.time; } else if (type === 'smr') { return conf.summary.time; } else if (type === 'dtl') { return conf.detail.time; } return null; } log.stat = function (stat_name) { addStat(stat_name); } log.debug = function (..._log) { if (conf.log.level > 0) return; write('app', processApplog('debug', ..._log)); } log.info = function (..._log) { if (conf.log.level > 1) return; write('app', processApplog('info', ..._log)); } log.warn = function (..._log) { if (conf.log.level > 2) return; write('app', processApplog('warn', ..._log)); } log.error = function (..._log) { if (conf.log.level > 3) return; write('app', processApplog('error', ..._log)); } log.detail = function (detailLog) { write('dtl', detailLog); } // log.detail = function (session, scenario, identity) { // var startTimeDate = new Date(); // var inputTime; // var outputTime; // var detailLog = { // Session: session, // InitInvoke: '', //only equinox platform // Scenario: scenario, // Identity: identity, // InputTimeStamp: null, // Input: [], // OutputTimeStamp: null, // Output: [], // ProcessingTime: null, // addInputRequest: function (node, cmd, rawData, data) { // this.addInput(node, cmd, 'REQ', rawData, data); // }, // addInputResponse: function (node, cmd, rawData, data, resTime) { // this.addInput(node, cmd, 'RES', rawData, data, resTime); // }, // addInputResponseTimeout: function (node, cmd) { // this.addInput(node, cmd, 'RES_TIMEOUT'); // }, // addInputResponseError: function (node, cmd) { // this.addInput(node, cmd, 'RES_ERROR'); // }, // addInput: function (node, cmd, type, rawData, data, resTime) { // inputTime = new Date(); // if (typeof resTime === 'number') { // resTime = resTime.toLocaleString() + ' ms'; // } // var input = { // Invoke: null, // Event: node + '.' + cmd, // Type: type, // RawData: rawData, // Data: data, // ResTime: resTime // }; // this.Input.push(input); // }, // addOutputRequest: function (node, cmd, rawData, data) { // this.addOutput(node, cmd, 'REQ', rawData, data); // }, // addOutputResponse: function (node, cmd, rawData, data) { // this.addOutput(node, cmd, 'RES', rawData, data); // }, // addOutputRequestRetry: function (node, cmd, rawData, data, total, maxCount) { // this.addOutput(node, cmd, ('REQ_RETRY_' + total + '/' + maxCount), rawData, data); // }, // addOutput: function (node, cmd, type, rawData, data) { // outputTime = new Date(); // var input = { // Invoke: null, // Event: node + '.' + cmd, // Type: type, // RawData: rawData, // Data: data // }; // this.Output.push(input); // }, // end: function () { // let currentTime = new Date(); // detailLog.ProcessingTime = new Date().getTime() - startTimeDate.getTime(); // detailLog.InputTimeStamp = dateFormat(inputTime, dateFMT); // detailLog.OutputTimeStamp = dateFormat(outputTime, dateFMT);; // write('dtl', JSON.stringify(detailLog)); // startTimeDate = currentTime; // detailLog._clr(); // }, // _clr: function (){ // detailLog.ProcessingTime = null; // detailLog.InputTimeStamp = null; // detailLog.OutputTimeStamp= null; // detailLog.Input=[]; // detailLog.Output=[]; // } // } // return detailLog; // } log.summary = function (session, cmd, identity) { var now = new Date(); var summaryLog = { requestTime: now, session: session, initInvoke: '', //only equinox platform cmd: cmd, identity: identity, /*resultCode: null, resultDescription: null,*/ blockDetail: [], addSuccessBlock: function (node, cmd, resultCode, resultDesc) { //this.blockDetail.push('['+ node+'; '+cmd+'(1); ['+ resultCode+'; '+resultDesc+'(1)]]'); addBlock(this.blockDetail, node, cmd, resultCode, resultDesc); }, addErrorBlock: function (node, cmd, resultCode, resultDesc) { //this.blockDetail.push('['+ node+'; '+cmd+'(1); ['+ resultCode+'; '+resultDesc+'(1)]]'); addBlock(this.blockDetail, node, cmd, resultCode, resultDesc); }, end: function (resultCode, resultDescription) { var endTime = new Date(); var blockDetailTxt = '['; for (var j = 0; j < this.blockDetail.length; j++) { var i = this.blockDetail[j]; var aa = i.node + '; ' + i.cmd + '(' + i.count + '); ['; for (var k = 0; k < i.result.length; k++) { var bb = i.result[k].resultCode + '; ' + i.result[k].resultDesc + '(' + i.result[k].count + ')'; if (k === i.result.length - 1) { aa += bb; } else { aa += (bb + ', '); } } if (j === this.blockDetail.length - 1) { aa += ']'; } else { aa += '], '; } blockDetailTxt += aa; } blockDetailTxt += ']'; var txt = dateFormat(this.requestTime, dateFMT) + '|'; txt += this.session + '|'; txt += this.initInvoke + '|' txt += this.cmd + '|' txt += this.identity + '|' txt += resultCode + '|' txt += resultDescription + '|' txt += blockDetailTxt + '|' txt += dateFormat(endTime, dateFMT) + '|' txt += (endTime.getTime() - this.requestTime.getTime()); write('smr', txt); } }; return summaryLog; } function addBlock(store, node, cmd, resultCode, resultDesc) { var found = null; for (var i = 0; i < store.length; i++) { if (store[i].node === node && store[i].cmd === cmd) { found = store[i]; store[i].count++; break; } } if (!found) { var result = { resultCode: resultCode, resultDesc: resultDesc, count: 1 } var b = { node: node, cmd: cmd, count: 1, result: [result] } store.push(b); } else { var foundResult = false; for (var j = 0; j < found.result.length; j++) { if (found.result[j].resultCode === resultCode && found.result[j].resultDesc === resultDesc) { found.result[j].count++; foundResult = true; break; } } if (!foundResult) { var result = { resultCode: resultCode, resultDesc: resultDesc, count: 1 } found.result.push(result); } } } log.init = function (_conf, express) { log.initLog = true; if (_conf) { conf = _conf; } if (conf.log) { if (conf.log.level === 'debug') { conf.log.level = 0; } else if (conf.log.level === 'info') { conf.log.level = 1; } else if (conf.log.level === 'warn') { conf.log.level = 2; } else if (conf.log.level === 'error') { conf.log.level = 3; } else { conf.log.level = 4; } //enable only debug if (express && conf.log.level === 0) { express.use(function (req, res, next) { req._reqTimeForLog = Date.now(); let sid; if(typeof log.sessionID === 'function'){ sid = log.sessionID(req, res); } let txtLogReq = 'INCOMING|__Method=' +req.method + ' __URL=' + req.url + ' __Headers=' + JSON.stringify(req.headers ) //+ ' __Params=' + JSON.stringify(req.params ) + ' __Body=' + JSON.stringify(req.body ); if(sid){ log.debug(sid, txtLogReq); }else{ log.debug(txtLogReq); } onHeaders(res, ()=>{ let txtLogRes = 'OUTGOING|__Statuscode=' + res.statusCode + ' __Headers=' + JSON.stringify(res._headers ) + ' __Body=' + req.res.resBody + ' __Restime=' + ( Date.now() - req._reqTimeForLog ); if(sid){ log.debug(sid, txtLogRes); }else{ log.debug(txtLogRes); } }); next(); }); } } initLog(); if (conf.stat) { initDB(); cron.schedule('*/' + conf.stat.statInterval + ' * * * *', function () { fushStat(); }); } return log; }; module.exports = log; // module.exports = commonLog();