Le démarrage de Tomcat échoue à cause de ' java.net.SocketException argument invalide ' sur Mac OS X

nous avons une application qui tourne sur Tomcat 6 (6.0.35.0 pour être précis), et la plupart de nos ingénieurs sur Mac OS ont des problèmes de démarrage de Tomcat en raison de l'appel socketAccept dans le Catalina.attendre la méthode lancer une SocketException:

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)

cela provoque la fermeture de Tomcat immédiatement après le démarrage (et pas une petite quantité de rage). Nous pensons que cela a été avec nous pour la durée sur Mac OS w / Java 1.7, au cours des derniers mois beaucoup d'entre nous sont passés à Macbook Pro. Jusqu'à présent, le seul symptôme était des réponses à zéro octet occasionnelles de la part de Tomcat, en raison de cette exception étant également jeté sur un socketRead. Les erreurs ne frappent pas les logs et nous les avons désactivées individuellement en tant que problème isolé, et n'en avons trouvé la cause que lorsque le problème de démarrage a commencé et que j'ai défini un point de rupture de 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

pour les arguments:

arg0  FileDescriptor  (id=499)  
  fd  1097  
  useCount  AtomicInteger  (id=503) 
    value 2 
arg1  (id=502)
arg2  0 
arg3  8192  
arg4  20000

le problème est sensible au temps. Augmenter le temps de démarrage en raison de changements d'application (beaucoup plus Spring introspection/singleton overhead) semble être le facteur qui affecte le démarrage de Tomcat; le point de basculement étant d'environ 160 secondes. Nous pouvons atténuer le problème en désactivant certains contextes non-obligatoires dont nous n'avons pas besoin pendant le développement pour réduire le temps de démarrage, mais je préférerais en trouver la cause profonde.

configuration de L'Application

les particularités de La demande sont beaucoup trop complexes pour aller dans trop de détails, mais j'ai un pressentiment que ce pourrait se rapporter à un bind plus tôt, donc je vais au moins lister les ports d'écoute sur ma machine:

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

Éléments exclu

  • la solution La plus évidente: -Djava.net.preferIPv4Stack=true. J'ai toujours eu cette option configurée
  • toute modification récente de la configuration de notre application de base, bibliothèques, options JVM (il n'y en a pas)
  • une régression JDK. J'ai testé JDK 1.7.0_09, 11, 15, 17 et 21 (Les JDKs que j'ai installés sur ma machine pour la durée)
  • mise à jour Mac OS. Mac OS 10.7.x et 10.8.0 à 1.8.3 sont affectés
  • limites du descripteur de fichier-augmentées de 500010000
  • désactiver IPv6 complètement sur l'interface ethernet principale
  • définir les points de rupture, et supprimer les premiers contextes à être affectés par la SocketException (ce sont des appels HTTP sortants vers des services web). Aucun changement
  • configurer /etc/hosts ainsi le nom d'hôte de la machine se résout à localhost, et configurer les options JVM pour préférer IPv4 et préférez des adresses IPv6 (Cette réponse: https://stackoverflow.com/a/16318860/364206)

pour ceux qui sont intéressés par la configuration des hôtes, c'est la même chose que par défaut. Je peux le reproduire sur une Fusion VM avec une installation propre de 10.8:

##
# 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

code Java enquête

en raison de la nature apparemment sensible au temps de la question, l'établissement de points d'arrêt pour résoudre le problème des causes pour ne pas se produire. Comme demandé dans les commentaires, j'ai aussi capturé arg0SocksSocketImpl(PlainSocketImpl).socketAccept(SocketImpl) rien ne semble sortir de l'ordinaire. 

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

je pense que tous les threads où les exceptions sont lancées sont des victimes d'un appel antérieur, qui ne débouche pas sur une SocketException donc je n'ai pas pu l'attraper. Être capable de démarrer Tomcat en réduisant les temps de démarrage me convainc que le déclencheur est probablement une tâche planifiée qui effectue une socket basée fonctionnement, qui affecte ensuite les autres opérations de socket.

cela n'explique pas comment et pourquoi cela pourrait affecter plusieurs threads, peu importe ce que nous faisons pour causer cette condition, Les Mystérieuses exceptions SocketExceptions ne devraient pas créer de bulles à partir du code natif et causer ces exceptions simultanément sur plusieurs threads - c'est-à-dire, deux threads faisant des appels de service web sortants, L'appel Tomcat en attente, et plusieurs threads de processeur TP à plusieurs reprises.

JNI code enquête

étant donné le message générique, j'ai supposé qu'un EINVAL l'erreur doit être retournée à partir d'un des appels système dans le code JNI de socketAccept, donc j'ai tracé les appels système menant à l'exception; il n'y a pas de EINVAL retourné de n'importe quel appel système. Donc, je suis allé aux sources OpenJDK à la recherche de conditions dans le code socketAccept qui seraient définies et ensuite lancer un EINVAL, mais je n'ai pas pu trouver de code qui définisse errnoEINVAL, ou appelle NET_ThrowByNameWithLastError, NET_ThrowCurrent ou NET_ThrowNew d'une manière qui lancerait une SocketException avec ce message d'erreur par défaut.

en ce qui concerne les appels système, nous ne semblons pas aller aussi loin que l'appel système 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 awaitnSEVERE: StandardServer.await: accept: njava.net.SocketException: Invalid argumentntat java.net.PlainSocketImpl.socketAccept(Native Method)ntat java.net.PlainSocketImpl.socketAcce", 0x644)    = 1604 0

Donc, J' penser le problème se produit dans le code de gestion du délai en haut de la boucle accept en socketAccept, mais je ne pouvais pas trouver tous les cas où NET_Timeout seraiterrnoEINVAL, et entraîne le lancement de cette SocketException. Je fais allusion à l' ce code; je suppose que la branche jdk7u est pour la plupart ce que les navires dans L'Oracle JDK:

Help!

je ne trouve pas quiconque dans le monde extérieur affecté par ce problème particulier sur Mac OS, mais presque tout le monde ici est affecté. Il doit y avoir une certaine configuration de l'application qui contribue, mais j'ai épuisé toutes les avenues auxquelles je peux penser pour trouver la cause profonde.

des conseils sur le dépannage ou sur une cause possible seraient très appréciés.

28
demandé sur Community 2013-04-24 15:48:58

4 réponses

Avez-vous essayé tournant sur la JNI de débogage-Xcheck:jni? Il est intéressant de noter l' documentation Oracle utilise un PlainSocketImpl.socketAccept erreur comme un exemple de l'utilisation de ce.

Notez aussi que l'implication de bogue 7131399 c'est que la JNI utilise poll() sur la plupart des plateformes mais select() sur Mac OS en raison d'un problème avec poll() sur le Mac. Alors peut-être select() est cassé aussi. En creusant un peu plus loin, select () retournera EINVAL si " ndfs est plus grand que FD_SETSIZE et _DARWIN_UNLIMITED_SELECT n'est pas défini."FD_SETSIZE est 1024 et il semble que vous avez une tonne d'applications de chargement vers le haut, donc peut-être que tout se Filtre vers le bas à attendre sur plus que 1024 FDs à la fois.

pour les crédits supplémentaires, voir si la (soi-disant fixe) bug de Java est en fait fixé sur votre machine. Le rapport de bogue contient des conseils pour tester les cas.

grâce à la réponse du Vieux Pro, j'ai confirmé que le select() la limitation FD_SETSIZE est la cause. J'ai localisé un bug existant pour cette limitation:

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

Le problème peut être reproduit avec le code suivant:

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();
  }
}

Presqu'un an plus tard, Java 7u60 a une solution à ce problème:

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

j'ai aussi découvert le Tomcat WebappClassLoader ferme les poignées de fichier après 90 secondes, ce qui explique pourquoi le réglage des points de rupture a empêché le problème de se produire.

21
répondu Danny Thomas 2014-11-25 14:28:20

j'ai eu exactement le même problème (avec Tomcat7), et ce qui semble fonctionner pour moi est de cocher l'option "Publier les contextes de modules pour séparer les fichiers XML" lorsque j'exécute tomcat à L'intérieur D'Eclipse. Avez-vous essayé de qui déjà?

1
répondu Clement 2013-05-01 06:55:56

Obtenir OpenJDK avec la correction:

http://www.java.net/download/jdk7u60/archive/b15/binaries/jdk-7u60-ea-bin-b15-macosx-x86_64-16_apr_2014.dmg

a Fonctionné pour moi!

1
répondu user3642751 2014-05-15 22:14:51

j'ai été aux prises avec ce problème dans un autre contexte. Solution(s) combiné à partir de différentes sources ressembler suivante:

  • mettre à Jour /etc/hosts avec la prochaine remplace:
    • ::1 EWD-MacBook-Pro.local
    • 127.0.0.1 EWD-MacBook-Pro.Local localhost

(EWD-MacBook-Pro.locale est mon nom de machine)

et

  • système de réglage propriété:
    • java.net.preferIPv4Stack = > true
    • java.net.preferIPv6Addresses = > false

Bonne chance!

0
répondu Petro Semeniuk 2013-05-01 13:18:09