You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mina.apache.org by Emmanuel Lecharny <el...@gmail.com> on 2008/08/22 22:47:32 UTC

LogFilter questions

Hi guys,

I think there is something wrong with the current implementation of the 
LogFilter.

The idea is to be able to log something _if_ a specific event is set to 
a certain level. For instance, one may log as debug when a 
MessageReceived event is received, but only log errors when a 
MessageSent event is received.

So when you initialize a logLevel, you inject two arguments :
- the eventType
- the desired log level

    public void setLogLevel(IoEventType eventType, LogLevel logLevel) {

The problem with this approach is that the way it's implemented, there 
is no way to get some logs for two different event with two different 
log level, simply because there is only one Logger which is used 
globally, and set to a level globally, too.

So we ned to fix that, and I'm wondering which is the best approach.
- we can simply consider that this is totally useless to tie an event to 
a log level, and just log all events to the same level (pretty much what 
we currently have right now).
- or we consider that the original idea is ok, but then we have to 
create a logger per event.

In both case, I think that the utter complexity of the current 
implementation need to be simplified a lot. We don't need a map to store 
the relation between an event and a logLevel, as the log level will be 
implicit if we have one logger per event (or implicitly set to the 
global logger if we chose option #1), we don't need a LogLevel enum 
either, as the implementation is straightforward in both case :

Option #1 :

    public void messageSent(NextFilter nextFilter, IoSession session,
            WriteRequest writeRequest) throws Exception {
        if (logger.isDebugEnabled()) {
            logger.debug("SENT: {}", writeRequest.getMessage());
        } else if (logger.isInfoEnabled()) {
            logger.info("SENT: {}", writeRequest.getMessage());
        } else if (logger.isTraceEnabled()) {
            logger.trace("SENT: {}", writeRequest.getMessage());
        } else if (logger.isWarnEnabled()) {
            logger.warn("SENT: {}", writeRequest.getMessage());
        } else if (logger.isErrorEnabled()) {
            logger.error("SENT: {}", writeRequest.getMessage());
        }

        nextFilter.messageSent(session, writeRequest);
    }

Option #2 :

    public void messageSent(NextFilter nextFilter, IoSession session,
            WriteRequest writeRequest) throws Exception {
        if (logger.isDebugEnabled()) {
            loggerMessageSent.debug("SENT: {}", writeRequest.getMessage());
        } else if (logger.isInfoEnabled()) {
            loggerMessageSent.info("SENT: {}", writeRequest.getMessage());
        } else if (logger.isTraceEnabled()) {
            loggerMessageSent.trace("SENT: {}", writeRequest.getMessage());
        } else if (logger.isWarnEnabled()) {
            loggerMessageSent.warn("SENT: {}", writeRequest.getMessage());
        } else if (logger.isErrorEnabled()) {
            loggerMessageSent.error("SENT: {}", writeRequest.getMessage());
        }

        nextFilter.messageSent(session, writeRequest);
    }

FYI, the current implemention is :

    private final Map<IoEventType, LogLevel> logSettings = new 
CopyOnWriteMap<IoEventType, LogLevel>();
    private final Logger logger;

    public LoggingFilter(String name) {
        if (name == null) {
            throw new NullPointerException("name should not be null");
        }
        this.name = name;
        logger = LoggerFactory.getLogger(name);
        ...

    public void messageSent(NextFilter nextFilter, IoSession session,
            Object message) throws Exception {
        log(IoEventType.MESSAGE_RECEIVED, "RECEIVED: {}", message);
        nextFilter.messageReceived(session, message);
    }

    protected void log(IoEventType eventType, String format, Object arg) {
        getLogLevel(eventType).log(logger, format, arg);
    }

    public LogLevel getLogLevel(IoEventType eventType) {
        if (eventType == null) {
            throw new NullPointerException("eventType");
        }

        return logSettings.get(eventType);
    }


// For Debug mode :
  
    /**
     * {@link LogLevel} which logs messages on the DEBUG level.
     */
    DEBUG(new LogLevelLogger() {
        public void log(Logger logger, String message, Object arg) {
            logger.debug(message, arg);
        }

        public void log(Logger logger, String message, Object[] args) {
            logger.debug(message, args);
        }

        public void log(Logger logger, String message, Throwable cause) {
            logger.debug(message, cause);
        }
    }),

(same thing for the other levels)

pretty complicated, IMHO :)

Thoughts ?

-- 
--
cordialement, regards,
Emmanuel Lécharny
www.iktek.com
directory.apache.org



Re: LogFilter questions

Posted by Emmanuel Lecharny <el...@gmail.com>.
Hi,


Julien Vermillard wrote:
> Hi,
>
> Comments inline.
>
> On Fri, 22 Aug 2008 22:47:32 +0200
> Emmanuel Lecharny <el...@gmail.com> wrote:
>
>   
>> Hi guys,
>>
>> I think there is something wrong with the current implementation of
>> the LogFilter.
>>     
>
> Sure it's a bit over complicated, specially that Map for IoEvent, due
> to the fact we aren't adding an event every days.
>   
yep.
>   
>> The idea is to be able to log something _if_ a specific event is set
>> to a certain level. For instance, one may log as debug when a 
>> MessageReceived event is received, but only log errors when a 
>> MessageSent event is received.
>>
>> So when you initialize a logLevel, you inject two arguments :
>> - the eventType
>> - the desired log level
>>
>>     public void setLogLevel(IoEventType eventType, LogLevel logLevel)
>> {
>>
>> The problem with this approach is that the way it's implemented,
>>     
>
> Really ? I start to think  after chatting with you a little , that the
> problem is trying to set log level with MINA. It's obviously log
> framework job.
>   
I agree. I tried to implement the LoggingFilter with the very same 
feature as the old one (but without the map), but at the end, this is 
questionable. Here are the points which can be discussed :
- do we really need one logger for each message ? I don't think so.
- why should we handle the log level for each event, when it's a logger 
configuration task ?
> <snip/>
>> FYI, the current implemention is :
>>     
> [..snip..]
> Can you paste that somewhere else for my poor eyes ;)
> LoggingFilter is a debug tool, in no production application you will
> log all the sent/rcvd message.
>   
Agreed. But you never know :) I already have had to do that in order to 
debug an application (long story short : I got 3 Gbs of logs, and found 
where was the problem after having done 4 hours of grep ...), so I would 
keep it as a last chance tool.
> The only usage could be exception & connec/disconnet
>   
For exception, definitively. For message sent and write, I would rather 
define a specific filter, than a generic one.
> So I think we could :
>
> hardcode created/sent/rcvd log level to trace/debug which is always
> used for debug
>   
Yeah, it does not make any sense to request the messages sent or 
received in ERROR mode.
> hardcode close/connect to info
>   
+1
> hardcode exception to error
>   
+1
> use a logger per event type, so the final user use log4j/wathever
> facilities to change the log level for hide/show messages, and not
> configure the LoggingFilter for changing the loglevel to the hidden
> one :)
>   
Totally agree. We could even have a filter for each logger.
>   
>> pretty complicated, IMHO :)
>>
>> Thoughts ?
>>
>>     
>
> and with that we provide a LogLevel class, sound pretty weirdo :)
>
> Those changes are pretty radical, let's wait for some feedback on how
> other users (ab)use the current implementation.
>   
Np. We can propose some implementation, push them into JIRA, and discuss 
them there.

I really want to favor a R-T-C process for such modifications (Review 
Then Commit) instead of the C-T-R we had before. (and this is the reason 
I didn't committed the changes I've done :)

Thanks.


-- 
--
cordialement, regards,
Emmanuel Lécharny
www.iktek.com
directory.apache.org



Re: LogFilter questions

Posted by Alex Karasulu <ak...@apache.org>.
On Mon, Aug 25, 2008 at 3:39 AM, Julien Vermillard
<jv...@archean.fr>wrote:

> LoggingFilter is a debug tool, in no production application you will
> log all the sent/rcvd message.
>
> The only usage could be exception & connec/disconnet
>
> So I think we could :
>
> hardcode created/sent/rcvd log level to trace/debug which is always
> used for debug
>
> hardcode close/connect to info
>
> hardcode exception to error
>
> use a logger per event type, so the final user use log4j/wathever
> facilities to change the log level for hide/show messages, and not
> configure the LoggingFilter for changing the loglevel to the hidden
> one :)
>

I like the idea of it simply sitting on top of underlying logging framework
configuration to figure out the log level.  Points above that are pretty
reasonable.  Maarten below also makes some good points with respect to even
possibly getting rid of it.

Alex

Re: LogFilter questions

Posted by Maarten Bosteels <mb...@gmail.com>.
I agree: the current LoggingFilter is pretty complicated.  I looked at it in
the past but found it too complex to use it.
I even think we could just get rid of it and let our users write a
customized LoggingFilter when they need one.

But what Julien suggest also looks OK to me.

Regards,
Maarten

On Mon, Aug 25, 2008 at 9:39 AM, Julien Vermillard
<jv...@archean.fr>wrote:

> Hi,
>
> Comments inline.
>
> On Fri, 22 Aug 2008 22:47:32 +0200
> Emmanuel Lecharny <el...@gmail.com> wrote:
>
> > Hi guys,
> >
> > I think there is something wrong with the current implementation of
> > the LogFilter.
>
> Sure it's a bit over complicated, specially that Map for IoEvent, due
> to the fact we aren't adding an event every days.
>
> >
> > The idea is to be able to log something _if_ a specific event is set
> > to a certain level. For instance, one may log as debug when a
> > MessageReceived event is received, but only log errors when a
> > MessageSent event is received.
> >
> > So when you initialize a logLevel, you inject two arguments :
> > - the eventType
> > - the desired log level
> >
> >     public void setLogLevel(IoEventType eventType, LogLevel logLevel)
> > {
> >
> > The problem with this approach is that the way it's implemented,
>
> Really ? I start to think  after chatting with you a little , that the
> problem is trying to set log level with MINA. It's obviously log
> framework job.
>
> > there is no way to get some logs for two different event with two
> > different log level, simply because there is only one Logger which is
> > used globally, and set to a level globally, too.
> >
> > So we ned to fix that, and I'm wondering which is the best approach.
> > - we can simply consider that this is totally useless to tie an event
> > to a log level, and just log all events to the same level (pretty
> > much what we currently have right now).
> > - or we consider that the original idea is ok, but then we have to
> > create a logger per event.
> >
> > In both case, I think that the utter complexity of the current
> > implementation need to be simplified a lot. We don't need a map to
> > store the relation between an event and a logLevel, as the log level
> > will be implicit if we have one logger per event (or implicitly set
> > to the global logger if we chose option #1), we don't need a LogLevel
> > enum either, as the implementation is straightforward in both case :
> >
> > Option #1 :
> >
> >     public void messageSent(NextFilter nextFilter, IoSession session,
> >             WriteRequest writeRequest) throws Exception {
> >         if (logger.isDebugEnabled()) {
> >             logger.debug("SENT: {}", writeRequest.getMessage());
> >         } else if (logger.isInfoEnabled()) {
> >             logger.info("SENT: {}", writeRequest.getMessage());
> >         } else if (logger.isTraceEnabled()) {
> >             logger.trace("SENT: {}", writeRequest.getMessage());
> >         } else if (logger.isWarnEnabled()) {
> >             logger.warn("SENT: {}", writeRequest.getMessage());
> >         } else if (logger.isErrorEnabled()) {
> >             logger.error("SENT: {}", writeRequest.getMessage());
> >         }
> >
> >         nextFilter.messageSent(session, writeRequest);
> >     }
> >
> > Option #2 :
> >
> >     public void messageSent(NextFilter nextFilter, IoSession session,
> >             WriteRequest writeRequest) throws Exception {
> >         if (logger.isDebugEnabled()) {
> >             loggerMessageSent.debug("SENT: {}",
> > writeRequest.getMessage()); } else if (logger.isInfoEnabled()) {
> >             loggerMessageSent.info("SENT: {}",
> > writeRequest.getMessage()); } else if (logger.isTraceEnabled()) {
> >             loggerMessageSent.trace("SENT: {}",
> > writeRequest.getMessage()); } else if (logger.isWarnEnabled()) {
> >             loggerMessageSent.warn("SENT: {}",
> > writeRequest.getMessage()); } else if (logger.isErrorEnabled()) {
> >             loggerMessageSent.error("SENT: {}",
> > writeRequest.getMessage()); }
> >
> >         nextFilter.messageSent(session, writeRequest);
> >     }
>
> loggerSent.trace(writeRequest.getMessage());
> no need SENT because it's already the sending logger.
>
> >
> > FYI, the current implemention is :
> [..snip..]
> Can you paste that somewhere else for my poor eyes ;)
> LoggingFilter is a debug tool, in no production application you will
> log all the sent/rcvd message.
>
> The only usage could be exception & connec/disconnet
>
> So I think we could :
>
> hardcode created/sent/rcvd log level to trace/debug which is always
> used for debug
>
> hardcode close/connect to info
>
> hardcode exception to error
>
> use a logger per event type, so the final user use log4j/wathever
> facilities to change the log level for hide/show messages, and not
> configure the LoggingFilter for changing the loglevel to the hidden
> one :)
>
> > pretty complicated, IMHO :)
> >
> > Thoughts ?
> >
>
> and with that we provide a LogLevel class, sound pretty weirdo :)
>
> Those changes are pretty radical, let's wait for some feedback on how
> other users (ab)use the current implementation.
>
> Julien
>

Re: LogFilter questions

Posted by Julien Vermillard <jv...@archean.fr>.
Hi,

Comments inline.

On Fri, 22 Aug 2008 22:47:32 +0200
Emmanuel Lecharny <el...@gmail.com> wrote:

> Hi guys,
> 
> I think there is something wrong with the current implementation of
> the LogFilter.

Sure it's a bit over complicated, specially that Map for IoEvent, due
to the fact we aren't adding an event every days.

> 
> The idea is to be able to log something _if_ a specific event is set
> to a certain level. For instance, one may log as debug when a 
> MessageReceived event is received, but only log errors when a 
> MessageSent event is received.
> 
> So when you initialize a logLevel, you inject two arguments :
> - the eventType
> - the desired log level
> 
>     public void setLogLevel(IoEventType eventType, LogLevel logLevel)
> {
> 
> The problem with this approach is that the way it's implemented,

Really ? I start to think  after chatting with you a little , that the
problem is trying to set log level with MINA. It's obviously log
framework job.

> there is no way to get some logs for two different event with two
> different log level, simply because there is only one Logger which is
> used globally, and set to a level globally, too.
> 
> So we ned to fix that, and I'm wondering which is the best approach.
> - we can simply consider that this is totally useless to tie an event
> to a log level, and just log all events to the same level (pretty
> much what we currently have right now).
> - or we consider that the original idea is ok, but then we have to 
> create a logger per event.
> 
> In both case, I think that the utter complexity of the current 
> implementation need to be simplified a lot. We don't need a map to
> store the relation between an event and a logLevel, as the log level
> will be implicit if we have one logger per event (or implicitly set
> to the global logger if we chose option #1), we don't need a LogLevel
> enum either, as the implementation is straightforward in both case :
> 
> Option #1 :
> 
>     public void messageSent(NextFilter nextFilter, IoSession session,
>             WriteRequest writeRequest) throws Exception {
>         if (logger.isDebugEnabled()) {
>             logger.debug("SENT: {}", writeRequest.getMessage());
>         } else if (logger.isInfoEnabled()) {
>             logger.info("SENT: {}", writeRequest.getMessage());
>         } else if (logger.isTraceEnabled()) {
>             logger.trace("SENT: {}", writeRequest.getMessage());
>         } else if (logger.isWarnEnabled()) {
>             logger.warn("SENT: {}", writeRequest.getMessage());
>         } else if (logger.isErrorEnabled()) {
>             logger.error("SENT: {}", writeRequest.getMessage());
>         }
> 
>         nextFilter.messageSent(session, writeRequest);
>     }
> 
> Option #2 :
> 
>     public void messageSent(NextFilter nextFilter, IoSession session,
>             WriteRequest writeRequest) throws Exception {
>         if (logger.isDebugEnabled()) {
>             loggerMessageSent.debug("SENT: {}",
> writeRequest.getMessage()); } else if (logger.isInfoEnabled()) {
>             loggerMessageSent.info("SENT: {}",
> writeRequest.getMessage()); } else if (logger.isTraceEnabled()) {
>             loggerMessageSent.trace("SENT: {}",
> writeRequest.getMessage()); } else if (logger.isWarnEnabled()) {
>             loggerMessageSent.warn("SENT: {}",
> writeRequest.getMessage()); } else if (logger.isErrorEnabled()) {
>             loggerMessageSent.error("SENT: {}",
> writeRequest.getMessage()); }
> 
>         nextFilter.messageSent(session, writeRequest);
>     }

loggerSent.trace(writeRequest.getMessage()); 
no need SENT because it's already the sending logger.

> 
> FYI, the current implemention is :
[..snip..]
Can you paste that somewhere else for my poor eyes ;)
LoggingFilter is a debug tool, in no production application you will
log all the sent/rcvd message.

The only usage could be exception & connec/disconnet

So I think we could :

hardcode created/sent/rcvd log level to trace/debug which is always
used for debug

hardcode close/connect to info

hardcode exception to error

use a logger per event type, so the final user use log4j/wathever
facilities to change the log level for hide/show messages, and not
configure the LoggingFilter for changing the loglevel to the hidden
one :)

> pretty complicated, IMHO :)
> 
> Thoughts ?
> 

and with that we provide a LogLevel class, sound pretty weirdo :)

Those changes are pretty radical, let's wait for some feedback on how
other users (ab)use the current implementation.

Julien