You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-user@logging.apache.org by Mark Lybarger <ml...@gmail.com> on 2005/05/18 14:47:35 UTC
logging http session identifying information
I'm looking for a method to log http session information in our log4j
logging. we want to be able to trace logging to a particular session. For
instance, when a user reports having trouble, we would like to see what they
did on the web site.
We have a thread id being logged with each log, but there's no way to tie
the threads together into a session of activity. I've also read that it's
very container specific as to weather or not the same thread is used for an
entire servlet execution.
I came across this note on using MDC for logging session information.
http://ulc-community.canoo.com/snipsnap/space/Contributions/Integration+Snippets/Log4J+MDC+Integration
It seems rather easy to extend to support any http session attributes that i
might want to log (user id, etc).
Are there other methods to easily log a session id or other information in
our log4j logs? Are there drawbacks to the solution of using the MDC
integration?
One thing that wasn't very clear with the MDC integration was where to put
the setup code in an servlet container environment. We're using a startup
servlet in all our web apps. Would we need this in each web app's startup
servlet?
Thanks!
~mark
RE: logging http session identifying information
Posted by Mark Womack <wo...@adobe.com>.
Mark,
I would not trust the JSESSIONID cookie. It is going to show you the value
of the cookie being PASSED in. If the session has been released or not yet
created, then you will have the wrong or no session id in your MDC.
I would instead access the session object directly in your filter and use
the getId() method for the value to stuff into the MDC. That way, if a new
session needs to be created, you will do that in the filter and get the new
id. I assume the JSESSIONID cookie value corresponds to the
session.getId(). You'll have to test it.
-Mark
> -----Original Message-----
> From: Mark Lybarger [mailto:mlybarger@gmail.com]
> Sent: Tuesday, May 24, 2005 10:22 AM
> To: Log4J Users List; womack@adobe.com
> Subject: Re: logging http session identifying information
>
> I'm currently tackling this challenge.
>
> In using the CookieMDCFilter, the JSESSIONID that gets logged is very hard
> to decipher. meaning, I'm not always getting a JSESSIONID logged, and
> sometimes, i seem to have stale JSESSIONID logged. I'm not quite up to par
> on the JSESSIONID lifecycle, but will get it soon.
>
> For instance, i get a logging message:
>
> 11:01:43,147 ERROR 86985045A03DC9301A6B05C9B0E5AA7C NextLogger :
> NextLogger
> - logging
>
> i close the browser window (IE) and reopen a new window, and execute the
> servlet, i see:
>
> 11:02:17,178 ERROR 86985045A03DC9301A6B05C9B0E5AA7C NextLogger :
> NextLogger
> - logging
>
> the session id I see has not changed, though i would think the browser
> uses
> a different session id per session... Using mozilla, I even close out all
> instances of mozilla, start a new mozilla instance, when i hit the servlet
> i
> still see:
>
> 11:06:19,987 ERROR 86985045A03DC9301A6B05C9B0E5AA7C NextLogger :
> NextLogger
> - logging
>
> very strange.. this is the id from IE. maybe this has something to do with
> the fact that it isn't cleaning out the MDC (at all) and doesn't clear its
> own map until the destroy method. Next, I modified the CookieMDCLogger to
> do
> a little cleanup like so:
>
> // pass control to the next filter
> try {
> chain.doFilter(request, response);
> } finally {
>
> // clean up the MDC.
> if (cookieMap != null)
> {
> for (Iterator iter = cookieMap.entrySet().iterator();iter.hasNext();)
> {
>
> Map.Entry element = (Map.Entry) iter.next();
> String key = (String) element.getKey();
> MDC.remove( key );
> if (LOG.isDebugEnabled()) { LOG.debug( "remove from MDC with name " + key
> );}
>
> }
> }
> }
>
> Please let me know if you see any issues with the clean up, but it seems
> to
> tidy things up a bit. There's still problems with this in that I don't
> always get a JSESSIONID logged.
>
> Some general questions. Should the server side session
> (HttpSession.getId())
> match the cookie session id? Which would be more reliable, the server
> side,
> or the client side, or both? Any comments on this would be most
> appreciated.
> I'll have to continue testing this out...
>
>
> On 5/18/05, Mark Womack <wo...@adobe.com> wrote:
> >
> > There is an example of putting stored cookie information into the MDC.
> You
> > could easily modify it to use information from the session instead.
> >
> >
> > http://cvs.apache.org/viewcvs.cgi/logging-log4j-
> sandbox/src/java/org/apache/
> > log4j/servlet/CookieMDCFilter.java?view=markup
> >
> > It doesn't do anything to remove the MDC information after the next
> filter
> > in the filter chain completes, so it might be a good idea to do that.
> That
> > way you don't have wayward MDC info sticking around in the thread local
> > getting reported later in some unrelated request context. I would do
> that
> > in a final block if possible to guarantee it gets removed.
> >
> > hth,
> > -Mark
> >
> > > -----Original Message-----
> > > From: Mark Lybarger [mailto: mlybarger@gmail.com]
> > > Sent: Wednesday, May 18, 2005 6:19 PM
> > > To: Log4J Users List
> > > Subject: Re: logging http session identifying information
> > >
> > > i want to log the session id, and any other info from the session that
> i
> >
> > > choose so that i can sort my logs per session.
> > >
> > > i'll check out the sandbox.
> > >
> > > On 5/18/05, Mark Womack <mw...@apache.org> wrote:
> > > >
> > > > If I understand correctly, you want to set session/user specific
> > > > information
> > > > per request? Since the MDC is stored in ThreadLocal, I think you
> will
> > > need
> > > > to use a servlet filter to set and unset the MDC for each request.
> And
> >
> > > > yes,
> > > > how threads are assigned to handle requests, etc is very container
> > > > specific.
> > > > So, setting and unsetting the MDC with each request is a good thing.
> I
> > > > cannot remember offhand if there is already an MDC related servlet
> > > filter
> > > > in
> > > > the log4j-sandbox. You might want to take a quick look and use it as
> > an
> > > > example.
> > > >
> > > > -Mark
> > > >
> > > > ----- Original Message -----
> > > > From: "Mark Lybarger" <ml...@gmail.com>
> > > > To: <lo...@logging.apache.org>
> > > > Sent: Wednesday, May 18, 2005 5:47 AM
> > > > Subject: logging http session identifying information
> > > >
> > > >
> > > > I'm looking for a method to log http session information in our
> log4j
> > > > logging. we want to be able to trace logging to a particular
> session.
> > > For
> > > > instance, when a user reports having trouble, we would like to see
> > what
> > > > they
> > > > did on the web site.
> > > >
> > > > We have a thread id being logged with each log, but there's no way
> to
> > > tie
> > > > the threads together into a session of activity. I've also read that
> > > it's
> > > > very container specific as to weather or not the same thread is used
> > for
> > > > an
> > > > entire servlet execution.
> > > >
> > > > I came across this note on using MDC for logging session
> information.
> > > >
> > > >
> > > > http://ulc-
> > >
> >
> community.canoo.com/snipsnap/space/Contributions/Integration+Snippets/Log4
> <http://community.canoo.com/snipsnap/space/Contributions/Integration+Snipp
> ets/Log4>
> > > J+MDC+Integration
> > > >
> > > > It seems rather easy to extend to support any http session
> attributes
> > > that
> > > > i
> > > > might want to log (user id, etc).
> > > >
> > > > Are there other methods to easily log a session id or other
> > information
> > > in
> > > > our log4j logs? Are there drawbacks to the solution of using the MDC
> > > > integration?
> > > >
> > > > One thing that wasn't very clear with the MDC integration was where
> to
> > > put
> > > > the setup code in an servlet container environment. We're using a
> > > startup
> > > > servlet in all our web apps. Would we need this in each web app's
> > > startup
> > > > servlet?
> > > >
> > > > Thanks!
> > > > ~mark
> > > >
> > > >
> > > >
> > > > --------------------------------------------------------------------
> -
> > > > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > > > For additional commands, e-mail: log4j-user-help@logging.apache.org
> > > >
> > > >
> >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > For additional commands, e-mail: log4j-user-help@logging.apache.org
> >
> >
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
Re: logging http session identifying information
Posted by Mark Lybarger <ml...@gmail.com>.
I'm currently tackling this challenge.
In using the CookieMDCFilter, the JSESSIONID that gets logged is very hard
to decipher. meaning, I'm not always getting a JSESSIONID logged, and
sometimes, i seem to have stale JSESSIONID logged. I'm not quite up to par
on the JSESSIONID lifecycle, but will get it soon.
For instance, i get a logging message:
11:01:43,147 ERROR 86985045A03DC9301A6B05C9B0E5AA7C NextLogger : NextLogger
- logging
i close the browser window (IE) and reopen a new window, and execute the
servlet, i see:
11:02:17,178 ERROR 86985045A03DC9301A6B05C9B0E5AA7C NextLogger : NextLogger
- logging
the session id I see has not changed, though i would think the browser uses
a different session id per session... Using mozilla, I even close out all
instances of mozilla, start a new mozilla instance, when i hit the servlet i
still see:
11:06:19,987 ERROR 86985045A03DC9301A6B05C9B0E5AA7C NextLogger : NextLogger
- logging
very strange.. this is the id from IE. maybe this has something to do with
the fact that it isn't cleaning out the MDC (at all) and doesn't clear its
own map until the destroy method. Next, I modified the CookieMDCLogger to do
a little cleanup like so:
// pass control to the next filter
try {
chain.doFilter(request, response);
} finally {
// clean up the MDC.
if (cookieMap != null)
{
for (Iterator iter = cookieMap.entrySet().iterator();iter.hasNext();)
{
Map.Entry element = (Map.Entry) iter.next();
String key = (String) element.getKey();
MDC.remove( key );
if (LOG.isDebugEnabled()) { LOG.debug( "remove from MDC with name " + key
);}
}
}
}
Please let me know if you see any issues with the clean up, but it seems to
tidy things up a bit. There's still problems with this in that I don't
always get a JSESSIONID logged.
Some general questions. Should the server side session (HttpSession.getId())
match the cookie session id? Which would be more reliable, the server side,
or the client side, or both? Any comments on this would be most appreciated.
I'll have to continue testing this out...
On 5/18/05, Mark Womack <wo...@adobe.com> wrote:
>
> There is an example of putting stored cookie information into the MDC. You
> could easily modify it to use information from the session instead.
>
>
> http://cvs.apache.org/viewcvs.cgi/logging-log4j-sandbox/src/java/org/apache/
> log4j/servlet/CookieMDCFilter.java?view=markup
>
> It doesn't do anything to remove the MDC information after the next filter
> in the filter chain completes, so it might be a good idea to do that. That
> way you don't have wayward MDC info sticking around in the thread local
> getting reported later in some unrelated request context. I would do that
> in a final block if possible to guarantee it gets removed.
>
> hth,
> -Mark
>
> > -----Original Message-----
> > From: Mark Lybarger [mailto: mlybarger@gmail.com]
> > Sent: Wednesday, May 18, 2005 6:19 PM
> > To: Log4J Users List
> > Subject: Re: logging http session identifying information
> >
> > i want to log the session id, and any other info from the session that i
>
> > choose so that i can sort my logs per session.
> >
> > i'll check out the sandbox.
> >
> > On 5/18/05, Mark Womack <mw...@apache.org> wrote:
> > >
> > > If I understand correctly, you want to set session/user specific
> > > information
> > > per request? Since the MDC is stored in ThreadLocal, I think you will
> > need
> > > to use a servlet filter to set and unset the MDC for each request. And
>
> > > yes,
> > > how threads are assigned to handle requests, etc is very container
> > > specific.
> > > So, setting and unsetting the MDC with each request is a good thing. I
> > > cannot remember offhand if there is already an MDC related servlet
> > filter
> > > in
> > > the log4j-sandbox. You might want to take a quick look and use it as
> an
> > > example.
> > >
> > > -Mark
> > >
> > > ----- Original Message -----
> > > From: "Mark Lybarger" <ml...@gmail.com>
> > > To: <lo...@logging.apache.org>
> > > Sent: Wednesday, May 18, 2005 5:47 AM
> > > Subject: logging http session identifying information
> > >
> > >
> > > I'm looking for a method to log http session information in our log4j
> > > logging. we want to be able to trace logging to a particular session.
> > For
> > > instance, when a user reports having trouble, we would like to see
> what
> > > they
> > > did on the web site.
> > >
> > > We have a thread id being logged with each log, but there's no way to
> > tie
> > > the threads together into a session of activity. I've also read that
> > it's
> > > very container specific as to weather or not the same thread is used
> for
> > > an
> > > entire servlet execution.
> > >
> > > I came across this note on using MDC for logging session information.
> > >
> > >
> > > http://ulc-
> >
> community.canoo.com/snipsnap/space/Contributions/Integration+Snippets/Log4<http://community.canoo.com/snipsnap/space/Contributions/Integration+Snippets/Log4>
> > J+MDC+Integration
> > >
> > > It seems rather easy to extend to support any http session attributes
> > that
> > > i
> > > might want to log (user id, etc).
> > >
> > > Are there other methods to easily log a session id or other
> information
> > in
> > > our log4j logs? Are there drawbacks to the solution of using the MDC
> > > integration?
> > >
> > > One thing that wasn't very clear with the MDC integration was where to
> > put
> > > the setup code in an servlet container environment. We're using a
> > startup
> > > servlet in all our web apps. Would we need this in each web app's
> > startup
> > > servlet?
> > >
> > > Thanks!
> > > ~mark
> > >
> > >
> > >
> > > ---------------------------------------------------------------------
> > > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > > For additional commands, e-mail: log4j-user-help@logging.apache.org
> > >
> > >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-user-help@logging.apache.org
>
>
RE: logging http session identifying information
Posted by Mark Womack <wo...@adobe.com>.
There is an example of putting stored cookie information into the MDC. You
could easily modify it to use information from the session instead.
http://cvs.apache.org/viewcvs.cgi/logging-log4j-sandbox/src/java/org/apache/
log4j/servlet/CookieMDCFilter.java?view=markup
It doesn't do anything to remove the MDC information after the next filter
in the filter chain completes, so it might be a good idea to do that. That
way you don't have wayward MDC info sticking around in the thread local
getting reported later in some unrelated request context. I would do that
in a final block if possible to guarantee it gets removed.
hth,
-Mark
> -----Original Message-----
> From: Mark Lybarger [mailto:mlybarger@gmail.com]
> Sent: Wednesday, May 18, 2005 6:19 PM
> To: Log4J Users List
> Subject: Re: logging http session identifying information
>
> i want to log the session id, and any other info from the session that i
> choose so that i can sort my logs per session.
>
> i'll check out the sandbox.
>
> On 5/18/05, Mark Womack <mw...@apache.org> wrote:
> >
> > If I understand correctly, you want to set session/user specific
> > information
> > per request? Since the MDC is stored in ThreadLocal, I think you will
> need
> > to use a servlet filter to set and unset the MDC for each request. And
> > yes,
> > how threads are assigned to handle requests, etc is very container
> > specific.
> > So, setting and unsetting the MDC with each request is a good thing. I
> > cannot remember offhand if there is already an MDC related servlet
> filter
> > in
> > the log4j-sandbox. You might want to take a quick look and use it as an
> > example.
> >
> > -Mark
> >
> > ----- Original Message -----
> > From: "Mark Lybarger" <ml...@gmail.com>
> > To: <lo...@logging.apache.org>
> > Sent: Wednesday, May 18, 2005 5:47 AM
> > Subject: logging http session identifying information
> >
> >
> > I'm looking for a method to log http session information in our log4j
> > logging. we want to be able to trace logging to a particular session.
> For
> > instance, when a user reports having trouble, we would like to see what
> > they
> > did on the web site.
> >
> > We have a thread id being logged with each log, but there's no way to
> tie
> > the threads together into a session of activity. I've also read that
> it's
> > very container specific as to weather or not the same thread is used for
> > an
> > entire servlet execution.
> >
> > I came across this note on using MDC for logging session information.
> >
> >
> > http://ulc-
> community.canoo.com/snipsnap/space/Contributions/Integration+Snippets/Log4
> J+MDC+Integration
> >
> > It seems rather easy to extend to support any http session attributes
> that
> > i
> > might want to log (user id, etc).
> >
> > Are there other methods to easily log a session id or other information
> in
> > our log4j logs? Are there drawbacks to the solution of using the MDC
> > integration?
> >
> > One thing that wasn't very clear with the MDC integration was where to
> put
> > the setup code in an servlet container environment. We're using a
> startup
> > servlet in all our web apps. Would we need this in each web app's
> startup
> > servlet?
> >
> > Thanks!
> > ~mark
> >
> >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > For additional commands, e-mail: log4j-user-help@logging.apache.org
> >
> >
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
Re: logging http session identifying information
Posted by Mark Lybarger <ml...@gmail.com>.
i want to log the session id, and any other info from the session that i
choose so that i can sort my logs per session.
i'll check out the sandbox.
On 5/18/05, Mark Womack <mw...@apache.org> wrote:
>
> If I understand correctly, you want to set session/user specific
> information
> per request? Since the MDC is stored in ThreadLocal, I think you will need
> to use a servlet filter to set and unset the MDC for each request. And
> yes,
> how threads are assigned to handle requests, etc is very container
> specific.
> So, setting and unsetting the MDC with each request is a good thing. I
> cannot remember offhand if there is already an MDC related servlet filter
> in
> the log4j-sandbox. You might want to take a quick look and use it as an
> example.
>
> -Mark
>
> ----- Original Message -----
> From: "Mark Lybarger" <ml...@gmail.com>
> To: <lo...@logging.apache.org>
> Sent: Wednesday, May 18, 2005 5:47 AM
> Subject: logging http session identifying information
>
>
> I'm looking for a method to log http session information in our log4j
> logging. we want to be able to trace logging to a particular session. For
> instance, when a user reports having trouble, we would like to see what
> they
> did on the web site.
>
> We have a thread id being logged with each log, but there's no way to tie
> the threads together into a session of activity. I've also read that it's
> very container specific as to weather or not the same thread is used for
> an
> entire servlet execution.
>
> I came across this note on using MDC for logging session information.
>
>
> http://ulc-community.canoo.com/snipsnap/space/Contributions/Integration+Snippets/Log4J+MDC+Integration
>
> It seems rather easy to extend to support any http session attributes that
> i
> might want to log (user id, etc).
>
> Are there other methods to easily log a session id or other information in
> our log4j logs? Are there drawbacks to the solution of using the MDC
> integration?
>
> One thing that wasn't very clear with the MDC integration was where to put
> the setup code in an servlet container environment. We're using a startup
> servlet in all our web apps. Would we need this in each web app's startup
> servlet?
>
> Thanks!
> ~mark
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-user-help@logging.apache.org
>
>
Re: logging http session identifying information
Posted by Mark Womack <mw...@apache.org>.
If I understand correctly, you want to set session/user specific information
per request? Since the MDC is stored in ThreadLocal, I think you will need
to use a servlet filter to set and unset the MDC for each request. And yes,
how threads are assigned to handle requests, etc is very container specific.
So, setting and unsetting the MDC with each request is a good thing. I
cannot remember offhand if there is already an MDC related servlet filter in
the log4j-sandbox. You might want to take a quick look and use it as an
example.
-Mark
----- Original Message -----
From: "Mark Lybarger" <ml...@gmail.com>
To: <lo...@logging.apache.org>
Sent: Wednesday, May 18, 2005 5:47 AM
Subject: logging http session identifying information
I'm looking for a method to log http session information in our log4j
logging. we want to be able to trace logging to a particular session. For
instance, when a user reports having trouble, we would like to see what they
did on the web site.
We have a thread id being logged with each log, but there's no way to tie
the threads together into a session of activity. I've also read that it's
very container specific as to weather or not the same thread is used for an
entire servlet execution.
I came across this note on using MDC for logging session information.
http://ulc-community.canoo.com/snipsnap/space/Contributions/Integration+Snippets/Log4J+MDC+Integration
It seems rather easy to extend to support any http session attributes that i
might want to log (user id, etc).
Are there other methods to easily log a session id or other information in
our log4j logs? Are there drawbacks to the solution of using the MDC
integration?
One thing that wasn't very clear with the MDC integration was where to put
the setup code in an servlet container environment. We're using a startup
servlet in all our web apps. Would we need this in each web app's startup
servlet?
Thanks!
~mark
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org