[jboss-dev] AS trunk boot time back to poor?

[John Bailey]

Below is a forum post containing a complete list of all the unguarded calls to Logger.dubug and Logger.debugf.

http://community.jboss.org/thread/147272

As an example of a call that should be fixed, take a look at the most invoked method.  

---
   private void logParserInfo()
   {
      StringBuffer sb = new StringBuffer();
      sb.append("Created parser: ").append(parser)
      .append(", isNamespaceAware: ").append(parser.isNamespaceAware())
      .append(", isValidating: ").append(parser.isValidating())
      .append(", isXIncludeAware: ");
      try
      {
         sb.append(parser.isXIncludeAware());
      }
      catch(UnsupportedOperationException e)
      {
         sb.append("unsupported operation '").append(e.getMessage()).append('\'');
      }
      log.debug(sb.toString());
   }
---



On Jan 22, 2010, at 7:55 AM, Brian Stansberry wrote:

> I don't know if John has that sort of info. He came up with numbers real 
> quickly so I suspect he did something simple like profile a boot and 
> look at the # of invocations of Logger.debug(). vs Logger.isDebugEnabled().
> 
> A simple thing to do is start the AS with 
> -Djboss.boot.server.log.level=DEBUG. Scroll through the log looking for 
> the numerous places where the contents of a classloader domain are 
> logged, filling up a couple screens. If those aren't guarded -- bad. ;)
> 
> On 01/21/2010 05:01 PM, Ales Justin wrote:
>> Is there a way we could pull out some stats?
>> e.g. # of debug calls per package/ class/log_owner
>> 
>> This way the biggest culprits could check, and fix things.
>> e.g. we used to have some heavy debug log in deployers
>> 
>> Although I guess the bad pieces are those where we loose time to
>> construct msg, which are not stats "bounty".
>> At least not with the old logging, w/o argvars.
>> 
>> Sent from my iPod
>> 
>> On 21.1.2010, at 23:50, Brian Stansberry<brian.stansberry at redhat.com>
>> wrote:
>> 
>>> On 01/21/2010 11:20 AM, Brian Stansberry wrote:
>>>> On 01/21/2010 10:41 AM, David M. Lloyd wrote:
>>>>> On 01/21/2010 10:39 AM, David M. Lloyd wrote:
>>>>>> On 01/21/2010 09:55 AM, Brian Stansberry wrote:
>>>> 
>>>> Semi-OT: a couple weeks ago, when boot.log was<   10MB I tried setting
>>>> -Djboss.boot.server.log.level=INFO and got very little improvement in
>>>> boot time (<   200ms). My take on that is we must have a lot of DEBUG
>>>> logging with very expensive message construction not guarded by
>>>> isDebugEnabled().
>>>> 
>>> 
>>> John Bailey did some quick profiling or something and estimated that
>>> during startup we have>  5000 log.debug() calls not guarded by
>>> log.isDebugEnabled(). If you look at the debug logging output, a lot
>>> of
>>> the messages are pretty heavy, some absolutely huge; if those aren't
>>> guarded it's a serious cost.
>>> 
>>> Warning: the rest of this post is completely unsupported by evidence;
>>> just my gut feel.
>>> 
>>> Perhaps not guarded because that method is deprecated?
>>> 
>>> Here's a good explanation of why it's deprecated:
>>> 
>>> http://blogs.jboss.org/blog/dimitris/2005/04/01/AC08547736BD16504BEC955AEBDAA48F.txt
>>> 
>>> I fear though that deprecating this method is a failed social
>>> experiment. Please resist the urge to make that deprecation warning go
>>> away by not putting a code guard around an expensive log.debug().
>>> Either
>>> reduce the level to trace (and keep a guard of course) or accept the
>>> warning and bitch publicly about the deprecation.
>>> 
>>> 
>>> Please also resist the urge to shift off of EE 6 work in order to
>>> scour
>>> all our code for logging cleanups. :)
>>> 
>>> --
>>> Brian Stansberry
>>> Lead, AS Clustering
>>> JBoss by Red Hat
>>> _______________________________________________
>>> jboss-development mailing list
>>> jboss-development at lists.jboss.org
>>> https://lists.jboss.org/mailman/listinfo/jboss-development
>> _______________________________________________
>> jboss-development mailing list
>> jboss-development at lists.jboss.org
>> https://lists.jboss.org/mailman/listinfo/jboss-development
> 
> 
> -- 
> Brian Stansberry
> Lead, AS Clustering
> JBoss by Red Hat
> _______________________________________________
> jboss-development mailing list
> jboss-development at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/jboss-development

--
  John Bailey
  JBoss by Red Hat
--