fix: changed internal logger timestamp to ISO string

[abhilash-sivan]

This was by default UNIX format for pino

[kirrg001]

Could you please share before and after (including Bunyan)?

[abhilash-sivan]

BEFORE CHANGES

PINO

{"level":30,"time":1737018253049,"name":"@instana/collector","module":"pidStore","threadId":0,"msg":"PID Store starting with pid 52675"}
The App is using the following preload flags: noFlags
{"level":30,"time":1737018253763,"pid":52675,"hostname":"mac.in.ibm.com","msg":"Server is running on http://localhost:3000"}
{"level":30,"time":1737018253128,"name":"@instana/collector","module":"index","threadId":0,"msg":"@instana/collector module version: 4.5.3"}
{"level":30,"time":1737018253133,"name":"@instana/collector","module":"announceCycle","threadId":0,"msg":"Transitioning from <init> to agentHostLookup"}
{"level":20,"time":1737018253468,"name":"@instana/collector","module":"index","threadId":0,"msg":"Attempt to load native add-on gcstats.js directly has been successful."}
{"level":20,"time":1737018253756,"name":"@instana/collector","module":"index","threadId":0,"msg":"Attempt to load native add-on event-loop-stats directly has been successful."}
{"level":30,"time":1737018253773,"module":"instana-nodejs-logger-parent","module":"announceCycle/agentHostLookup","threadId":0,"msg":"Found an agent on 127.0.0.1:42699, proceeding to announce request."}
{"level":30,"time":1737018253773,"module":"instana-nodejs-logger-parent","module":"announceCycle","threadId":0,"msg":"Transitioning from agentHostLookup to unannounced"}
{"level":20,"time":1737018253776,"module":"instana-nodejs-logger-parent","module":"agentConnection","threadId":0,"msg":"Failed to retrieve inode for file descriptor 21: ENOENT: no such file or directory, readlink '/proc/52675/fd/21'"}
{"level":30,"time":1737018253779,"module":"instana-nodejs-logger-parent","module":"announceCycle","threadId":0,"msg":"Transitioning from unannounced to announced"}
{"level":30,"time":1737018254785,"module":"instana-nodejs-logger-parent","module":"announceCycle/announced","threadId":0,"msg":"The Instana host agent is ready to accept data."}
{"level":30,"time":1737018254786,"module":"instana-nodejs-logger-parent","module":"announceCycle","threadId":0,"msg":"Transitioning from announced to agentready"}
{"level":20,"time":1737018254787,"module":"instana-nodejs-logger-parent","module":"announceCycle/agentready","threadId":0,"msg":"isMainThread: true"}
{"level":30,"time":1737018254787,"module":"instana-nodejs-logger-parent","module":"util/uncaughtExceptionHandler","threadId":0,"msg":"Reporting unhandled promise rejections is disabled."}
{"level":30,"time":1737018254793,"module":"instana-nodejs-logger-parent","module":"announceCycle/agentready","threadId":0,"msg":"The Instana Node.js collector is now fully initialized and connected to the Instana host agent."}
{"level":20,"time":1737018254797,"module":"instana-nodejs-logger-parent","module":"metrics","threadId":0,"msg":"addDirectDependenciesFromMainPackageJson: /Users/abhi/instana/test-apps/app-with-logger/package.json"}
{"level":20,"time":1737018254809,"module":"instana-nodejs-logger-parent","module":"metrics","threadId":0,"msg":"Collection of direct dependencies took 11 ms."}
{"level":20,"time":1737018254816,"module":"instana-nodejs-logger-parent","module":"metrics","threadId":0,"msg":"Collection of dependencies took 29 ms."}

BUNYAN

{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"announceCycle","threadId":0,"level":30,"msg":"Transitioning from agentHostLookup to unannounced","time":"2025-01-16T09:05:02.561Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"agentConnection","threadId":0,"level":20,"msg":"Failed to retrieve inode for file descriptor 21: ENOENT: no such file or directory, readlink '/proc/52791/fd/21'","time":"2025-01-16T09:05:02.563Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"announceCycle","threadId":0,"level":30,"msg":"Transitioning from unannounced to announced","time":"2025-01-16T09:05:02.565Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"announceCycle/announced","threadId":0,"level":30,"msg":"The Instana host agent is ready to accept data.","time":"2025-01-16T09:05:03.571Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"announceCycle","threadId":0,"level":30,"msg":"Transitioning from announced to agentready","time":"2025-01-16T09:05:03.573Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"announceCycle/agentready","threadId":0,"level":20,"msg":"isMainThread: true","time":"2025-01-16T09:05:03.574Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"util/uncaughtExceptionHandler","threadId":0,"level":30,"msg":"Reporting unhandled promise rejections is disabled.","time":"2025-01-16T09:05:03.575Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"announceCycle/agentready","threadId":0,"level":30,"msg":"The Instana Node.js collector is now fully initialized and connected to the Instana host agent.","time":"2025-01-16T09:05:03.584Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"metrics","threadId":0,"level":20,"msg":"addDirectDependenciesFromMainPackageJson: /Users/abhi/instana/test-apps/app-with-logger/package.json","time":"2025-01-16T09:05:03.590Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"metrics","threadId":0,"level":20,"msg":"Collection of direct dependencies took 5 ms.","time":"2025-01-16T09:05:03.595Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52791,"module":"metrics","threadId":0,"level":20,"msg":"Collection of dependencies took 27 ms.","time":"2025-01-16T09:05:03.603Z","v":0}

AFTER CHANGES

PINO

{"level":30,"time":1737018492126,"pid":52936,"hostname":"mac.in.ibm.com","msg":"Server is running on http://localhost:3000"}
{"level":30,"time":"2025-01-16T09:08:12.068Z","name":"@instana/collector","module":"index","threadId":0,"msg":"@instana/collector module version: 4.5.3"}
{"level":30,"time":"2025-01-16T09:08:12.073Z","name":"@instana/collector","module":"announceCycle","threadId":0,"msg":"Transitioning from <init> to agentHostLookup"}
{"level":20,"time":"2025-01-16T09:08:12.124Z","name":"@instana/collector","module":"index","threadId":0,"msg":"Attempt to load native add-on gcstats.js directly has been successful."}
{"level":20,"time":"2025-01-16T09:08:12.125Z","name":"@instana/collector","module":"index","threadId":0,"msg":"Attempt to load native add-on event-loop-stats directly has been successful."}
{"level":30,"time":"2025-01-16T09:08:12.129Z","module":"instana-nodejs-logger-parent","module":"announceCycle/agentHostLookup","threadId":0,"msg":"Found an agent on 127.0.0.1:42699, proceeding to announce request."}
{"level":30,"time":"2025-01-16T09:08:12.129Z","module":"instana-nodejs-logger-parent","module":"announceCycle","threadId":0,"msg":"Transitioning from agentHostLookup to unannounced"}
{"level":20,"time":"2025-01-16T09:08:12.130Z","module":"instana-nodejs-logger-parent","module":"agentConnection","threadId":0,"msg":"Failed to retrieve inode for file descriptor 21: ENOENT: no such file or directory, readlink '/proc/52936/fd/21'"}
{"level":30,"time":"2025-01-16T09:08:12.133Z","module":"instana-nodejs-logger-parent","module":"announceCycle","threadId":0,"msg":"Transitioning from unannounced to announced"}
{"level":30,"time":"2025-01-16T09:08:13.137Z","module":"instana-nodejs-logger-parent","module":"announceCycle/announced","threadId":0,"msg":"The Instana host agent is ready to accept data."}
{"level":30,"time":"2025-01-16T09:08:13.137Z","module":"instana-nodejs-logger-parent","module":"announceCycle","threadId":0,"msg":"Transitioning from announced to agentready"}
{"level":20,"time":"2025-01-16T09:08:13.137Z","module":"instana-nodejs-logger-parent","module":"announceCycle/agentready","threadId":0,"msg":"isMainThread: true"}
{"level":30,"time":"2025-01-16T09:08:13.137Z","module":"instana-nodejs-logger-parent","module":"util/uncaughtExceptionHandler","threadId":0,"msg":"Reporting unhandled promise rejections is disabled."}
{"level":30,"time":"2025-01-16T09:08:13.140Z","module":"instana-nodejs-logger-parent","module":"announceCycle/agentready","threadId":0,"msg":"The Instana Node.js collector is now fully initialized and connected to the Instana host agent."}
{"level":20,"time":"2025-01-16T09:08:13.141Z","module":"instana-nodejs-logger-parent","module":"metrics","threadId":0,"msg":"addDirectDependenciesFromMainPackageJson: /Users/abhi/instana/test-apps/app-with-logger/package.json"}
{"level":20,"time":"2025-01-16T09:08:13.146Z","module":"instana-nodejs-logger-parent","module":"metrics","threadId":0,"msg":"Collection of direct dependencies took 5 ms."}
{"level":20,"time":"2025-01-16T09:08:13.150Z","module":"instana-nodejs-logger-parent","module":"metrics","threadId":0,"msg":"Collection of dependencies took 13 ms."}

BUNYAN

{"level":30,"time":"2025-01-16T09:07:39.379Z","name":"@instana/collector","module":"index","threadId":0,"msg":"@instana/collector module version: 4.5.3"}
{"level":30,"time":"2025-01-16T09:07:39.386Z","name":"@instana/collector","module":"announceCycle","threadId":0,"msg":"Transitioning from <init> to agentHostLookup"}
{"level":20,"time":"2025-01-16T09:07:39.469Z","name":"@instana/collector","module":"index","threadId":0,"msg":"Attempt to load native add-on gcstats.js directly has been successful."}
{"level":20,"time":"2025-01-16T09:07:39.471Z","name":"@instana/collector","module":"index","threadId":0,"msg":"Attempt to load native add-on event-loop-stats directly has been successful."}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"announceCycle/agentHostLookup","threadId":0,"level":30,"msg":"Found an agent on 127.0.0.1:42699, proceeding to announce request.","time":"2025-01-16T09:07:39.476Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"announceCycle","threadId":0,"level":30,"msg":"Transitioning from agentHostLookup to unannounced","time":"2025-01-16T09:07:39.476Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"agentConnection","threadId":0,"level":20,"msg":"Failed to retrieve inode for file descriptor 23: ENOENT: no such file or directory, readlink '/proc/52904/fd/23'","time":"2025-01-16T09:07:39.477Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"announceCycle","threadId":0,"level":30,"msg":"Transitioning from unannounced to announced","time":"2025-01-16T09:07:39.479Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"announceCycle/announced","threadId":0,"level":30,"msg":"The Instana host agent is ready to accept data.","time":"2025-01-16T09:07:40.485Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"announceCycle","threadId":0,"level":30,"msg":"Transitioning from announced to agentready","time":"2025-01-16T09:07:40.486Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"announceCycle/agentready","threadId":0,"level":20,"msg":"isMainThread: true","time":"2025-01-16T09:07:40.487Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"util/uncaughtExceptionHandler","threadId":0,"level":30,"msg":"Reporting unhandled promise rejections is disabled.","time":"2025-01-16T09:07:40.487Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"announceCycle/agentready","threadId":0,"level":30,"msg":"The Instana Node.js collector is now fully initialized and connected to the Instana host agent.","time":"2025-01-16T09:07:40.495Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"metrics","threadId":0,"level":20,"msg":"addDirectDependenciesFromMainPackageJson: /Users/abhi/instana/test-apps/app-with-logger/package.json","time":"2025-01-16T09:07:40.498Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"metrics","threadId":0,"level":20,"msg":"Collection of direct dependencies took 8 ms.","time":"2025-01-16T09:07:40.506Z","v":0}
{"name":"test-logger","hostname":"mac.in.ibm.com","pid":52904,"module":"metrics","threadId":0,"level":20,"msg":"Collection of dependencies took 28 ms.","time":"2025-01-16T09:07:40.516Z","v":0}

[kirrg001]

Commit suggestion

fix: changed internal logger timestamp to ISO string