-
Bug
-
Resolution: Done
-
Major
-
fuse-esb-7.0.1
-
None
-
None
-
%
With a clean install of ESB 7.0.1.fuse-084 I issue the following commands
FuseESB:karaf@root> log:get ALL ROOT: INFO FuseESB:karaf@root> log:set DEBUG FuseESB:karaf@root> log:get
The log:get appears to hang indefinitely. I have also tried the command "osgi:list" after the "log:set DEBUG" and it appears to hang indefinitely also.
From the thread dump (attached) I can see the following threads are waiting on a lock owned by pool-org.ops4j.pax.logging.pax-logging-service-1.6.9-thread-2 that in turn appears to be waiting on a lock (7fb1fcf58). I cannot find that lock in the thread dump.
... "pool-org.ops4j.pax.logging.pax-logging-service-1.6.9-thread-2" prio=5 tid=7f89e33e4800 nid=0x110788000 waiting on condition [110786000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <7fb1fcf58> (a java.util.concurrent.FutureTask$Sync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:969) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1281) at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:218) at java.util.concurrent.FutureTask.get(FutureTask.java:83) at org.apache.felix.framework.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:223) at org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:321) at org.apache.felix.framework.Felix.getService(Felix.java:3607) at org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:468) at org.osgi.util.tracker.ServiceTracker.addingService(ServiceTracker.java:450) at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:980) at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:1) at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:262) at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:185) at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:348) at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:283) at org.ops4j.pax.logging.service.internal.PaxAppenderProxy.<init>(PaxAppenderProxy.java:38) at org.apache.log4j.PaxLoggingConfigurator.parseAppender(PaxLoggingConfigurator.java:71) at org.apache.log4j.PropertyConfigurator.parseCategory(PropertyConfigurator.java:735) at org.apache.log4j.PropertyConfigurator.configureRootCategory(PropertyConfigurator.java:615) - locked <7e09ee150> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:502) at org.apache.log4j.PaxLoggingConfigurator.doConfigure(PaxLoggingConfigurator.java:57) at org.ops4j.pax.logging.service.internal.PaxLoggingServiceImpl.updated(PaxLoggingServiceImpl.java:212) at org.ops4j.pax.logging.service.internal.PaxLoggingServiceImpl$1ManagedPaxLoggingService.updated(PaxLoggingServiceImpl.java:352) at org.apache.felix.cm.impl.ConfigurationManager$1.call(ConfigurationManager.java:1756) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:680) Locked ownable synchronizers: - <7fb1e2588> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) - <7e11c6790> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) .... "pool-org.apache.karaf.shell.log-2.2.5.fuse-70-084-thread-4" prio=5 tid=7f89e30a2000 nid=0x11088b000 waiting on condition [11088a000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <7e11c6790> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:941) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1261) at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:594) at org.ops4j.pax.logging.service.internal.PaxLoggerImpl.setDelegateContext(PaxLoggerImpl.java:104) at org.ops4j.pax.logging.service.internal.PaxLoggerImpl.debug(PaxLoggerImpl.java:134) at org.ops4j.pax.logging.internal.TrackingLogger.debug(TrackingLogger.java:81) at org.ops4j.pax.logging.slf4j.Slf4jLogger.debug(Slf4jLogger.java:301) at org.apache.aries.blueprint.container.ServiceRecipe.internalGetService(ServiceRecipe.java:244) at org.apache.aries.blueprint.container.ServiceRecipe.getService(ServiceRecipe.java:327) at org.apache.aries.blueprint.container.ServiceRecipe$TriggerServiceFactory.getService(ServiceRecipe.java:430) at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:325) at org.apache.felix.framework.ServiceRegistrationImpl.access$100(ServiceRegistrationImpl.java:46) at org.apache.felix.framework.ServiceRegistrationImpl$1.call(ServiceRegistrationImpl.java:234) at org.apache.felix.framework.Felix$6.call(Felix.java:2036) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:680) Locked ownable synchronizers: - <7fb80c188> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) ... "pool-org.apache.karaf.shell.log-2.2.5.fuse-70-084-thread-3" prio=5 tid=7f89e302c800 nid=0x10ed74000 waiting on condition [10ed73000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <7e11c6790> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:941) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1261) at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:594) at org.ops4j.pax.logging.service.internal.PaxLoggerImpl.setDelegateContext(PaxLoggerImpl.java:104) at org.ops4j.pax.logging.service.internal.PaxLoggerImpl.debug(PaxLoggerImpl.java:134) at org.ops4j.pax.logging.internal.TrackingLogger.debug(TrackingLogger.java:81) at org.ops4j.pax.logging.slf4j.Slf4jLogger.debug(Slf4jLogger.java:301) at org.apache.aries.blueprint.container.ServiceRecipe.internalGetService(ServiceRecipe.java:244) at org.apache.aries.blueprint.container.ServiceRecipe.getService(ServiceRecipe.java:327) at org.apache.aries.blueprint.container.ServiceRecipe$TriggerServiceFactory.getService(ServiceRecipe.java:430) at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:325) at org.apache.felix.framework.ServiceRegistrationImpl.access$100(ServiceRegistrationImpl.java:46) at org.apache.felix.framework.ServiceRegistrationImpl$1.call(ServiceRegistrationImpl.java:234) at org.apache.felix.framework.Felix$6.call(Felix.java:2036) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:680) Locked ownable synchronizers: - <7fa594ce8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) .... "ActiveMQ Journal Checkpoint Worker" daemon prio=5 tid=7f89d90cb800 nid=0x120ef5000 waiting on condition [120ef4000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <7e11c6790> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:941) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1261) at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:594) at org.ops4j.pax.logging.service.internal.PaxLoggerImpl.setDelegateContext(PaxLoggerImpl.java:104) at org.ops4j.pax.logging.service.internal.PaxLoggerImpl.debug(PaxLoggerImpl.java:134) at org.ops4j.pax.logging.internal.TrackingLogger.debug(TrackingLogger.java:81) at org.ops4j.pax.logging.slf4j.Slf4jLogger.debug(Slf4jLogger.java:262) at org.apache.activemq.store.kahadb.MessageDatabase.checkpointUpdate(MessageDatabase.java:1318) at org.apache.activemq.store.kahadb.MessageDatabase$10.execute(MessageDatabase.java:796) at org.apache.kahadb.page.Transaction.execute(Transaction.java:765) at org.apache.activemq.store.kahadb.MessageDatabase.checkpointCleanup(MessageDatabase.java:794) at org.apache.activemq.store.kahadb.MessageDatabase$3.run(MessageDatabase.java:317) Locked ownable synchronizers: - <7e1af7ae0> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) ... "fileinstall-/apps/fusebin/fuse-esb-7.0.1.fuse-084/etc" prio=5 tid=7f89d937c800 nid=0x10e562000 waiting on condition [10e561000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <7e11c6790> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:941) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1261) at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:594) at org.ops4j.pax.logging.service.internal.PaxLoggerImpl.setDelegateContext(PaxLoggerImpl.java:104) at org.ops4j.pax.logging.service.internal.PaxLoggerImpl.debug(PaxLoggerImpl.java:134) at org.ops4j.pax.logging.service.internal.PaxLoggingServiceImpl.log(PaxLoggingServiceImpl.java:169) at org.ops4j.pax.logging.service.internal.PaxLoggingServiceImpl.access$000(PaxLoggingServiceImpl.java:47) at org.ops4j.pax.logging.service.internal.PaxLoggingServiceImpl$1ManagedPaxLoggingService.log(PaxLoggingServiceImpl.java:336) at org.apache.felix.cm.impl.ConfigurationManager.log(ConfigurationManager.java:1017) at org.apache.felix.cm.impl.ConfigurationAdapter.getProperties(ConfigurationAdapter.java:136) at org.apache.felix.fileinstall.internal.ConfigInstaller.setConfig(ConfigInstaller.java:220) at org.apache.felix.fileinstall.internal.ConfigInstaller.update(ConfigInstaller.java:87) at org.apache.felix.fileinstall.internal.DirectoryWatcher.update(DirectoryWatcher.java:1057) at org.apache.felix.fileinstall.internal.DirectoryWatcher.update(DirectoryWatcher.java:859) at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:455) at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:273) Locked ownable synchronizers: - None
Notes:
- I have only seen to occur if the root logger is set to DEBUG. Setting other loggers to DEBUG did not seem to have an impact
- I could recover by killing the karaf process and restarting the instance - it seems to work normally. However if using "log:set DEUG" it seems to hang again.
