13 Replies Latest reply on Aug 15, 2013 3:21 PM by N T

    JBoss 5.1 issue with trace level?

    alberto Gori Novice

      Why do I need to restart JBoss-5.1.0.GA to switch logging level to TRACE?
      For example I have to restart to switch to TRACE level for logger org.hibernate.type.

      I experienced the same problem in 4.2.2.GA version, and I hoped you solved because it's very annoying. Expecially if you think that newer JBossAS are quite slow at startup.

        • 1. Re: JBoss 5.1 issue with trace level?
          jaikiran pai Master

          How do you change the levels? You don't need a restart. You have to wait for around 60 seconds for the Log4j task to pickup these changes. More details about your issue will help in understanding what's going on.

          Furthermore, there's even a Log4jService Mbean which can be accessed from the jmx-console. This MBean provides a reconfigure() operation which you can use (instead of waiting for 60 seconds).

          • 2. Re: JBoss 5.1 issue with trace level?
            alberto Gori Novice

             

            "jaikiran" wrote:
            How do you change the levels? You don't need a restart. You have to wait for around 60 seconds for the Log4j task to pickup these changes. More details about your issue will help in understanding what's going on.


            I just edited the jboss-log4.xml file. After 60 seconds anything happen with TRACE level.
            It works with other logging levels.
            What is worse is that when logger is refreshed, jboss doesn't send anything to console. It did in 4.2.2.GA.

            "jaikiran" wrote:

            Furthermore, there's even a Log4jService Mbean which can be accessed from the jmx-console. This MBean provides a reconfigure() operation which you can use (instead of waiting for 60 seconds).


            I tried but again nothing happen with TRACE level.

            • 3. Re: JBoss 5.1 issue with trace level?
              jaikiran pai Master

              Please post your entire jboss-log4j.xml containing the TRACE level configurations. And when you say TRACE does not work, what exactly happens? You don't see TRACE level logs in server.log? I believe you are aware of the threshold that can be set for each appender in log4j. For server.log, by default its set to INFO, so you will have to set it to TRACE too.

              • 4. Re: JBoss 5.1 issue with trace level?
                alberto Gori Novice

                When I set TRACE I don't see the TRACE logs in server.log. If I restart JBoss I can see the TRACE logs, so my problem doesn't concern the threshold.

                This is my xml:

                <?xml version="1.0" encoding="UTF-8"?>
                <!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
                
                <!-- ===================================================================== -->
                <!-- -->
                <!-- Log4j Configuration -->
                <!-- -->
                <!-- ===================================================================== -->
                
                <!-- $Id: jboss-log4j.xml 87678 2009-04-22 16:47:08Z bstansberry@jboss.com $ -->
                
                <!--
                 | For more configuration information and examples see the Jakarta Log4j
                 | owebsite: http://jakarta.apache.org/log4j
                 -->
                
                <log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">
                
                 <!-- ================================= -->
                 <!-- Preserve messages in a local file -->
                 <!-- ================================= -->
                
                 <!-- A time/date based rolling appender -->
                 <appender name="FILE" class="org.jboss.logging.appender.DailyRollingFileAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                 <param name="File" value="${jboss.server.log.dir}/server.log"/>
                 <param name="Append" value="true"/>
                 <!-- In AS 5.0.x the server log threshold was set by a system
                 property. In 5.1 and later we are instead using the system
                 property to set the priority on the root logger (see <root/> below)
                 <param name="Threshold" value="${jboss.server.log.threshold}"/>
                 -->
                
                 <!-- Rollover at midnight each day -->
                 <param name="DatePattern" value="'.'yyyy-MM-dd"/>
                
                 <!-- Rollover at the top of each hour
                 <param name="DatePattern" value="'.'yyyy-MM-dd-HH"/>
                 -->
                
                 <layout class="org.apache.log4j.PatternLayout">
                 <!-- The default pattern: Date Priority [Category] (Thread) Message\n -->
                 <param name="ConversionPattern" value="%d %-5p [%c] (%t) %m%n"/>
                
                 <!-- The full pattern: Date MS Priority [Category] (Thread:NDC) Message\n
                 <param name="ConversionPattern" value="%d %-5r %-5p [%c] (%t:%x) %m%n"/>
                 -->
                 </layout>
                 </appender>
                
                 <!-- A size based file rolling appender
                 <appender name="FILE" class="org.jboss.logging.appender.RollingFileAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                 <param name="File" value="${jboss.server.log.dir}/server.log"/>
                 <param name="Append" value="false"/>
                 <param name="MaxFileSize" value="500KB"/>
                 <param name="MaxBackupIndex" value="1"/>
                
                 <layout class="org.apache.log4j.PatternLayout">
                 <param name="ConversionPattern" value="%d %-5p [%c] %m%n"/>
                 </layout>
                 </appender>
                 -->
                
                 <!-- ============================== -->
                 <!-- Append messages to the console -->
                 <!-- ============================== -->
                
                 <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                 <param name="Target" value="System.out"/>
                 <param name="Threshold" value="INFO"/>
                
                 <layout class="org.apache.log4j.PatternLayout">
                 <!-- The default pattern: Date Priority [Category] Message\n -->
                 <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p [%c{1}] %m%n"/>
                 </layout>
                 </appender>
                
                 <!-- ====================== -->
                 <!-- More Appender examples -->
                 <!-- ====================== -->
                
                 <!-- Buffer events and log them asynchronously
                 <appender name="ASYNC" class="org.apache.log4j.AsyncAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                 <appender-ref ref="FILE"/>
                 <appender-ref ref="CONSOLE"/>
                 <appender-ref ref="SMTP"/>
                 </appender>
                 -->
                
                 <!-- EMail events to an administrator
                 <appender name="SMTP" class="org.apache.log4j.net.SMTPAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                 <param name="Threshold" value="ERROR"/>
                 <param name="To" value="admin@myhost.domain.com"/>
                 <param name="From" value="nobody@myhost.domain.com"/>
                 <param name="Subject" value="JBoss Sever Errors"/>
                 <param name="SMTPHost" value="localhost"/>
                 <param name="BufferSize" value="10"/>
                 <layout class="org.apache.log4j.PatternLayout">
                 <param name="ConversionPattern" value="[%d{ABSOLUTE},%c{1}] %m%n"/>
                 </layout>
                 </appender>
                 -->
                
                 <!-- Syslog events
                 <appender name="SYSLOG" class="org.apache.log4j.net.SyslogAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                 <param name="Facility" value="LOCAL7"/>
                 <param name="FacilityPrinting" value="true"/>
                 <param name="SyslogHost" value="localhost"/>
                 <layout class="org.apache.log4j.PatternLayout">
                 <param name="ConversionPattern" value="[%d{ABSOLUTE},%c{1}] %m%n"/>
                 </layout>
                 </appender>
                 -->
                
                 <!-- Log events to JMS (requires a topic to be created)
                 <appender name="JMS" class="org.apache.log4j.net.JMSAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                 <param name="Threshold" value="ERROR"/>
                 <param name="TopicConnectionFactoryBindingName" value="java:/ConnectionFactory"/>
                 <param name="TopicBindingName" value="topic/MyErrorsTopic"/>
                 </appender>
                 -->
                
                 <!-- Log events through SNMP
                 <appender name="TRAP_LOG" class="org.apache.log4j.ext.SNMPTrapAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                 <param name="ImplementationClassName" value="org.apache.log4j.ext.JoeSNMPTrapSender"/>
                 <param name="ManagementHost" value="127.0.0.1"/>
                 <param name="ManagementHostTrapListenPort" value="162"/>
                 <param name="EnterpriseOID" value="1.3.6.1.4.1.24.0"/>
                 <param name="LocalIPAddress" value="127.0.0.1"/>
                 <param name="LocalTrapSendPort" value="161"/>
                 <param name="GenericTrapType" value="6"/>
                 <param name="SpecificTrapType" value="12345678"/>
                 <param name="CommunityString" value="public"/>
                 <param name="ForwardStackTraceWithTrap" value="true"/>
                 <param name="Threshold" value="DEBUG"/>
                 <param name="ApplicationTrapOID" value="1.3.6.1.4.1.24.12.10.22.64"/>
                 <layout class="org.apache.log4j.PatternLayout">
                 <param name="ConversionPattern" value="%d,%p,[%t],[%c],%m%n"/>
                 </layout>
                 </appender>
                 -->
                
                 <!-- Emit events as JMX notifications
                 <appender name="JMX" class="org.jboss.monitor.services.JMXNotificationAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                
                 <param name="Threshold" value="WARN"/>
                 <param name="ObjectName" value="jboss.system:service=Logging,type=JMXNotificationAppender"/>
                
                 <layout class="org.apache.log4j.PatternLayout">
                 <param name="ConversionPattern" value="%d %-5p [%c] %m"/>
                 </layout>
                 </appender>
                 -->
                
                 <!-- Security AUDIT Appender
                 <appender name="AUDIT" class="org.jboss.logging.appender.DailyRollingFileAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                 <param name="File" value="${jboss.server.log.dir}/audit.log"/>
                 <param name="Append" value="true"/>
                 <param name="DatePattern" value="'.'yyyy-MM-dd"/>
                 <layout class="org.apache.log4j.PatternLayout">
                 <param name="ConversionPattern" value="%d %-5p [%c] (%t:%x) %m%n"/>
                 </layout>
                 </appender>
                 -->
                
                 <!-- ================ -->
                 <!-- Limit categories -->
                 <!-- ================ -->
                
                 <!-- Limit the org.apache category to INFO as its DEBUG is verbose -->
                 <category name="org.apache">
                 <priority value="INFO"/>
                 </category>
                
                 <!-- Limit the jacorb category to WARN as its INFO is verbose -->
                 <category name="jacorb">
                 <priority value="WARN"/>
                 </category>
                
                 <!-- Set the logging level of the JSF implementation that uses
                 | java.util.logging. The jdk logging levels can be controlled
                 | through the org.jboss.logging.log4j.JDKLevel class that
                 | in addition to the standard log4j levels it adds support for
                 | SEVERE, WARNING, CONFIG, FINE, FINER, FINEST
                 -->
                 <category name="javax.enterprise.resource.webcontainer.jsf">
                 <priority value="INFO" class="org.jboss.logging.log4j.JDKLevel"/>
                 </category>
                
                 <!-- Limit the org.jgroups category to WARN as its INFO is verbose -->
                 <category name="org.jgroups">
                 <priority value="WARN"/>
                 </category>
                
                 <!-- Limit the org.quartz category to INFO as its DEBUG is verbose -->
                 <category name="org.quartz">
                 <priority value="INFO"/>
                 </category>
                
                 <!-- Limit the com.sun category to INFO as its FINE is verbose -->
                 <category name="com.sun">
                 <priority value="INFO"/>
                 </category>
                
                 <!-- Limit the sun category to INFO as its FINE is verbose -->
                 <category name="sun">
                 <priority value="INFO"/>
                 </category>
                
                 <!-- Limit the javax.xml.bind category to INFO as its FINE is verbose -->
                 <category name="javax.xml.bind">
                 <priority value="INFO"/>
                 </category>
                
                 <!-- Limit JBoss categories
                 <category name="org.jboss">
                 <priority value="INFO"/>
                 </category>
                 -->
                
                 <!-- Limit the JSR77 categories -->
                 <category name="org.jboss.management">
                 <priority value="INFO"/>
                 </category>
                
                 <!-- Limit the verbose facelets compiler -->
                 <category name="facelets.compiler">
                 <priority value="WARN"/>
                 </category>
                
                 <!-- Limit the verbose ajax4jsf cache initialization -->
                 <category name="org.ajax4jsf.cache">
                 <priority value="WARN"/>
                 </category>
                
                 <!-- Limit the verbose embedded jopr categories -->
                 <category name="org.rhq">
                 <priority value="WARN"/>
                 </category>
                
                 <!-- Limit the verbose seam categories -->
                 <category name="org.jboss.seam">
                 <priority value="WARN"/>
                 </category>
                
                 <!-- Show the evolution of the DataSource pool in the logs [inUse/Available/Max]
                 <category name="org.jboss.resource.connectionmanager.JBossManagedConnectionPool">
                 <priority value="TRACE"/>
                 </category>
                 -->
                
                 <!-- Category specifically for Security Audit Provider
                 <category name="org.jboss.security.audit.providers.LogAuditProvider" additivity="false">
                 <priority value="TRACE"/>
                 <appender-ref ref="AUDIT"/>
                 </category>
                 -->
                
                 <!-- Limit the org.jboss.serial (jboss-serialization) to INFO as its DEBUG is verbose -->
                 <category name="org.jboss.serial">
                 <priority value="INFO"/>
                 </category>
                
                 <!-- Decrease the priority threshold for the org.jboss.varia category
                 <category name="org.jboss.varia">
                 <priority value="DEBUG"/>
                 </category>
                 -->
                
                 <!-- Enable JBossWS message tracing
                 <category name="org.jboss.ws.core.MessageTrace">
                 <priority value="TRACE"/>
                 </category>
                 -->
                
                 <!--
                 | An example of enabling the custom TRACE level priority that is used
                 | by the JBoss internals to diagnose low level details. This example
                 | turns on TRACE level msgs for the org.jboss.ejb.plugins package and its
                 | subpackages. This will produce A LOT of logging output.
                 |
                 | Note: since jboss AS 4.2.x, the trace level is supported natively by
                 | log4j, so although the custom org.jboss.logging.XLevel priority will
                 | still work, there is no need to use it. The two examples that follow
                 | will both enable trace logging.
                 <category name="org.jboss.system">
                 <priority value="TRACE" class="org.jboss.logging.XLevel"/>
                 </category>
                 <category name="org.jboss.ejb.plugins">
                 <priority value="TRACE"/>
                 </category>
                 -->
                
                 <!--
                 | Logs these events to SNMP:
                 - server starts/stops
                 - cluster evolution (node death/startup)
                 - When an EJB archive is deployed (and associated verified messages)
                 - When an EAR archive is deployed
                
                 <category name="org.jboss.system.server.Server">
                 <priority value="INFO" />
                 <appender-ref ref="TRAP_LOG"/>
                 </category>
                
                 <category name="org.jboss.ha.framework.interfaces.HAPartition.lifecycle">
                 <priority value="INFO" />
                 <appender-ref ref="TRAP_LOG"/>
                 </category>
                
                 <category name="org.jboss.deployment.MainDeployer">
                 <priority value="ERROR" />
                 <appender-ref ref="TRAP_LOG"/>
                 </category>
                
                 <category name="org.jboss.ejb.EJBDeployer">
                 <priority value="INFO" />
                 <appender-ref ref="TRAP_LOG"/>
                 </category>
                
                 <category name="org.jboss.deployment.EARDeployer">
                 <priority value="INFO" />
                 <appender-ref ref="TRAP_LOG"/>
                 </category>
                 -->
                
                 <!-- Clustering logging -->
                 <!-- Uncomment the following to redirect the org.jgroups and
                 org.jboss.ha categories to a cluster.log file.
                
                 <appender name="CLUSTER" class="org.jboss.logging.appender.RollingFileAppender">
                 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
                 <param name="File" value="${jboss.server.log.dir}/cluster.log"/>
                 <param name="Append" value="false"/>
                 <param name="MaxFileSize" value="500KB"/>
                 <param name="MaxBackupIndex" value="1"/>
                
                 <layout class="org.apache.log4j.PatternLayout">
                 <param name="ConversionPattern" value="%d %-5p [%c] %m%n"/>
                 </layout>
                 </appender>
                 <category name="org.jgroups">
                 <priority value="DEBUG" />
                 <appender-ref ref="CLUSTER"/>
                 </category>
                 <category name="org.jboss.ha">
                 <priority value="DEBUG" />
                 <appender-ref ref="CLUSTER"/>
                 </category>
                 -->
                
                 <!-- per soffocare i log assurdi di jboss-5.1.0.GA-->
                 <category name="org.jboss.resource.connectionmanager.CachedConnectionManager">
                 <priority value="WARN"/>
                 </category>
                
                
                 <category name="org.jboss.ejb3.stateless.StatelessBeanContext">
                 <priority value="ERROR"/>
                 </category>
                
                 <category name="org.jboss.ejb3.interceptors.aop.InterceptorsFactory">
                 <priority value="ERROR"/>
                 </category>
                
                
                 <!--
                 ###########################################
                 ###########################################
                 impostazioni personali
                 ###########################################
                 ###########################################
                 -->
                 <category name="org.hibernate.SQL">
                 <priority value="DEBUG"/>
                 </category>
                 <category name="org.hibernate.type">
                 <priority value="INFO"/>
                 </category>
                 <category name="com.sia.shell.adapter.millennium.DbUtils">
                 <priority value="DEBUG" />
                 </category>
                
                
                
                 <!-- ======================= -->
                 <!-- Setup the Root category -->
                 <!-- ======================= -->
                
                 <root>
                 <!--
                 Set the root logger priority via a system property. Note this is parsed by log4j,
                 so the full JBoss system property format is not supported; e.g.
                 setting a default via ${jboss.server.log.threshold:WARN} will not work.
                 -->
                 <priority value="${jboss.server.log.threshold}"/>
                 <appender-ref ref="CONSOLE"/>
                 <appender-ref ref="FILE"/>
                 </root>
                
                </log4j:configuration>
                


                • 5. Re: JBoss 5.1 issue with trace level?
                  jaikiran pai Master

                   

                  What is worse is that when logger is refreshed, jboss doesn't send anything to console. It did in 4.2.2.GA.


                  https://jira.jboss.org/jira/browse/JBAS-6997

                  • 6. Re: JBoss 5.1 issue with trace level?
                    alberto Gori Novice

                     

                    "agori" wrote:

                     <category name="org.hibernate.type">
                     <priority value="INFO"/>
                     </category>
                    
                    


                    Sorry I quoted the wrong xml: in my experiments the priority was TRACE not INFO, obviously.

                    • 7. Re: JBoss 5.1 issue with trace level?
                      jaikiran pai Master

                      I am surprised that it works on a restart. It should not, because the default threshold level of server.log is INFO. So unless you change that, there no way the TRACE level logs (or even DEBUG) level logs are going to make it to the server.log

                      • 8. Re: JBoss 5.1 issue with trace level?
                        alberto Gori Novice

                         

                        "jaikiran" wrote:
                        I am surprised that it works on a restart. It should not, because the default threshold level of server.log is INFO. So unless you change that, there no way the TRACE level logs (or even DEBUG) level logs are going to make it to the server.log


                        AFAIK

                         <category name="org.hibernate.type">
                         <priority value="INFO"/>
                         </category>
                        


                        should override the default level. Every unspecified logger will use INFO leve, but not specified ones.

                        • 9. Re: JBoss 5.1 issue with trace level?
                          jaikiran pai Master

                          Yes, that's correct. That configuration is at logger/category level which controls what is sent to appenders. The appenders (like the FILE appender) themselves have a threshold which decides, what they "accept" and log. By default for the server.log it's set to INFO:

                          <root>
                           <!--
                           Set the root logger priority via a system property. Note this is parsed by log4j,
                           so the full JBoss system property format is not supported; e.g.
                           setting a default via ${jboss.server.log.threshold:WARN} will not work.
                           -->
                           <!--Jaikiran: By default this is INFO -->
                           <priority value="${jboss.server.log.threshold}"/>
                           <appender-ref ref="CONSOLE"/>
                           <appender-ref ref="FILE"/>
                          


                          Can you please post the TRACE level logs that you see in server.log on server restart? And you are not packaging any log4j configuration files in your application, are you?


                          • 10. Re: JBoss 5.1 issue with trace level?
                            alberto Gori Novice

                            Ok, but If you look at my config file I commented the threshold stuff in FILE appender.

                            Anyway that's part of my TRACE log (about Hibernate sql):

                            2009-06-03 15:11:20,101 WARNING [javax.enterprise.resource.webcontainer.jsf.config] (main) Unable to process deployment descriptor for context '/jmiljavaligu-jmil'
                            2009-06-03 15:11:20,101 INFO [javax.enterprise.resource.webcontainer.jsf.config] (main) Initializing Mojarra (1.2_12-b01-FCS) for context '/jmiljavaligu-jmil'
                            2009-06-03 15:11:20,163 INFO [org.jboss.web.tomcat.service.deployers.TomcatDeployment] (main) deploy, ctxPath=/jmiljavaligu
                            2009-06-03 15:11:20,804 DEBUG [org.hibernate.SQL] (main) select disco0_.ID as ID17_, disco0_.USERID as USERID17_, disco0_.DESCR as DESCR17_, disco0_.valoreint as valoreint17_, disco0_.VALORESTR as VALORESTR17_ from DISCO disco0_
                            2009-06-03 15:11:21,304 TRACE [org.hibernate.type.LongType] (main) returning '31' as column: ID17_
                            2009-06-03 15:11:21,304 TRACE [org.hibernate.type.LongType] (main) returning '0' as column: USERID17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.StringType] (main) returning null as column: DESCR17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.LongType] (main) returning '31' as column: ID17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.LongType] (main) returning '0' as column: USERID17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.IntegerType] (main) returning '0' as column: valoreint17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.StringType] (main) returning 'MSOFFICE' as column: VALORESTR17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.LongType] (main) returning '1517' as column: ID17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.LongType] (main) returning '0' as column: USERID17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.StringType] (main) returning 'Data per emissione' as column: DESCR17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.LongType] (main) returning '1517' as column: ID17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.LongType] (main) returning '0' as column: USERID17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.IntegerType] (main) returning '0' as column: valoreint17_
                            2009-06-03 15:11:21,319 TRACE [org.hibernate.type.StringType] (main) returning null as column: VALORESTR17_
                            ...
                            


                            • 11. Re: JBoss 5.1 issue with trace level?
                              alberto Gori Novice

                              I cleaned JBoss (undeployed everything and cleaned temp, data, ... folder) and now TRACE logger works as expected.

                              Sorry, I don't know what happened.
                              Thanks

                              • 12. Re: JBoss 5.1 issue with trace level?
                                Angus Morison Newbie

                                In some oldish code in JBoss Cache they set a global variable for tracing. This does not get changed when you change the logging level. So you have to restart.
                                I should think that is pretty rare now, but something to be aware of.

                                • 13. Re: JBoss 5.1 issue with trace level?
                                  N T Newbie

                                  Jaikiran,

                                   

                                  How about this thread to configure TRACE level logging, is this valid? if not can you explain where can we change the gloabl default logging to "TRACE" level...

                                   

                                  https://community.jboss.org/wiki/JBossMessagingUserEnablingTRACEloggingonserver