Transport refactor #107
Transport refactor #107
Conversation
mattberther
force-pushed
the
transport-refactor
branch
from
3c6a761 to
54cc81a
Compare
mattberther
force-pushed
the
transport-refactor
branch
from
d7942cf to
b028bc3
Compare
|
Is "Legacy" meant to imply that there is some better alternative for daily rotating log files? |
|
@gilly3 "Legacy" will be the non winston 3.0 stuff. :) |
|
Will (does) winston 3.0 have daily rotate built in? Or is there a winston 3.0 version of this transport? (I don't see any 3.0 branch here) |
|
No, winston 3.0 will not have this built in. I'm currently working on a 3.0 version (which is what this PR started). |
|
TLDR; I got it working. Now we just need to figure out how what the right way to fix it is. @ericdrobinson Thanks for the tips
So... after removing the stack trace limit and scattering some more traces around, it does look like the behaviors I described are taking place Commenting out the behavior for the However If I make it so that In terms of actually fixing it, I'm not sure we want to completely prevent the close event from bubbling. If the stream unexpectedly closes, I think we want that to be proxied. This may be a matter of disabling some of those event proxies when we know that a rotation is happening? @mattberther @indexzero What are your thoughts? |
|
@crussell52 Smashup job tracking this down. It now makes a lot of sense and may explain why the main Winston
I'm not sure that I agree. Let's take a look at the architecture of what we have: [The The point is that from Winston's point of view, if a transport emits a standard "I'm closing" event, then it should close: it's transport has completed its work. It is the rotators that wrap the actual file streams and present themselves as streams that are doing things incorrectly. If Winston Daily Rotate File is a stream, then it should only emit a You could go a step further and say that the culprit is actually The point here is that a Winston Transport "stream" should only emit/bubble the To that end, I see two possible directions for addressing this:
Looking over the source code of @indexzero A few questions:
Thoughts? |
|
@ericdrobinson I'd call it a very collaborative effort in tracking it down 👍
I agree entirely (after this exercise) that the Expanding on that, if such a transport (let's call it a
I think it is better to just swallow/handle the events. Even if they are renamed, it ends up leaking implementation details of the stream-proxy, again. The outside world should not know or care that there is an internal stream in play. |
I'm convinced. Perhaps an Issue (or PR?) should be created in the @mattberther @indexzero does this approach make sense? |
|
@ericdrobinson, @mattberther, @indexzero Unfortunately, EDIT: clarified ambiguous pronoun |
|
@crussell52 What would your proposed upstream changes be? I'm happy to make a fork of the file-stream-rotator project to test this out (and ultimately submit the PR back to that project for incorporation). Also, I presume similar changes would need to be made in the |
I don't think that's a problem. I can see users wanting the With respect to the
I would argue that The other option would be to rename-and-bubble, but I can't see what the value of that would be.
If you rename-and-bubble the event, then you could still see it. The other option would be to add a new,
Regardless of any upstream changes (see above for my suggestions, though note that I consider them unnecessary), You could incorporate the Basically, the bug we've been discussing here can be eliminated by changing That make sense? |
|
@ericdrobinson @crussell52 I've pushed some new changes that should address this issue and pushed |
|
@mattberther Looks good to me. Checked the code and I ran my test script and I see logs rotating correctly with no message loss. Also took a look at the commit... LGTM |
|
Cheers, @crussell52. Thanks for doing all the heavy lifting. :) |
|
I learned a lot in the process! Thanks @ericdrobinson |
There was a problem hiding this comment.
Overall looks great! I don't pretend to understand the reason behind changing close() to end() and providing the function parameters, but it looks familiar enough (perhaps taken from the TransportStream super-class version?). Either way, these changes do address the transport-close-on-rotate issues (for my environment) discussed in the main PR comments.
The one request I have is that the README.md be updated to no longer claim:
You can listen to the open, close, error, and finish events generated by the underlying stream.
So... documentation update and then all set for me!
|
My pleasure, @crussell52! Glad I was able to help out, but also thank you for actually identifying the core issue! I'd found a bunch of hints but not quite enough to put it all together. Great work! Also, @mattberther, as I mentioned in the Review, I just tested 2.0.0rc4 and the daily rotation now works for me! Hurray!!! |
daily-rotate-file.js
Outdated
| @@ -137,9 +121,14 @@ if (semver.major(winston.version) === 2) { | |||
| }; | |||
| } | |||
|
|
|||
| DailyRotateFile.prototype.close = function () { | |||
| DailyRotateFile.prototype.end = function (chunk, encoding, callback) { | |||
There was a problem hiding this comment.
I'm continuing to read about Streams -- I'm actually not sure end() should be overridden. The base implementation does a lot more work which is not being handled here, including managing the corked state of the stream
This trivial example for decoding within a stream also wraps another stream and they do their cleanup as part of _destroy()_final(). I'm still not clear on the full lifecycle of Streams, so this is all still a little mysterious to me, but my gut says that overriding end() might have odd side effects later.
There was a problem hiding this comment.
Good point. Pushing a version that does the cleanup in _final(). Please try npm install winston-daily-rotate-file@next and let me know of any issues.
Actually, _final() was introduced with 8.0, so I need to look for another place to implement the cleanup code. Please hold off on trying the new version until we have a passing build.
|
Fundamentally, that You've made very valid points as to why |
daily-rotate-file.js
Outdated
| callback = callback || noop; | ||
| callback(); | ||
| }); | ||
| DailyRotateFile.prototype.close = function () { |
There was a problem hiding this comment.
I'm a little concerned about this function name. Streams already expose a close event and this feels ripe for confusion. For my part (not a stream expert by any stretch), I had to go and look at the core NodeJS stream and winston-transport source code to verify that this wasn't overwriting a pre-existing close() function.
If this is specifically for winston-daily-rotate-rotate (WDRF) would it be possible to sidestep any such confusion and call it something WDRF-specific? Something like endRotation() or endLogging() or closeTransport()?
@indexzero This raises an interesting question. Is there a set of functions (hooks?) defined in winston-transport that cover setup and teardown? Or at least a convention by which Transports can name basic functionality like this?
There was a problem hiding this comment.
For my part (not a stream expert by any stretch), I had to go and look at the core NodeJS stream and winston-transport source code to verify that this wasn't overwriting a pre-existing close() function.
FWIW, I did the same thing.
However, I think it does have meaning to winston. In the area I explored with the rotation bug -- In winston-transport -- the unpipe handler calls close on the Transport if it is defined: (https://github.com/winstonjs/winston-transport/blob/master/index.js#L49-L62)
Perhaps this just needs some clarity in the documentation -- maybe this is also the "most correct" place for transports to call this.end()" and do additional cleanup if necessary since _final()` is not an option in node versions < 8.0. I'll add more thoughts about that to the thread about _final() main PR conversation
|
so that's unfortunate about Maybe From what I've seen, I'd say the important points are about
Technically, the |
Hmmmmm... Okay, I realize this is now out of scope for this plugin but I want to add a followup thought since it builds on the current conversation and the audience is right since this is a winston-maintained transport. 😬 What if.... I haven't worked out all the details, of course... but basically if (this._close) {
this._close(function() {
this.end();
this.emit('finish'); // Does the built-in `end()` emit this for us?
});
} else {
this.end();
this.emit('finish');
}The "rule" for |
|
@crussell52 You might want to open a new Issue on the main Winston repo for this. Linking to that comment (or this PR in general) for added context would probably be helpful as well. :) |
No description provided.