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

[Brian Stansberry]

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'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. :-)

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