startup hangs 180s at 37%

View: New views

2 Messages — Rating Filter: Alert me

startup hangs 180s at 37%

by Juergen Weber :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

Hi,

my startup hangs 180s at 37%

2.2-SNAPSHOT
Build 2009.09.10-08:12:53.147-0400
Ubuntu 9.0.4 in VMWare Player

I took this thread dump:

[************** ] 37% 43s Starting org.apache.ger...2009-09-13 19:56:32
Full thread dump Java HotSpot(TM) Client VM (14.2-b01 mixed mode):

"TP-Monitor" daemon prio=10 tid=0x09a2c400 nid=0x10d8 in Object.wait() [0xac022000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae71a328> (a org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable)
at org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable.run(ThreadPool.java:565)
- locked <0xae71a328> (a org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable)
at java.lang.Thread.run(Thread.java:619)

"TP-Processor4" daemon prio=10 tid=0x08fbac00 nid=0x10d7 runnable [0xac073000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
- locked <0xae71a3d0> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at org.apache.jk.common.ChannelSocket.accept(ChannelSocket.java:307)
at org.apache.jk.common.ChannelSocket.acceptConnections(ChannelSocket.java:661)
at org.apache.jk.common.ChannelSocket$SocketAcceptor.runIt(ChannelSocket.java:872)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
at java.lang.Thread.run(Thread.java:619)

"TP-Processor3" daemon prio=10 tid=0x08fbf400 nid=0x10d6 in Object.wait() [0xac0c4000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae71a5e8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Object.wait(Object.java:485)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:662)
- locked <0xae71a5e8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Thread.run(Thread.java:619)

"TP-Processor2" daemon prio=10 tid=0x09634800 nid=0x10d5 in Object.wait() [0xac115000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae71a688> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Object.wait(Object.java:485)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:662)
- locked <0xae71a688> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Thread.run(Thread.java:619)

"TP-Processor1" daemon prio=10 tid=0x09633800 nid=0x10d4 in Object.wait() [0xac166000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae71a728> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Object.wait(Object.java:485)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:662)
- locked <0xae71a728> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Thread.run(Thread.java:619)

"http-8443-Acceptor-0" daemon prio=10 tid=0x09d74000 nid=0x10d3 runnable [0xac1b7000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
- locked <0xae6faa70> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at com.sun.net.ssl.internal.ssl.SSLServerSocketImpl.accept(SSLServerSocketImpl.java:259)
at org.apache.tomcat.util.net.jsse.JSSESocketFactory.acceptSocket(JSSESocketFactory.java:151)
at org.apache.tomcat.util.net.JIoEndpoint$Acceptor.run(JIoEndpoint.java:317)
at java.lang.Thread.run(Thread.java:619)

"http-8080-Acceptor-0" daemon prio=10 tid=0x09d70c00 nid=0x10d2 runnable [0xac208000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
- locked <0xae627ac0> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at org.apache.tomcat.util.net.DefaultServerSocketFactory.acceptSocket(DefaultServerSocketFactory.java:61)
at org.apache.tomcat.util.net.JIoEndpoint$Acceptor.run(JIoEndpoint.java:317)
at java.lang.Thread.run(Thread.java:619)

"ContainerBackgroundProcessor[StandardEngine[Catalina]]" daemon prio=10 tid=0x09d6bc00 nid=0x10d1 waiting on condition [0xac259000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1579)
at java.lang.Thread.run(Thread.java:619)

"MulticastDiscovery: Broadcaster" daemon prio=10 tid=0x09c96400 nid=0x10ce in Object.wait() [0xac347000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae29e380> (a java.util.TaskQueue)
at java.util.TimerThread.mainLoop(Timer.java:509)
- locked <0xae29e380> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:462)

"MulticastDiscovery: Listener" daemon prio=10 tid=0x09c94c00 nid=0x10cd runnable [0xac398000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainDatagramSocketImpl.receive0(Native Method)
- locked <0xae2a0448> (a java.net.PlainDatagramSocketImpl)
at java.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:136)
- locked <0xae2a0448> (a java.net.PlainDatagramSocketImpl)
at java.net.DatagramSocket.receive(DatagramSocket.java:712)
- locked <0xae2a0488> (a java.net.DatagramPacket)
- locked <0xae2a04a8> (a java.net.MulticastSocket)
at org.apache.openejb.server.discovery.MulticastDiscoveryAgent$Listener.run(MulticastDiscoveryAgent.java:338)
at java.lang.Thread.run(Thread.java:619)

"DiscoveryRegistry" daemon prio=10 tid=0x09c8d400 nid=0x10cc waiting on condition [0xac3e9000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0xae285770> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)

"Multicast Discovery Agent Notifier" daemon prio=10 tid=0x09c8ac00 nid=0x10cb waiting on condition [0xac43a000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0xae2a0600> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)

"service.null@17479295" daemon prio=10 tid=0x09c92000 nid=0x10ca runnable [0xac48b000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
- locked <0xae2a0760> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at org.apache.openejb.server.ServiceDaemon$SocketListener.run(ServiceDaemon.java:258)
at java.lang.Thread.run(Thread.java:619)

"KeepAliveTimer" daemon prio=10 tid=0x09c86400 nid=0x10c9 in Object.wait() [0xac4dc000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae27de48> (a java.util.TaskQueue)
at java.util.TimerThread.mainLoop(Timer.java:509)
- locked <0xae27de48> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:462)

"derby.rawStoreDaemon" daemon prio=10 tid=0x09893c00 nid=0x10c8 in Object.wait() [0xac5c2000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae0fbd98> (a org.apache.derby.impl.services.daemon.BasicDaemon)
at org.apache.derby.impl.services.daemon.BasicDaemon.rest(Unknown Source)
- locked <0xae0fbd98> (a org.apache.derby.impl.services.daemon.BasicDaemon)
at org.apache.derby.impl.services.daemon.BasicDaemon.run(Unknown Source)
at java.lang.Thread.run(Thread.java:619)

"Timer-4" daemon prio=10 tid=0x09ad6000 nid=0x10c5 in Object.wait() [0xac613000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae0d9268> (a java.util.TaskQueue)
at java.util.TimerThread.mainLoop(Timer.java:509)
- locked <0xae0d9268> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:462)

"NetworkServerThread_5" daemon prio=10 tid=0x0991ec00 nid=0x10c4 runnable [0xac664000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
- locked <0xae0c3850> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at org.apache.derby.impl.drda.ClientThread$1.run(Unknown Source)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.derby.impl.drda.ClientThread.run(Unknown Source)

"derby.NetworkServerStarter" daemon prio=10 tid=0x09917400 nid=0x10c3 in Object.wait() [0xac6b5000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae0c3aa0> (a java.lang.Object)
at java.lang.Object.wait(Object.java:485)
at org.apache.derby.impl.drda.NetworkServerControlImpl.blockingStart(Unknown Source)
- locked <0xae0c3aa0> (a java.lang.Object)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.derby.iapi.jdbc.DRDAServerStarter.run(Unknown Source)
at java.lang.Thread.run(Thread.java:619)

"Timer-3" daemon prio=10 tid=0x092b0400 nid=0x10c2 in Object.wait() [0xac706000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae09c6e8> (a java.util.TaskQueue)
at java.lang.Object.wait(Object.java:485)
at java.util.TimerThread.mainLoop(Timer.java:483)
- locked <0xae09c6e8> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:462)

"derby.antiGC" daemon prio=10 tid=0x09ac4400 nid=0x10c1 in Object.wait() [0xac757000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xae099270> (a org.apache.derby.impl.services.monitor.AntiGC)
at java.lang.Object.wait(Object.java:485)
at org.apache.derby.impl.services.monitor.AntiGC.run(Unknown Source)
- locked <0xae099270> (a org.apache.derby.impl.services.monitor.AntiGC)
at java.lang.Thread.run(Thread.java:619)

"FlushManager" daemon prio=10 tid=0x09914800 nid=0x10c0 waiting on condition [0xac7ea000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.objectweb.howl.log.LogBufferManager$FlushManager.run(LogBufferManager.java:1254)

"LogFileManager.EventManager" daemon prio=10 tid=0x0991a800 nid=0x10bf in Object.wait() [0xac83b000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xadf54ba8> (a java.lang.Object)
at java.lang.Object.wait(Object.java:485)
at org.objectweb.howl.log.LogFileManager$EventManager.run(LogFileManager.java:1260)
- locked <0xadf54ba8> (a java.lang.Object)

"RMI Scheduler(0)" daemon prio=10 tid=0x09344000 nid=0x10be waiting on condition [0xac99a000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0xadbd5348> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1963)
at java.util.concurrent.DelayQueue.take(DelayQueue.java:164)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:583)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:576)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)

"RMI TCP Connection(idle)" daemon prio=10 tid=0x09342800 nid=0x10bd waiting on condition [0xac9eb000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0xadbcf530> (a java.util.concurrent.SynchronousQueue$TransferStack)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)

"RMI RenewClean-[192.168.44.128:9999]" daemon prio=10 tid=0x0933e400 nid=0x10bc in Object.wait() [0xaca3c000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xadd5b388> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0xadd5b388> (a java.lang.ref.ReferenceQueue$Lock)
at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:516)
at java.lang.Thread.run(Thread.java:619)

"RMI TCP Connection(idle)" daemon prio=10 tid=0x0961b400 nid=0x10bb waiting on condition [0xaca8d000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0xadbcf530> (a java.util.concurrent.SynchronousQueue$TransferStack)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)

"GC Daemon" daemon prio=10 tid=0x09597000 nid=0x10ba in Object.wait() [0xacade000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xadd5d6c0> (a sun.misc.GC$LatencyLock)
at sun.misc.GC$Daemon.run(GC.java:100)
- locked <0xadd5d6c0> (a sun.misc.GC$LatencyLock)

"RMI Reaper" prio=10 tid=0x09594c00 nid=0x10b9 in Object.wait() [0xacb2f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xadbd0c00> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0xadbd0c00> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
at sun.rmi.transport.ObjectTable$Reaper.run(ObjectTable.java:333)
at java.lang.Thread.run(Thread.java:619)

"RMI TCP Accept-9999" daemon prio=10 tid=0x09617000 nid=0x10b8 runnable [0xacb80000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
- locked <0xadd5d7b0> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369)
at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
at java.lang.Thread.run(Thread.java:619)

"RMI TCP Accept-1099" daemon prio=10 tid=0x092ee000 nid=0x10b7 runnable [0xacd58000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
- locked <0xadbce6e8> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369)
at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
at java.lang.Thread.run(Thread.java:619)

"Progress Display Update Thread" daemon prio=10 tid=0x09324800 nid=0x10b6 waiting on condition [0xaccb6000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.apache.geronimo.system.main.SimpleProgressBarStartupMonitor$UpdateThread.run(SimpleProgressBarStartupMonitor.java:220)

"Timer-2" daemon prio=10 tid=0x092eb800 nid=0x10b5 in Object.wait() [0xacd07000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xadaa37b0> (a java.util.TaskQueue)
at java.util.TimerThread.mainLoop(Timer.java:509)
- locked <0xadaa37b0> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:462)

"Timer-0" daemon prio=10 tid=0x092ea400 nid=0x10b3 in Object.wait() [0xacda9000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xada8d920> (a java.util.TaskQueue)
at java.lang.Object.wait(Object.java:485)
at java.util.TimerThread.mainLoop(Timer.java:483)
- locked <0xada8d920> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:462)

"Low Memory Detector" daemon prio=10 tid=0x08f5e400 nid=0x10b1 runnable [0x00000000]
java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x08f5b400 nid=0x10b0 waiting on condition [0x00000000]
java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x08f13c00 nid=0x10af waiting on condition [0x00000000]
java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x08f03800 nid=0x10ae in Object.wait() [0xad0b6000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xad8f0360> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0xad8f0360> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x08efec00 nid=0x10ad in Object.wait() [0xad107000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xad8f03e8> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:485)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0xad8f03e8> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x08eab800 nid=0x10ab runnable [0xb7576000]
java.lang.Thread.State: RUNNABLE
at java.io.FileInputStream.readBytes(Native Method)
at java.io.FileInputStream.read(FileInputStream.java:199)
at sun.security.provider.NativePRNG$RandomIO.readFully(NativePRNG.java:185)
at sun.security.provider.NativePRNG$RandomIO.implGenerateSeed(NativePRNG.java:202)
- locked <0xad931778> (a java.lang.Object)
at sun.security.provider.NativePRNG$RandomIO.access$300(NativePRNG.java:108)
at sun.security.provider.NativePRNG.engineGenerateSeed(NativePRNG.java:102)
at java.security.SecureRandom.generateSeed(SecureRandom.java:495)
at com.sun.net.ssl.internal.pkcs12.PKCS12KeyStore.getSalt(PKCS12KeyStore.java:477)
at com.sun.net.ssl.internal.pkcs12.PKCS12KeyStore.calculateMac(PKCS12KeyStore.java:834)
at com.sun.net.ssl.internal.pkcs12.PKCS12KeyStore.engineStore(PKCS12KeyStore.java:788)
- locked <0xad5a0740> (a com.sun.net.ssl.internal.pkcs12.PKCS12KeyStore)
at java.security.KeyStore.store(KeyStore.java:1117)
at org.apache.geronimo.crypto.KeystoreUtil.<clinit>(KeystoreUtil.java:101)
at org.apache.geronimo.tomcat.TomcatManagerImpl.addSslConnectorAttributes(TomcatManagerImpl.java:459)
at org.apache.geronimo.tomcat.TomcatManagerImpl.<clinit>(TomcatManagerImpl.java:112)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at org.apache.xbean.recipe.ReflectionUtil$ConstructorFactory.create(ReflectionUtil.java:952)
at org.apache.xbean.recipe.ObjectRecipe.internalCreate(ObjectRecipe.java:276)
at org.apache.xbean.recipe.AbstractRecipe.create(AbstractRecipe.java:96)
at org.apache.xbean.recipe.AbstractRecipe.create(AbstractRecipe.java:61)
at org.apache.geronimo.gbean.runtime.GBeanInstance.createInstance(GBeanInstance.java:910)
at org.apache.geronimo.gbean.runtime.GBeanInstanceState.attemptFullStart(GBeanInstanceState.java:269)
at org.apache.geronimo.gbean.runtime.GBeanInstanceState.start(GBeanInstanceState.java:103)
at org.apache.geronimo.gbean.runtime.GBeanInstance.start(GBeanInstance.java:524)
at org.apache.geronimo.gbean.runtime.GBeanDependency.attemptFullStart(GBeanDependency.java:110)
- locked <0xae4de438> (a org.apache.geronimo.gbean.runtime.GBeanDependency)
at org.apache.geronimo.gbean.runtime.GBeanDependency.addTarget(GBeanDependency.java:145)
- locked <0xae4de438> (a org.apache.geronimo.gbean.runtime.GBeanDependency)
at org.apache.geronimo.gbean.runtime.GBeanDependency$1.running(GBeanDependency.java:119)
at org.apache.geronimo.kernel.basic.BasicLifecycleMonitor.fireRunningEvent(BasicLifecycleMonitor.java:175)
at org.apache.geronimo.kernel.basic.BasicLifecycleMonitor.access$300(BasicLifecycleMonitor.java:44)
at org.apache.geronimo.kernel.basic.BasicLifecycleMonitor$RawLifecycleBroadcaster.fireRunningEvent(BasicLifecycleMonitor.java:253)
at org.apache.geronimo.gbean.runtime.GBeanInstanceState.attemptFullStart(GBeanInstanceState.java:295)
at org.apache.geronimo.gbean.runtime.GBeanInstanceState.start(GBeanInstanceState.java:103)
at org.apache.geronimo.gbean.runtime.GBeanInstanceState.startRecursive(GBeanInstanceState.java:125)
at org.apache.geronimo.gbean.runtime.GBeanInstance.startRecursive(GBeanInstance.java:538)
at org.apache.geronimo.kernel.basic.BasicKernel.startRecursiveGBean(BasicKernel.java:377)
at org.apache.geronimo.kernel.config.ConfigurationUtil.startConfigurationGBeans(ConfigurationUtil.java:456)
at org.apache.geronimo.kernel.config.KernelConfigurationManager.start(KernelConfigurationManager.java:190)
at org.apache.geronimo.kernel.config.SimpleConfigurationManager.startConfiguration(SimpleConfigurationManager.java:546)
- locked <0xadaa44e0> (a org.apache.geronimo.kernel.config.EditableKernelConfigurationManager)
at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.geronimo.gbean.runtime.ReflectionMethodInvoker.invoke(ReflectionMethodInvoker.java:34)
at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:130)
at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:815)
at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
at org.apache.geronimo.gbean.GBeanLifecycle$$EnhancerByCGLIB$$579d13d0.startConfiguration(<generated>)
at org.apache.geronimo.system.main.EmbeddedDaemon.doStartup(EmbeddedDaemon.java:161)
at org.apache.geronimo.system.main.EmbeddedDaemon.execute(EmbeddedDaemon.java:78)
at org.apache.geronimo.kernel.util.MainConfigurationBootstrapper.main(MainConfigurationBootstrapper.java:45)
at org.apache.geronimo.cli.AbstractCLI.executeMain(AbstractCLI.java:65)
at org.apache.geronimo.cli.daemon.DaemonCLI.main(DaemonCLI.java:30)

"VM Thread" prio=10 tid=0x08efac00 nid=0x10ac runnable

"VM Periodic Task Thread" prio=10 tid=0x08f6a000 nid=0x10b2 waiting on condition

JNI global references: 860

Heap
def new generation total 1856K, used 795K [0xad400000, 0xad600000, 0xad8e0000)
eden space 1664K, 39% used [0xad400000, 0xad4a2fe8, 0xad5a0000)
from space 192K, 74% used [0xad5a0000, 0xad5c3ee0, 0xad5d0000)
to space 192K, 0% used [0xad5d0000, 0xad5d0000, 0xad600000)
tenured generation total 24244K, used 14759K [0xad8e0000, 0xaf08d000, 0xb1400000)
the space 24244K, 60% used [0xad8e0000, 0xae749f00, 0xae74a000, 0xaf08d000)
compacting perm gen total 30720K, used 30484K [0xb1400000, 0xb3200000, 0xb5400000)
the space 30720K, 99% used [0xb1400000, 0xb31c5010, 0xb31c5200, 0xb3200000)
No shared spaces configured.

[************************************** ] 97% 218s Starting org.apache.ger...2009-09-13 19:59:26,824 WARN [DTDEntityResolver] Deprecated public id in dwr.xml. Use: <!DOCTYPE dwr PUBLIC "-//GetAhead Limited//DTD Direct Web Remoting 3.0//EN" "http://getahead.org/dwr//dwr30.dtd">
[****************************************] 100% 221s Startup complete
Listening on Ports:
1050 192.168.44.128 CORBA Naming Service
1099 192.168.44.128 RMI Naming
1527 192.168.44.128 Derby Connector
2001 192.168.44.128 OpenEJB ORB Adapter
4201 192.168.44.128 OpenEJB Daemon
6882 192.168.44.128 OpenEJB ORB Adapter
8009 0.0.0.0 Tomcat Connector AJP TomcatAJPConnector
8080 0.0.0.0 Tomcat Connector HTTP BIO TomcatWebConnector
8443 0.0.0.0 Tomcat Connector HTTPS BIO TomcatWebSSLConnector
9999 192.168.44.128 JMX Remoting Connector

Re: startup hangs 180s at 37%

by kevan :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

On Sep 13, 2009, at 2:02 PM, Juergen Weber wrote:

>
> Hi,
>
> my startup hangs 180s at 37%
>
> 2.2-SNAPSHOT
> Build 2009.09.10-08:12:53.147-0400
> Ubuntu 9.0.4 in VMWare Player
>
> I took this thread dump:
>
> [************** ] 37% 43s Starting
> org.apache.ger...2009-09-13 19:56:32
>

<snip>

>
> "main" prio=10 tid=0x08eab800 nid=0x10ab runnable [0xb7576000]
> java.lang.Thread.State: RUNNABLE
> at java.io.FileInputStream.readBytes(Native Method)
> at java.io.FileInputStream.read(FileInputStream.java:199)
> at
> sun.security.provider.NativePRNG$RandomIO.readFully(NativePRNG.java:
> 185)
> at
> sun.security.provider.NativePRNG
> $RandomIO.implGenerateSeed(NativePRNG.java:202)
> - locked <0xad931778> (a java.lang.Object)
> at
> sun.security.provider.NativePRNG$RandomIO.access$300(NativePRNG.java:
> 108)
> at
> sun.security.provider.NativePRNG.engineGenerateSeed(NativePRNG.java:
> 102)
> at java.security.SecureRandom.generateSeed(SecureRandom.java:
> 495)
> at
> com
> .sun
> .net.ssl.internal.pkcs12.PKCS12KeyStore.getSalt(PKCS12KeyStore.java:
> 477)
> at
> com
> .sun
> .net
> .ssl.internal.pkcs12.PKCS12KeyStore.calculateMac(PKCS12KeyStore.java:
> 834)
> at
> com
> .sun
> .net
> .ssl.internal.pkcs12.PKCS12KeyStore.engineStore(PKCS12KeyStore.java:
> 788)
> - locked <0xad5a0740> (a
> com.sun.net.ssl.internal.pkcs12.PKCS12KeyStore)
> at java.security.KeyStore.store(KeyStore.java:1117)
> at
> org.apache.geronimo.crypto.KeystoreUtil.<clinit>(KeystoreUtil.java:
> 101)
> at
> org
> .apache
> .geronimo
> .tomcat
> .TomcatManagerImpl.addSslConnectorAttributes(TomcatManagerImpl.java:
> 459)
> at
> org
> .apache
> .geronimo.tomcat.TomcatManagerImpl.<clinit>(TomcatManagerImpl.java:
> 112)
> at
> sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
> Method)

<snip>

Hi Jurgen,
Your system is running low on entropy. The main thread is trying to
generate a random number and is reading from /dev/random to generate a
seed value. However, there's not enough external events for the system
to generate "random" data for /dev/random.

There's some discussion, here -- http://www.nabble.com/Startup-time-delay-in-Ubuntu-server-td21301711s134.html

Using /dev/urandom is likely to be your best bet, though it may affect
the quality (i.e. randomness) of your random number. I'm not an
expert. So, don't know how concerned you should be...

You may find these useful:

http://n0tablog.wordpress.com/2007/11/24/running-out-of-entropy-in-debian-etch/
http://whatan00b.com/slow-apache-starts-on-ubuntu
http://en.wikipedia.org/wiki/Urandom

--kevan
--kevan