tomcat - Mac OS X で「java.net.SocketException Invalid argument」が原因で Tomcat の起動に失敗する

Question

Tomcat 6 (正確には 6.0.35.0) で実行されるアプリケーションがあり、Mac OS のほとんどのエンジニアは、Catalina.await メソッドの socketAccept 呼び出しが SocketException をスローするため、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 は起動直後にシャットダウンします (そして、少なからず激怒します)。これは、Java 1.7 を搭載した Mac OS の期間中ずっと続いていたと思います。ここ数か月で、多くの人が Macbook Pro に切り替えました。これまでは、この例外が socketRead でもスローされるため、Tomcat から時折 0 バイトの応答が返されるという唯一の症状がありました。エラーはログに記録されず、孤立した問題として個別に無視し、起動時の問題が発生して 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

問題は時間に敏感です。アプリケーションの変更による起動時間の増加 (Spring イントロスペクション/シングルトンのオーバーヘッドが大幅に増加) が、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)
マック OS アップデート. Mac OS 10.7.x および 10.8.0 ～ 1.8.3 が影響を受けます
ファイル記述子の制限 - から5000に増加10000
メインのイーサネットインターフェイスで IPv6 を完全に無効にする
ブレークポイントを設定し、SocketException の影響を受ける最初のコンテキストを削除します (Web サービスへの発信 HTTP 呼び出しです)。変化なし
/etc/hostsマシンのホスト名が localhost に解決されるように構成し、IPv4 アドレスを優先し、IPv6 アドレスを優先しないように JVM オプションを構成します(この回答: https://stackoverflow.com/a/16318860/364206 ) 。

ホスト構成に興味がある人にとっては、デフォルトと同じです。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 がネイティブコードからバブルアップして、これらの例外を複数のスレッド (つまり 2 つのスレッド) で同時に発生させるべきではありません。送信 Web サービス呼び出し、Tomcat await 呼び出し、およびいくつかの TP プロセッサスレッドを繰り返し実行します。

JNIコード調査

一般的なメッセージを考えるとEINVAL、socketAccept JNI コード内のシステムコールの 1 つからエラーが返されなければならないと想定したので、例外に至るまでのシステムコールを追跡しました。EINVALシステムコールから返されるものはありません。そのため、OpenJDK ソースに移動して、socketAccept コードでを設定してからスローする条件を探しましたが、に設定する、またはを呼び出す、またはこれで SocketException をスローする方法で SocketException をスローするEINVALコードも見つかりませんでした。デフォルトのエラーメッセージ。errnoEINVALNET_ThrowByNameWithLastErrorNET_ThrowCurrentNET_ThrowNew

システムコールに関する限り、accept システムコールまでは到達していないようです。

 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

ということで、のacceptループの先頭にあるタイムアウト処理のコードで問題が発生していると思いますが、に設定してこの SocketException がスローされるsocketAcceptケースは見当たりませんでした。私はこのコードを参照しています。jdk7u ブランチは、ほとんどの場合、Oracle JDK に同梱されているものだと思います。NET_TimeouterrnoEINVAL

ヘルプ！

Mac OS でのこの特定の問題の影響を受けた人を外の世界で見つけることはできませんが、ここにいるほとんどすべての人が影響を受けています。原因となるアプリケーション構成がいくつかあるはずですが、根本原因を見つけるために考えられるあらゆる手段を尽くしました。

考えられる原因に関するトラブルシューティングまたは洞察に関する指針をいただければ幸いです。

score 21 · Accepted Answer

で JNI デバッグをオンにしてみました-Xcheck:jniか? 興味深いことに、Oracle のドキュメントでは、PlainSocketImpl.socketAcceptこれをいつ使用するかの例としてエラーが使用されています。

また、バグ 7131399の意味するところは、JNI はpoll()ほとんどのプラットフォームで使用されますがselect()、Mac の問題により Mac OS で使用されることpoll()です。だから多分それselect()も壊れています。さらに掘り下げると、「ndfs が FD_SETSIZE よりも大きく、_DARWIN_UNLIMITED_SELECT が定義されていない」場合、select() は EINVAL を返します。FD_SETSIZE は 1024 であり、大量のアプリケーションがロードされているように聞こえるため、一度に 1024 を超える FD を待機するようにすべてがフィルター処理される可能性があります。

余分なクレジットとして、関連する (修正されたと思われる) Java バグが実際にマシンで修正されているかどうかを確認してください。バグレポートには、テストケースへのポインタがあります。

Old Proさんの回答のおかげで、select()FD_SETSIZEの制限が原因であることが確認できました。この制限に関する既存のバグを見つけました。

https://bugs.openjdk.java.net/browse/JDK-8021820

この問題は、次のコードで再現できます。

import java.io.*;
import java.net.*;

public class SelectTest {
  public static void main(String[] args) throws Exception {
    // Use 1024 file descriptors. There'll already be some in use, obviously, but this guarantees the problem will occur
    for(int i = 0; i < 1024; i++) {
      new FileInputStream("/dev/null");
    }
    ServerSocket socket = new ServerSocket(8080);
    socket.accept();
  }
}

ほぼ 1 年後、Java 7u60 でこの問題が修正されました。

http://www.oracle.com/technetwork/java/javase/2col/7u60-bugfixes-2202029.html

また、Tomcat の WebappClassLoader が 90 秒後にファイルハンドルを閉じることも発見しました。これは、ブレークポイントを設定することで問題が発生しなかった理由を説明しています。

score 1 · Accepted Answer

私は（Tomcat7で）まったく同じ問題を抱えていました.Eclipse内でTomcatを実行しているときに、「モジュールコンテキストを個別のXMLファイルに公開する」オプションにチェックマークを付けるとうまくいくようです。もう試しましたか？

tomcat - Mac OS X で「java.net.SocketException Invalid argument」が原因で Tomcat の起動に失敗する

アプリケーション構成

除外された項目

Javaコード調査

JNIコード調査

ヘルプ！

4 に答える 4

Related

Reference