[jboss-jira] [JBoss JIRA] Updated: (JBAS-8261) Finalizer and Timer-Log4jService threads deadlock

Bart Berger (JIRA) jira-events at lists.jboss.org
Fri Jul 30 16:28:49 EDT 2010


     [ https://jira.jboss.org/browse/JBAS-8261?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Bart Berger updated JBAS-8261:
------------------------------

    Steps to Reproduce: Don't know.  Seen only once so far.  User may have edited jboss-log4j.xml to cause the deadlock, but that is not confirmed.  The issue was not discovered until much later when the Finalizer queue grew large enough to consume all available memory.  (was: Don't know.  Seen only once so far.  Customer says jboss-log4j.xml was not modified, so possibly the deadlock occurred during system startup when jboss-log4j.xml was first read.  The issue was not discovered until days later when the Finalizer queue grew large enough to consume all available memory.)


> Finalizer and Timer-Log4jService threads deadlock
> -------------------------------------------------
>
>                 Key: JBAS-8261
>                 URL: https://jira.jboss.org/browse/JBAS-8261
>             Project: JBoss Application Server
>          Issue Type: Bug
>      Security Level: Public(Everyone can see) 
>          Components: Logging
>    Affects Versions: JBossAS-5.1.0.GA
>         Environment: OS: Linux (2.6.16.46-0.12-bigsmp)
> JVM: Java HotSpot(TM) Server VM (16.3-b01, mixed mode) (JRE 1.6.0_20)
>            Reporter: Bart Berger
>            Assignee: David Lloyd
>
> Encountered the following deadlock:
>   "Finalizer" daemon prio=8 tid=3 BLOCKED
> 	at org.jboss.logmanager.LoggerNode.getParentLogger(LoggerNode.java:142)
> 	   Local Variable: org.jboss.logmanager.LoggerNode#362
> 	at org.jboss.logmanager.LoggerInstance.getParent(LoggerInstance.java:167)
> 	at org.jboss.logmanager.LoggerInstance.setLevel(LoggerInstance.java:96)
> 	   Local Variable: java.util.logging.Level#2
> 	   Local Variable: org.jboss.logmanager.LogContext#1
> 	at org.jboss.logmanager.LoggerInstance.finalize(LoggerInstance.java:204)
> 	at java.lang.ref.Finalizer.$$YJP$$invokeFinalizeMethod(Native Method)
> 	at java.lang.ref.Finalizer.invokeFinalizeMethod(Finalizer.java)
> 	at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:83)
> 	   Local Variable: org.jboss.logmanager.LoggerInstance#161
> 	at java.lang.ref.Finalizer.access$100(Finalizer.java:14)
> 	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:160)
> 	   Local Variable: java.lang.ref.Finalizer#65597
>   "Timer-Log4jService" daemon prio=5 tid=25 WAITING
> 	at sun.misc.Unsafe.$$YJP$$park(Native Method)
> 	at sun.misc.Unsafe.park(Unsafe.java)
> 	   Local Variable: sun.misc.Unsafe#1
> 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> 	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:747)
> 	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:778)
> 	   Local Variable: java.util.concurrent.locks.AbstractQueuedSynchronizer$Node#629
> 	   Local Variable: java.util.concurrent.locks.AbstractQueuedSynchronizer$Node#630
> 	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1114)
> 	at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:186)
> 	   Local Variable: java.util.concurrent.locks.ReentrantLock$NonfairSync#89
> 	at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:262)
> 	   Local Variable: java.util.concurrent.locks.ReentrantLock#42
> 	at org.jboss.logmanager.LoggerInstance.setLevel(LoggerInstance.java:89)
> 	at org.jboss.logmanager.LoggerInstance.<init>(LoggerInstance.java:53)
> 	   Local Variable: org.jboss.logmanager.LoggerInstance#1049
> 	   Local Variable: java.lang.String#936666
> 	at org.jboss.logmanager.LoggerNode.getOrCreateLogger(LoggerNode.java:127)
> 	at org.jboss.logmanager.LogContext.getLogger(LogContext.java:71)
> 	at org.jboss.logmanager.LogManager.getLogger(LogManager.java:273)
> 	at java.util.logging.LogManager.demandLogger(LogManager.java:390)
> 	at java.util.logging.Logger.getLogger(Logger.java:274)
> 	   Local Variable: org.jboss.logmanager.LogManager#1
> 	at org.jboss.logbridge.LogBridgeHandler.updateLoggers(LogBridgeHandler.java:123)
> 	   Local Variable: java.util.Collections$SynchronizedMap#43
> 	   Local Variable: java.util.Vector$1#3
> 	   Local Variable: org.apache.log4j.spi.RootLogger#1
> 	   Local Variable: org.apache.log4j.Hierarchy#1
> 	   Local Variable: org.apache.log4j.Logger#375
> 	   Local Variable: java.lang.String#582052
> 	   Local Variable: org.jboss.logbridge.LevelMapper#1
> 	   Local Variable: org.jboss.logbridge.LogBridgeHandler#1
> 	at org.jboss.logbridge.LogNotificationListener.handleNotification(LogNotificationListener.java:67)
> 	at sun.reflect.GeneratedMethodAccessor203.invoke(<unknown string>)
> 	   Local Variable: sun.reflect.GeneratedMethodAccessor203#1
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> 	   Local Variable: sun.reflect.DelegatingMethodAccessorImpl#458
> 	at java.lang.reflect.Method.invoke(Method.java:597)
> 	   Local Variable: org.jboss.logbridge.LogNotificationListener#1
> 	at org.jboss.mx.notification.NotificationListenerProxy.invoke(NotificationListenerProxy.java:153)
> 	   Local Variable: java.lang.String#2851584
> 	   Local Variable: java.lang.Object[]#760535
> 	   Local Variable: org.jboss.mx.notification.NotificationListenerProxy#2
> 	   Local Variable: java.lang.reflect.Method#16042
> 	at $Proxy73.handleNotification(<unknown string>)
> 	at org.jboss.mx.util.JBossNotificationBroadcasterSupport.handleNotification(JBossNotificationBroadcasterSupport.java:127)
> 	   Local Variable: $Proxy73#1
> 	at org.jboss.mx.util.JBossNotificationBroadcasterSupport.sendNotification(JBossNotificationBroadcasterSupport.java:108)
> 	   Local Variable: org.jboss.mx.notification.DefaultListenerRegistration#3
> 	   Local Variable: org.jboss.mx.notification.ListenerRegistry$ListenerRegistrationIterator#1
> 	at org.jboss.logging.Log4jService.emitReconfigureNotification(Log4jService.java:560)
> 	   Local Variable: org.jboss.logging.Log4jService#1
> 	   Local Variable: javax.management.Notification#1
> 	at org.jboss.logging.Log4jService$URLWatchTimerTask.reconfigure(Log4jService.java:716)
> 	at org.jboss.logging.Log4jService$URLWatchTimerTask.run(Log4jService.java:636)
> 	   Local Variable: org.jboss.net.protocol.resource.ResourceURLConnection#1
> 	at java.util.TimerThread.mainLoop(Timer.java:512)
> 	   Local Variable: java.lang.Object#18446
> 	   Local Variable: org.jboss.logging.Log4jService$URLWatchTimerTask#1
> 	   Local Variable: java.util.TaskQueue#5
> 	at java.util.TimerThread.run(Timer.java:462)
> The timer thread ran logging configuration while the finalizer was processing LoggerInstance objects.
> The Finalizer thread calls context.levelTreeLock.lock() in LoggerInstance.setLevel(), then enters a synchronized code block in LoggerNode.getParentLogger().  The configuration thread enters a synchronized code block in LoggerNode.getOrCreateLogger(), then creates a new LoggerInstance which calls context.levelTreeLock.lock() in LoggerInstance.setLevel().

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        


More information about the jboss-jira mailing list