1. Accueil
  2. Question et réponse
  3. Blocage du fil Java

Blocage du fil Java

2010-08-20 12 views
5

J'ai un problème avec mon environnement Java. Je cours Solr 1.3 (moteur de recherche) depuis plus d'un an maintenant et soudainement j'ai eu beaucoup de problèmes avec lui. Tout mon pool de threads (250) a été bloqué au hasard une ou deux fois par jour. Je n'ai fait aucun changement sur mon application solr ou sur mon serveur Tomcat.Blocage du fil Java

Je cours tomcat 5.5.25 et Solr 1.3. Je suis une décharge de fil lorsque le système est totalement surchargé:

igot comme 240 fil comme celui-ci:

"http-8080-Processor1" daemon prio=10 tid=0x0000000000b2e000 nid=0x193 waiting for monitor entry [0x000000004066c000..0x000000004066cb20] 
    java.lang.Thread.State: BLOCKED (on object monitor) 
    at java.util.logging.StreamHandler.publish(StreamHandler.java:174) 
    - waiting to lock <0x00007fe37e72b340> (a java.util.logging.ConsoleHandler) 
    at java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:88) 
    at java.util.logging.Logger.log(Logger.java:472) 
    at java.util.logging.Logger.doLog(Logger.java:494) 
    at java.util.logging.Logger.log(Logger.java:517) 
    at java.util.logging.Logger.info(Logger.java:1036) 
    at org.apache.solr.core.SolrCore.execute(SolrCore.java:1212) 
    at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:303) 
    at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:232) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188) 
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213) 
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:172) 
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) 
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117) 
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108) 
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151) 
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:874) 
    at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665) 
    at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528) 
    at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81) 
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689) 
    at java.lang.Thread.run(Thread.java:619)

On peut voir que ce fil est bloqué et en attente sur: < 0x00007fe37e72b340>

le fil qui possèdent en fait le < 0x00007fe37e72b340> est celui-ci:

"http-8080-Processor156" daemon prio=10 tid=0x0000000000df2000 nid=0x1e52 runnable [0x0000000044521000..0x0000000044521c20] 
    java.lang.Thread.State: RUNNABLE 
    at java.io.FileOutputStream.writeBytes(Native Method) 
    at java.io.FileOutputStream.write(FileOutputStream.java:260) 
    at java.io.BufferedOutputStream.write(BufferedOutputStream.java:105) 
    - locked <0x00007fe37e3abcd8> (a java.io.BufferedOutputStream) 
    at java.io.PrintStream.write(PrintStream.java:430) 
    - locked <0x00007fe37e3abca0> (a java.io.PrintStream) 
    at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202) 
    at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:272) 
    at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:276) 
    at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:122) 
    - locked <0x00007fe37e72cd90> (a java.io.OutputStreamWriter) 
    at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:212) 
    at java.util.logging.StreamHandler.flush(StreamHandler.java:225) 
    - locked <0x00007fe37e72b340> (a java.util.logging.ConsoleHandler) 
    at java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:89) 
    at java.util.logging.Logger.log(Logger.java:472) 
    at java.util.logging.Logger.doLog(Logger.java:494) 
    at java.util.logging.Logger.log(Logger.java:517) 
    at java.util.logging.Logger.info(Logger.java:1036) 
    at org.apache.solr.core.SolrCore.execute(SolrCore.java:1212) 
    at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:303) 
    at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:232) 
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215) 
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188) 
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213) 
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:172) 
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) 
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117) 
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108) 
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151) 
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:874) 
    at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665) 
    at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528) 
    at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81) 
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689) 
    at java.lang.Thread.run(Thread.java:619)

ce qui est la dernière partie de mon thre dump annonce:

"ContainerBackgroundProcessor[StandardEngine[Catalina]]" daemon prio=10 tid=0x00007f6510349800 nid=0xbff waiting on condition [0x0000000041d8d000..0x0000000041d8dd20] 
    java.lang.Thread.State: TIMED_WAITING (sleeping) 
    at java.lang.Thread.sleep(Native Method) 
    at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1548) 
    at java.lang.Thread.run(Thread.java:619) 

"pool-1-thread-1" prio=10 tid=0x0000000000c26400 nid=0xbfe waiting on condition [0x000000004200e000..0x000000004200eca0] 
    java.lang.Thread.State: WAITING (parking) 
    at sun.misc.Unsafe.park(Native Method) 
    - parking to wait for <0x00007f651b275510> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) 
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158) 
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925) 
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358) 
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:946) 
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:906) 
    at java.lang.Thread.run(Thread.java:619) 

"Low Memory Detector" daemon prio=10 tid=0x00007f6510004400 nid=0xbfa runnable [0x0000000000000000..0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

"CompilerThread1" daemon prio=10 tid=0x00007f6510001000 nid=0xbf9 waiting on condition [0x0000000000000000..0x0000000040d5e340] 
    java.lang.Thread.State: RUNNABLE 

"CompilerThread0" daemon prio=10 tid=0x00000000006bc400 nid=0xbf8 waiting on condition [0x0000000000000000..0x0000000040c5d2d0] 
    java.lang.Thread.State: RUNNABLE 

"Signal Dispatcher" daemon prio=10 tid=0x00000000006bb000 nid=0xbf7 runnable [0x0000000000000000..0x0000000040b5da30] 
    java.lang.Thread.State: RUNNABLE 

"Finalizer" daemon prio=10 tid=0x0000000000690c00 nid=0xbf6 in Object.wait() [0x000000004065e000..0x000000004065ed20] 
    java.lang.Thread.State: WAITING (on object monitor) 
    at java.lang.Object.wait(Native Method) 
    - waiting on <0x00007f651aa10258> (a java.lang.ref.ReferenceQueue$Lock) 
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116) 
    - locked <0x00007f651aa10258> (a java.lang.ref.ReferenceQueue$Lock) 
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132) 
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159) 

"Reference Handler" daemon prio=10 tid=0x000000000068f400 nid=0xbf5 in Object.wait() [0x000000004055d000..0x000000004055dca0] 
    java.lang.Thread.State: WAITING (on object monitor) 
    at java.lang.Object.wait(Native Method) 
    - waiting on <0x00007f651aa10338> (a java.lang.ref.Reference$Lock) 
    at java.lang.Object.wait(Object.java:485) 
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116) 
    - locked <0x00007f651aa10338> (a java.lang.ref.Reference$Lock) 

"main" prio=10 tid=0x0000000000622400 nid=0xbeb runnable [0x0000000000000000..0x00007fff69fcbba0] 
    java.lang.Thread.State: RUNNABLE 

"VM Thread" prio=10 tid=0x000000000068a000 nid=0xbf4 runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x000000000062cc00 nid=0xbec runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x000000000062e000 nid=0xbed runnable 

"GC task thread#2 (ParallelGC)" prio=10 tid=0x000000000062f400 nid=0xbee runnable 

"GC task thread#3 (ParallelGC)" prio=10 tid=0x0000000000630400 nid=0xbef runnable 

"GC task thread#4 (ParallelGC)" prio=10 tid=0x0000000000631800 nid=0xbf0 runnable 

"GC task thread#5 (ParallelGC)" prio=10 tid=0x0000000000632c00 nid=0xbf1 runnable 

"GC task thread#6 (ParallelGC)" prio=10 tid=0x0000000000634000 nid=0xbf2 runnable 

"GC task thread#7 (ParallelGC)" prio=10 tid=0x0000000000635400 nid=0xbf3 runnable 

"VM Periodic Task Thread" prio=10 tid=0x00007f6510006800 nid=0xbfb waiting on condition 

JNI global references: 1201

Je sais que ce n'est pas un prob de blocage de fil depuis un thread est runnning en fait avec tous les tous les fils ressource veulent.

Quelqu'un at-il une idée de ce qui peut causer ce problème?

Source

2010-08-20 Alexandre Boudreault

Répondre

0

je jamais utilisé java.util.logging, donc je ne sais pas si ma suggestion est utile, mais netherless:
essayer d'utiliser différentes instance de java.util.logging.Logger, donc pas tous les 240 threads seront bloqués sur le même moniteur
(il aidera si différentes instances de Logger utilisent différentes instances de java.util.logging.ConsoleHandler).

Source

2010-08-20 14:26:51

0

Il semble que le thread propriétaire de "0x00007fe37e72b340" est bloqué au niveau des E/S. Peut-être un problème de disque (raid?)?

pouvez-vous faire un vidage de fil 5 minutes plus tard le voir si le même fil est toujours bloqué?

Source

2010-08-20 14:27:12

+0

Merci pour les conseils, mal essayer de surveiller l'activité du fil au cours du prochain accident dans une couple d'heure;) –

5

Tous vos threads enregistrent des choses. Ils ont tous besoin d'écrire sur le disque de temps en temps. Chaque fois que l'un de vos 240 threads rencontre une ligne de connexion, il y a des problèmes d'accès au disque.

Je me défie que le fil ayant le verrou est dans l'état RUNNABLE.

Je pense qu'il pourrait être en attente d'une ressource externe pour être libéré (comme l'accès au disque par exemple)

Êtes-vous Manquer d'espace disque? Avez-vous récemment changé quelque chose dans votre système de stockage?

Source

2010-08-20 14:29:56 BenoitParis

+1

Je pense que c'est la bonne voie. Je regarderais les facteurs externes. De même, si vous écrivez non pas dans un fichier traditionnel, mais dans un tube nommé Unix, assurez-vous que quelqu'un lit l'autre extrémité du tube à un rythme suffisant. Si le tampon se remplit, vous allez juste bloquer. –

+0

L'espace disque est correct et nous n'avons rien changé sur le système. Nous avons essayé de changer le système sur un autre serveur et nous avons eu le même problème. –

+0

Je ne pense pas que ce soit un problème avec la sécurité Thread. Cela aurait brisé beaucoup plus tôt. 240 Threads n'est pas un problème pour la JVM. 240 Threads éditant un seul fichier pourrait être. Une solution laide serait de réduire la quantité de messages enregistrés. Essayez de peaufiner la chose en utilisant getLoggerNames(), getLogger() et setLevel() depuis http://download-llnw.oracle.com/javase/1.4.2/docs/api/java/util/logging/LogManager.html et http://download-llnw.oracle.com/javase/1.4.2/docs/api/java/util/logging/Logger.html – BenoitParis

0

Le vidage après chaque enregistrement de journal coûte cher si vous avez des journaux très verbeux.

Une correction de qualité serait de nettoyer la journalisation, probablement basée sur l'audit.

En guise de solution rapide, remplacez StreamHandler.flush ou OutputStream.flush pour ne pas le faire immédiatement. Ne rincez qu'une fois de temps en temps. Notez toutefois que vous risquez de perdre des données de journalisation immédiatement avant un incident si vous le faites.

Source

2010-08-20 14:35:08

5

Si vous utilisez Windows et que l'application Java démarre une console, veillez à ne pas cliquer dans la zone DOS. La marque "ficelle" de marque et de copie de Windows bloque la sortie vers ConsoleHandler. Donc tout enregistreur qui essaie d'écrire à l'écran va bloquer. L'écriture sur la console se fait dans un appel natif et le thread java apparaîtra dans un état RUNNING alors qu'en fait il est bloqué, il n'y a aucun moyen de renvoyer ce statut bloqué à l'application (parce que vous êtes en natif espace).

Si l'application est bloquée (vous avez cliqué dans la boîte DOS), appuyez sur Échap pour continuer.

Source

2012-06-20 13:21:20

0

Selon votre journal, le problème concerne l'utilisation de java.util.logging.ConsoleHandler.

Essayez d'abord de désactiver le gestionnaire de console en le supprimant de la liste 'handlers' et '.handlers' dans '$ {TOMCAT_HOME} /conf/logging.properties'. Voir si le problème se produit toujours.

Si cela vous aide, c'est définitivement un problème avec la sortie de ConsoleHandler. Essayez de vérifier s'il y a des problèmes concernant le fichier 'catalina.out'. C'est le fichier où tomcat redirige la sortie de la console.

Source

2013-12-11 20:05:19 dstibbe

 Questions connexes

  • Aucun problème connexe^_^