search

cjbhaines / Log4Net.Async

Asynchronous Log4Net appenders and forwarder
http://www.nuget.org/packages/Log4Net.Async/
MIT License
121 stars 37 forks source link

Fix Issue #29 #32

Closed Djiu13 closed 7 years ago

Djiu13 commented 7 years ago

Immediately shutdown can throw an OperationCancelException. We should wait the first 100ms and then check if it is Completed and wait again if not.

Djiu13 commented 7 years ago

I believe this will fix the issue #29 @cjbhaines

rcollette commented 7 years ago

The question still remains, does the issue you are trying to fix resolve if you put in LogManager.shutdown() in the Application_End event? If so, this introducing an arbitrary and unnecessary delay.

Djiu13 commented 7 years ago

You're right, at the beginning I was trying to solve my issue which looks very similar to this one. It works for me and the delay was there before the immediate shutdown change. Also, I have just tried replacing the 'Act' part in my tests by just LogManager.Shutdown(); and it is still working with my changes.

cjbhaines commented 7 years ago

I'm a bit lost, does LogManager.Shutdown() fix your issue and mean we can cancel this PR? I don't like the look of the change because as Richard says it introduces unnecessary delays if there are no messages in the buffer.

Djiu13 commented 7 years ago

LogManager.Shutdown() doesn't fix the issue. My issue and I think it is linked to this one is that Shutdown is somehow called even when the application starts. It is not really a problem but there is no event at this point and the subscriber loop is trying to get the next one while the Immediate shutdown is called at the same time. Wait 100ms allows the loop to finish before we do the Cancel and the exception is not raised. I didn't come up with the 100ms, it was already there. I didn't change the behaviour and it will still wait longer if needed or shutdown straight after. Sorry if it is not clear enough but It is something you cannot see during debug as a breakpoint is leaving time for the loop to finish. You will see that the test fail without my changes and pass with.

Djiu13 commented 7 years ago

Hi, I can offer another solution that will not add any delays. By checking that we have some events in _loogingEvents before trying to get them in the foreach we can avoid the exception. I will create an new pull request so you can review it and cancel this one. Log4Net.Async is great and very helpful for my project, I just want to have it working without throwing this exception when there is no error behind. Thank you.

Djiu13 commented 7 years ago

Actually merged into this one... Let me know if you want me to start again with a clean branch. Thank you.

rcollette commented 7 years ago

You could not have possibly run this. You are exiting the subscriber loop whose purpose is to sit there waiting for the for entries to come in. The count can absolutely be zero when the loop starts.

Perhaps you might want to try checking the collection count when the OperationCanceled exception is caught in the subscriber loop. If the collection size is zero at that point then the exception might not need to be forwarded. Give that a try.

lbras commented 7 years ago

(Was about to post this when @rcollette replied):

I can confirm LogManager.Shutdown() doesn't fix the issue (@rcollette my apologies for not responding sooner).

@Djiu13 _loggingEvents.Count check doesn't seem to work with a BufferingForwardingAppender. When the logging task starts there are no logging events, so it will end the task prematurely and nothing is ever logged. When the app pool recycles I get "The buffer was not able to be flushed before timeout occurred".

The 100ms delay (7c78798) does seem to have fixed the issue.

Djiu13 commented 7 years ago

Sorry for the last commit, of course it won't work... I got lost. I have actually already tried to put the if condition in the catch and it was working fine. I will commit this change then and hopefully it will be ok with everyone. Thanks for your help and feedback.

rcollette commented 7 years ago

This looks good. @cjbhaines Just doing a mental exercise on version numbers with this. If the task is ended without LogManager.shutdown(), it will no longer error if there are no entries in the queue. It's a slight behavior change but probably still a patch?

Djiu13 commented 7 years ago

Hi, any progress on merging this change? Thank you :)

rcollette commented 7 years ago

Merged but would like agreement from @cjbhaines about the release being patch, point or major. Personally I am inclined to call it a patch.

cjbhaines commented 7 years ago

Hey guys, really sorry about delayed response. I'm happy to release this as a patch, pushing major updates is a pain for consumers so I would like to reserve those for breaking changes.