Too much jboss cache INFO logging

[dimitris]

I think we've discussed this before. We really don't need all this stuff to be logged as INFO, it should be DEBUG:

12:34:58,343 INFO [PojoCacheImpl] PojoCache version: JBossCache 'Habanero' 2.0.
0.CR3[ $Id: Version.java,v 1.33 2007/06/12 07:41:03 msurtani Exp $]
12:34:58,593 INFO [InterceptorChainFactory] interceptor chain is:
class org.jboss.cache.interceptors.CallInterceptor
class org.jboss.cache.interceptors.DataGravitatorInterceptor
class org.jboss.cache.interceptors.PassivationInterceptor
class org.jboss.cache.interceptors.ActivationInterceptor
class org.jboss.cache.interceptors.UnlockInterceptor
class org.jboss.cache.interceptors.PessimisticLockInterceptor
class org.jboss.cache.interceptors.ReplicationInterceptor
class org.jboss.cache.interceptors.NotificationInterceptor
class org.jboss.cache.interceptors.TxInterceptor
class org.jboss.cache.interceptors.CacheMgmtInterceptor
class org.jboss.cache.interceptors.InvocationContextInterceptor
12:34:58,687 INFO [InterceptorChainFactory] interceptor chain is:
class org.jboss.cache.interceptors.CallInterceptor
class org.jboss.cache.interceptors.EvictionInterceptor
class org.jboss.cache.interceptors.UnlockInterceptor
class org.jboss.cache.interceptors.PessimisticLockInterceptor
class org.jboss.cache.interceptors.ReplicationInterceptor
class org.jboss.cache.interceptors.NotificationInterceptor
class org.jboss.cache.interceptors.TxInterceptor
class org.jboss.cache.interceptors.CacheMgmtInterceptor
class org.jboss.cache.interceptors.InvocationContextInterceptor
12:34:58,734 INFO [InterceptorChainFactory] interceptor chain is:
class org.jboss.cache.interceptors.CallInterceptor
class org.jboss.cache.interceptors.EvictionInterceptor
class org.jboss.cache.interceptors.DataGravitatorInterceptor
class org.jboss.cache.interceptors.PassivationInterceptor
class org.jboss.cache.interceptors.ActivationInterceptor
class org.jboss.cache.interceptors.UnlockInterceptor
class org.jboss.cache.interceptors.PessimisticLockInterceptor
class org.jboss.cache.interceptors.ReplicationInterceptor
class org.jboss.cache.interceptors.NotificationInterceptor
class org.jboss.cache.interceptors.TxInterceptor
class org.jboss.cache.interceptors.CacheMgmtInterceptor
class org.jboss.cache.interceptors.InvocationContextInterceptor
12:34:58,750 INFO [InterceptorChainFactory] interceptor chain is:
class org.jboss.cache.interceptors.CallInterceptor
class org.jboss.cache.interceptors.UnlockInterceptor
class org.jboss.cache.interceptors.PessimisticLockInterceptor
class org.jboss.cache.interceptors.ReplicationInterceptor
class org.jboss.cache.interceptors.NotificationInterceptor
class org.jboss.cache.interceptors.TxInterceptor
class org.jboss.cache.interceptors.CacheMgmtInterceptor
class org.jboss.cache.interceptors.InvocationContextInterceptor
12:34:58,750 INFO [PojoCacheImpl] PojoCache version: JBossCache 'Habanero' 2.0.
0.CR3[ $Id: Version.java,v 1.33 2007/06/12 07:41:03 msurtani Exp $]
12:34:59,968 INFO [DefaultPartition-TomcatCache] Using marshaller org.jboss.cac
he.marshall.VersionAwareMarshaller

[brian.stansberry]

:-)

INFO is good only if it's quite likely to save a round trip back and forth with a customer on a support case to get config info. Of the 3 types of logging in Dimitris' snippet, the only one that comes up routinely is the version logging. That IMHO is OK at INFO, but really should just be a corporate policy thing -- i.e. if we decide across JBoss not to log versions at INFO, JBC shouldn't; if it's OK to do it at info, then JBC should, since it comes up so often.

The "12:34:59,968 INFO [DefaultPartition-TomcatCache] Using marshaller org.jboss.cache.marshall.VersionAwareMarshaller" info can easily be deduced by looking at a config file. It's not something that comes up often either; maybe never.

The interceptor chain factory stuff is harder; i.e. takes *some* effort to figure out the chain from a config file, and knowing the chain is important in some tricky cases. But, 90% of the benefit could be achieved just by adding a wiki page that shows what the chains look like in the standard setups:

PESSIMISTIC, no cacheloader
OPTIMISTIC, no cacheloader

PESSIMISTIC, cacheloader w/ passivation=false
OPTIMISTIC, cacheloader w/ passivation=false

PESSIMISTIC, cacheloader w/ passivation=true
OPTIMISTIC, cacheloader w/ passivation=true

(Include DataGravitationInterceptor in all with a comment about how it's not there if buddy replication isn't enabled. Same for CacheMgmtInterceptor.)

[dmlloyd]

It might be worth having a look at this:

http://wiki.jboss.org/wiki/Wiki.jsp?page=LoggingStandards

[brian.stansberry]

Thanks. :)

The definition of INFO vs DEBUG there is slightly vague, until you interpret the concept of "service state" in the INFO description in terms of the AS ServiceMBean.getState() definitions; i.e. lifecycle state -- created/started/stopped/destroyed.

With that interpretation all these should be at DEBUG.

We could cheat and log the version as part of a "Cache started" INFO message. :-)

BTW, with the practice of only supporting Platforms, the need to log versions is reduced, since the JBC version is defined by the Platform version. When we support JBC as a Framework, the support tools will be fixed so the customer can properly specify the version in the form they fill out to submit a case. Presumably they know the version if they went to the effort of specifically buying support for it.

[dimitris]

The interceptor list should certainly be DEBUG, this is just too much detail for the average user. Imagine if we printed interceptor lists, e.g. for EJB Containers. It doesn't make sense.

Same for the marshaller message, should be DEBUG.

The Cache version is reporting Ok, that's useful to know at the INFO level and infact most components should do that.

If you look into a standard boot output of the 'all' config you may find more cluster/cache related details that could be INFO. But I'll leave that as an exercise :-)

[manik]

Reopening http://jira.jboss.com/jira/browse/JBCACHE-725