[jboss-dev] Re: Excessive logging in AS 4.2.3 and AS 5

Jay Balunas jbalunas at redhat.com
Mon Jan 5 11:15:56 EST 2009


On Dec 23, 2008, at 5:11 PM, Brian Stansberry wrote:

> Jay Balunas wrote:
>> The threshold you're referring to should be the exception not the  
>> rule.  I'll admit I have not been following all of this closely,  
>> but I thought the only reason we did not set logging to INFO by  
>> default was because CI builds need to have DEBUG set.
>
> As much as anything it was a timing issue. I made it controllable  
> via a system property pretty shortly before AS 5 GA, when we were  
> struggling to get valid testsuite results, QA lab was being shut  
> down for days at a time etc etc. Changing the default to INFO would  
> have meant ensuring all the various server configs we use in AS,  
> EJB3, TCK tests etc were tweaked to run at DEBUG. Just one moving  
> part to many.
>
> https://jira.jboss.org/jira/browse/JBASM-25 will make all that easy,  
> but that would have required another server-manager release, which  
> wasn't in the cards.

I understand about timing ;-) thanks for the info

>
>
>> I'm still confused why we don't just set a default value in log4j  
>> config file for the log setting to INFO.  Since I can see the need  
>> to have a scriptable (i.e. command line) way to override for CI  
>> builds the we can use the ability to override via command line  
>> ( which I thought log4j supported anyway ).
>
> If you know another better way to meet the requirements, please  
> describe it in detail or better yet implement it. :-)

One way this can be done is to have a separate jboss-log4j-debug.xml  
file that contains the desired debug logging, then when starting JBoss  
use "-Dlog4j.configuration=jboss-log4j-debug.xml".  In hudson this can  
be done by updating the the start shell command.

I was hunting for a way to update the log level directly via -D but  
could not find it.  I thought there was a way, but the separate config  
file might be a better way anyway ;-)

>
>
> Darran - good point that having a Threshold set but leaving it at  
> DEBUG really gains nothing but adds an extra step to turning on  
> TRACE logging.  Don't see why you'd muck with the system property to  
> enable TRACE logging on a running server though; just change the  
> threshold from "${jboss.server.log.threshold}" to "TRACE".
>
> Re: cost of isDebugEnabled() I proposed controlling the value of the  
> org.jboss category via the same jboss.server.log.threshold property.  
> Any comments?
>
>> Parting thoughts before the holidays ;-)
>> -Jay
>> On Dec 23, 2008, at 12:53 PM, Darran Lofthouse wrote:
>>>
>>> One drawback of this new Threshold is that to enable TRACE logging  
>>> you are forced to set the property - 
>>> Djboss.server.log.threshold=TRACE as even if this property is not  
>>> set TRACE logging will be disabled just by the presence of this  
>>> setting.
>>>
>>> Secondly I don't believe this is going to cause isDebugEnabled()  
>>> to return false as the category is still set to the default so  
>>> expensive operations wrapped by isDebugEnabled will still be called.
>>>
>>>
>>> Brian Stansberry wrote:
>>>> https://jira.jboss.org/jira/browse/JBAS-6205 is done.
>>>> Shelly, if there is going to be a new server-manager release, how  
>>>> about we add a -Djboss.server.log.threshold=DEBUG to the args  
>>>> that get passed when an AS is started?  That's a quick way to  
>>>> ensure testsuite configs launch with the correct level if we move  
>>>> the default to INFO.  Otherwise we'd have to figure out all  
>>>> projects that use server-manager and edit their build file  
>>>> server:config elements.
>>>> Jay Balunas wrote:
>>>>> OK thanks for the update.  This property should make it very  
>>>>> easy to adjust this for the test environment while still  
>>>>> allowing us to ship AS5 in a configuration that does not created  
>>>>> MBs of logs.
>>>>>
>>>>> On Nov 17, 2008, at 3:13 PM, Brian Stansberry wrote:
>>>>>
>>>>>> Jay Balunas wrote:
>>>>>>> ----- "Brian Stansberry" <brian.stansberry at redhat.com> wrote:
>>>>>>>> I see 3 different issues here:
>>>>>>>>
>>>>>>>> 1) Code that does per-request logging at DEBUG level instead  
>>>>>>>> of TRACE.
>>>>>>>>
>>>>>>>> That's in violation of the logging standards and should be  
>>>>>>>> fixed.
>>>>>>> +1 and that is what we are seeing to some extent.  We don't  
>>>>>>> regularly need to known every time a class is loaded, or a  
>>>>>>> persistence connection is closed.
>>>>>>>> 2) How much we log at DEBUG as part of service startup/ 
>>>>>>>> shutdown. IMHO, this is not a huge problem.  We should  
>>>>>>>> probably clean it up some, but
>>>>>>>>
>>>>>>>> the point of the logging is to make problem diagnosis easier,  
>>>>>>>> not to produce small logs for infrequent events.
>>>>>>> Start up time in no little issue, but in general I agree.  if  
>>>>>>> there is extra logging during start up thats fine.  The real  
>>>>>>> issue is the reoccurring logs
>>>>>>>> 3) The default loggging level for server.log. If #1 is  
>>>>>>>> broken, then having it be INFO makes sense, otherwise we  
>>>>>>>> punish users for our problems.  If #1 is fixed, then  
>>>>>>>> different people can have different preferences, which I  
>>>>>>>> expect we're about to debate here. :-)  My
>>>>>>>> personal one is to leave it at DEBUG, unless we can make it  
>>>>>>>> configurable via system property substitution.  Otherwise all  
>>>>>>>> testsuite runs will log
>>>>>>>> at INFO unless we introduce testsuite hacks to replace the  
>>>>>>>> logging conf.
>>>>>>> IMO - I would like to see it at info, and use an ant command  
>>>>>>> to adjust the debug level for hudson builds.  Why punish our  
>>>>>>> users so that the continuous builds log enough.
>>>>>>
>>>>>> Log4j supports a basic system property substitution, so the  
>>>>>> server.log logging level can be controlled that way. I'll  
>>>>>> selfishly add that -- since it will help Bela in some stuff  
>>>>>> he's doing this week that in turn helps me. ;)
>>>>>>
>>>>>> https://jira.jboss.org/jira/browse/JBAS-6205
>>>>>>
>>>>>> Note that JBAS-6205 doesn't include changing the default to  
>>>>>> INFO. I think INFO's fine, but it's not my call and in any case  
>>>>>> it's a separate JIRA that involves some extra work (to get the  
>>>>>> testsuites to log at DEBUG).
>>>>>>
>>>>>>
>>>>>> -- 
>>>>>> Brian Stansberry
>>>>>> Lead, AS Clustering
>>>>>> JBoss, a division of Red Hat
>>>>>> brian.stansberry at redhat.com
>>>>>
>>>
>
>
> -- 
> Brian Stansberry
> Lead, AS Clustering
> JBoss, a division of Red Hat
> brian.stansberry at redhat.com

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.jboss.org/pipermail/jboss-development/attachments/20090105/40250c82/attachment.html 


More information about the jboss-development mailing list