why?: By default, winston doesn't show where the log comes from (function, file, line number...). This gist tries to workaround that limitation. code source: winstonjs/winston#890
Created
February 25, 2023 15:06
-
-
Save jerrylususu/27a723ca08d56654718e25ca07dc07a5 to your computer and use it in GitHub Desktop.
Node.js Winston logging with source lines example
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
## method | |
disable line no / file name logging: comment out line 10~13 in `index.js` | |
benchmark use `gocannon`: ./gocannon http://localhost:3000 -d 10s -c 50 | |
## summary | |
without: 3495 req/s | |
with: 3204 req/s | |
perf cost: ~8.3% | |
## without line no / file name logging | |
Attacking http://localhost:3000 with 50 connections over 10s using 4 CPUs | |
gocannon goes brr... | |
Total Req: 34952 | |
Req/s: 3495.20 | |
Interval stats: (interval = 250ms) | |
|--REQS--| |------------------------LATENCY-------------------------| | |
Count AVG P50 P75 P90 P99 | |
458 25.8442ms 23.3829ms 27.2571ms 32.2578ms 49.5821ms | |
569 22.1120ms 21.8482ms 23.0722ms 24.1072ms 25.7898ms | |
594 21.0490ms 20.6712ms 21.5269ms 22.6293ms 26.3451ms | |
690 18.1833ms 17.9538ms 19.1818ms 20.4899ms 30.9507ms | |
719 17.4896ms 16.4754ms 18.2747ms 22.1431ms 32.7838ms | |
768 16.2350ms 16.1180ms 16.8924ms 17.7465ms 19.5314ms | |
815 15.3881ms 15.0551ms 15.7312ms 17.1888ms 25.9920ms | |
864 14.4900ms 14.1435ms 14.5879ms 16.6522ms 19.7990ms | |
878 14.2161ms 14.1307ms 14.5715ms 15.6243ms 17.2240ms | |
882 14.1489ms 14.0052ms 14.3521ms 14.8451ms 17.0768ms | |
848 14.7781ms 13.6755ms 14.8186ms 19.2275ms 26.9868ms | |
879 14.2383ms 13.7428ms 14.5117ms 16.1441ms 24.7835ms | |
885 14.0974ms 13.3969ms 14.0188ms 17.8626ms 20.5165ms | |
947 13.1151ms 13.1192ms 13.4033ms 13.5918ms 15.3343ms | |
905 13.8797ms 13.6873ms 14.4155ms 15.3361ms 17.5092ms | |
894 13.9085ms 13.3956ms 13.8387ms 16.3138ms 20.7168ms | |
949 13.2528ms 13.0991ms 13.5689ms 14.5484ms 15.5259ms | |
931 13.4792ms 13.1328ms 13.7163ms 16.1166ms 19.9574ms | |
930 13.3030ms 13.3488ms 13.8446ms 15.1255ms 19.1597ms | |
960 13.0987ms 12.9476ms 13.4628ms 14.3893ms 17.5773ms | |
829 15.0613ms 14.0233ms 14.8693ms 17.6066ms 28.4333ms | |
938 13.3049ms 13.3658ms 13.7919ms 14.2921ms 15.5163ms | |
896 13.9752ms 13.4951ms 14.1176ms 17.2068ms 21.7407ms | |
988 12.6860ms 12.5219ms 13.1900ms 14.7095ms 16.0405ms | |
937 13.2674ms 12.9765ms 13.5940ms 15.7229ms 19.1452ms | |
965 12.9722ms 12.7691ms 13.1163ms 14.5703ms 17.4133ms | |
963 12.9934ms 12.8559ms 13.3873ms 14.3052ms 15.0799ms | |
957 13.0464ms 12.8626ms 13.2365ms 14.0347ms 17.0460ms | |
953 13.1252ms 12.8791ms 13.6698ms 14.5584ms 15.6707ms | |
758 16.3127ms 13.6787ms 17.7732ms 27.9488ms 39.4134ms | |
970 13.0190ms 12.8637ms 13.4615ms 14.1488ms 15.7439ms | |
937 13.2700ms 12.8959ms 13.3711ms 15.7014ms 25.9828ms | |
899 13.8892ms 13.2595ms 14.3760ms 17.3312ms 20.3996ms | |
918 13.7387ms 13.2634ms 14.5906ms 16.3839ms 22.9320ms | |
974 12.8078ms 12.4575ms 12.9062ms 15.1095ms 19.1516ms | |
968 12.8880ms 12.7404ms 13.1320ms 14.5098ms 19.6310ms | |
942 13.2577ms 13.1053ms 13.5921ms 14.6262ms 18.2704ms | |
948 13.1915ms 12.9714ms 13.7257ms 15.6529ms 21.7514ms | |
916 13.5281ms 13.3490ms 13.8036ms 14.2574ms 19.0630ms | |
931 13.5173ms 13.3797ms 13.6633ms 14.6346ms 16.5966ms | |
---------- | |
34952 14.2901ms 13.3958ms 14.6026ms 17.7465ms 26.7069ms | |
Responses by HTTP status code: | |
200 -> 34952 | |
## with line no / file name logging | |
Attacking http://localhost:3000 with 50 connections over 10s using 4 CPUs | |
gocannon goes brr... | |
Total Req: 32043 | |
Req/s: 3204.30 | |
Interval stats: (interval = 250ms) | |
|--REQS--| |------------------------LATENCY-------------------------| | |
Count AVG P50 P75 P90 P99 | |
432 27.5755ms 24.7449ms 27.1762ms 38.9615ms 61.4458ms | |
555 22.4508ms 22.4334ms 23.4422ms 23.8177ms 25.1948ms | |
572 21.8803ms 21.2945ms 23.4420ms 25.0340ms 29.5757ms | |
685 18.2078ms 17.8909ms 19.3792ms 20.4553ms 29.5776ms | |
701 17.9507ms 17.5373ms 19.0518ms 20.9483ms 25.8483ms | |
706 17.7859ms 17.0134ms 19.0553ms 22.1766ms 25.7361ms | |
770 16.2938ms 15.6004ms 17.1695ms 19.4394ms 21.4295ms | |
833 15.0295ms 14.8916ms 15.3590ms 16.3660ms 16.8254ms | |
865 14.4561ms 14.3586ms 14.9402ms 17.2988ms 21.7790ms | |
861 14.4012ms 14.3298ms 14.9216ms 15.2871ms 15.6972ms | |
831 15.1284ms 14.5429ms 16.0055ms 19.4530ms 25.9611ms | |
812 15.2346ms 14.9929ms 15.7487ms 16.1371ms 18.8379ms | |
868 14.5543ms 14.2480ms 14.8253ms 16.9966ms 17.3114ms | |
864 14.4083ms 14.1180ms 14.5544ms 16.1599ms 19.8636ms | |
855 14.6617ms 14.2212ms 14.8484ms 16.3958ms 20.8048ms | |
886 14.0492ms 13.9436ms 14.3381ms 14.7308ms 16.7339ms | |
901 13.9776ms 13.7766ms 14.3156ms 15.9564ms 17.4717ms | |
838 14.7584ms 14.3752ms 15.0662ms 16.5879ms 23.1690ms | |
825 15.1679ms 14.8319ms 15.3487ms 17.7969ms 21.9793ms | |
814 15.2518ms 14.9577ms 15.8061ms 16.4585ms 19.1865ms | |
860 14.7130ms 14.5644ms 15.0391ms 16.4494ms 22.6582ms | |
831 15.0345ms 14.6650ms 15.2414ms 17.1102ms 19.0298ms | |
855 14.6276ms 14.4125ms 15.1532ms 15.6730ms 18.3026ms | |
867 14.4253ms 14.4473ms 14.8038ms 15.4259ms 16.5588ms | |
867 14.4036ms 14.3030ms 14.7887ms 15.8689ms 16.8083ms | |
872 14.3425ms 14.2776ms 14.6434ms 15.0936ms 17.1534ms | |
839 14.8852ms 14.3241ms 14.7169ms 19.3854ms 20.2019ms | |
841 14.7220ms 14.5203ms 14.9814ms 15.6032ms 18.2284ms | |
811 15.5508ms 15.2127ms 15.9921ms 18.1572ms 20.6724ms | |
888 14.0586ms 13.8034ms 14.4153ms 15.1900ms 17.6392ms | |
970 12.9712ms 13.4499ms 14.3082ms 14.8291ms 15.8381ms | |
313 39.4220ms 14.4465ms 17.9910ms 167.9722ms 170.8162ms | |
841 14.9566ms 14.5815ms 15.4027ms 16.6175ms 18.2388ms | |
833 15.0414ms 14.7481ms 15.2262ms 16.8827ms 20.4082ms | |
824 15.1230ms 14.8337ms 15.5041ms 16.3993ms 22.4337ms | |
838 14.9308ms 14.3337ms 15.0785ms 18.7772ms 21.0754ms | |
789 15.8302ms 15.5121ms 16.6774ms 18.0671ms 21.2681ms | |
871 14.3293ms 14.1187ms 14.6803ms 15.2785ms 17.1435ms | |
881 14.1797ms 14.0712ms 14.7812ms 15.3772ms 20.0545ms | |
878 14.2621ms 14.2022ms 14.7461ms 15.4875ms 16.3227ms | |
---------- | |
32043 15.5877ms 14.5811ms 15.6429ms 18.6193ms 26.2815ms | |
Responses by HTTP status code: | |
200 -> 32043 |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
const express = require('express') | |
const logger = require("./logger"); | |
const app = express() | |
const port = 3000 | |
function someFunc(){ | |
logger.info("great job!") | |
} | |
app.get('/', (req, res) => { | |
res.send('Hello World!') | |
someFunc() | |
}) | |
app.listen(port, () => { | |
console.log(`Example app listening on port ${port}`) | |
}) |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
const winston = require("winston"); | |
const StackElements = require("./stackElements"); | |
const logger = winston.createLogger({ | |
level: "debug", | |
format: winston.format.json(), | |
transports: [new winston.transports.Console()], | |
}); | |
logger.old_info = logger.info; | |
logger.info = function(msg, ...vars) { | |
logger.old_info(StackElements.getFormatedStackTraceElement(1) + ": " + msg, ...vars); | |
} | |
module.exports = logger; |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
const path = require('path'); | |
class V8StackElements { | |
static get stack() { | |
return this.customStack; | |
} | |
constructor(callerIndex) { | |
// Use V8's feature to get a structured stack trace | |
const oldStackTrace = Error.prepareStackTrace; | |
const oldLimit = Error.stackTraceLimit; | |
try { | |
Error.stackTraceLimit = callerIndex + 1; // <- we only want the top couple of elements | |
Error.prepareStackTrace = (err, structuredStackTrace) => structuredStackTrace; | |
Error.captureStackTrace(this); | |
this.customStack = this.stack; // <- invoke the getter for 'stack' | |
} finally { | |
Error.stackTraceLimit = oldLimit; | |
Error.prepareStackTrace = oldStackTrace; | |
} | |
} | |
} | |
class StackElements { | |
static getFormatedStackTraceElement(callerIndex = 0) { | |
callerIndex = callerIndex + 2; //ignor v8 level and this level | |
const stack = new V8StackElements(callerIndex).stack; | |
const element = stack[callerIndex]; | |
const fileName = path.basename(element.getFileName()); | |
return element.getFunctionName() + "(" + fileName + ":" + element.getLineNumber() + ")"; | |
} | |
} | |
module.exports = StackElements; |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Okay, I will explain my-loader.js line by line.
The first line exports a function that takes the source code as an argument and returns a transformed version of it. This is how webpack loaders work.
The second line gets the file name from webpack using this.resourcePath, which is a property that contains the absolute path of the current file. Then it splits the path by / and pops the last element, which is the file name.
The third line uses a regular expression to replace all occurrences of console.log(...) with console.log('[file-name:line-number]', ...). It uses a callback function to generate the new console.log statement based on the match and arguments.
The fourth line gets the line number from match index using source.substr(0, match.index).split('\n').length. It takes a substring of the source code from 0 to match index, which is where console.log starts. Then it splits it by \n, which is a newline character. Then it counts how many elements are in the array, which is equal to how many lines are before console.log. This gives us the line number.
The fifth line returns a new console.log statement with [file-name:line-number] added as a prefix to args. Args are whatever was inside console.log parentheses.