Including sequence reset capability or local sequence capability
Closed this issue · 14 comments
I'm currently using Roarr for a node.js API server. I find the inclusion of a sequence number to be useful, but I was hoping that I can use it to see the sequence of events in a single API call. So for example if Request A comes I might see 4 events with sequence 1, 2, 3 and 4. The next Request B that comes will have 3 events with sequence 1, 2 and 3 occur
However, currently I notice that the sequence always increments across different API requests (and likely between API requests). This causes Request B in the above example to start with sequence = 5 and increments to sequence = 7. I did notice that Roarr makes use of a global sequence variable that increments every time a log call is made so I understand why this is happening.
I was wondering what are your thoughts on providing a capability to either use a locally specified sequence, or reset the sequence so that it would be possible to use the sequence to show the sequence of events for a particular action
How are you using sequence value?
@gajus The way that I'd like it to work is the following:
HTTP Request A to GET /endpoint comes
Log sequence 1
Log sequence 2
Log sequence 3
HTTP Request B to GET /endpoint comes
Log sequence 1
Log sequence 2
Log sequence 3
Right now Request B will create logs with sequence 4 to 6. I use a global singleton logger as is suggested in the README. Per incoming request I call logger.child(...) in an express middleware before any log methods are called.
Resetting sequences per request would help my team clearly see in a log aggregation tool which actions happened in what order for a particular request action/event
Logically, it could not work that way. You need some sort of unique identifier of a sequence.
Otherwise, it would not be clear how logs would be produced for operations that are executed in parallel, like:
Promise.all([require('https://a'), require('https://b')])Are you thinking of the calls above as being made within the logged application, or into the logged application?
The scenario I'm working with is about the latter, just want to make sure.
So for parallel requests into the application per request I will be making child loggers scoped to that particular request. Now I just want the sequence to be able to be scoped per logger instance, rather than the sequence used globally across all logger instances
So for parallel requests into the application per request I will be making child loggers scoped to that particular request. Now I just want the sequence to be able to be scoped per logger instance, rather than the sequence used globally across all logger instances
Can you produce an example of an expected log output?
Can you produce an example of an expected log output?
Sure thing:
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 1","sequence":1,"time":1624305447427,"version":"1.0.0"}
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 2","sequence":2,"time":1624305447427,"version":"1.0.0"}
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 1","sequence":1,"time":1624305451751,"version":"1.0.0"}
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 2","sequence":2,"time":1624305451751,"version":"1.0.0"}So the above is the ideal case for me (the zero-th sequence is at the start of the application). Above I made 2 GET /endpoint calls
In reality this is what I receive
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 1","sequence":1,"time":1624305447427,"version":"1.0.0"}
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 2","sequence":2,"time":1624305447427,"version":"1.0.0"}
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 1","sequence":3,"time":1624305451751,"version":"1.0.0"}
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 2","sequence":4,"time":1624305451751,"version":"1.0.0"}There is no guarantee in what order those comments are printed, i.e. You would actually get logs:
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 1","sequence":1,"time":1624305447427,"version":"1.0.0"}
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 1","sequence":1,"time":1624305451751,"version":"1.0.0"}
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 2","sequence":2,"time":1624305451751,"version":"1.0.0"}
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 2","sequence":2,"time":1624305447427,"version":"1.0.0"}
The only to make something like this to work would be to have "threadId" (or some other variable) that is created every time a new async context is created. I cannot think of a simple way to implement that.
There is no guarantee in what order those comments are printed, i.e. You would actually get logs:
{"context":{"path":"/endpoint","logLevel":30},"message":"Log event 1","sequence":1,"time":1624305447427,"version":"1.0.0"} {"context":{"path":"/endpoint","logLevel":30},"message":"Log event 1","sequence":1,"time":1624305451751,"version":"1.0.0"} {"context":{"path":"/endpoint","logLevel":30},"message":"Log event 2","sequence":2,"time":1624305451751,"version":"1.0.0"} {"context":{"path":"/endpoint","logLevel":30},"message":"Log event 2","sequence":2,"time":1624305447427,"version":"1.0.0"}
Oh yes agreed that can happen, but that is fine for me since in the real thing I will have request IDs forwarded to the application from outside. So a bit of jumbled re-ordering is fine. My example was probably too simplistic to showcase my tolerance for re-ordering across parallel execution
The main aim is just to have the sequence "restarted"/"reset" per distinct request. My thought was that if a sequence argument can be provided through the .child(...) API, the provided sequence can be used instead of incrementing the global sequence value. Would something like this be okay and align with your thoughts?
@gajus just wondering if you had the chance to see and think about my reply above
For your specific case, can you not just add a second sequence ID?
child allows you to define arbitrary middleware.
All you have to do is create a sequence property in context.
I cannot see broad applications for what is being asked.
Closing the issue, but please continue discussion if I am missing anything.
I do want to find a way to track individual async operations, though. That's a separate issue it seems.