dev@glassfish.java.net

Re: Domain (domain1) did not respond in 90 seconds

From: Amy Roh <Amelia.Roh_at_Sun.COM>
Date: Tue, 24 Mar 2009 21:52:22 -0700

Kedar Mhaswade wrote:
> I suspect that it is not shutting down cleanly. When this happens,
> do you know if any java process (for server) are left behind. Can
> you get a stack dump in such a case?

The latest run seems to get stuck during startDomain and asadmin client
doesn't "gives up on server after 90 seconds" which caused the test to
hang for 7+ hours and I had to manually kill it. Here's what I have -
still need to find the root cause whether if it's a test or server issue.

startDomainUnix:
      [exec] 2009-03-24 21:42:10
      [exec] Full thread dump Java HotSpot(TM) Client VM (10.0-b22 mixed
mode):
      [exec]
      [exec] "domain1-StderrDrainer" daemon prio=10 tid=0xad3c1400
nid=0x198a runnable [0xad47e000..0xad47f040]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec] at java.io.FileInputStream.readBytes(Native Method)
      [exec] at java.io.FileInputStream.read(FileInputStream.java:199)
      [exec] at
java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
      [exec] at
java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
      [exec] at
java.io.BufferedInputStream.read(BufferedInputStream.java:317)
      [exec] - locked <0xae199350> (a java.io.BufferedInputStream)
      [exec] at java.io.FilterInputStream.read(FilterInputStream.java:90)
      [exec] at
com.sun.enterprise.universal.process.ProcessStreamDrainerWorker.run(ProcessStreamDrainerWorker.java:70)
      [exec] at java.lang.Thread.run(Thread.java:619)
      [exec]
      [exec] "domain1-StdoutDrainer" daemon prio=10 tid=0xad3c6400
nid=0x1989 runnable [0xad4cf000..0xad4cffc0]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec] at java.io.FileInputStream.readBytes(Native Method)
      [exec] at java.io.FileInputStream.read(FileInputStream.java:199)
      [exec] at
java.io.BufferedInputStream.read1(BufferedInputStream.java:256)
      [exec] at
java.io.BufferedInputStream.read(BufferedInputStream.java:317)
      [exec] - locked <0xae19c428> (a java.io.BufferedInputStream)
      [exec] at
java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
      [exec] at
java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
      [exec] at
java.io.BufferedInputStream.read(BufferedInputStream.java:317)
      [exec] - locked <0xae19c448> (a java.io.BufferedInputStream)
      [exec] at java.io.FilterInputStream.read(FilterInputStream.java:90)
      [exec] at
com.sun.enterprise.universal.process.ProcessStreamDrainerWorker.run(ProcessStreamDrainerWorker.java:70)
      [exec] at java.lang.Thread.run(Thread.java:619)
      [exec]
      [exec] "process reaper" daemon prio=10 tid=0xad3b4c00 nid=0x1987
runnable [0xad683000..0xad683f40]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec] at java.lang.UNIXProcess.waitForProcessExit(Native Method)
      [exec] at java.lang.UNIXProcess.access$900(UNIXProcess.java:20)
      [exec] at java.lang.UNIXProcess$1$1.run(UNIXProcess.java:132)
      [exec]
      [exec] "Low Memory Detector" daemon prio=10 tid=0x080c8800
nid=0x1985 runnable [0x00000000..0x00000000]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec]
      [exec] "CompilerThread0" daemon prio=10 tid=0x080bdc00 nid=0x1984
waiting on condition [0x00000000..0xad80e868]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec]
      [exec] "Signal Dispatcher" daemon prio=10 tid=0x080bc800
nid=0x1983 runnable [0x00000000..0x00000000]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec]
      [exec] "Finalizer" daemon prio=10 tid=0x080ac000 nid=0x1982 in
Object.wait() [0xad8ef000..0xad8f00c0]
      [exec] java.lang.Thread.State: WAITING (on object monitor)
      [exec] at java.lang.Object.wait(Native Method)
      [exec] - waiting on <0xae105230> (a
java.lang.ref.ReferenceQueue$Lock)
      [exec] at
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
      [exec] - locked <0xae105230> (a java.lang.ref.ReferenceQueue$Lock)
      [exec] at
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
      [exec] at
java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
      [exec]
      [exec] "Reference Handler" daemon prio=10 tid=0x080a7c00
nid=0x1981 in Object.wait() [0xad940000..0xad941040]
      [exec] java.lang.Thread.State: WAITING (on object monitor)
      [exec] at java.lang.Object.wait(Native Method)
      [exec] - waiting on <0xae1052b8> (a java.lang.ref.Reference$Lock)
      [exec] at java.lang.Object.wait(Object.java:485)
      [exec] at
java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
      [exec] - locked <0xae1052b8> (a java.lang.ref.Reference$Lock)
      [exec]
      [exec] "main" prio=10 tid=0x08058800 nid=0x197f runnable
[0xb7d58000..0xb7d59218]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec] at java.net.SocketInputStream.socketRead0(Native Method)
      [exec] at java.net.SocketInputStream.read(SocketInputStream.java:129)
      [exec] at
java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
      [exec] at
java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
      [exec] at
java.io.BufferedInputStream.read(BufferedInputStream.java:317)
      [exec] - locked <0xadc62040> (a java.io.BufferedInputStream)
      [exec] at
sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:687)
      [exec] at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:632)
      [exec] at
sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1000)
      [exec] - locked <0xadc45008> (a
sun.net.www.protocol.http.HttpURLConnection)
      [exec] at
com.sun.enterprise.admin.cli.remote.CLIRemoteCommand.runCommand(CLIRemoteCommand.java:160)
      [exec] at
com.sun.enterprise.admin.cli.remote.CommandInvoker.invoke(CommandInvoker.java:57)
      [exec] at
com.sun.enterprise.admin.cli.remote.CLIRemoteCommand.pingDAS(CLIRemoteCommand.java:438)
      [exec] at
com.sun.enterprise.admin.cli.remote.CLIRemoteCommand.pingDASQuietly(CLIRemoteCommand.java:488)
      [exec] at
com.sun.enterprise.admin.cli.StartDomainCommand.isServerAlive(StartDomainCommand.java:134)
      [exec] at
com.sun.enterprise.admin.cli.StartDomainCommand.waitForDAS(StartDomainCommand.java:104)
      [exec] at
com.sun.enterprise.admin.cli.StartDomainCommand.runCommand(StartDomainCommand.java:74)
      [exec] at
com.sun.enterprise.cli.framework.CLIMain.invokeCommand(CLIMain.java:160)
      [exec] at
com.sun.enterprise.admin.cli.AsadminMain.local(AsadminMain.java:124)
      [exec] at
com.sun.enterprise.admin.cli.AsadminMain.main(AsadminMain.java:60)
      [exec]
      [exec] "VM Thread" prio=10 tid=0x080a4800 nid=0x1980 runnable
      [exec]
      [exec] "VM Periodic Task Thread" prio=10 tid=0x080ca000 nid=0x1986
waiting on condition
      [exec]
      [exec] JNI global references: 705
      [exec]
      [exec] Heap
      [exec] def new generation total 960K, used 412K [0xadc00000,
0xadd00000, 0xae0e0000)
      [exec] eden space 896K, 44% used [0xadc00000, 0xadc64530,
0xadce0000)
      [exec] from space 64K, 17% used [0xadcf0000, 0xadcf2d80,
0xadd00000)
      [exec] to space 64K, 0% used [0xadce0000, 0xadce0000,
0xadcf0000)
      [exec] tenured generation total 4096K, used 783K [0xae0e0000,
0xae4e0000, 0xb1c00000)
      [exec] the space 4096K, 19% used [0xae0e0000, 0xae1a3d60,
0xae1a3e00, 0xae4e0000)
      [exec] compacting perm gen total 12288K, used 5944K [0xb1c00000,
0xb2800000, 0xb5c00000)
      [exec] the space 12288K, 48% used [0xb1c00000, 0xb21ce358,
0xb21ce400, 0xb2800000)
      [exec] No shared spaces configured.
      [exec]
      [exec] 2009-03-24 21:43:48
      [exec] Full thread dump Java HotSpot(TM) Client VM (10.0-b22 mixed
mode):
      [exec]
      [exec] "domain1-StderrDrainer" daemon prio=10 tid=0xad3c1400
nid=0x198a runnable [0xad47e000..0xad47f040]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec] at java.io.FileInputStream.readBytes(Native Method)
      [exec] at java.io.FileInputStream.read(FileInputStream.java:199)
      [exec] at
java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
      [exec] at
java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
      [exec] at
java.io.BufferedInputStream.read(BufferedInputStream.java:317)
      [exec] - locked <0xae199350> (a java.io.BufferedInputStream)
      [exec] at java.io.FilterInputStream.read(FilterInputStream.java:90)
      [exec] at
com.sun.enterprise.universal.process.ProcessStreamDrainerWorker.run(ProcessStreamDrainerWorker.java:70)
      [exec] at java.lang.Thread.run(Thread.java:619)
      [exec]
      [exec] "domain1-StdoutDrainer" daemon prio=10 tid=0xad3c6400
nid=0x1989 runnable [0xad4cf000..0xad4cffc0]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec] at java.io.FileInputStream.readBytes(Native Method)
      [exec] at java.io.FileInputStream.read(FileInputStream.java:199)
      [exec] at
java.io.BufferedInputStream.read1(BufferedInputStream.java:256)
      [exec] at
java.io.BufferedInputStream.read(BufferedInputStream.java:317)
      [exec] - locked <0xae19c428> (a java.io.BufferedInputStream)
      [exec] at
java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
      [exec] at
java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
      [exec] at
java.io.BufferedInputStream.read(BufferedInputStream.java:317)
      [exec] - locked <0xae19c448> (a java.io.BufferedInputStream)
      [exec] at java.io.FilterInputStream.read(FilterInputStream.java:90)
      [exec] at
com.sun.enterprise.universal.process.ProcessStreamDrainerWorker.run(ProcessStreamDrainerWorker.java:70)
      [exec] at java.lang.Thread.run(Thread.java:619)
      [exec]
      [exec] "process reaper" daemon prio=10 tid=0xad3b4c00 nid=0x1987
runnable [0xad683000..0xad683f40]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec] at java.lang.UNIXProcess.waitForProcessExit(Native Method)
      [exec] at java.lang.UNIXProcess.access$900(UNIXProcess.java:20)
      [exec] at java.lang.UNIXProcess$1$1.run(UNIXProcess.java:132)
      [exec]
      [exec] "Low Memory Detector" daemon prio=10 tid=0x080c8800
nid=0x1985 runnable [0x00000000..0x00000000]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec]
      [exec] "CompilerThread0" daemon prio=10 tid=0x080bdc00 nid=0x1984
waiting on condition [0x00000000..0xad80e868]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec]
      [exec] "Signal Dispatcher" daemon prio=10 tid=0x080bc800
nid=0x1983 runnable [0x00000000..0x00000000]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec]
      [exec] "Finalizer" daemon prio=10 tid=0x080ac000 nid=0x1982 in
Object.wait() [0xad8ef000..0xad8f00c0]
      [exec] java.lang.Thread.State: WAITING (on object monitor)
      [exec] at java.lang.Object.wait(Native Method)
      [exec] - waiting on <0xae105230> (a
java.lang.ref.ReferenceQueue$Lock)
      [exec] at
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
      [exec] - locked <0xae105230> (a java.lang.ref.ReferenceQueue$Lock)
      [exec] at
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
      [exec] at
java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
      [exec]
      [exec] "Reference Handler" daemon prio=10 tid=0x080a7c00
nid=0x1981 in Object.wait() [0xad940000..0xad941040]
      [exec] java.lang.Thread.State: WAITING (on object monitor)
      [exec] at java.lang.Object.wait(Native Method)
      [exec] - waiting on <0xae1052b8> (a java.lang.ref.Reference$Lock)
      [exec] at java.lang.Object.wait(Object.java:485)
      [exec] at
java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
      [exec] - locked <0xae1052b8> (a java.lang.ref.Reference$Lock)
      [exec]
      [exec] "main" prio=10 tid=0x08058800 nid=0x197f runnable
[0xb7d58000..0xb7d59218]
      [exec] java.lang.Thread.State: RUNNABLE
      [exec] at java.net.SocketInputStream.socketRead0(Native Method)
      [exec] at java.net.SocketInputStream.read(SocketInputStream.java:129)
      [exec] at
java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
      [exec] at
java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
      [exec] at
java.io.BufferedInputStream.read(BufferedInputStream.java:317)
      [exec] - locked <0xadc62040> (a java.io.BufferedInputStream)
      [exec] at
sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:687)
      [exec] at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:632)
      [exec] at
sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1000)
      [exec] - locked <0xadc45008> (a
sun.net.www.protocol.http.HttpURLConnection)
      [exec] at
com.sun.enterprise.admin.cli.remote.CLIRemoteCommand.runCommand(CLIRemoteCommand.java:160)
      [exec] at
com.sun.enterprise.admin.cli.remote.CommandInvoker.invoke(CommandInvoker.java:57)
      [exec] at
com.sun.enterprise.admin.cli.remote.CLIRemoteCommand.pingDAS(CLIRemoteCommand.java:438)
      [exec] at
com.sun.enterprise.admin.cli.remote.CLIRemoteCommand.pingDASQuietly(CLIRemoteCommand.java:488)
      [exec] at
com.sun.enterprise.admin.cli.StartDomainCommand.isServerAlive(StartDomainCommand.java:134)
      [exec] at
com.sun.enterprise.admin.cli.StartDomainCommand.waitForDAS(StartDomainCommand.java:104)
      [exec] at
com.sun.enterprise.admin.cli.StartDomainCommand.runCommand(StartDomainCommand.java:74)
      [exec] at
com.sun.enterprise.cli.framework.CLIMain.invokeCommand(CLIMain.java:160)
      [exec] at
com.sun.enterprise.admin.cli.AsadminMain.local(AsadminMain.java:124)
      [exec] at
com.sun.enterprise.admin.cli.AsadminMain.main(AsadminMain.java:60)
      [exec]
      [exec] "VM Thread" prio=10 tid=0x080a4800 nid=0x1980 runnable
      [exec]
      [exec] "VM Periodic Task Thread" prio=10 tid=0x080ca000 nid=0x1986
waiting on condition
      [exec]
      [exec] JNI global references: 707
      [exec]
      [exec] Heap
      [exec] def new generation total 960K, used 412K [0xadc00000,
0xadd00000, 0xae0e0000)
      [exec] eden space 896K, 44% used [0xadc00000, 0xadc64530,
0xadce0000)
      [exec] from space 64K, 17% used [0xadcf0000, 0xadcf2d80,
0xadd00000)
      [exec] to space 64K, 0% used [0xadce0000, 0xadce0000,
0xadcf0000)
      [exec] tenured generation total 4096K, used 783K [0xae0e0000,
0xae4e0000, 0xb1c00000)
      [exec] the space 4096K, 19% used [0xae0e0000, 0xae1a3d60,
0xae1a3e00, 0xae4e0000)
      [exec] compacting perm gen total 12288K, used 5944K [0xb1c00000,
0xb2800000, 0xb5c00000)
      [exec] the space 12288K, 48% used [0xb1c00000, 0xb21ce378,
0xb21ce400, 0xb2800000)
      [exec] No shared spaces configured.
      [exec]

Amy

> We can make asadmin wait longer before it bails out, but that's
> not the root cause. Also, note that server might be continuing to come up
> or already has gone down. It's just that asadmin client "gives up"
> on server after 90 seconds.
>
> -Kedar
>
>
> Amy Roh wrote:
>> The web devtests start/stop the server numerous times during its test
>> suite execution and I've been noticing (for a while now) that the
>> server does not respond between its runs occasionally. I can
>> reproduce it in the latest workspace also and was wondering if anyone
>> else is seeing this problem. Nothing in the server.log for more info.
>>
>> startDomainUnix:
>> [exec] Domain (domain1) did not respond in 90 seconds. It means
>> it is still coming up
>> [exec] or it has failed to come up. Check server.log for details.
>>
>> Amy
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
>> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>