RequestLogger and MDC

[Marios Skounakis <ms...@gmail.com>]

Hi all,

I have run into the following problem with request logger:

I have a RequestCycleListener which populates MDC (logging mapped
diagnostic context) with some custom properties such as the sessionId, the
userId, and some other stuff. The listener populates the MDC in
onBeginRequest and clears the MDC in onEndRequest.

What happens is that log entries written by the RequestLogger have empty
values for these MDC properties. By digging around I discovered that
RequestLogger.log is called in RequestCycle onInternalDetach() which
happens after onEndRequest(). So the MDC has been cleared before
RequestLogger.log() is called.

I think that my approach which uses a RequestCycleListener to populate and
clear the MDC is valid and that the RequestLogger should be amended to do
the logging before the MDC is cleared (at the latest before
RequestCycleListener.onDetach()).

Note that even if the MDC is cleared in RequestCycleListener.onDetach()
this still happens before RequestLogger.log() is called.

Is there something invalid with my approach?

I now have a workaround with a custom RequestLogger which clears the MDC in
log but this is ugly (if you remove the logger you get a leaking MDC). Any
other ideas for workarounds?

Thanks
Marios

Re: RequestLogger and MDC

[Martijn Dashorst <ma...@gmail.com>]

No. One of the problems encountered with the request logger was that
it didn't properly record request times. There was a JIRA reported
that flagged this. The detach phase was not reported, but added
significant duration to the request of that particular project. In
principle the request should flush the response prior to detaching,
since the response is closed at that point (sending the response to
the browser, enabling it to start rendering). Unfortunately I
discovered that the redirect to buffer strategy lets the browser wait
until the detach of the previous request is completed, making the it
rather moot whether the flush was executed earlier.

See: https://issues.apache.org/jira/browse/WICKET-5241

Martijn

On Thu, Aug 8, 2013 at 3:49 PM, Sven Meier <sv...@meiers.net> wrote:
> We could probably move the call to IRequestLogger#performLogging() before
> IRequestCycleListener#onDetach().
>
> Please create a Jira issue.
>
> Best regards
> Sven
>
>
>
> On 08/08/2013 03:03 PM, Marios Skounakis wrote:
>>
>> Hi all,
>>
>> I have run into the following problem with request logger:
>>
>> I have a RequestCycleListener which populates MDC (logging mapped
>> diagnostic context) with some custom properties such as the sessionId, the
>> userId, and some other stuff. The listener populates the MDC in
>> onBeginRequest and clears the MDC in onEndRequest.
>>
>> What happens is that log entries written by the RequestLogger have empty
>> values for these MDC properties. By digging around I discovered that
>> RequestLogger.log is called in RequestCycle onInternalDetach() which
>> happens after onEndRequest(). So the MDC has been cleared before
>> RequestLogger.log() is called.
>>
>> I think that my approach which uses a RequestCycleListener to populate and
>> clear the MDC is valid and that the RequestLogger should be amended to do
>> the logging before the MDC is cleared (at the latest before
>> RequestCycleListener.onDetach()).
>>
>> Note that even if the MDC is cleared in RequestCycleListener.onDetach()
>> this still happens before RequestLogger.log() is called.
>>
>> Is there something invalid with my approach?
>>
>> I now have a workaround with a custom RequestLogger which clears the MDC
>> in
>> log but this is ugly (if you remove the logger you get a leaking MDC). Any
>> other ideas for workarounds?
>>
>> Thanks
>> Marios
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@wicket.apache.org
> For additional commands, e-mail: users-help@wicket.apache.org
>



-- 
Become a Wicket expert, learn from the best: http://wicketinaction.com

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@wicket.apache.org
For additional commands, e-mail: users-help@wicket.apache.org

Re: RequestLogger and MDC

[Sven Meier <sv...@meiers.net>]

We could probably move the call to IRequestLogger#performLogging() 
before IRequestCycleListener#onDetach().

Please create a Jira issue.

Best regards
Sven


On 08/08/2013 03:03 PM, Marios Skounakis wrote:
> Hi all,
>
> I have run into the following problem with request logger:
>
> I have a RequestCycleListener which populates MDC (logging mapped
> diagnostic context) with some custom properties such as the sessionId, the
> userId, and some other stuff. The listener populates the MDC in
> onBeginRequest and clears the MDC in onEndRequest.
>
> What happens is that log entries written by the RequestLogger have empty
> values for these MDC properties. By digging around I discovered that
> RequestLogger.log is called in RequestCycle onInternalDetach() which
> happens after onEndRequest(). So the MDC has been cleared before
> RequestLogger.log() is called.
>
> I think that my approach which uses a RequestCycleListener to populate and
> clear the MDC is valid and that the RequestLogger should be amended to do
> the logging before the MDC is cleared (at the latest before
> RequestCycleListener.onDetach()).
>
> Note that even if the MDC is cleared in RequestCycleListener.onDetach()
> this still happens before RequestLogger.log() is called.
>
> Is there something invalid with my approach?
>
> I now have a workaround with a custom RequestLogger which clears the MDC in
> log but this is ugly (if you remove the logger you get a leaking MDC). Any
> other ideas for workarounds?
>
> Thanks
> Marios
>


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@wicket.apache.org
For additional commands, e-mail: users-help@wicket.apache.org