Its certainly happening when its trying to switch to a new log file. It doesn't try and close the file otherwise. Why there is such a pause doing it, I dunno. Perhaps because there are tons of file descriptors around?
Does it happen on a fresh system, or did it just start after running for a long time? I recently found and resolved a file descriptor leak in the java replication code. -- - Mark http://www.lucidimagination.com Jeffery Newburn wrote: > I originally thought it was replication but one of the servers > exhibited the same issue with polling disabled. If it is tomcat why > would it block for so long on a simple log rotation? > > Additionally, we see similar things during the day. Replication often > is around the occurance but never at the same time > > > > On Sep 27, 2009, at 8:32 AM, "Yonik Seeley" > <yo...@lucidimagination.com> wrote: > >> Perhaps something like Tomcat rotating it's log files nightly? >> >> -Yonik >> http://www.lucidimagination.com >> >> On Sun, Sep 27, 2009 at 11:13 AM, Mark Miller <markrmil...@gmail.com> >> wrote: >>> Doesn't sound so random ;) >>> >>> Do you have anything specific going on at that time? Replication, >>> something else scheduled? Pretty odd it would happen at around the same >>> time every night unless something is set to occur then ... >>> >>> Jeff Newburn wrote: >>>> It appears that a few seconds after midnight every night our solr 1.4 >>>> instances block for about 15-30 seconds and stop serving search >>>> requests. I >>>> have included a stack trace of the the running thread and one that is >>>> blocked by it. Please let me know of any way I can stop this or if >>>> it is a >>>> solr issue at all. >>>> >>>> "http-8080-exec-5" - Thread t...@37 >>>> java.lang.Thread.State: RUNNABLE >>>> at java.io.FileOutputStream.close0(Native Method) >>>> at java.io.FileOutputStream.close(FileOutputStream.java:279) >>>> at sun.nio.cs.StreamEncoder.implClose(StreamEncoder.java:301) >>>> at sun.nio.cs.StreamEncoder.close(StreamEncoder.java:130) >>>> - locked java.io.FileWriter@@">295650d <monitor://> >>>> at java.io.OutputStreamWriter.close(OutputStreamWriter.java:216) >>>> at java.io.PrintWriter.close(PrintWriter.java:295) >>>> - locked java.io.FileWriter@@">295650d <monitor://> >>>> at org.apache.juli.FileHandler.close(FileHandler.java:159) >>>> at org.apache.juli.FileHandler.publish(FileHandler.java:120) >>>> - locked org.apache.juli.FileHandler@@">e0f34c <monitor://> >>>> at java.util.logging.Logger.log(Logger.java:472) >>>> at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:587) >>>> at >>>> org.slf4j.impl.JDK14LoggerAdapter.info(JDK14LoggerAdapter.java:284) >>>> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1341) >>>> at >>>> org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:3 >>>> >>>> 03) >>>> at >>>> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java: >>>> >>>> 232) >>>> at >>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Application >>>> >>>> FilterChain.java:235) >>>> at >>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterCh >>>> >>>> ain.java:206) >>>> at >>>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.ja >>>> >>>> va:233) >>>> at >>>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.ja >>>> >>>> va:175) >>>> at >>>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128 >>>> >>>> ) >>>> at >>>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102 >>>> >>>> ) >>>> at >>>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java >>>> >>>> :109) >>>> at >>>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286) >>>> >>>> at >>>> org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java: >>>> >>>> 879) >>>> at >>>> org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(H >>>> >>>> ttp11NioProtocol.java:719) >>>> at >>>> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java: >>>> >>>> 2080) >>>> at >>>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja >>>> >>>> va:885) >>>> at >>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9 >>>> >>>> 07) >>>> at java.lang.Thread.run(Thread.java:619) >>>> Locked ownable synchronizers: >>>> - locked >>>> java.util.concurrent.locks.ReentrantLock$NonfairSync@@">b5117a >>>> <monitor://> >>>> >>>> >>>> "http-8080-exec-6" - Thread t...@38 >>>> java.lang.Thread.State: BLOCKED on >>>> org.apache.juli.filehand...@e0f34c5 >>>> owned by: http-8080-exec-5 >>>> at java.util.logging.Handler.getLevel(Handler.java:250) >>>> at java.util.logging.Handler.isLoggable(Handler.java:267) >>>> at org.apache.juli.FileHandler.publish(FileHandler.java:107) >>>> at java.util.logging.Logger.log(Logger.java:472) >>>> at org.slf4j.impl.JDK14LoggerAdapter.log(JDK14LoggerAdapter.java:587) >>>> at >>>> org.slf4j.impl.JDK14LoggerAdapter.info(JDK14LoggerAdapter.java:284) >>>> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1341) >>>> at >>>> org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:3 >>>> >>>> 03) >>>> at >>>> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java: >>>> >>>> 232) >>>> at >>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Application >>>> >>>> FilterChain.java:235) >>>> at >>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterCh >>>> >>>> ain.java:206) >>>> at >>>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.ja >>>> >>>> va:233) >>>> at >>>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.ja >>>> >>>> va:175) >>>> at >>>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128 >>>> >>>> ) >>>> at >>>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102 >>>> >>>> ) >>>> at >>>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java >>>> >>>> :109) >>>> at >>>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286) >>>> >>>> at >>>> org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java: >>>> >>>> 879) >>>> at >>>> org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(H >>>> >>>> ttp11NioProtocol.java:719) >>>> at >>>> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java: >>>> >>>> 2080) >>>> at >>>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja >>>> >>>> va:885) >>>> at >>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9 >>>> >>>> 07) >>>> at java.lang.Thread.run(Thread.java:619) >>>> Locked ownable synchronizers: >>>> - locked >>>> java.util.concurrent.locks.ReentrantLock$NonfairSync@@">1ac730b >>>> <monitor://> >>>> -- >>>> Jeff Newburn >>>> Software Engineer, Zappos.com >>>> jnewb...@zappos.com - 702-943-7562 >>>> >>>> >>>> >>> >>> >>> -- >>> - Mark >>> >>> http://www.lucidimagination.com >>> >>> >>> >>>
