You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mina.apache.org by "vincent bourdaraud (JIRA)" <ji...@apache.org> on 2007/09/24 16:02:50 UTC

[jira] Created: (DIRMINA-445) SessionLog improvement

SessionLog improvement
----------------------

                 Key: DIRMINA-445
                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
             Project: MINA
          Issue Type: Improvement
          Components: Core
    Affects Versions: 1.1.3, 2.0.0-M1
         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
            Reporter: vincent bourdaraud
            Priority: Minor


SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.

The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).

Some code snippet the illustrate this:

    public void messageReceived(IoSession session, Object o) throws Exception
    {
       MyProtocolRequest req = (MyProtocolRequest) o;
       NDC.put(req.getUserId());
       SessionLog.debug(session, new RequestDumper(req));
       NDC.pop();
    }
   
    class RequestDumper()
    {
        public RequestDumper(MyProtocolRequest req)
        {
            this.req = req;
        }
        
        public String toString()
        {
            return req.toString();
        }
        
        private MyProtocolRequest req;
    }

In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.

With this feature, we could enable debug in production for some few users only, without killing the overall performances.


-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Maarten Bosteels (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531114 ] 

Maarten Bosteels commented on DIRMINA-445:
------------------------------------------

I was thinking that the call to MessageFormatter.format(String messagePattern, Object arg1, Object arg2)
would be slower than the simple string concatenation we have now.
http://svn.slf4j.org/viewvc/slf4j/trunk/slf4j-api/src/main/java/org/slf4j/helpers/MessageFormatter.java?revision=761&view=markup

and it is about 50% slower
but in absolute numbers the difference is of course insignificant :  0,0006 ms per invocation :-)

I will apply the proposed change immediately.

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Maarten Bosteels (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531127 ] 

Maarten Bosteels commented on DIRMINA-445:
------------------------------------------

I completely agree with replacing IoSessionLogger with MdcInjectionFilter
(that's why I proposed it in my first comment on this issue).
I just didn't dare to push 'my' MdcInjectionFilter too hard :-)

IMO MdcInjectionFilter has several advantages:
* all log events will contain the remoteIP, as opposed to only those created via IoSessionLogger
   (but maybe not everybody wants that ?)
* users can use all methods of org.slf4j.Logger while currently IoSessionLogger only offers a subset
* it's an othogonal concern: remove the filter and the log-statements still work
* users can add custom session attributes to the Mdc
* users can decide how to format the IoSession attributes (remoteIp, remotePort, ...)


> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Trustin Lee (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531169 ] 

Trustin Lee commented on DIRMINA-445:
-------------------------------------

Ah.. I thought you don't want to remove IoSessionLogger because remoteAddress will not be printed out. :D

Another critial issue with SLF4J MDC is not that it doesn't support any other logging frameworks than Log4J.  It should at least work with java.util.logging.

and here's another related issue:

http://www.nabble.com/Integrating-SessionLog-into-IoSession-tf4156058s16868.html#a12138654

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Maarten Bosteels (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531160 ] 

Maarten Bosteels commented on DIRMINA-445:
------------------------------------------

Not sure I understand what you mean.
I was still suggesting to remove IoSessionLogger, but the consequence is that MINA-generated loggings will
no longer have the remoteAdrress, unless users add a MdcInjectionFilter.
But you think that's not acceptable ?

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Trustin Lee (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531140 ] 

Trustin Lee commented on DIRMINA-445:
-------------------------------------

I completely agree with you, too. :)
(in that you are pushing so hard! Just kidding. ;)

Let's go for it!

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Assigned: (DIRMINA-445) SessionLog improvement

Posted by "Maarten Bosteels (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Maarten Bosteels reassigned DIRMINA-445:
----------------------------------------

    Assignee: Maarten Bosteels

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12529952 ] 

Emmanuel Lecharny commented on DIRMINA-445:
-------------------------------------------

Hmmm... Not sure I understand the potential negative impact of this change, when the event is not filtered... Do you mean if log is not activated, for instance?

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Maarten Bosteels (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531155 ] 

Maarten Bosteels commented on DIRMINA-445:
------------------------------------------

about documentation on MdcInjectionFilter: will do it asap

about removing IoSessionLogger: 
It is used a lot in current code, would you replace it with plain calls to org.slf4j.Logger ?
IoSessionLogger has the advantage that it always emits remoteAddress, regardless of filters in the chain.
We could inform people that they will only see the remoteAddress for MINA-generated loggings when they have an MdcInjectionFilter in their chain. 

WDYT ?

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Trustin Lee (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531141 ] 

Trustin Lee commented on DIRMINA-445:
-------------------------------------

I forgot to mention it would be nice if you can add a section about MdcInjectionFilter to our new logging manual page after removing IoSessionLogger.

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Maarten Bosteels (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531161 ] 

Maarten Bosteels commented on DIRMINA-445:
------------------------------------------

You're right I think we need a vote, although I am afraid I won't like the outcome :-) 

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Maarten Bosteels (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12529891 ] 

Maarten Bosteels commented on DIRMINA-445:
------------------------------------------

Emmanuel, you're right: IoSessionLogger can use the Marker mechnism itself, I hadn' thought about that :-)

The solution will certainly save CPU when the LoggingEvent is filtered out
but it might add some overhead when the event is not filtered ?

I will try to test the performance impact and apply the change when it's beneficial.


> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Maarten Bosteels (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12529874 ] 

Maarten Bosteels commented on DIRMINA-445:
------------------------------------------

Some remarks:

* MINA uses the SLF4J API (not log4j) and for some reason SLF4J does not have the logger.debug(Object obj) API
   So while we could change the API of SessionLog, we would have to call toString() anyway
   (unless we would do the isDebugEnabled check in SessionLog)
   
* Have you looked at the MdcInjectionFilter ?
   IMHO it covers the functionality of SessionLog, with much more flexibility 

* SLF4J supports the elegant Marker mechanism, which you can use to avoid the expensive toString() call :
   logger.debug("message received: {}", new RequestDumper(req));
   => toString() will only be called when the LoggingEvent is actually generated

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Priority: Minor
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Trustin Lee (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531159 ] 

Trustin Lee commented on DIRMINA-445:
-------------------------------------

However, I am just worried about losing this advantage:

* users can use all methods of org.slf4j.Logger while currently IoSessionLogger only offers a subset 

We could modify IoSessionLogger to provide all the methods, but does it worth?  Assuming all users are going to use MdcInjectionFilter eventually, we might be just OK to remove IoSessionLogger.  I'd like to know what others think about this issue.

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Resolved: (DIRMINA-445) SessionLog improvement

Posted by "Maarten Bosteels (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Maarten Bosteels resolved DIRMINA-445.
--------------------------------------

       Resolution: Fixed
    Fix Version/s: 2.0.0-M1

Applied change proposed by Emmanuel Lecharny 

Please note that in the comments I mistakenly used the term "Marker mechanism" when I meant
the methods that take a format parameter that contains {} placeholders .

Apparently Marker's are a different concept: http://www.slf4j.org/api/org/slf4j/Marker.html


> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Trustin Lee (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531157 ] 

Trustin Lee commented on DIRMINA-445:
-------------------------------------

Hmm you are right.  Modifying MdcInjectionFilter to clear IoSessionLogger.PREFIX attribute to an empty string will be needed though, to prevent unwanted prefix for advanced users.

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "vincent bourdaraud (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12539820 ] 

vincent bourdaraud commented on DIRMINA-445:
--------------------------------------------

Please find my remark inline.

On Mon, 2007-09-24 at 07:37 -0700, ext Maarten Bosteels (JIRA) wrote: 

Right. I had miss that point.


No I didn't since this class is new to MINA 2 if I'm correct?
I had a look to it from SVN. If my understanding is correct, it gives a
way to push data to filter on. This is half the trick, but it does not
address performance issue (prevent building the string when not needed).
Am I correct? 


SLF4J is now much more mature than it was a year ago! I was not aware of
that feature in SLF4J. From what I see, this feature plus the  I believe
it fully suits my needs and there is hence no need to change MINA in
anyway. This feature plus the MdcInjectionFilter covers everything I
need :)

Thanks for your help.
Vincent.




> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Closed: (DIRMINA-445) SessionLog improvement

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Emmanuel Lecharny closed DIRMINA-445.
-------------------------------------


> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>             Fix For: 2.0.0-M1
>
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Trustin Lee (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531119 ] 

Trustin Lee commented on DIRMINA-445:
-------------------------------------

Wait a sec... we have MDCInjectionFilter now.  Do we really need ioSessionLogger?  We could just insert MDCInjectionFilter and let the user format the whole message without using IoSessionLogget at all.

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Trustin Lee (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12531006 ] 

Trustin Lee commented on DIRMINA-445:
-------------------------------------

How's the test going Maarten?  I guess there won't be any negative performance impact regarding the proposed change.

> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Assignee: Maarten Bosteels
>            Priority: Minor
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (DIRMINA-445) SessionLog improvement

Posted by "Emmanuel Lecharny (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DIRMINA-445?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12529886 ] 

Emmanuel Lecharny commented on DIRMINA-445:
-------------------------------------------

I have looked at the trunk. It seems that SessionLog has been moved to a IoSessionLogger, but Vincent proposal is still valid.

The code looks like :
    public static void trace(Logger log, IoSession session, String message) {
        if (log.isTraceEnabled()) {
            log.trace(String.valueOf(getPrefix(session)) + message);
        }
    }

Two remarks there :
1) using the Marker mechanism, it could be written like  :
    public static void trace(Logger log, IoSession session, String message) {
        if (log.isTraceEnabled()) {
            log.trace( "{} {}", getPrefix(session), message); // No need to call the String.valueOf( getPrefix()), getprefix already returns a String
        } 
    }

2) As soon as you encapsulate the log method in such a wrapper, then suddenly you can pass an Object instead of a String, and transform the methods to looks like :
    public static void trace(Logger log, IoSession session, Object message) {
        if (log.isTraceEnabled()) {
            log.trace( "{} {}", getPrefix(session), message);
        } 
    }

It comes at no cost, and will save a lot of CPU


Regarding 1.1.2, we have almost the same code :
    public static void debug(IoSession session, String message) {
        Logger log = getLogger(session);
        if (log.isDebugEnabled()) {
            log.debug(String.valueOf(session.getAttribute(PREFIX)) + message);
        }
    }

which can be written like :
    public static void debug(IoSession session, Object message) {
        Logger log = getLogger(session);
        if (log.isDebugEnabled()) {
            log.debug( "{} {}", session.getAttribute(PREFIX), message); // No need either to call String.valueOf(), slf4j will handle the object itself.
        } 
    }




> SessionLog improvement
> ----------------------
>
>                 Key: DIRMINA-445
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-445
>             Project: MINA
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 1.1.3, 2.0.0-M1
>         Environment: Use Object instead of String inSessionLog logging method to allow for massive perfs improvement on production running instances (when logs filtering is used).
>            Reporter: vincent bourdaraud
>            Priority: Minor
>
> SessionLog.debug(IoSession,String), info(IoSession,String), warn(IoSession,String) and error(IoSession,String) should be changed to SessionLog.debug(IoSession,Object), info(IoSession,Object), warn(IoSession,Object) and error(IoSession,Object), as in log4j.
> The reason for this is that if passing Objects instead of String allow to delay the composition of the logging message (.toString() call) until really needed and that could greatly improve performance. This kind of feature is needed to build SW able to be turned in debug while in production using NDC/MDC filters (using log4j e.g.).
> Some code snippet the illustrate this:
>     public void messageReceived(IoSession session, Object o) throws Exception
>     {
>        MyProtocolRequest req = (MyProtocolRequest) o;
>        NDC.put(req.getUserId());
>        SessionLog.debug(session, new RequestDumper(req));
>        NDC.pop();
>     }
>    
>     class RequestDumper()
>     {
>         public RequestDumper(MyProtocolRequest req)
>         {
>             this.req = req;
>         }
>         
>         public String toString()
>         {
>             return req.toString();
>         }
>         
>         private MyProtocolRequest req;
>     }
> In that snippet, the cost of converting MyProtocolRequest to a String is not paied when SessionLog.debug() is called, but when the underlying logging framework needs the string for logging. The perf improvement could be massive if the underlying protocol uses some kind of filtering to filter-out most debug logs; in that example, the logging framework would be configured to filter-in only logs with a NDC set to a specific user.
> With this feature, we could enable debug in production for some few users only, without killing the overall performances.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.