Tomcat 启动失败,原因是 Mac OS X 上的 “java.net.SocketException Invalid argument”
我们有一个在Tomcat 6上运行的应用程序(确切地说是6.0.35.0),由于Catalina.await方法中的socketAccept调用抛出SocketException,我们在Mac OS上的大多数工程师在启动Tomcat时都遇到了问题:
SEVERE: StandardServer.await: accept:
java.net.SocketException: Invalid argument
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.socketAccept(PlainSocketImpl.java)
at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
at java.net.ServerSocket.implAccept(ServerSocket.java:522)
at java.net.ServerSocket.accept(ServerSocket.java:490)
at org.apache.catalina.core.StandardServer.await(StandardServer.java:431)
at org.apache.catalina.startup.Catalina.await(Catalina.java:676)
at org.apache.catalina.startup.Catalina.start(Catalina.java:628)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
at mycompany.tomcat.startup.ThreadDumpWrapper.main(ThreadDumpWrapper.java:260)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.tanukisoftware.wrapper.WrapperStartStopApp.run(WrapperStartStopApp.java:238)
at java.lang.Thread.run(Thread.java:722)
这导致Tomcat在启动后立即关闭(并且不小的愤怒)。我们认为这在Mac OS和Java 1.7上已经存在了很长时间,在过去的几个月里,我们很多人已经切换到Macbook Pros。到目前为止,唯一的症状是Tomcat偶尔会有零字节响应,因为这个异常也被抛到了socketRead上。错误不会命中日志,我们单独将其作为孤立的问题耸耸肩,并且仅在启动问题开始时才找到原因,并且我设置了SocketException断点:
Daemon Thread [http-8080-1] (Suspended (breakpoint at line 47 in SocketException))
SocketException.<init>(String) line: 47
SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int) line: not available [native method]
SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int) line: not available
SocketInputStream.read(byte[], int, int, int) line: 150
SocketInputStream.read(byte[], int, int) line: 121
InternalInputBuffer.fill() line: 735
InternalInputBuffer.parseRequestLine() line: 366
Http11Processor.process(Socket) line: 814
Http11Protocol$Http11ConnectionHandler.process(Socket) line: 602
JIoEndpoint$Worker.run() line: 489
Thread.run() line: 722
对于参数:
arg0 FileDescriptor (id=499)
fd 1097
useCount AtomicInteger (id=503)
value 2
arg1 (id=502)
arg2 0
arg3 8192
arg4 20000
这个问题对时间很敏感。由于应用程序更改而增加的启动时间(更多的春季内省/单例开销)似乎是导致这影响Tomcat启动的因素;临界点约为160秒。我们可以通过禁用一些在开发过程中不需要的非强制上下文来缓解这个问题,以减少启动时间,但我更愿意找到根本原因。
应用程序配置
应用程序的细节太复杂了,无法详细介绍,但我有一种预感,这可能与早期的绑定有关,所以我至少会列出我机器上的侦听端口:
localhost:32000 - Java service wrapper port
*:10001 - RMI registry
*:2322 - Java debug
*:56566 - RMI
*:8180 - Tomcat HTTP connector
*:8543 - Tomcat HTTPS connector
*:2223 - Tomcat Internal HTTP connector (used for cross-server requests)
*:14131 - 'Locking' port to determine if an internal service is running
*:56571 - EhCache RMI
*:56573 - RMI
*:62616 - ActiveMQ broker
*:5001 - SOAPMonitorService
*:8109 - Tomcat shutdown port
排除的项目
- 最明显的解决方案:.我一直配置该选项
-Djava.net.preferIPv4Stack=true
- 最近对我们的基本应用程序配置、库、JVM 选项的任何配置更改(没有任何更改)
- JDK 回归。我已经测试了JDK 1.7.0_09,11,15,17和21(我在机器上安装了JDK)
- Mac OS 更新。Mac OS 10.7.x 和 10.8.0 至 1.8.3 受到影响
- 文件描述符限制 - 从 增加到
5000
10000
- 在主以太网接口上完全禁用 IPv6
- 设置断点,并删除要受 SocketException 影响的第一个上下文(它们是对 Web 服务的传出 HTTP 调用)。无变化
- 配置以便将计算机主机名解析为本地主机,并配置 JVM 选项以首选 IPv4 而不是首选 IPv6 地址(此答案:https://stackoverflow.com/a/16318860/364206
/etc/hosts
)
对于那些对主机配置感兴趣的人,它与默认值相同。我可以在具有 10.8 全新安装的 Fusion VM 上重现此内容:
##
# Host Database
#
# localhost is used to configure the loopback interface
# when the system is booting. Do not change this entry.
##
127.0.0.1 localhost
255.255.255.255 broadcasthost
::1 localhost
fe80::1%lo0 localhost
Java 代码调查
由于问题的明显时间敏感性,设置断点以解决问题会导致问题不会发生。正如评论中所要求的,我也捕获了,似乎没有什么不寻常的。arg0
SocksSocketImpl(PlainSocketImpl).socketAccept(SocketImpl)
arg0 SocksSocketImpl (id=460)
address InetAddress (id=465)
canonicalHostName null
holder InetAddress$InetAddressHolder (id=475)
address 0
family 0
hostName null
applicationSetProxy false
closePending false
cmdIn null
cmdOut null
cmdsock null
CONNECTION_NOT_RESET 0
CONNECTION_RESET 2
CONNECTION_RESET_PENDING 1
external_address null
fd FileDescriptor (id=713)
fd -1
useCount AtomicInteger (id=771)
value 0
fdLock Object (id=714)
fdUseCount 0
localport 0
port 0
resetLock Object (id=716)
resetState 0
server null
serverPort 1080
serverSocket null
shut_rd false
shut_wr false
socket Socket (id=718)
bound false
closed false
closeLock Object (id=848)
connected false
created false
impl null
oldImpl false
shutIn false
shutOut false
socketInputStream null
stream false
timeout 0
trafficClass 0
useV4 false
我认为所有引发异常的线程都是早期调用的受害者,该调用不会导致SocketException,因此我无法捕获它。能够通过减少启动时间来启动Tomcat使我相信触发器可能是执行基于套接字的操作的某个计划任务,然后影响其他套接字操作。
这并不能解释这如何影响以及为什么会影响多个线程,无论我们采取什么措施来导致这种情况,神秘的SocketExceptions都不应该从本机代码中冒出来并在多个线程上同时导致这些异常 - 也就是说,两个线程进行传出Web服务调用,Tomcat await调用以及几个TP处理器线程重复。
JNI 代码调查
给定通用消息,我假设必须从 socketAccept JNI 代码中的一个系统调用返回错误,因此我跟踪了导致异常的系统调用;没有从任何系统调用返回。因此,我去了 OpenJDK 源代码,在 socketAccept 代码中寻找条件,这些条件将设置然后抛出一个 ,但我也找不到任何设置为 、或调用 的代码,或者以一种会引发 SocketException 的方式出现此默认错误消息。EINVAL
EINVAL
EINVAL
errno
EINVAL
NET_ThrowByNameWithLastError
NET_ThrowCurrent
NET_ThrowNew
就系统调用而言,我们似乎没有达到接受系统调用的程度:
PID/THRD RELATIVE ELAPSD CPU SYSCALL(args) = return
6606/0x2c750d: 221538243 5 0 sigprocmask(0x1, 0x0, 0x14D8BE100) = 0x0 0
6606/0x2c750d: 221538244 3 0 sigaltstack(0x0, 0x14D8BE0F0, 0x0) = 0 0
6606/0x2c750d: 221538836 14 10 socket(0x2, 0x1, 0x0) = 1170 0
6606/0x2c750d: 221538837 3 0 fcntl(0x492, 0x3, 0x4) = 2 0
6606/0x2c750d: 221538839 3 1 fcntl(0x492, 0x4, 0x6) = 0 0
6606/0x2c750d: 221538842 5 2 setsockopt(0x492, 0xFFFF, 0x4) = 0 0
6606/0x2c750d: 221538852 7 4 bind(0x492, 0x14D8BE5D8, 0x10) = 0 0
6606/0x2c750d: 221538857 5 2 listen(0x492, 0x1, 0x4) = 0 0
6606/0x2c750d: 221539625 6 2 psynch_cvsignal(0x7FEFBFE00868, 0x10000000200, 0x100) = 257 0
6606/0x2c750d: 221539633 4 1 write(0x2, "Apr 18, 2013 11:05:35 AM org.apache.catalina.core.StandardServer await\nSEVERE: StandardServer.await: accept: \njava.net.SocketException: Invalid argument\n\tat java.net.PlainSocketImpl.socketAccept(Native Method)\n\tat java.net.PlainSocketImpl.socketAcce", 0x644) = 1604 0
所以,我认为问题发生在 接受 循环顶部的超时处理代码 中,但我找不到任何可以设置为 的情况,并导致抛出这个 SocketException。我指的是这个代码;我假设 jdk7u 分支在很大程度上是 Oracle JDK 中附带的内容:socketAccept
NET_Timeout
errno
EINVAL
- http://hg.openjdk.java.net/jdk7u/jdk7u/jdk/file/d4bf5c15837c/src/solaris/native/java/net/PlainSocketImpl.c
- http://hg.openjdk.java.net/jdk7u/jdk7u/jdk/file/d4bf5c15837c/src/solaris/native/java/net/bsd_close.c
- http://hg.openjdk.java.net/jdk7u/jdk7u/jdk/file/d4bf5c15837c/src/solaris/native/java/net/net_util_md.c
帮助!
在Mac OS上,我找不到受此特定问题影响的外部世界中的任何人,但这里的几乎每个人都受到影响。必须有一些应用程序配置可以做出贡献,但是我已经用尽了我能想到的所有途径来找到根本原因。
有关故障排除的指针或对可能原因的见解将不胜感激。