1 2 Previous Next 19 Replies Latest reply on Jan 10, 2002 9:21 PM by adrian.brock

    Logger Madness: speed

    marc.fleury

      Some more work is needed on making the loggers work as they should,

      the recommended way to do this now is to use
      if (log.isDebugEnabled())
      log.debug(bla bla bla) )

      so that bla bla bla doesn't get created each time (expensive string creation)

      the log.info() should really be at a minimum.

        • 1. Re: Logger Madness: speed

          Hi,

          Wrote a small service to analyse logging.

          https://sourceforge.net/tracker/index.php?func=detail&aid=496087&group_id=22866&atid=376687

          This involves a patch to org.jboss.logging.Logger

          This next bit should test the forums, I'm posting
          the html source, paste it into a file and use your
          favourite browser.

          Here is the output from running the testsuite up to
          the Web integration test (where it hangs)
          I had both appenders set to treshold WARN.

          <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">


          Java Dynamic Management View of analyse invocation



          <FONT SIZE=+3 COLOR=green>analyse SuccessfulThe operation [analyse] was successfully invoked for the MBean [JBOSS-SYSTEM:service=LogAnalysis].The operation returned with the value:
          <h1>Total Categories: 81</h1><h2>Messages by category and priority</h2>CategoryTotalTraceDebugInfoWarnErrorFatalOtherorg.jboss.resource.ConnectionFactoryLoader.ConnectionFactoryLoaderTestDS100244000org.jboss.resource.connectionmanager.jboss.MinervaSharedLocalCM30030000org.jboss.resource.security.ManyToOnePrincipalMapping.ConnectionFactoryLoaderTestDS10010000org.jboss.ejb.plugins.StatefulSessionFilePersistenceManager1401400000org.jboss.jetty.JettyService2702610000org.jboss.resource.JBossConnectionListenerImpl.JmsXA2202200000org.jboss.test.jmx.mbeanc.TestDeployerC1600160000org.jboss.mq.il.oil.OILServerILService208020800000org.jboss.jetty.Jetty2400231000org.jboss.ejb.plugins.local.BaseLocalContainerInvoker8708700000org.jboss.deployment.ServiceDeployer3100233740300org.jboss.mq.server.QueueManager#testObjectMessage30030000org.jboss.deployment.J2eeDeployer#Default1300231070000org.jboss.resource.ConnectionFactoryLoader.JmsXA60213000org.jboss.mq.server.ClientConsumer:ID6910001000org.jboss.system.ServiceConfigurator4904900000org.jboss.pool.PoolGCThread90900000org.jboss.ejb.plugins.jrmp.server.JRMPContainerInvoker464046200200org.jboss.pool.ObjectPool.ConnectionFactoryLoaderTestDS20200000org.jboss.resource.connectionmanager.BaseConnectionManager$SharedLocalConnectionListener511511000000org.jboss.mq.server.StateManager1801800000org.jboss.resource.ConnectionFactoryLoader.NoTransDS70412000org.jboss.test.jmx.mbeane.TestDeployerE40040000org.jboss.test.jmx.mbeana.TestDeployerA1200120000org.jboss.jetty.JBossUserRealm#JBossTest Servlets1700161000org.jboss.deployment.Installer65051014000org.jboss.mq.pm.file.PersistenceManager80800000org.jboss.resource.adapter.jdbc.local.JDBCManagedConnectionFactory.ConnectionFactoryLoaderTestDS20110000org.jboss.resource.security.ManyToOnePrincipalMapping.NoTransDS10010000org.jboss.web.WebServer2323000000org.jboss.ejb.ContainerFactory29901411580000org.jboss.resource.RARDeployer30030000org.jboss.test.jmx.mbeancrashtest.Test30030000org.jboss.pool.ObjectPool.JmsXA2202200000org.jboss.resource.security.ManyToOnePrincipalMapping.JmsXA10010000org.jboss.test.jmx.mbeanb.TestDeployerB1600160000org.jboss.resource.ConnectionFactoryLoader.DefaultDS70313000org.jboss.system.ServiceController4103303500org.jboss.ejb.plugins.jaws.bmp.CustomFindByEntitiesCommand60600000org.jboss.ejb.plugins.TxInterceptorBMT10000100org.jboss.ejb.plugins.LogInterceptor60000600org.jboss.resource.ConnectionFactoryLoader.DeployTestDS200488000org.jboss.resource.ConnectionFactoryLoader126060000org.jboss.ejb.StatefulSessionContainer2702200500org.jboss.resource.adapter.jdbc.local.JDBCManagedConnectionFactory.NoTransDS20110000org.jboss.resource.security.ManyToOnePrincipalMapping.DeployTestDS20020000org.jboss.mq.il.oil.OILClientIL207002070000org.jboss.ejb.plugins.jms.DLQHandler1400130100000org.jboss.ejb.plugins.jrmp13.server.JRMPContainerInvoker7707700000org.jboss.resource.security.ManyToOnePrincipalMapping.DefaultDS10010000org.jboss.ejb.MessageDrivenContainer3603600000org.jboss.mq.Connection10100000org.jboss.resource.JBossConnectionListenerImpl.DefaultDS15210152100000org.jboss.system.ServiceCreator5205200000org.jboss.ejb.plugins.jaws.metadata.JawsXmlFileLoader1601600000org.jboss.resource.connectionmanager.XAConnectionManager1100110000org.jboss.ejb.BeanLock20000200org.jboss.resource.adapter.jdbc.local.JDBCManagedConnectionFactory.DeployTestDS40220000org.jboss.ejb.StatelessSessionContainer623061400900org.jboss.logging.LogAnalysis10010000org.jboss.jetty.JBossWebApplicationContext#/jbosstest30210000org.jboss.resource.RARMetaData7106740000org.jboss.ejb.EntityContainer1550136001900org.jboss.mq.server.TopicManager#testDurableTopic30030000org.jboss.test.jmx.mbean.TestDeployer2800280000org.jboss.resource.JBossConnectionListenerImpl.ConnectionFactoryLoaderTestDS20200000org.jboss.jetty.JettyResolver40040000org.jboss.mq.server.JMSServer40200200org.jboss.ejb.plugins.EnterpriseContextCachePolicy208020710000org.jboss.mq.il.uil.UILServerILService3403400000org.jboss.management.j2ee.JNDI90000900org.jboss.test.jmx.mbeand.TestDeployerD40040000org.jboss.ejb.plugins.EntitySynchronizationInterceptor2120000100org.jboss.deployment.AutoDeployer35018815660000org.jboss.mq.server.MessageCache77067706000000org.jboss.pool.ObjectPool.DefaultDS10880108800000org.jboss.resource.adapter.jdbc.local.JDBCManagedConnectionFactory.DefaultDS20110000org.jboss.security.plugins.JaasSecurityManagerService$SecurityDomainObjectFactory30030000org.jboss.mq.server.ClientConsumer:ID110001000org.jboss.security.plugins.JaasSecurityManager.other10100000org.jboss.jms.ra.JmsManagedConnectionFactory.JmsXA20110000
          <TABLE WIDTH=100%>
          <TD ALIGN=LEFT>Back to MBean View
          <TD ALIGN=RIGHT>Back to Agent View




          Regards,
          Adrian

          • 2. Re: Logger Madness: speed
            marc.fleury

            Go ahead adrian, you have rw ?

            marcf

            • 3. Re: Logger Madness: speed

              Hi Marc,

              Not sure this should be added to core.

              There's an extra

              if (analysis != null)
              on every log request.

              Or doesn't that matter?

              Regards,
              Adrian

              • 4. Re: Logger Madness: speed

                Hi,

                I've added the service anyway. It can easily be removed.

                Regards,
                Adrian

                • 5. Re: Logger Madness: speed
                  marc.fleury

                  Adrian

                  I am not sure I understand what the "logger" analysis does. What I wanted was to check every debug log against "isDebugEnabled" and then remove almost all log.info from the runtime (it is ok during setup and deployment).

                  What does this do?

                  • 6. Re: Logger Madness: speed

                    Marc,

                    I can easily add that check to the the analysis code.

                    It would be hard to differentiate
                    the AutoDeployer from the MessageCache.

                    Perhaps I flag it and let a human filter the results?

                    Regards,
                    Adrian

                    • 7. Re: Logger Madness: speed

                      Ok,

                      I've added some code to double check a priority is
                      enabled.

                      The incorrect loggings are highlighted in red.

                      You can also specify analyse(false) to only
                      view incorrect loggings.

                      Add the following to log4j.properties to "disable"
                      everyting upto warnings.

                      # Only show WARN messages for org.jboss
                      log4j.category.org.jboss=WARN

                      This doesn't stop loggings to [Default], i.e.
                      System.out.println().

                      Regards,
                      Adrian

                      • 8. Re: Logger Madness: speed
                        sanders

                        I would be happy to start patching all of these if you would like :)


                        Scott Sanders
                        {Expert at going back through code to add (if log.isDebugEnabled()) ;-) }

                        • 9. Re: Logger Madness: speed

                          Hi,

                          Go ahead.

                          I was going to do the major ones between other stuff,
                          but feel free.

                          I think Marc wants to move some of the info messages
                          to debug.

                          Work on the big ones for now, e.g. MessageCache & TRACE

                          Regards,
                          Adrian

                          • 10. Re: Logger Madness: speed
                            sanders

                            I now have this ready (about 100 files changed), but it is getting stale fast. Should I post it to Sourceforge as one huge patch, or one patch per module, etc?

                            Scott

                            • 11. Re: Logger Madness: speed
                              sanders

                              After merging with the current cvs tree, I now have 110 files to change :)

                              • 12. Re: Logger Madness: speed

                                Hi,

                                Thanks for that.

                                If you post it as one big patch, I'll apply it to my
                                tree, check it and commit it :-)

                                Regards,
                                Adrian

                                • 13. Re: Logger Madness: speed
                                  sanders

                                  Done, patch 499624.

                                  Thanks,
                                  Scott Sanders

                                  • 14. Re: Logger Madness: speed

                                    Hi,

                                    It applied quite nicely. Just one source to change
                                    manually.

                                    I see you have an editor that likes to minimise white
                                    space as well :-)

                                    Now all I have to do is scan the patch for Trojans
                                    Only kidding :-)
                                    and run the testsuite.

                                    Regards,
                                    Adrian

                                    1 2 Previous Next