Uploaded image for project: 'Application Server 3 4 5 and 6'
  1. Application Server 3 4 5 and 6
  2. JBAS-9537

AsyncAppender and URLWatchTimerTask deadlock

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Major Major
    • None
    • JBossAS-4.2.1.GA
    • Logging
    • None
    • Hide

      Not easy, but best chances are to set priority to 'TRACE' and force reconfiguration to happen often.

      Modify jboss-log4j.xml to 'TRACE' for 'org.jboss.logging'.

      We want URLWatchTimerTask to check for configuration often so set 'RefreshPeriod' to 5 for Log4JService mbean.

      We also want URLWatchTimerTask to repeat configuration - JBoss 4.2.1 will compare the timestamp of jboss-log4j.xml to system time then notes system time as the last reconfigure time. If we set the modification time of jboss-log4j.xml to a time/date in the future then JBoss will reconfigure logging every RefreshPeriod. I've been using touch -t 201510211629 jboss-log4j.xml to set the timestamp and wait for Marty McFly and Doc Brown.

      Start JBoss and wait.

      Show
      Not easy, but best chances are to set priority to 'TRACE' and force reconfiguration to happen often. Modify jboss-log4j.xml to 'TRACE' for 'org.jboss.logging'. We want URLWatchTimerTask to check for configuration often so set 'RefreshPeriod' to 5 for Log4JService mbean. We also want URLWatchTimerTask to repeat configuration - JBoss 4.2.1 will compare the timestamp of jboss-log4j.xml to system time then notes system time as the last reconfigure time. If we set the modification time of jboss-log4j.xml to a time/date in the future then JBoss will reconfigure logging every RefreshPeriod. I've been using touch -t 201510211629 jboss-log4j.xml to set the timestamp and wait for Marty McFly and Doc Brown. Start JBoss and wait.

      Logging stops if AsyncAppender's buffer is full and logging is reconfigured.

      Example: I want to get detailed logs of something so I modify jboss-log4j.xml and change priority of some category to DEBUG. I tail the log file and it stops. Stackdump reveals the following:

      "Timer-0" daemon prio=10 tid=0x000000001c956000 nid=0x8b1 in Object.wait() [0x00002ae22e8c0000]
      java.lang.Thread.State: WAITING (on object monitor)
      at java.lang.Object.wait(Native Method)
      at java.lang.Thread.join(Unknown Source)

      • locked <0x0000000096a71230> (a java.lang.Thread)
        at java.lang.Thread.join(Unknown Source)
        at org.apache.log4j.AsyncAppender.close(AsyncAppender.java:240)
        at org.apache.log4j.helpers.AppenderAttachableImpl.removeAllAppenders(AppenderAttachableImpl.java:140)
        at org.apache.log4j.Category.removeAllAppenders(Category.java:868)
      • locked <0x00000000c850b4e0> (a org.apache.log4j.spi.RootLogger)
        at org.apache.log4j.xml.DOMConfigurator.parseChildrenOfLoggerElement(DOMConfigurator.java:410)
        at org.apache.log4j.xml.DOMConfigurator.parseRoot(DOMConfigurator.java:394)
      • locked <0x00000000c850b4e0> (a org.apache.log4j.spi.RootLogger)
        at org.apache.log4j.xml.DOMConfigurator.parse(DOMConfigurator.java:829)
        at org.apache.log4j.xml.DOMConfigurator.doConfigure(DOMConfigurator.java:712)
        at org.apache.log4j.xml.DOMConfigurator.doConfigure(DOMConfigurator.java:618)
        at org.apache.log4j.xml.DOMConfigurator.configure(DOMConfigurator.java:743)
        at org.jboss.logging.Log4jService$URLWatchTimerTask.reconfigure(Log4jService.java:643)
        at org.jboss.logging.Log4jService$URLWatchTimerTask.run(Log4jService.java:582)
        at java.util.TimerThread.mainLoop(Unknown Source)
        at java.util.TimerThread.run(Unknown Source)

              Unassigned Unassigned
              teddy_lizard Theodore Lizard (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Created:
                Updated: