Re: Protocol handler initialization failed, Address already in use

2018-07-11 Thread Sergey Esin
Hi,

Thanks for your reply.

The only change that I've made - I've added *address="0.0.0.0"* to all of
my Tomcat Connectors and seems that it solves the issue. At least I can not
reproduce it any more.

Java runs with *-Djava.net.preferIPv4Stack=true*

Here what ifconfig shows inside the container with Tomcat:

# ifconfig -a
eth0  Link encap:Ethernet  HWaddr 02:42:AC:11:00:03
  inet addr:172.17.0.3  Bcast:172.17.255.255  Mask:255.255.0.0
  UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
  RX packets:1011460 errors:0 dropped:0 overruns:0 frame:0
  TX packets:1101758 errors:0 dropped:0 overruns:0 carrier:0
  collisions:0 txqueuelen:0
  RX bytes:24309 (231.8 MiB)  TX bytes:122695784 (117.0 MiB)

loLink encap:Local Loopback
  inet addr:127.0.0.1  Mask:255.0.0.0
  UP LOOPBACK RUNNING  MTU:65536  Metric:1
  RX packets:35 errors:0 dropped:0 overruns:0 frame:0
  TX packets:35 errors:0 dropped:0 overruns:0 carrier:0
  collisions:0 txqueuelen:1000
  RX bytes:9215 (8.9 KiB)  TX bytes:9215 (8.9 KiB)


On Tue, Jul 10, 2018 at 9:00 AM Jäkel, Guido  wrote:

> Dear Sergey,
>
> does this actually happen on a restart situation (with less than about
> 5min pausing time)? Then maybe you have a dangling connection (close/time
> waiting) on the TCP stack from the shutdown  of a client connection (or the
> reverse proxy). Please check if any is still open after closing down Tomcat
> ...
>
> ... or after stopping the Container. If it is bridged, did it use a veth
> device? This also don't closed down before the last connection have closed
> and may prevent to creade a new on (with the same name or the same IP).
>
> Greetings
>
> Guido
>
> >-Original Message-
> >From: Sergey Esin [mailto:sergey.e...@jetbrains.com]
> >Sent: Monday, July 09, 2018 5:12 PM
> >To: users@tomcat.apache.org
> >Subject: Protocol handler initialization failed, Address already in use
> >
> >Hi,
> >
> >I  have not-100% reproducable issue with the latest Tomcat 8.5.32 (Java
> >8u172). It happens only time to time.
> >
> >It's running in docker container under AWS ECS on a separate machine in
> ECS
> >cluster.
> >Brigde networking - so the Tomcat container gets it's own IP address.
> >
> >I have a number of Nio HTTP/1.1 connectors configured in Tomcat and upon
> >container startup I can get such issue for _any_ of configured ports:
> >
> >09 Jul 2018 16:46:03,570 INFO  [Http11NioProtocol ]
> >Initializing ProtocolHandler ["http-nio-8080"]
> >09 Jul 2018 16:46:03,598 INFO  [NioSelectorPool   ] Using a
> >shared selector for servlet write/read
> >09 Jul 2018 16:46:03,609 INFO  [Http11NioProtocol ]
> >Initializing ProtocolHandler ["http-nio-49080"]
> >09 Jul 2018 16:46:03,610 INFO  [NioSelectorPool   ] Using a
> >shared selector for servlet write/read
> >09 Jul 2018 16:46:03,611 INFO  [Http11NioProtocol ]
> >Initializing ProtocolHandler ["http-nio-50080"]
> >09 Jul 2018 16:46:03,612 ERROR [StandardService   ] Failed to
> >initialize connector [Connector[HTTP/1.1-50080]]
> >org.apache.catalina.LifecycleException: Failed to initialize component
> >[Connector[HTTP/1.1-50080]]
> >at
> >org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:112)
> >~[catalina.jar:8.5.32]
> >at
>
> >org.apache.catalina.core.StandardService.initInternal(StandardService.java:549)
> >[catalina.jar:8.5.32]
> >at
> >org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:107)
> >[catalina.jar:8.5.32]
> >at
>
> >org.apache.catalina.core.StandardServer.initInternal(StandardServer.java:875)
> >[catalina.jar:8.5.32]
> >at
> >org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:107)
> >[catalina.jar:8.5.32]
> >at org.apache.catalina.startup.Catalina.load(Catalina.java:632)
> >[catalina.jar:8.5.32]
> >at org.apache.catalina.startup.Catalina.load(Catalina.java:655)
> >[catalina.jar:8.5.32]
> >at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> >~[?:1.8.0_172]
> >at
>
> >sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> >~[?:1.8.0_172]
> >at
>
> >sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> >~[?:1.8.0_172]
> >at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_172]
> >at org.apache.catalina.startu

Protocol handler initialization failed, Address already in use

2018-07-09 Thread Sergey Esin
Hi,

I  have not-100% reproducable issue with the latest Tomcat 8.5.32 (Java
8u172). It happens only time to time.

It's running in docker container under AWS ECS on a separate machine in ECS
cluster.
Brigde networking - so the Tomcat container gets it's own IP address.

I have a number of Nio HTTP/1.1 connectors configured in Tomcat and upon
container startup I can get such issue for _any_ of configured ports:

09 Jul 2018 16:46:03,570 INFO  [Http11NioProtocol ]
Initializing ProtocolHandler ["http-nio-8080"]
09 Jul 2018 16:46:03,598 INFO  [NioSelectorPool   ] Using a
shared selector for servlet write/read
09 Jul 2018 16:46:03,609 INFO  [Http11NioProtocol ]
Initializing ProtocolHandler ["http-nio-49080"]
09 Jul 2018 16:46:03,610 INFO  [NioSelectorPool   ] Using a
shared selector for servlet write/read
09 Jul 2018 16:46:03,611 INFO  [Http11NioProtocol ]
Initializing ProtocolHandler ["http-nio-50080"]
09 Jul 2018 16:46:03,612 ERROR [StandardService   ] Failed to
initialize connector [Connector[HTTP/1.1-50080]]
org.apache.catalina.LifecycleException: Failed to initialize component
[Connector[HTTP/1.1-50080]]
at
org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:112)
~[catalina.jar:8.5.32]
at
org.apache.catalina.core.StandardService.initInternal(StandardService.java:549)
[catalina.jar:8.5.32]
at
org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:107)
[catalina.jar:8.5.32]
at
org.apache.catalina.core.StandardServer.initInternal(StandardServer.java:875)
[catalina.jar:8.5.32]
at
org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:107)
[catalina.jar:8.5.32]
at org.apache.catalina.startup.Catalina.load(Catalina.java:632)
[catalina.jar:8.5.32]
at org.apache.catalina.startup.Catalina.load(Catalina.java:655)
[catalina.jar:8.5.32]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
~[?:1.8.0_172]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
~[?:1.8.0_172]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
~[?:1.8.0_172]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_172]
at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:309)
[bootstrap.jar:8.5.32]
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:492)
[bootstrap.jar:8.5.32]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
~[?:1.8.0_172]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
~[?:1.8.0_172]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
~[?:1.8.0_172]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_172]
at
org.tanukisoftware.wrapper.WrapperStartStopApp.run(WrapperStartStopApp.java:400)
[wrapper.jar:3.5.32]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
Caused by: org.apache.catalina.LifecycleException: Protocol handler
initialization failed
at
org.apache.catalina.connector.Connector.initInternal(Connector.java:995)
~[catalina.jar:8.5.32]
at
org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:107)
~[catalina.jar:8.5.32]
... 18 more
Caused by: java.net.BindException: Address already in use
at sun.nio.ch.Net.bind0(Native Method) ~[?:1.8.0_172]
at sun.nio.ch.Net.bind(Net.java:433) ~[?:1.8.0_172]
at sun.nio.ch.Net.bind(Net.java:425) ~[?:1.8.0_172]
at
sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)
~[?:1.8.0_172]
at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
~[?:1.8.0_172]
at
org.apache.tomcat.util.net.NioEndpoint.bind(NioEndpoint.java:210)
~[tomcat-coyote.jar:8.5.32]
at
org.apache.tomcat.util.net.AbstractEndpoint.init(AbstractEndpoint.java:1086)
~[tomcat-coyote.jar:8.5.32]
at
org.apache.tomcat.util.net.AbstractJsseEndpoint.init(AbstractJsseEndpoint.java:268)
~[tomcat-coyote.jar:8.5.32]
at
org.apache.coyote.AbstractProtocol.init(AbstractProtocol.java:581)
~[tomcat-coyote.jar:8.5.32]
at
org.apache.coyote.http11.AbstractHttp11Protocol.init(AbstractHttp11Protocol.java:68)
~[tomcat-coyote.jar:8.5.32]
at
org.apache.catalina.connector.Connector.initInternal(Connector.java:993)
~[catalina.jar:8.5.32]
at
org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:107)
~[catalina.jar:8.5.32]
... 18 more
09 Jul 2018 16:46:03,618 INFO  [Http11NioProtocol ]
Initializing ProtocolHandler ["http-nio-61080"]
09 Jul 2018 16:46:03,620 INFO  [NioSelectorPool   ] Using a
shared selector for servlet write/read
09 Jul 2018 16:46:03,620 INFO  [Http11NioProtocol ]
Initializing ProtocolHandler ["http-nio-63080"]
09 Jul 2018 16:46:03,621 INFO  [NioSelectorPool   ] Using a
shar