Démarrage de Tomcat échoue en raison d'un 'java.net.Exception socketexception argument non Valide " sur Mac OS X

Nous avons une application qui s'exécute sur le serveur Tomcat 6 (6.0.35.0 pour être précis), et la plupart de nos ingénieurs sur Mac OS sont d'avoir des problèmes au démarrage de Tomcat en raison de la socketAccept appel dans le Catalina.attendent de la méthode de jeter une exception 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 Tomcat à l'arrêt immédiatement après le démarrage (et pas une petite quantité de rage).
Nous pensons que cela a été avec nous pendant la durée sur Mac OS w/Java 1.7, depuis plusieurs mois, beaucoup d'entre nous ont opté pour Macbook Pros. Jusqu'à maintenant, le seul symptôme était occasionnel de zéro octet réponses de Tomcat, en raison de cette exception s'être jeté sur un socketRead. Les erreurs à ne pas frapper les journaux et nous avions individuellement, il haussa les épaules comme un problème isolé, et seulement trouvé la cause lorsque le problème de démarrage a commencé et j'ai mis une exception socketexception point d'arrêt:

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 le temps sensible. L'augmentation du temps de démarrage en raison de la modification des applications (beaucoup plus de Ressort introspection/singleton frais généraux) semble être le facteur qui provoque cette affecter démarrage de Tomcat; le point de basculement étant d'environ 160 secondes. On peut atténuer le problème en désactivant certains de la non-obligatoire contextes nous n'avons pas besoin au cours du développement afin de réduire les temps de démarrage, mais je préfère trouver la cause.

De configuration de l'Application

Les particularités de la demande sont beaucoup trop complexes pour aller dans trop de détails, mais j'ai l'intuition que cela pourrait être lié à une précédente liaison, donc je vais au moins liste les ports en é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 récente modification de la configuration de notre base de configuration de l'application, les bibliothèques, les options JVM (il n'y a pas tout)
Un JDK de régression. J'ai testé JDK 1.7.0_09, 11, 15, 17 et 21 (le Jdk j'ai eu installé sur ma machine pour la durée)
Mise à jour Mac OS. Mac OS 10.7.x et 10.8.0 par 1.8.3 sont affectés
Limites des descripteurs de fichiers - augmentation de 5000 à 10000
De désactiver IPv6 complètement sur la principale interface ethernet
Définition de points d'arrêt, et la suppression de la première contextes d'être touchés par l'exception socketexception (ils sont HTTP sortants appels à des services web). Pas de changement
Configuration /etc/hosts de sorte que le nom d'hôte de la machine décide de localhost, et la configuration des options JVM à préférer IPv4 et pas préfèrent les adresses IPv6 (Cette réponse: https://stackoverflow.com/a/16318860/364206)

Pour ceux qui sont intéressés dans la configuration des hôtes, c'est la même chose en tant que par défaut. Je peux reproduire ce sur une Fusion VM w/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 l'apparente du temps de la nature sensible de la question, la définition 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é arg0 pour SocksSocketImpl(PlainSocketImpl).socketAccept(SocketImpl), rien ne semble hors 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 toutes les discussions où les exceptions sont levées, sont victimes d'un appel antérieur, l'une qui ne risque pas d'entraîner une exception socketexception donc je n'ai pas pu l'attraper. Être en mesure 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 prise de base de fonctionnement, ce qui affecte les autres opérations de socket.

Qui ne s'explique pas comment et pourquoi cela pourrait affecter plusieurs threads, peu importe ce que nous faisons à cause de ce problème, mystérieux SocketExceptions ne devrait pas remonter à partir de code natif et la cause de ces exceptions simultanément sur plusieurs threads - qui est, les deux fils à la prise de sortants appels de service web, Tomcat attendent d'appel, et de plusieurs TP processeur fils à plusieurs reprises.

JNI code enquête

Donné le message générique, je suppose qu'une EINVAL erreur doit être retourné à partir de l'un des appels système dans le socketAccept JNI code, donc j'ai tracé les appels système menant à l'exception; il n'y a pas EINVAL retourné à partir de tout système d'appel. Donc, je suis allé à l'OpenJDK sources de la recherche de conditions dans le socketAccept code qui permettrait de définir et de jeter un EINVAL, mais je n'arrivais pas à trouver le code qui définit errno à EINVAL, ou des appels NET_ThrowByNameWithLastError, NET_ThrowCurrent ou NET_ThrowNew de manière à lancer une exception socketexception avec ce message d'erreur par défaut.

Autant que le système des appels, nous ne semblons pas à aller aussi loin que le système d'appel accepter:

 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

Donc, je pense le problème se produit dans le délai de la manipulation de code en haut de l'accepter en boucle dans socketAccept, mais je ne pouvais pas trouver tous les cas où NET_Timeout serait mis errno à EINVAL, et de faire en sorte que cette exception socketexception être jeté. Je fais référence à ce code; je suppose que le jdk7u branche est, pour la plupart, que des navires dans l'Oracle JDK:

Aider!

Je ne peux pas trouver quelqu'un dans le monde extérieur touchés par ce problème particulier sur Mac OS, mais presque tout le monde ici est affecté. Il doit y avoir une configuration de l'application qui contribue, mais j'ai épuisé toutes les voies que je peux penser à trouver la cause.

Conseils sur le dépannage ou d'un aperçu sur une cause possible serait très apprécié.

Je suis aussi confronté à ce exactement le même problème lors du démarrage de Tomcat sur mon Mac. J'ai aussi une grande application web (uPortal) qui prend environ 100 secondes pour Tomcat pour le démarrage.
Génial d'avoir un "moi aussi". Étonnamment peu de choses sur cette ligne.
Pourriez-vous récupérer les valeurs qui sont passés à la méthode native et de la poster ici? Elle peut conduire à de nulle part, mais il vaut la peine de vérifier les arguments lorsque vous obtenez une "Argument non Valide" erreur 🙂
J'ai ajouté des détails pour arg0 pour SocksSocketImpl(PlainSocketImpl).socketAccept(SocketImpl), mais cette exception peut être levée lorsque apparemment identiques arguments sont passés dans l'
Ayant un problème similaire. Cela se bloque Eclipse - j'ai des projets avec un shitload de Pots dans les dépendances (calculée par le plugin), et Eclipse garde une ouverte FD pour chacun d'eux...
Puis-je vous demander, pourquoi avez-vous été à la recherche dans src/solaris/native dossier, tout en ayant un problème sur Mac OSX? Je suis actuellement à la recherche de sources natives de Mac, et je me demande si c'est un bon endroit?
pas très familier avec le JDK structure, mais il semble que c'est là que le code natif pour BSD trop de vies. J'ai remarqué des instructions conditionnelles pour Linux dans ce code trop, si mon hypothèse est que le Solaris sources sont à la base de tous les systèmes Unix.

InformationsquelleAutor Danny Thomas | 2013-04-24

21

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

Note également que l'implication de Bug 7131399 est que la JNI utilise poll() sur la plupart des plates-formes, mais select() sur Mac OS en raison d'un problème avec poll() sur le Mac. Alors peut-être select() est cassé aussi. Creuser un peu plus loin, sélectionnez() retournera EINVAL si "les acnp est plus grand que FD_SETSIZE et _DARWIN_UNLIMITED_SELECT n'est pas défini." FD_SETSIZE est de 1024 et il semble que vous avez une tonne d'applications de chargement, donc peut-être tous les filtres vers le bas à l'attente sur plus de 1024 FDs à la fois.

Pour le crédit supplémentaire, voir si connexes (supposé fixe) bug de Java est en fait fixé sur votre machine. Le rapport de bug a des pointeurs à des cas de test.

Grâce à Vieille Pro de la réponse, j'ai confirmé que le select() FD_SETSIZE limitation est la cause. J'ai repéré un bug existant à 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();
}
}
```
Près d'un an plus tard, Java 7u60 a résoudre 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 descripteurs de fichiers après 90 secondes, ce qui explique pourquoi les points de rupture empêché le problème de se produire.
- Je n'avais pas essayé -Xcheck:jni. Il rend le démarrage prendre beaucoup plus de sorte que le problème ne se produit pas; je suppose que le lien de cause et de la victime appelle arrive trop loin avec cette option. Au moins pas de problème a été constaté avec la personne JNI appels. J' a remarqué que select() a été utilisé sur Mac OS, il est indiqué clairement sur NET_Timeout dans bsd_close.c. Je vais essayer un JDK version encore utilisé poll() pour voir si c'est peut-être liée à ce changement, mais 7u5 a été le premier officiel de l'Oracle JDK version pour Mac OS et cela a été corrigé dans u4. Je vais regarder de plus près à ces scénarios de test la semaine prochaine.
- Creuser un peu plus loin, select() sera de retour EINVAL si "ndfs est plus grand que FD_SETSIZE et _DARWIN_UNLIMITED_SELECT n'est pas défini." FD_SETSIZE est de 1024 et il semble que vous avez une tonne d'applications de chargement, donc peut-être tous les filtres vers le bas à l'attente sur plus de 1024 FDs à la fois.
- Maintenant, ce une possibilité distincte! Chargeur de classe de l'activité à partir du Printemps pourrait à lui seul peut-être à cause de cela. Très prometteuses.
- Ça expliquerait pourquoi c'est le moment sensibles et de faire chanceler-à partir de la solution correcte.
- ...et l'utilisation de sélectionner plus de sondage pourquoi c'est Mac OS spécifique.
- Ce bogue a été corrigé dans 7u60. Ne semble pas avoir une date de sortie encore, mais early access versions sont disponibles à l'adresse jdk7.java.net/download.html
- Le select FD_SETSIZE limitation de bug la référence est marquée fixe dans le JDK 8, mais, comme pour sigget, la mise à niveau vers le début de l'accès JDK 7u60 résout ce problème pour moi. Si vous êtes en cours d'exécution dans intermittent SocketExceptions sur OS X et vous ne faites pas beaucoup de connexions, donnez-7u60 un essai.
- J'ai eu cette erreur en essayant de se connecter VisualVM sur 7u51 mais le problème semble être déjà fixé sur la dernière version 7u55.
- elasticsearch 1.4.0 souffre de cette question
- Bien holy crap, j'ai rencontré le même problème et la mise à niveau vers u75, il fixe. Je crois que c'est encore la seule ressource qui explique le problème et sa solution - merci!
InformationsquelleAutor
1

J'ai eu exactement le même problème (avec Tomcat7), et ce qui semble fonctionner pour moi est de cocher "Publier module de contextes pour séparer les fichiers XML" option quand je suis en cours d'exécution de tomcat depuis Eclipse. Avez-vous essayé de qui déjà?
- Nous ne configurer les contextes dans server.xml, il y a 51 contextes configuré statiquement. Nous avons un autre de 80 ou plus déployé de manière dynamique par notre plugin cadre. Cela semble plus proche de la solution, qu'une cause. Avez-vous des informations sur pourquoi cela fait-il une différence? Voyez-vous le zéro octet à la suite de problèmes?
InformationsquelleAutor Clement
1

Obtenir OpenJDK avec le correctif:

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!
- Cette mise à jour ne fonctionne pas sur OSX Yosemite. Voir java.com/en/download/help/mac_10_10.xml . Utilisation 7u71 ou 7u72 à la place.
InformationsquelleAutor user3642751
0

J'ai été aux prises avec ce problème dans un autre contexte. Solution(s) combiné à partir de différentes sources ressembler suivante:
- Mise à jour de /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
- De définir les propriétés système:
  - java.net.preferIPv4Stack => true
  - java.net.preferIPv6Addresses => false
Bonne chance!
- Prometteur réponse, mais pas de chance j'ai peur 🙁
InformationsquelleAutor Petro Semeniuk

Vous devez vous connecter pour publier un commentaire.