tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Adam Hardy <adam....@cyberspaceroad.com>
Subject Re: Long freeze during tomcat start
Date Thu, 22 May 2008 16:29:39 GMT
Tell you the truth, I can only assume IPv6 stuff is configured to the debian 
etch defaults - although that might have changed between the date I installed 
the no-pause-box and the date I installed the problem box.

no-pause-box:
eth0      Link encap:Ethernet  HWaddr 00:10:DC:79:FF:8F
           inet addr:192.168.0.234  Bcast:192.168.0.255  Mask:255.255.255.0
           inet6 addr: fe80::210:dcff:fe79:ff8f/64 Scope:Link
           UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
           RX packets:606692 errors:0 dropped:0 overruns:0 frame:0
           TX packets:598681 errors:0 dropped:0 overruns:0 carrier:0
           collisions:65 txqueuelen:1000
           RX bytes:145074456 (138.3 MiB)  TX bytes:44751878 (42.6 MiB)

lo        Link encap:Local Loopback
           inet addr:127.0.0.1  Mask:255.0.0.0
           inet6 addr: ::1/128 Scope:Host
           UP LOOPBACK RUNNING  MTU:16436  Metric:1
           RX packets:59645 errors:0 dropped:0 overruns:0 frame:0
           TX packets:59645 errors:0 dropped:0 overruns:0 carrier:0
           collisions:0 txqueuelen:0
           RX bytes:5125125 (4.8 MiB)  TX bytes:5125125 (4.8 MiB)

box-with-pause (eth1 is LAN, eth2 is internet):
eth1      Link encap:Ethernet  HWaddr 00:18:F3:98:F4:EC
           inet addr:192.168.0.2  Bcast:192.168.0.255  Mask:255.255.255.0
           inet6 addr: fe80::218:f3ff:fe98:f4ec/64 Scope:Link
           UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
           RX packets:134101 errors:0 dropped:0 overruns:0 frame:0
           TX packets:138909 errors:0 dropped:0 overruns:0 carrier:0
           collisions:0 txqueuelen:100
           RX bytes:12595060 (12.0 MiB)  TX bytes:53461584 (50.9 MiB)
           Base address:0xbc00 Memory:fe8e0000-fe900000

eth2      Link encap:Ethernet  HWaddr 00:08:54:0A:B1:E7
           inet addr:86.138.125.132  Bcast:86.138.125.132  Mask:255.255.255.255
           inet6 addr: fe80::208:54ff:fe0a:b1e7/64 Scope:Link
           UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
           RX packets:56889 errors:0 dropped:0 overruns:0 frame:0
           TX packets:50695 errors:0 dropped:0 overruns:0 carrier:0
           collisions:0 txqueuelen:1000
           RX bytes:42379708 (40.4 MiB)  TX bytes:6543279 (6.2 MiB)
           Interrupt:58 Base address:0xd800

lo        Link encap:Local Loopback
           inet addr:127.0.0.1  Mask:255.0.0.0
           inet6 addr: ::1/128 Scope:Host
           UP LOOPBACK RUNNING  MTU:16436  Metric:1
           RX packets:3894 errors:0 dropped:0 overruns:0 frame:0
           TX packets:3894 errors:0 dropped:0 overruns:0 carrier:0
           collisions:0 txqueuelen:0
           RX bytes:236606 (231.0 KiB)  TX bytes:236606 (231.0 KiB)


Jim Cox on 22/05/08 14:05, wrote:
> I'm assuming the pause you saw was at the following line?
>   connect(11, {sa_family=AF_INET6, sin6_port=htons(48669),
> inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0},
> 28) = -1 ETIMEDOUT (Connection timed out)
> 
> That looks like a connect attempt to the IPv6 loopback address (?) which
> times out, but the corresponding line from the "no-pause" box seems to do
> the same without delay. Do you have IPv6 enabled on both boxes, i.e. does
> the output from "/sbin/ifconfig -a" look similar?
> 
> On Thu, May 22, 2008 at 8:52 AM, Adam Hardy <adam.ant@cyberspaceroad.com>
> wrote:
> 
>> I think this is the equivalent part of the strace log from another machine
>> on the LAN:
>>
>> socket(PF_INET6, SOCK_STREAM, IPPROTO_IP) = 10
>> listen(10, 1)                           = 0
>> getsockname(10, {sa_family=AF_INET6, sin6_port=htons(54792),
>> inet_pton(AF_INET6, "::", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0},
>> [28]) = 0
>> socket(PF_INET6, SOCK_STREAM, IPPROTO_IP) = 11
>> connect(11, {sa_family=AF_INET6, sin6_port=htons(54792),
>> inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0},
>> 28) = 0
>> fcntl64(10, F_GETFL)                    = 0x2 (flags O_RDWR)
>> fcntl64(10, F_SETFL, O_RDWR|O_NONBLOCK) = 0
>> accept(10, {sa_family=AF_INET6, sin6_port=htons(51175), inet_pton(AF_INET6,
>> "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 12
>> shutdown(11, 2 /* send and receive */)  = 0
>>
>>
>>
>> Jim Cox on 22/05/08 13:38, wrote:
>>
>>> Can you compare that output to a capture from the box where you don't see
>>> the pause? I wonder if it's a difference in IPv4/IPv6 configuration
>>> between
>>> the boxes...
>>>
>>> On Thu, May 22, 2008 at 8:24 AM, Adam Hardy <adam.ant@cyberspaceroad.com>
>>> wrote:
>>>
>>>  Found it! But I think my knowledge of linux system calls and kernel
>>>> functions is letting me down now. Presumably that is port 48669, which
>>>> should be open - but is it a DNS call? If it is a DNS call, then the DNS
>>>> server on the same machine should serve it - piping it out to the net,
>>>> presumably. But with my DNS server running, which up to now has worked
>>>> fine,
>>>> and with the gateway open to allow internet access, tomcat still freezes.
>>>>
>>>> So I guess it doesn't matter what the DNS call is for, the problem is
>>>> that
>>>> my DNS server is not serving it? I guess that means its config needs
>>>> tweaking to tell it to serve DNS requests on the loopback interface.
>>>>
>>>>
>>>> socket(PF_INET6, SOCK_STREAM, IPPROTO_IP) = 10
>>>> listen(10, 1)                           = 0
>>>> getsockname(10, {sa_family=AF_INET6, sin6_port=htons(48669),
>>>> inet_pton(AF_INET6, "::", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0},
>>>> [28]) = 0
>>>> socket(PF_INET6, SOCK_STREAM, IPPROTO_IP) = 11
>>>> connect(11, {sa_family=AF_INET6, sin6_port=htons(48669),
>>>> inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0,
>>>> sin6_scope_id=0},
>>>> 28) = -1 ETIMEDOUT (Connection timed out)
>>>> close(10)                               = 0
>>>> close(11)                               = 0
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> Jim Cox on 22/05/08 11:23, wrote:
>>>>
>>>>  I'd think it's more likely to be timing out while resolving a hostname
>>>>> via
>>>>> DNS, but starting tomcat via strace should show you exactly where it
is
>>>>> pausing.
>>>>>
>>>>> On Thu, May 22, 2008 at 5:08 AM, Adam Hardy <
>>>>> adam.ant@cyberspaceroad.com>
>>>>> wrote:
>>>>>
>>>>>  I'm still frustrated by this freeze. Looking at this thread dump, I
can
>>>>>
>>>>>> see
>>>>>> it must be the "main" thread that's hanging - but how can I work
out
>>>>>> anything more regarding the problem?
>>>>>>
>>>>>> I've done all I can think of to open up the machine it's running
on -
>>>>>> stopping all other unnecessary processes such as the firewall, apache,
>>>>>> the
>>>>>> DNS server etc.
>>>>>>
>>>>>> Could tomcat be waiting in vain for a port? As far as I can tell,
it
>>>>>> should
>>>>>> be using 8080 and 8005 - nothing else is set up in server.xml. Yet
>>>>>> these
>>>>>> ports are free on the machine. Is there a linux tool I can use to
check
>>>>>> those ports?
>>>>>>
>>>>>> Thanks
>>>>>> Adam
>>>>>>
>>>>>> -------- Original Message --------
>>>>>> Date: Mon, 19 May 2008 23:13:02 +0100
>>>>>>
>>>>>> 19-May-2008 23:04:32 org.apache.tomcat.util.modeler.BaseModelMBean
>>>>>> preRegister
>>>>>> FINE: preRegister org.apache.catalina.connector.Connector@17f1ba3
>>>>>> Catalina:type=Connector,port=8080
>>>>>> Full thread dump Java HotSpot(TM) Client VM (1.5.0_12-b04 mixed mode,
>>>>>> sharing):
>>>>>>
>>>>>> "Low Memory Detector" daemon prio=1 tid=0x0809e1a8 nid=0xe39 runnable
>>>>>> [0x00000000..0x00000000]
>>>>>>
>>>>>> "CompilerThread0" daemon prio=1 tid=0x0809cc40 nid=0xe38 waiting
on
>>>>>> condition
>>>>>> [0x00000000..0xb2176828]
>>>>>>
>>>>>> "Signal Dispatcher" daemon prio=1 tid=0x0809bd60 nid=0xe37 runnable
>>>>>> [0x00000000..0x00000000]
>>>>>>
>>>>>> "Finalizer" daemon prio=1 tid=0x08094f38 nid=0xe36 in Object.wait()
>>>>>> [0xb23a0000..0xb23a1140]
>>>>>>      at java.lang.Object.wait(Native Method)
>>>>>>      - waiting on <0x88e609e8> (a java.lang.ref.ReferenceQueue$Lock)
>>>>>>      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
>>>>>>      - locked <0x88e609e8> (a java.lang.ref.ReferenceQueue$Lock)
>>>>>>      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
>>>>>>      at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
>>>>>>
>>>>>> "Reference Handler" daemon prio=1 tid=0x08094240 nid=0xe35 in
>>>>>> Object.wait()
>>>>>> [0xb2421000..0xb24220c0]
>>>>>>      at java.lang.Object.wait(Native Method)
>>>>>>      - waiting on <0x88e60910> (a java.lang.ref.Reference$Lock)
>>>>>>      at java.lang.Object.wait(Object.java:474)
>>>>>>      at
>>>>>> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
>>>>>>      - locked <0x88e60910> (a java.lang.ref.Reference$Lock)
>>>>>>
>>>>>> "main" prio=1 tid=0x080557c8 nid=0xe33 runnable
>>>>>> [0xbf8d6000..0xbf8d8078]
>>>>>>      at java.net.PlainSocketImpl.initProto(Native Method)
>>>>>>      at java.net.PlainSocketImpl.<clinit>(PlainSocketImpl.java:84)
>>>>>>      at java.net.ServerSocket.setImpl(ServerSocket.java:236)
>>>>>>      at java.net.ServerSocket.<init>(ServerSocket.java:178)
>>>>>>      at java.net.ServerSocket.<init>(ServerSocket.java:141)
>>>>>>      at
>>>>>>
>>>>>>
>>>>>>
>>>>>> org.apache.tomcat.util.net.DefaultServerSocketFactory.createSocket(DefaultServerSocketFactory.java:50)
>>>>>>      at
>>>>>> org.apache.tomcat.util.net.JIoEndpoint.init(JIoEndpoint.java:496)
>>>>>>      at
>>>>>> org.apache.coyote.http11.Http11Protocol.init(Http11Protocol.java:177)
>>>>>>      at
>>>>>> org.apache.catalina.connector.Connector.initialize(Connector.java:1059)
>>>>>>      at
>>>>>>
>>>>>>
>>>>>>
>>>>>> org.apache.catalina.core.StandardService.initialize(StandardService.java:677)
>>>>>>      - locked <0x88f6e690> (a
>>>>>> [Lorg.apache.catalina.connector.Connector;)
>>>>>>      at
>>>>>>
>>>>>>
>>>>>> org.apache.catalina.core.StandardServer.initialize(StandardServer.java:792)
>>>>>>      at org.apache.catalina.startup.Catalina.load(Catalina.java:518)
>>>>>>      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:585)
>>>>>>      at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:260)
>>>>>>      at org.apache.catalina.startup.Bootstrap.init(Bootstrap.java:275)
>>>>>>      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:585)
>>>>>>      at
>>>>>>
>>>>>>
>>>>>> org.apache.commons.daemon.support.DaemonLoader.load(DaemonLoader.java:160)
>>>>>>
>>>>>> "VM Thread" prio=1 tid=0x08092e48 nid=0xe34 runnable
>>>>>>
>>>>>> "VM Periodic Task Thread" prio=1 tid=0x0809f650 nid=0xe3a waiting
on
>>>>>> condition
>>>>>>
>>>>>> Full thread dump Java HotSpot(TM) Client VM (1.5.0_12-b04 mixed mode,
>>>>>> sharing):
>>>>>>
>>>>>> "Low Memory Detector" daemon prio=1 tid=0x0809e1a8 nid=0xe39 runnable
>>>>>> [0x00000000..0x00000000]
>>>>>>
>>>>>> "CompilerThread0" daemon prio=1 tid=0x0809cc40 nid=0xe38 waiting
on
>>>>>> condition
>>>>>> [0x00000000..0xb2176828]
>>>>>>
>>>>>> "Signal Dispatcher" daemon prio=1 tid=0x0809bd60 nid=0xe37 runnable
>>>>>> [0x00000000..0x00000000]
>>>>>>
>>>>>> "Finalizer" daemon prio=1 tid=0x08094f38 nid=0xe36 in Object.wait()
>>>>>> [0xb23a0000..0xb23a1140]
>>>>>>      at java.lang.Object.wait(Native Method)
>>>>>>      - waiting on <0x88e609e8> (a java.lang.ref.ReferenceQueue$Lock)
>>>>>>      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
>>>>>>      - locked <0x88e609e8> (a java.lang.ref.ReferenceQueue$Lock)
>>>>>>      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
>>>>>>      at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
>>>>>>
>>>>>> "Reference Handler" daemon prio=1 tid=0x08094240 nid=0xe35 in
>>>>>> Object.wait()
>>>>>> [0xb2421000..0xb24220c0]
>>>>>>      at java.lang.Object.wait(Native Method)
>>>>>>      - waiting on <0x88e60910> (a java.lang.ref.Reference$Lock)
>>>>>>      at java.lang.Object.wait(Object.java:474)
>>>>>>      at
>>>>>> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
>>>>>>      - locked <0x88e60910> (a java.lang.ref.Reference$Lock)
>>>>>>
>>>>>> "main" prio=1 tid=0x080557c8 nid=0xe33 runnable
>>>>>> [0xbf8d6000..0xbf8d8078]
>>>>>>      at java.net.PlainSocketImpl.initProto(Native Method)
>>>>>>      at java.net.PlainSocketImpl.<clinit>(PlainSocketImpl.java:84)
>>>>>>      at java.net.ServerSocket.setImpl(ServerSocket.java:236)
>>>>>>      at java.net.ServerSocket.<init>(ServerSocket.java:178)
>>>>>>      at java.net.ServerSocket.<init>(ServerSocket.java:141)
>>>>>>      at
>>>>>>
>>>>>>
>>>>>>
>>>>>> org.apache.tomcat.util.net.DefaultServerSocketFactory.createSocket(DefaultServerSocketFactory.java:50)
>>>>>>      at
>>>>>> org.apache.tomcat.util.net.JIoEndpoint.init(JIoEndpoint.java:496)
>>>>>>      at
>>>>>> org.apache.coyote.http11.Http11Protocol.init(Http11Protocol.java:177)
>>>>>>      at
>>>>>> org.apache.catalina.connector.Connector.initialize(Connector.java:1059)
>>>>>>      at
>>>>>>
>>>>>>
>>>>>>
>>>>>> org.apache.catalina.core.StandardService.initialize(StandardService.java:677)
>>>>>>      - locked <0x88f6e690> (a
>>>>>> [Lorg.apache.catalina.connector.Connector;)
>>>>>>      at
>>>>>>
>>>>>>
>>>>>> org.apache.catalina.core.StandardServer.initialize(StandardServer.java:792)
>>>>>>      at org.apache.catalina.startup.Catalina.load(Catalina.java:518)
>>>>>>      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:585)
>>>>>>      at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:260)
>>>>>>      at org.apache.catalina.startup.Bootstrap.init(Bootstrap.java:275)
>>>>>>      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:585)
>>>>>>      at
>>>>>>
>>>>>>
>>>>>> org.apache.commons.daemon.support.DaemonLoader.load(DaemonLoader.java:160)
>>>>>>
>>>>>> "VM Thread" prio=1 tid=0x08092e48 nid=0xe34 runnable
>>>>>>
>>>>>> "VM Periodic Task Thread" prio=1 tid=0x0809f650 nid=0xe3a waiting
on
>>>>>> condition
>>>>>>
>>>>>>
>>>>>>
>>>>>> Filip Hanik - Dev Lists on 19/05/08 22:17, wrote:
>>>>>>
>>>>>>  just do two thread dumps during the freeze
>>>>>>
>>>>>>> kill -3 <tomcat process id>
>>>>>>> sleep 5
>>>>>>> kill -3 <tomcat process id>
>>>>>>>
>>>>>>> the thread dump will identify where it is hanging, and it gets
output
>>>>>>> to
>>>>>>> std.out, by default to catalina.out


---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Mime
View raw message