Summary: | Socket bind fails on tomcat startup when using apr | ||
---|---|---|---|
Product: | Tomcat Native | Reporter: | Erik Moller <erjomo> |
Component: | Library | Assignee: | Tomcat Developers Mailing List <dev> |
Status: | RESOLVED FIXED | ||
Severity: | normal | CC: | david, jfclere, siegmund.gorr |
Priority: | P2 | ||
Version: | unspecified | ||
Target Milestone: | --- | ||
Hardware: | HP | ||
OS: | Linux | ||
Attachments: |
script to demonstrate problem
logfile of build using the script Native patch APR Java connector patch |
Description
Erik Moller
2007-09-07 07:22:31 UTC
I am having trouble reproducing this error. It may have already been fixed or it may be an issue with your build environment. Please can you re-test with the latest APR, openssl, tomcat-native and 6.0.16 and, if you still see this error, provide the exact version numbers and commands you used to build so I can try and repeat this. I also get this problem. Using: * Tomcat 6.0.16 * APR 1.2.11-1 from Ubuntu Hardy * OpenSSL 0.9.8g-4ubuntu3.1 from Hardy * tcnative 1.1.12 I'm attempting to package this for debian and ubuntu. You can fetch the build from my git repo at svn://femme.catnip.org.uk/tomcat6.git That should be git://femme.catnip.org.uk/tomcat6.git Suitable snippet from the strace log: 9749 socket(PF_INET6, SOCK_STREAM, IPPROTO_TCP) = 30 9749 setsockopt(30, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 9749 setsockopt(30, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0 9749 bind(30, {sa_family=AF_INET, sin_port=htons(8180), sin_addr=inet_addr("0.0.0.0")}, 16) = -1 EINVAL (Invalid argument) I still can't reproduce this. I wonder if the some local changes in the Ubuntu packages are involved. Can you provide step by step instructions to reproduce this using the distros from an Apache mirror rather than the Ubuntu versions. Also, what is the IP config of the machine you are using? I can attempt to build using the tarballs from upstream. Do you have IPv6 enabled on your box, as that appears to be the problem? If you disable IPv6 there isn't a problem. If you enable it, it attempts to create an IPv6 socket and then attempts to bind to an IPv4 address of '0.0.0.0'. I've checked the packaging of APR in hardy and there are no patches that would affect sockets. There is nothing in the tomcat packaging. beebo david% ip addr 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 inet 127.0.0.1/8 scope host lo inet6 ::1/128 scope host valid_lft forever preferred_lft forever 2: eth0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc pfifo_fast qlen 1000 link/ether 00:09:6b:42:b2:61 brd ff:ff:ff:ff:ff:ff 3: wifi0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast qlen 1000 link/ieee802.11 00:04:e2:63:83:ee brd ff:ff:ff:ff:ff:ff 4: eth1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue link/ether 00:04:e2:63:83:ee brd ff:ff:ff:ff:ff:ff inet 10.1.0.6/24 brd 10.1.0.255 scope global eth1 inet6 fe80::204:e2ff:fe63:83ee/64 scope link valid_lft forever preferred_lft forever I've attached a script I've used to replicate this bug and the build log. I'm not entirely sure why configure spits out errors. From a cursory glance at the code, it appears to iterate through the environment attempting to eval them all. It doesn't appear to result in any functional problems: 30-May-2008 05:52:43 org.apache.catalina.core.AprLifecycleListener init INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/lib/jvm/java-6-sun-1.6.0.06/jre/lib/i386/client:/usr/lib/jvm/java-6-sun-1.6.0.06/jre/lib/i386:/usr/lib/jvm/java-6-sun-1.6.0.06/jre/../lib/i386:/usr/java/packages/lib/i386:/lib:/usr/lib 30-May-2008 05:52:43 org.apache.coyote.http11.Http11Protocol init INFO: Initializing Coyote HTTP/1.1 on http-8080 30-May-2008 05:52:43 org.apache.catalina.startup.Catalina load INFO: Initialization processed in 1963 ms 30-May-2008 05:52:44 org.apache.catalina.core.StandardService start INFO: Starting service Catalina 30-May-2008 05:52:44 org.apache.catalina.core.StandardEngine start INFO: Starting Servlet Engine: Apache Tomcat/6.0.16 30-May-2008 05:52:45 org.apache.catalina.core.StandardContext addApplicationListener INFO: The listener "listeners.ContextListener" is already configured for this context. The duplicate definition has been ignored. 30-May-2008 05:52:45 org.apache.catalina.core.StandardContext addApplicationListener INFO: The listener "listeners.SessionListener" is already configured for this context. The duplicate definition has been ignored. 30-May-2008 05:52:46 org.apache.coyote.http11.Http11Protocol start INFO: Starting Coyote HTTP/1.1 on http-8080 30-May-2008 05:52:46 org.apache.jk.common.ChannelSocket init INFO: JK: ajp13 listening on /0.0.0.0:8009 30-May-2008 05:52:46 org.apache.jk.server.JkMain start INFO: Jk running ID=0 time=0/204 config=null 30-May-2008 05:52:46 org.apache.catalina.startup.Catalina start INFO: Server startup in 2795 ms 30-May-2008 05:52:52 org.apache.coyote.http11.Http11Protocol pause INFO: Pausing Coyote HTTP/1.1 on http-8080 30-May-2008 05:52:53 org.apache.catalina.core.StandardService stop INFO: Stopping service Catalina 30-May-2008 05:52:53 org.apache.coyote.http11.Http11Protocol destroy INFO: Stopping Coyote HTTP/1.1 on http-8080 30-May-2008 05:52:56 org.apache.catalina.core.AprLifecycleListener init INFO: Loaded APR based Apache Tomcat Native library 1.1.12. 30-May-2008 05:52:56 org.apache.catalina.core.AprLifecycleListener init INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true]. 30-May-2008 05:53:04 org.apache.catalina.startup.Catalina stopServer SEVERE: Catalina.stop: java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333) at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195) at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366) at java.net.Socket.connect(Socket.java:519) at java.net.Socket.connect(Socket.java:469) at java.net.Socket.<init>(Socket.java:366) at java.net.Socket.<init>(Socket.java:180) at org.apache.catalina.startup.Catalina.stopServer(Catalina.java:421) 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.catalina.startup.Bootstrap.stopServer(Bootstrap.java:337) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:415) Created attachment 22036 [details]
script to demonstrate problem
Created attachment 22037 [details]
logfile of build using the script
Hi, I could add another target environment with same problems, except that no SSL is being used. Linux openSUSE-103-64-minimal 2.6.22.9-0.4-default #1 SMP 2007/10/05 21:32:04 UTC x86_64 x86_64 x86_64 GNU/Linux Tomcat 6.0.14 It is pretty frigthening that a server help tool like jsvc prevents this lib from working. It looks that the design and integration of jsvc or APR has some side effects. I could not recommend any furhter production use of this combination. David, IPv6 is enabled. I was using tcnative 1.1.13. It might be worth testing with that. Also, could you provide the contents of /etc/network/interfaces and the connector elements of your server.xml. Finally, are you starting with jsvc? Meanwhile, I'll double check I have IPv6 enabled. Siegmund, Where does jsvc fit into this? Are you saying you only see this issue when starting via jsvc but not when starting from the scripts? I did a diff from what is in tomcat6-6.0.16/bin/tcnative.tar.gz and tcnative-1.1.13 and the only differences were svn commit info in the comments, so there is no code difference what so ever. I am running via jsvc: root 3966 0.0 0.1 2056 364 ? Ss May30 0:00 /usr/bin/jsvc -user tomcat6 -cp /usr/share/java/commons-daemon.jar:/usr/share/tomcat6/bin/bootstrap.jar -outfile /var/lib/tomcat6/logs/catalina.out -errfile /usr/share/tomcat6/logs/catalina.err -pidfile /var/run/tomcat6.pid -Djava.awt.headless=true -Xmx128M -Djava.endorsed.dirs=/usr/share/tomcat6/common/endorsed -Dcatalina.base=/var/lib/tomcat6 -Dcatalina.home=/usr/share/tomcat6 -Djava.io.tmpdir=/var/lib/tomcat6/temp -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.util.logging.config.file=/var/lib/tomcat6/conf/logging.properties org.apache.catalina.startup.Bootstrap tomcat6 3974 0.0 10.4 282728 27484 ? Sl May30 2:40 /usr/bin/jsvc -user tomcat6 -cp /usr/share/java/commons-daemon.jar:/usr/share/tomcat6/bin/bootstrap.jar -outfile /var/lib/tomcat6/logs/catalina.out -errfile /usr/share/tomcat6/logs/catalina.err -pidfile /var/run/tomcat6.pid -Djava.awt.headless=true -Xmx128M -Djava.endorsed.dirs=/usr/share/tomcat6/common/endorsed -Dcatalina.base=/var/lib/tomcat6 -Dcatalina.home=/usr/share/tomcat6 -Djava.io.tmpdir=/var/lib/tomcat6/temp -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.util.logging.config.file=/var/lib/tomcat6/conf/logging.properties org.apache.catalina.startup.Bootstrap my interfaces file is: # This file describes the network interfaces available on your system # and how to activate them. For more information, see interfaces(5). # The loopback network interface auto lo iface lo inet loopback # The primary network interface auto eth0 iface eth0 inet dhcp # post-up ethtool -K eth0 tx off # # The commented out line above will disable TCP checksumming which # might resolve problems for some users. It is disabled by default # results in: 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 inet 127.0.0.1/8 scope host lo inet6 ::1/128 scope host valid_lft forever preferred_lft forever 2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast qlen 1000 link/ether aa:00:0a:00:02:3b brd ff:ff:ff:ff:ff:ff inet 10.0.2.59/16 brd 10.0.255.255 scope global eth0 inet6 fe80::a800:aff:fe00:23b/64 scope link valid_lft forever preferred_lft forever My only enabled connectors are: <!-- Define a non-SSL HTTP/1.1 Connector on port 8180 --> <Connector port="8180" maxHttpHeaderSize="8192" maxThreads="150" minSpareThreads="25" maxSpareThreads="75" enableLookups="false" redirectPort="8443" acceptCount="100" connectionTimeout="20000" disableUploadTimeout="true" /> <!-- Define an AJP 1.3 Connector on port 8009 --> <Connector port="8009" enableLookups="false" redirectPort="8443" protocol="AJP/1.3" /> Update on JSVC and APR Involving debugging I found that my problem with JSVC and APR could be drilled down to SSL library access I did not found the reason why it hangs - may be the privileges are not sufficient after switching from root to the www-user. After a time period (on my three servers approx. 6 min. the startup suddenly continues - like a timeout has been reached. My problems could be resolved by deactivating ssl in the tomcat apr configuration which might be a hint for other server operators as well. We are handling the ssl separat and do not pass the data via the Apache mod_jk module to the AJP handler (which is been boosted by APR). So configuration in httpd.conf is JkOptions +ForwardkeySize +ForwardURICompat -ForwardDirectories JkExtractSSL off JkRequestLogFormat "%w %V %T" And whithin server.xml <Listener className="org.apache.catalina.core.AprLifecycleListener" SSLEngine="off" /> Sorry but I did not find the reason why this problems is not existing when we start tomcat without jsvc. Bingo! I can now reproduce this. Hopefully a fix won't be too far away... OK. There are two issues here. The first is that the APR calls eventually called as a result of Address.info() and Socket.create() in o.a.t.util.net.AprEndpoint use slightly different logic to determine whether to create an IPv4 socket or an IPv6 socket. If you have an IPv6 capable interface that does not have an explicit IPv6 address defined these functions will assume different IP families. The second issue is that whilst the first issue could be fixed by using Address.getInfo().family to specify that the family of the address should be used to use to create the socket, Address.getInfo() does not convert the APR_INET and APR_INET6 constants back into the ones defined in Socket (the constants are different in the Java code and in APR). So, I have two patches. The first converts the constants back to the Java defined values and the second uses the family from the address to create the socket. Patches to follow. Created attachment 22216 [details]
Native patch
*Health Warning*
I am no C programmer. This patch fixes the problem for me but it needs to be checked by someone who actually knows what they are doing.
Created attachment 22217 [details]
APR Java connector patch
This needs the native patch to work.
I (finally) tested it on my development machine which has both a NAT IPv4 and an IPv6 address, and it does not appear to work any better. No address attribute -> error 22 address="127.0.0.1"-> error 22 address="myIPv6"-> no error (and ot correctly) Ok, so I was testing the old version :( The new testing result is: - no address attribute -> slow bind (20s at least), and does not bind the IPv6 - address="127.0.0.1"-> works - address="myIPv6"-> works So it's a lot better, but not glitch free yet. Is this true on Linux, Remy? Or another OS. Solaris, for example, is known to not tolerate sharing an ipv4+6 listener very well. Essentially, any OS in which the ipv4 stack is built of different driver components than the ipv6 stack gives headaches attempting a single listener. For all of these cases, two listening sockets, one explicitly IPv4 and the other IPv6 is preferable. I am testing on Linux. With the latest changes, this now works :) Really tricky to get right ... Fixed in tc-native and trunk proposed for 6.0.x how I can add the patch |