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

[Brian Stansberry]

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