You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mina.apache.org by Trustin Lee <tr...@gmail.com> on 2007/10/23 03:22:22 UTC

MDC without impedance mismatch?

Hi,

As you know MDC (Map backed Diagnostic Context IIRC) for all modern
logging frameworks use ThreadLocal.  I think this is a big headache
for MINA because MINA doesn't work very well with ThreadLocal.
Looking at MdcInjectionFilter, we have to copy all map data for each
event emission because a session spans over multiple threads.  This is
inefficient and can lead to performance issues.

I thought about fixing this 'impedance mismatch' between ThreadLocal
and MINA, but didn't success to come up with a good answer yet.

At least for logging frameworks, we could resolve this problem if all
logging frameworks provides SPI for MDC, so we can directly get
attributes from session attribute map, which is much more efficient
than using the current MDC implementation.  However, the reality is
that no logging framework provides such facility.

Do we need SDC (Session backed Diagnostic Context) here?  I think yes.

As for Log4J, you might be able to achieve that by extending
PatternLayout and PatternParser and let users use our PatternLayout
class in their log4j.properties (or .xml).

Logback looks like it provides some extension mechanism somehow, but I
didn't look into it much in detail.  java.util.logging needs somewhat
more work to do IMO.

One problem is how the Logger instance is created.  Because we have to
associate a session with a logger, we have to provide a wrapper class
for an existing SLF4J Logger instance:

Logger logger = new
IoSessionLogger(LoggerFactory.getLogger(ABC.class), session);

The next problem is to access the associated session from each logging
framework's implementation.  It's impossible AFAIK unfortunately
because SLF4J just forwards the logging calls other than providing a
mean to pass additional information to the actual logging framework
being used.

Possible workarounds are:

1) Change existing logging frameworks. (impossible probably)
2) Provide additional pattern layout configuration in IoSessionLogger,
which is configurable via a constructor parameter of IoSessionLogger.
And of course with the default global layout. (somewhat ugly)

WDYT?  Any better ideas?

Trustin
-- 
what we call human nature is actually human habit
--
http://gleamynode.net/
--
PGP Key ID: 0x0255ECA6

Re: MDC without impedance mismatch?

Posted by Trustin Lee <tr...@gmail.com>.
On 10/25/07, Maarten Bosteels <mb...@gmail.com> wrote:
> > > I am not sure getProperty should fall back to values in the MDC though.
> >
> > I am not sure actually.  :)
> >
> > Would there be any side effect?
>
>
> Well, I can't really think of a reason to call getProperty (that's why I
> didn' add it :-)
>
> but I think the values in the MDC and the values in the Context are two
> different sets:
> when a key/value is in the MDC but not in the context of the mdcFilter it
> will not be added to the MDC for the next event.
>
> users can directly access the MDC, so why is the fallback needed ?

Just wanted to make the API look complete.  I just couldn't imagine
setter without getter.  :)

BTW, I rewrote the IoSessionLogger as we discussed.  Please review the
following classes:

http://svn.apache.org/viewvc/mina/trunk/core/src/main/java/org/apache/mina/common/IoSessionLogger.java?view=markup
http://svn.apache.org/viewvc/mina/trunk/core/src/main/java/org/apache/mina/filter/logging/LoggingFilter.java?view=markup

I hope it is just exactly what you imagined. :D

Cheers,
Trustin
-- 
what we call human nature is actually human habit
--
http://gleamynode.net/
--
PGP Key ID: 0x0255ECA6

Re: MDC without impedance mismatch?

Posted by Maarten Bosteels <mb...@gmail.com>.
On 10/25/07, Trustin Lee <tr...@gmail.com> wrote:
>
> On 10/25/07, Maarten Bosteels <mb...@gmail.com> wrote:
> > On 10/25/07, Trustin Lee <tr...@gmail.com> wrote:
> > >
> > > On 10/24/07, Maarten Bosteels <mb...@gmail.com> wrote:
> > > > On 10/23/07, Trustin Lee <tr...@gmail.com> wrote:
> > > > >
> > > > > On 10/23/07, Maarten Bosteels <mb...@gmail.com> wrote:
> > > > > > Hi,
> > > > > >
> > > > > > Some comments:
> > > > > >
> > > > > > 1) I understand your worries about performance impact but I
> think we
> > > > > should
> > > > > > to a little benchmark before jumping to conclusions. Maybe you
> > > already
> > > > > did
> > > > > > ?
> > > > >
> > > > > Good idea.  I didn't do any benchmark yet.  But my primary concern
> is
> > > > > not performance now.  It's impedance mismatch.  I feel like we are
> > > > > working around the problem.  We can go as we discussed so far, but
> > > > > it's also a lot of fun to explore another possibility.  Please
> don't
> > > > > get me wrong.  :)
> > > > >
> > > > > > 2) I was planning to create an Enum of all the keys that
> > > > > MdcInjectionFilter
> > > > > > supports (remoteAddress, remotePort,...)
> > > > > > and add a constructor that takes an EnumSet, that way users can
> > > minimize
> > > > > the
> > > > > > size of the map.
> > > > >
> > > > > That would be really nice.
> > > >
> > > > Done, please review.
> > >
> > > Great job!  I've done some additional tweak:
> > >
> > > http://svn.apache.org/viewvc?view=rev&revision=588153
> > >
> > > Please review. ;)
> >
> >
> > Yes, much better, thanks  (and I should have cleaned up that unused code
> > myself)
> >
> > I am not sure getProperty should fall back to values in the MDC though.
>
> I am not sure actually.  :)
>
> Would there be any side effect?


Well, I can't really think of a reason to call getProperty (that's why I
didn' add it :-)

but I think the values in the MDC and the values in the Context are two
different sets:
when a key/value is in the MDC but not in the context of the mdcFilter it
will not be added to the MDC for the next event.

users can directly access the MDC, so why is the fallback needed ?

Maarten

Trustin
> --
> what we call human nature is actually human habit
> --
> http://gleamynode.net/
> --
> PGP Key ID: 0x0255ECA6
>

Re: MDC without impedance mismatch?

Posted by Trustin Lee <tr...@gmail.com>.
On 10/25/07, Maarten Bosteels <mb...@gmail.com> wrote:
> On 10/25/07, Trustin Lee <tr...@gmail.com> wrote:
> >
> > On 10/24/07, Maarten Bosteels <mb...@gmail.com> wrote:
> > > On 10/23/07, Trustin Lee <tr...@gmail.com> wrote:
> > > >
> > > > On 10/23/07, Maarten Bosteels <mb...@gmail.com> wrote:
> > > > > Hi,
> > > > >
> > > > > Some comments:
> > > > >
> > > > > 1) I understand your worries about performance impact but I think we
> > > > should
> > > > > to a little benchmark before jumping to conclusions. Maybe you
> > already
> > > > did
> > > > > ?
> > > >
> > > > Good idea.  I didn't do any benchmark yet.  But my primary concern is
> > > > not performance now.  It's impedance mismatch.  I feel like we are
> > > > working around the problem.  We can go as we discussed so far, but
> > > > it's also a lot of fun to explore another possibility.  Please don't
> > > > get me wrong.  :)
> > > >
> > > > > 2) I was planning to create an Enum of all the keys that
> > > > MdcInjectionFilter
> > > > > supports (remoteAddress, remotePort,...)
> > > > > and add a constructor that takes an EnumSet, that way users can
> > minimize
> > > > the
> > > > > size of the map.
> > > >
> > > > That would be really nice.
> > >
> > > Done, please review.
> >
> > Great job!  I've done some additional tweak:
> >
> > http://svn.apache.org/viewvc?view=rev&revision=588153
> >
> > Please review. ;)
>
>
> Yes, much better, thanks  (and I should have cleaned up that unused code
> myself)
>
> I am not sure getProperty should fall back to values in the MDC though.

I am not sure actually.  :)

Would there be any side effect?

Trustin
-- 
what we call human nature is actually human habit
--
http://gleamynode.net/
--
PGP Key ID: 0x0255ECA6

Re: MDC without impedance mismatch?

Posted by Maarten Bosteels <mb...@gmail.com>.
On 10/25/07, Trustin Lee <tr...@gmail.com> wrote:
>
> On 10/24/07, Maarten Bosteels <mb...@gmail.com> wrote:
> > On 10/23/07, Trustin Lee <tr...@gmail.com> wrote:
> > >
> > > On 10/23/07, Maarten Bosteels <mb...@gmail.com> wrote:
> > > > Hi,
> > > >
> > > > Some comments:
> > > >
> > > > 1) I understand your worries about performance impact but I think we
> > > should
> > > > to a little benchmark before jumping to conclusions. Maybe you
> already
> > > did
> > > > ?
> > >
> > > Good idea.  I didn't do any benchmark yet.  But my primary concern is
> > > not performance now.  It's impedance mismatch.  I feel like we are
> > > working around the problem.  We can go as we discussed so far, but
> > > it's also a lot of fun to explore another possibility.  Please don't
> > > get me wrong.  :)
> > >
> > > > 2) I was planning to create an Enum of all the keys that
> > > MdcInjectionFilter
> > > > supports (remoteAddress, remotePort,...)
> > > > and add a constructor that takes an EnumSet, that way users can
> minimize
> > > the
> > > > size of the map.
> > >
> > > That would be really nice.
> >
> > Done, please review.
>
> Great job!  I've done some additional tweak:
>
> http://svn.apache.org/viewvc?view=rev&revision=588153
>
> Please review. ;)


Yes, much better, thanks  (and I should have cleaned up that unused code
myself)

I am not sure getProperty should fall back to values in the MDC though.

regards
Maarten

Cheers,
> Trustin
> --
> what we call human nature is actually human habit
> --
> http://gleamynode.net/
> --
> PGP Key ID: 0x0255ECA6
>

Re: MDC without impedance mismatch?

Posted by Trustin Lee <tr...@gmail.com>.
On 10/24/07, Maarten Bosteels <mb...@gmail.com> wrote:
> On 10/23/07, Trustin Lee <tr...@gmail.com> wrote:
> >
> > On 10/23/07, Maarten Bosteels <mb...@gmail.com> wrote:
> > > Hi,
> > >
> > > Some comments:
> > >
> > > 1) I understand your worries about performance impact but I think we
> > should
> > > to a little benchmark before jumping to conclusions. Maybe you already
> > did
> > > ?
> >
> > Good idea.  I didn't do any benchmark yet.  But my primary concern is
> > not performance now.  It's impedance mismatch.  I feel like we are
> > working around the problem.  We can go as we discussed so far, but
> > it's also a lot of fun to explore another possibility.  Please don't
> > get me wrong.  :)
> >
> > > 2) I was planning to create an Enum of all the keys that
> > MdcInjectionFilter
> > > supports (remoteAddress, remotePort,...)
> > > and add a constructor that takes an EnumSet, that way users can minimize
> > the
> > > size of the map.
> >
> > That would be really nice.
>
> Done, please review.

Great job!  I've done some additional tweak:

http://svn.apache.org/viewvc?view=rev&revision=588153

Please review. ;)

Cheers,
Trustin
-- 
what we call human nature is actually human habit
--
http://gleamynode.net/
--
PGP Key ID: 0x0255ECA6

Re: MDC without impedance mismatch?

Posted by Maarten Bosteels <mb...@gmail.com>.
On 10/23/07, Trustin Lee <tr...@gmail.com> wrote:
>
> On 10/23/07, Maarten Bosteels <mb...@gmail.com> wrote:
> > Hi,
> >
> > Some comments:
> >
> > 1) I understand your worries about performance impact but I think we
> should
> > to a little benchmark before jumping to conclusions. Maybe you already
> did
> > ?
>
> Good idea.  I didn't do any benchmark yet.  But my primary concern is
> not performance now.  It's impedance mismatch.  I feel like we are
> working around the problem.  We can go as we discussed so far, but
> it's also a lot of fun to explore another possibility.  Please don't
> get me wrong.  :)
>
> > 2) I was planning to create an Enum of all the keys that
> MdcInjectionFilter
> > supports (remoteAddress, remotePort,...)
> > and add a constructor that takes an EnumSet, that way users can minimize
> the
> > size of the map.
>
> That would be really nice.


Done, please review.

regards
Maarten

> 3) Currently, when using the MdcInjectionFilter, all logging events
> > generated by code down the call-stack (or is it up ?) will also have the
> MDC
> > set, even when that code is completely unwaware of MINA. That's a big
> > advantage IMO.
> > And AFAICS this can only be done using a ThreadLocal ?
>
> Very true.  Backward compatibility!  Please consider my previous post
> as a fundamental question about the current logging frameworks.
>
> > I think the solution we discussed previously, is reasonable:
> >
> > 1) IoSessionLogger constructor takes an org.slf4j.Logger and an
> IoSession
> > 2) use a session attribute " IoSessionLogger.usePrefix" that determines
> if a
> > prefix should be prepended
> > 3) IoSessionLogger forwards all messages to the org.slf4j.Logger and
> > optionally prepends a prefix
> >
> > * people using the MdcInjectionFilter will see the remoteAddress for ALL
> log
> > messages
> > * people not using MdcInjectionFilter will only see the remoteAddress
> for
> > log messages generated via IoSessionLogger
>
> Yep.  Let me go ahead.
>
> > On the other hand, when performance impact of MdcInjectionFilter is
> really
> > small, and when MDC support is added for JUL
> > I think we could just drop IoSessionLogger, as you wrote on the slf4j
> > mailing list.
>
> I can't agree more.  Unfortunately Ceki is going for vacation, so we
> might need to wait for a while.  Anyways, we can keep working on it.
> :)
>
> Cheers,
> Trustin
> --
> what we call human nature is actually human habit
> --
> http://gleamynode.net/
> --
> PGP Key ID: 0x0255ECA6
>

Re: MDC without impedance mismatch?

Posted by Trustin Lee <tr...@gmail.com>.
On 10/23/07, Maarten Bosteels <mb...@gmail.com> wrote:
> Hi,
>
> Some comments:
>
> 1) I understand your worries about performance impact but I think we should
> to a little benchmark before jumping to conclusions. Maybe you already did
> ?

Good idea.  I didn't do any benchmark yet.  But my primary concern is
not performance now.  It's impedance mismatch.  I feel like we are
working around the problem.  We can go as we discussed so far, but
it's also a lot of fun to explore another possibility.  Please don't
get me wrong.  :)

> 2) I was planning to create an Enum of all the keys that MdcInjectionFilter
> supports (remoteAddress, remotePort,...)
> and add a constructor that takes an EnumSet, that way users can minimize the
> size of the map.

That would be really nice.

> 3) Currently, when using the MdcInjectionFilter, all logging events
> generated by code down the call-stack (or is it up ?) will also have the MDC
> set, even when that code is completely unwaware of MINA. That's a big
> advantage IMO.
> And AFAICS this can only be done using a ThreadLocal ?

Very true.  Backward compatibility!  Please consider my previous post
as a fundamental question about the current logging frameworks.

> I think the solution we discussed previously, is reasonable:
>
> 1) IoSessionLogger constructor takes an org.slf4j.Logger and an IoSession
> 2) use a session attribute " IoSessionLogger.usePrefix" that determines if a
> prefix should be prepended
> 3) IoSessionLogger forwards all messages to the org.slf4j.Logger and
> optionally prepends a prefix
>
> * people using the MdcInjectionFilter will see the remoteAddress for ALL log
> messages
> * people not using MdcInjectionFilter will only see the remoteAddress for
> log messages generated via IoSessionLogger

Yep.  Let me go ahead.

> On the other hand, when performance impact of MdcInjectionFilter is really
> small, and when MDC support is added for JUL
> I think we could just drop IoSessionLogger, as you wrote on the slf4j
> mailing list.

I can't agree more.  Unfortunately Ceki is going for vacation, so we
might need to wait for a while.  Anyways, we can keep working on it.
:)

Cheers,
Trustin
-- 
what we call human nature is actually human habit
--
http://gleamynode.net/
--
PGP Key ID: 0x0255ECA6

Re: MDC without impedance mismatch?

Posted by Maarten Bosteels <mb...@gmail.com>.
Hi,

Some comments:

1) I understand your worries about performance impact but I think we should
to a little benchmark before jumping to conclusions. Maybe you already did
?

2) I was planning to create an Enum of all the keys that MdcInjectionFilter
supports (remoteAddress, remotePort,...)
and add a constructor that takes an EnumSet, that way users can minimize the
size of the map.

3) Currently, when using the MdcInjectionFilter, all logging events
generated by code down the call-stack (or is it up ?) will also have the MDC
set, even when that code is completely unwaware of MINA. That's a big
advantage IMO.
And AFAICS this can only be done using a ThreadLocal ?

I think the solution we discussed previously, is reasonable:

1) IoSessionLogger constructor takes an org.slf4j.Logger and an IoSession
2) use a session attribute " IoSessionLogger.usePrefix" that determines if a
prefix should be prepended
3) IoSessionLogger forwards all messages to the org.slf4j.Logger and
optionally prepends a prefix

* people using the MdcInjectionFilter will see the remoteAddress for ALL log
messages
* people not using MdcInjectionFilter will only see the remoteAddress for
log messages generated via IoSessionLogger

On the other hand, when performance impact of MdcInjectionFilter is really
small, and when MDC support is added for JUL
I think we could just drop IoSessionLogger, as you wrote on the slf4j
mailing list.

What do the other MINA users think ?
Anybody wants to do a little benchmark ?

Maarten

On 10/23/07, Trustin Lee <tr...@gmail.com> wrote:
>
> Hi,
>
> As you know MDC (Map backed Diagnostic Context IIRC) for all modern
> logging frameworks use ThreadLocal.  I think this is a big headache
> for MINA because MINA doesn't work very well with ThreadLocal.
> Looking at MdcInjectionFilter, we have to copy all map data for each
> event emission because a session spans over multiple threads.  This is
> inefficient and can lead to performance issues.
>
> I thought about fixing this 'impedance mismatch' between ThreadLocal
> and MINA, but didn't success to come up with a good answer yet.
>
> At least for logging frameworks, we could resolve this problem if all
> logging frameworks provides SPI for MDC, so we can directly get
> attributes from session attribute map, which is much more efficient
> than using the current MDC implementation.  However, the reality is
> that no logging framework provides such facility.
>
> Do we need SDC (Session backed Diagnostic Context) here?  I think yes.
>
> As for Log4J, you might be able to achieve that by extending
> PatternLayout and PatternParser and let users use our PatternLayout
> class in their log4j.properties (or .xml).
>
> Logback looks like it provides some extension mechanism somehow, but I
> didn't look into it much in detail.  java.util.logging needs somewhat
> more work to do IMO.
>
> One problem is how the Logger instance is created.  Because we have to
> associate a session with a logger, we have to provide a wrapper class
> for an existing SLF4J Logger instance:
>
> Logger logger = new
> IoSessionLogger(LoggerFactory.getLogger(ABC.class), session);
>
> The next problem is to access the associated session from each logging
> framework's implementation.  It's impossible AFAIK unfortunately
> because SLF4J just forwards the logging calls other than providing a
> mean to pass additional information to the actual logging framework
> being used.
>
> Possible workarounds are:
>
> 1) Change existing logging frameworks. (impossible probably)
> 2) Provide additional pattern layout configuration in IoSessionLogger,
> which is configurable via a constructor parameter of IoSessionLogger.
> And of course with the default global layout. (somewhat ugly)
>
> WDYT?  Any better ideas?
>
> Trustin
> --
> what we call human nature is actually human habit
> --
> http://gleamynode.net/
> --
> PGP Key ID: 0x0255ECA6
>