dev@glassfish.java.net

glassfish hang (blocking all upgrades)

From: Bobby Bissett <Robert.Bissett_at_Sun.COM>
Date: Mon, 09 Nov 2009 13:12:38 -0500

 This is new.... With revision 34100 gf is hanging during an upgrade. I'm starting the domain using a v2.1 domain with no apps deployed. The asadmin output is:

kamakawiwoole% ./bin/asadmin start-domain domain1
Domain needs to be upgraded before it can be started.
Attempting upgrade now...

...and that's it. The server log is simply:

Nov 9, 2009 12:50:35 PM com.sun.enterprise.admin.launcher.GFLauncherLogger info
INFO: JVM invocation command line:
/kauai/beach/jdk1.6.0_17/bin/java
-cp
/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/modules/glassfish.jar
-XX:MaxPermSize=192m
-XX:NewRatio=2
-Xmx512m
-client
-javaagent:/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/lib/monitor/btrace-agent.jar=unsafe=true,noServer=true
-Dsun.rmi.dgc.client.gcInterval=3600000
-Djdbc.drivers=org.apache.derby.jdbc.ClientDriver
-Djavax.net.ssl.keyStore=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1/config/keystore.jks
-Djava.security.policy=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1/config/server.policy
-Dsun.rmi.dgc.server.gcInterval=3600000
-Dcom.sun.aas.instanceRoot=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1
-Dcom.sun.enterprise.config.config_environment_factory_class=com.sun.enterprise.config.serverbeans.AppserverConfigEnvironmentFactory
-Djava.endorsed.dirs=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/lib/endorsed
-Dcom.sun.aas.installRoot=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish
-Djava.ext.dirs=/kauai/beach/jdk1.6.0_17/lib/ext:/kauai/beach/jdk1.6.0_17/jre/lib/ext:/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1/lib/ext:/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/javadb/lib
-Djavax.net.ssl.trustStore=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1/config/cacerts.jks
-Dcom.sun.enterprise.taglisteners=jsf-impl.jar
-Dcom.sun.enterprise.taglibs=appserv-jstl.jar,jsf-impl.jar
-Djava.security.auth.login.config=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1/config/login.conf
-Djava.library.path=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/lib:/kauai/beach/jdk1.6.0_17/jre/lib/sparc/server:/kauai/beach/jdk1.6.0_17/jre/lib/sparc:/kauai/beach/jdk1.6.0_17/lib/sparc:/usr/jdk/packages/lib/sparc:/usr/lib
com.sun.enterprise.glassfish.bootstrap.ASMain
-domainname
domain1
-asadmin-args
start-domain,,,domain1
-instancename
server
-verbose
false
-debug
false
-asadmin-classpath
/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/modules/admin-cli.jar
-asadmin-classname
com.sun.enterprise.admin.cli.AsadminMain
-upgrade
false
-domaindir
/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1
-read-stdin
true
Nov 9, 2009 12:50:38 PM com.sun.enterprise.admin.launcher.GFLauncherLogger info
INFO: JVM invocation command line:
/kauai/beach/jdk1.6.0_17/bin/java
-cp
/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/modules/glassfish.jar
-XX:MaxPermSize=192m
-XX:NewRatio=2
-Xmx512m
-client
-javaagent:/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/lib/monitor/btrace-agent.jar=unsafe=true,noServer=true
-Dsun.rmi.dgc.client.gcInterval=3600000
-Djdbc.drivers=org.apache.derby.jdbc.ClientDriver
-Djavax.net.ssl.keyStore=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1/config/keystore.jks
-Djava.security.policy=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1/config/server.policy
-Dsun.rmi.dgc.server.gcInterval=3600000
-Dcom.sun.aas.instanceRoot=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1
-Dcom.sun.enterprise.config.config_environment_factory_class=com.sun.enterprise.config.serverbeans.AppserverConfigEnvironmentFactory
-Djava.endorsed.dirs=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/lib/endorsed
-Dcom.sun.aas.installRoot=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish
-Djava.ext.dirs=/kauai/beach/jdk1.6.0_17/lib/ext:/kauai/beach/jdk1.6.0_17/jre/lib/ext:/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1/lib/ext:/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/javadb/lib
-Djavax.net.ssl.trustStore=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1/config/cacerts.jks
-Dcom.sun.enterprise.taglisteners=jsf-impl.jar
-Dcom.sun.enterprise.taglibs=appserv-jstl.jar,jsf-impl.jar
-Djava.security.auth.login.config=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1/config/login.conf
-Djava.library.path=/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/lib:/kauai/beach/jdk1.6.0_17/jre/lib/sparc/server:/kauai/beach/jdk1.6.0_17/jre/lib/sparc:/kauai/beach/jdk1.6.0_17/lib/sparc:/usr/jdk/packages/lib/sparc:/usr/lib
com.sun.enterprise.glassfish.bootstrap.ASMain
-domainname
domain1
-asadmin-args
start-domain,,,domain1
-instancename
server
-verbose
false
-debug
false
-asadmin-classpath
/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/modules/admin-cli.jar
-asadmin-classname
com.sun.enterprise.admin.cli.AsadminMain
-upgrade
true
-domaindir
/kauai/beach/ws/v3/distributions/glassfish/target/glassfishv3/glassfish/domains/domain1
-read-stdin
true
Nov 9, 2009 12:50:38 PM com.sun.enterprise.admin.launcher.GFLauncherLogger info
INFO: Successfully launched in 54 msec.

...and that's it. At the >10 minute mark, here are the thread dumps:

---begin asadmin dump---
kamakawiwoole% jstack 26553
2009-11-09 13:03:28
Full thread dump Java HotSpot(TM) Server VM (14.3-b01 mixed mode):

"Attach Listener" daemon prio=3 tid=0x00456c00 nid=0x12 waiting on condition [0x00000000]
   java.lang.Thread.State: RUNNABLE

"domain1-StderrDrainer" daemon prio=3 tid=0x00516000 nid=0x11 runnable [0xd6bff000]
   java.lang.Thread.State: RUNNABLE
at java.io.FileInputStream.readBytes(Native Method)
at java.io.FileInputStream.read(FileInputStream.java:199)
at java.lang.UNIXProcess$DeferredCloseInputStream.read(UNIXProcess.java:227)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
- locked <0xf15618e8> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(FilterInputStream.java:90)
at com.sun.enterprise.universal.process.ProcessStreamDrainerWorker.run(ProcessStreamDrainerWorker.java:69)
at java.lang.Thread.run(Thread.java:619)

"domain1-StdoutDrainer" daemon prio=3 tid=0x00515800 nid=0x10 runnable [0xd6cff000]
   java.lang.Thread.State: RUNNABLE
at java.io.FileInputStream.readBytes(Native Method)
at java.io.FileInputStream.read(FileInputStream.java:199)
at java.lang.UNIXProcess$DeferredCloseInputStream.read(UNIXProcess.java:227)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:256)
at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
- locked <0xf1555e98> (a java.io.BufferedInputStream)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
- locked <0xf155f608> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(FilterInputStream.java:90)
at com.sun.enterprise.universal.process.ProcessStreamDrainerWorker.run(ProcessStreamDrainerWorker.java:69)
at java.lang.Thread.run(Thread.java:619)

"process reaper" daemon prio=3 tid=0x009af400 nid=0xf runnable [0xd6dff000]
   java.lang.Thread.State: RUNNABLE
at java.lang.UNIXProcess.waitForProcessExit(Native Method)
at java.lang.UNIXProcess.access$900(UNIXProcess.java:17)
at java.lang.UNIXProcess$2$1.run(UNIXProcess.java:86)

"Low Memory Detector" daemon prio=3 tid=0x00100800 nid=0xb runnable [0x00000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread1" daemon prio=3 tid=0x000fe000 nid=0xa waiting on condition [0x00000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=3 tid=0x000fb000 nid=0x9 waiting on condition [0x00000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=3 tid=0x000f9800 nid=0x8 runnable [0x00000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=3 tid=0x000e8000 nid=0x7 in Object.wait() [0xd74ff000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xf1900298> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0xf1900298> (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=3 tid=0x000e3400 nid=0x6 in Object.wait() [0xd75ff000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xf1900320> (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 <0xf1900320> (a java.lang.ref.Reference$Lock)

"main" prio=3 tid=0x0002f400 nid=0x2 in Object.wait() [0xfefff000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xf1553b80> (a java.lang.UNIXProcess)
at java.lang.Object.wait(Object.java:485)
at java.lang.UNIXProcess.waitFor(UNIXProcess.java:115)
- locked <0xf1553b80> (a java.lang.UNIXProcess)
at com.sun.enterprise.admin.cli.StartDomainCommand.runCommandNotEmbedded(StartDomainCommand.java:168)
at com.sun.enterprise.admin.cli.StartDomainCommand.executeCommand(StartDomainCommand.java:117)
at com.sun.enterprise.admin.cli.CLICommand.execute(CLICommand.java:257)
at com.sun.enterprise.admin.cli.AsadminMain.executeCommand(AsadminMain.java:229)
at com.sun.enterprise.admin.cli.AsadminMain.main(AsadminMain.java:167)

"VM Thread" prio=3 tid=0x000df400 nid=0x5 runnable

"GC task thread#0 (ParallelGC)" prio=3 tid=0x00035800 nid=0x3 runnable

"GC task thread#1 (ParallelGC)" prio=3 tid=0x00036c00 nid=0x4 runnable

"VM Periodic Task Thread" prio=3 tid=0x00102400 nid=0xc waiting on condition

JNI global references: 877

---end asadmin dump---

---begin server dump---
kamakawiwoole% jstack 26556
2009-11-09 13:04:10
Full thread dump Java HotSpot(TM) Client VM (14.3-b01 mixed mode):

"Attach Listener" daemon prio=3 tid=0x00f94000 nid=0x15 waiting on condition [0x00000000]
   java.lang.Thread.State: RUNNABLE

"{}" daemon prio=3 tid=0x00f91800 nid=0x14 in Object.wait() [0xce2ff000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xd0037830> (a org.apache.felix.fileinstall.internal.DirectoryWatcher)
at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:210)
- locked <0xd0037830> (a org.apache.felix.fileinstall.internal.DirectoryWatcher)

"Configuration Updater" daemon prio=3 tid=0x00f8d000 nid=0x13 in Object.wait() [0xce3ff000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xd08b01c0> (a java.util.LinkedList)
at java.lang.Object.wait(Object.java:485)
at org.apache.felix.cm.impl.UpdateThread.run(UpdateThread.java:67)
- locked <0xd08b01c0> (a java.util.LinkedList)

"telnetconsole.Listener" daemon prio=3 tid=0x00f78000 nid=0x12 runnable [0xce4ff000]
   java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
- locked <0xd08b0250> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at org.apache.felix.shell.remote.Listener$Acceptor.run(Listener.java:137)
at java.lang.Thread.run(Thread.java:619)

"pool-4-thread-1" daemon prio=3 tid=0x0095a000 nid=0x11 waiting on condition [0xce5ff000]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0xdb688d58> (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.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
at org.jvnet.hk2.config.Transactions$Notifier$1.run(Transactions.java:157)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
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:619)

"pool-3-thread-1" daemon prio=3 tid=0x00953400 nid=0x10 waiting on condition [0xce6ff000]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0xdb663290> (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.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
at org.jvnet.hk2.config.Transactions$Notifier$1.run(Transactions.java:157)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
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:619)

"pool-2-thread-1" daemon prio=3 tid=0x00951800 nid=0xf waiting on condition [0xce7ff000]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0xdb663160> (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.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
at org.jvnet.hk2.config.Transactions$Notifier$1.run(Transactions.java:157)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
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:619)

"FelixPackageAdmin" daemon prio=3 tid=0x00484400 nid=0xd in Object.wait() [0xcf67f000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xdab2fc90> (a org.apache.felix.framework.PackageAdminImpl)
at java.lang.Object.wait(Object.java:485)
at org.apache.felix.framework.PackageAdminImpl.run(PackageAdminImpl.java:314)
- locked <0xdab2fc90> (a org.apache.felix.framework.PackageAdminImpl)
at java.lang.Thread.run(Thread.java:619)

"FelixStartLevel" daemon prio=3 tid=0x00487c00 nid=0xc in Object.wait() [0xcf77f000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xdab2fea8> (a java.util.ArrayList)
at java.lang.Object.wait(Object.java:485)
at org.apache.felix.framework.StartLevelImpl.run(StartLevelImpl.java:242)
- locked <0xdab2fea8> (a java.util.ArrayList)
at java.lang.Thread.run(Thread.java:619)

"FelixDispatchQueue" prio=3 tid=0x00486400 nid=0xb in Object.wait() [0xcf87f000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xdab02600> (a java.util.ArrayList)
at java.lang.Object.wait(Object.java:485)
at org.apache.felix.framework.util.EventDispatcher.run(EventDispatcher.java:931)
- locked <0xdab02600> (a java.util.ArrayList)
at org.apache.felix.framework.util.EventDispatcher.access$000(EventDispatcher.java:54)
at org.apache.felix.framework.util.EventDispatcher$1.run(EventDispatcher.java:106)
at java.lang.Thread.run(Thread.java:619)

"DestroyJavaVM" prio=3 tid=0x00032800 nid=0x2 waiting on condition [0x00000000]
   java.lang.Thread.State: RUNNABLE

"OSGi Framework Launcher" prio=3 tid=0x002bfc00 nid=0xa in Object.wait() [0xcf97e000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xdab03968> (a org.apache.felix.framework.util.ThreadGate)
at org.apache.felix.framework.util.ThreadGate.await(ThreadGate.java:79)
- locked <0xdab03968> (a org.apache.felix.framework.util.ThreadGate)
at org.apache.felix.framework.Felix.waitForStop(Felix.java:794)
at org.apache.felix.main.Main.main(Main.java:299)
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 com.sun.enterprise.glassfish.bootstrap.ASMainFelix$1.run(ASMainFelix.java:116)
at java.lang.Thread.run(Thread.java:619)

"Low Memory Detector" daemon prio=3 tid=0x00208c00 nid=0x8 runnable [0x00000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=3 tid=0x00202800 nid=0x7 waiting on condition [0x00000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=3 tid=0x000c8000 nid=0x6 runnable [0x00000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=3 tid=0x000b3000 nid=0x5 in Object.wait() [0xcfe7f000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xdaabb990> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0xdaabb990> (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=3 tid=0x000b1000 nid=0x4 in Object.wait() [0xcff7f000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0xdaabb7d0> (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 <0xdaabb7d0> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=3 tid=0x000ad400 nid=0x3 runnable

"VM Periodic Task Thread" prio=3 tid=0x0020bc00 nid=0x9 waiting on condition

JNI global references: 910
---end server dump---

I'm not in a good position to debug right now, but will look for more info. Any help?

Thanks,
Bobby