1. casa
  2. Domanda e risposta
  3. Blocco thread Java

Blocco thread Java

2010-08-20 18 views
5

Ho un problema con il mio ambiente java. Sto gestendo Solr 1.3 (motore di ricerca) da più di un anno e improvvisamente ho avuto molti problemi con esso. Tutti i miei pool di thread (250) sono stati bloccati casualmente una o due volte al giorno. Non ho apportato alcuna modifica alla mia applicazione solr o al mio server tomcat.Blocco thread Java

Sono in esecuzione tomcat 5.5.25 e Solr 1.3. Ho ottenuto una discarica thread quando il sistema è completamente sovraccarico:

igot come 240 filo come questo:

"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)

Possiamo vedere che questa discussione è bloccata e in attesa di: < 0x00007fe37e72b340>

il filo che effettivamente possiede il < 0x00007fe37e72b340> è questa:

"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)

e questa è l'ultima parte del mio thre annuncio discarica:

"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

So che questo non è un prob filo situazione di stallo in quanto un thread è in realtà runnning con tutte le ressource ogni altro thread vuole.

Qualcuno ha un'idea di cosa può causare questo problema?

fonte

2010-08-20 Alexandre Boudreault

risposta

0

ho mai usato java.util.logging, quindi non so se il mio suggerimento è utile, ma netherless:
tenta di utilizzare un'istanza diversa di java.util.logging.Logger, quindi non tutti i 240 discussioni verranno bloccati sullo stesso monitor
(si aiuterà se istanze diverse di Logger utilizzano istanze diverse di java.util.logging.ConsoleHandler).

fonte

2010-08-20 14:26:51

0

Sembra che il thread che possiede "0x00007fe37e72b340" sia bloccato a livello di IO. Forse un problema di disco (raid?)?

è possibile eseguire un dump del thread 5 minuti dopo per vedere se lo stesso thread è ancora bloccato?

fonte

2010-08-20 14:27:12

+0

Grazie per i suggerimenti, non riesco a monitorare l'attività del thread durante il prossimo crash in un paio d'ore;) –

5

Tutti i tuoi thread stanno registrando le cose. Tutti hanno bisogno di scrivere sul disco di volta in volta. Ogni volta che uno dei 240 thread raggiunge una linea di registrazione, ci saranno problemi di accesso al disco.

Mi sconcerta che il thread con il blocco sia nello stato RUNNABLE.

Penso che potrebbe essere in attesa di un po 'di ressource esterna per essere rilasciato (come l'accesso al disco, per esempio)

Sei in esecuzione spazio su disco? Hai recentemente cambiato qualcosa nel tuo sistema di archiviazione?

fonte

2010-08-20 14:29:56 BenoitParis

+1

Penso che questa sia la traccia giusta. Guarderei i fattori esterni. Inoltre, se si scrive non in un file tradizionale ma in una pipe con nome Unix, assicurarsi che qualcuno stia leggendo l'altra estremità della pipe a un ritmo adeguato. Se il buffer si riempie, bloccherai. –

+0

Lo spazio su disco va bene e non abbiamo cambiato nulla sul sistema. Abbiamo provato a cambiare il sistema su un altro server e abbiamo avuto lo stesso problema. –

+0

Non penso che questo sia un problema con la sicurezza di Thread. Si sarebbe rotto molto prima. 240 thread non è un problema per la JVM. 240 I thread che modificano un singolo file potrebbero essere. Una brutta soluzione sarebbe ridurre la quantità di messaggi registrati. Prova a modificare la cosa utilizzando getLoggerNames(), getLogger() e setLevel() da http://download-llnw.oracle.com/javase/1.4.2/docs/api/java/util/logging/LogManager.html e http://download-llnw.oracle.com/javase/1.4.2/docs/api/java/util/logging/Logger.html – BenoitParis

0

Il lavaggio dopo ogni record di registro è costoso se si dispone di registri molto dettagliati.

Una correzione di qualità consisterebbe nel pulire la registrazione, probabilmente basata sul controllo.

Come soluzione rapida, ignorare StreamHandler.flush o OutputStream.flush per non farlo immediatamente. Lavare solo una volta ogni tanto. Si noti, tuttavia, che si potrebbe potenzialmente perdere i dati di registrazione immediatamente prima di un arresto anomalo, se si esegue questa operazione.

fonte

2010-08-20 14:35:08

5

Se si utilizza Windows e l'applicazione java avvia una console, fare attenzione a non fare clic nella casella DOS. Il marchio di merda di Windows e la "funzionalità" di copia bloccano l'output su ConsoleHandler. Quindi qualsiasi registratore che tenta di scrivere sullo schermo si bloccherà. La scrittura sulla console avviene in una chiamata nativa e quindi il thread java apparirà in uno stato RUNNING quando in realtà è bloccato, non c'è modo di restituire lo stato bloccato all'applicazione (perché si è nativi spazio).

Se l'applicazione è bloccata (è stato fatto clic nella casella DOS), premere Esc per continuare.

fonte

2012-06-20 13:21:20

0

In base al registro, il problema riguarda l'utilizzo di java.util.logging.ConsoleHandler.

Prima prova a disabilitare il gestore della console rimuovendolo dall'elenco 'handler' e '.handlers' in '$ {TOMCAT_HOME} /conf/logging.properties'. Verifica se il problema si verifica ancora.

Se ciò aiuta, è sicuramente un problema con l'output di ConsoleHandler. Prova a verificare se sono presenti problemi relativi al file "catalina.out". Questo è il file in cui tomcat reindirizza l'output della console.

fonte

2013-12-11 20:05:19 dstibbe

Problemi correlati

 Problemi correlati