Fix request attribute-related race condition in Logback request logging #1678
Conversation
|
It's very strange to step on those thread-safety issues with Logback (or the SLF4J bridge). Let's see if the fix helps, I even don't known how to write a unit to reproduce it. |
| event.prepareForDeferredProcessing(); | ||
| } | ||
| }; | ||
| return new AsyncAppenderBase<IAccessEvent>(); |
There was a problem hiding this comment.
Could you please also update the Javadoc for this method? In looks a lit bit wrong for me.
- It should link to
AsyncAppenderBaserather than toAsyncAppenderFactory(not-related issue to this change) - I think we should remove a claim about deferred processing.
There was a problem hiding this comment.
Definitely, thanks for mentioning. It would be nice to collapse this and io.dropwizard.logging.async.AsyncLoggingEventAppenderFactory into a single class parameterized on the type of event, since they're now almost identical. This would be a breaking change, though.
I took the liberty of updating AsyncLoggingEventAppenderFactory's Javadoc too, since it also incorrectly links to AsyncAppenderFactory.
|
Thanks, @evnm! |
|
Cherry-picked to the 1.0,x branch. |
Addresses #1672
i.d.request.logging.async.AsyncAccessEventAppenderFactoryinvokesAccessEvent. prepareForDeferredProcessing, which triggers a race with an identical invocation within Logback itself. The reported issue indicates that the race manifests in inconsistent logging behavior when request attributes are set within a resource class.This change removes the
prepareForDeferredProcessingcall from dropwizard-request-logging. As far as I know, allIAccessEvents encountered by this class will be of concrete typeAccessEventand all non-async appenders extendOutputStreamAppender, so theprepareForDeferredProcessingmethod should always be invoked exactly once.