what could cause "incref on a closed log" exception

[Liu Bo <di...@gmail.com>]

Dear Solr users

We have a 2 shards solr cloud set up on 4 machines.
solr version: 4.6.0
web server: tomcat

One of our nodes(10.20.121.20) is down and hanged at recovering status. The
others are working fine.

>From the log I notice an unexpected tomcat restarting and then the cores
can't be loaded because of "incref on a closed log" error. It seems that
the transaction log is corrupted somehow.

My questions what might cause "incref on a closed log" error? Will
unexpected shut down cause this? Or an unstable server set up (the system
puppet had messed things up before).
This could help me to find out what's wrong and fix our solrcloud setup.

Your help will be much of my appreciation.

The first "incref on a closed log" seems happened while sync with node
10.20.123.25, the last one is the error from machine "10.20.121.20" itself.

Some of the exception logs (full log trace is attached):

while peerSync:

INFO  - 2014-04-09 19:04:59.281;
org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
WARN  - 2014-04-09 19:05:03.855; org.apache.solr.update.PeerSync; PeerSync:
core=shop url=http://10.20.121.20:8105/solr  exception talking to
http://10.20.123.25:8105/solr/shop/, failed
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException:
incref on a closed log:
tlog{file=/MSTR/alertApps/shardSearch/apache-tomcat-7.0.39/solr/shop/data/tlog/tlog.0000000000000000007
refcount=1}
at
org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:491)
at
org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:197)
at
org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:156)
at
org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:118)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
.....
WARN  - 2014-04-09 18:51:40.337;
org.apache.solr.common.cloud.ZkStateReader$3; ZooKeeper watch triggered,
but Solr cannot talk to ZK
ERROR - 2014-04-09 18:51:40.438; org.apache.zookeeper.ClientCnxn$1; from
localhost-startStop-1-SendThread(adcbg03.machine.wisdom.com:2181)
java.lang.NoClassDefFoundError: org/apache/zookeeper/server/ZooTrace
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1115)
Caused by: java.lang.ClassNotFoundException:
org.apache.zookeeper.server.ZooTrace
at
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1713)
at
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1558)
... 1 more


And then after a weird leader election process and all the cores are shut
down, and solr decided to restart itself again and again. Each restart ends
up with a "java.lang.NoClassDefFoundError:
org/apache/zookeeper/server/ZooTrace" error.
Eventually failed with errors:


INFO  - 2014-04-09 19:35:19.697; org.apache.solr.core.SolrCore; [shop]
webapp=/solr path=/get
params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2}
status=500 QTime=9
ERROR - 2014-04-09 19:35:19.699; org.apache.solr.common.SolrException;
null:org.apache.solr.common.SolrException: incref on a closed log:
tlog{file=/MSTR/alertApps/shardSearch/apache-tomcat-7.0.39/solr/shop/data/tlog/tlog.0000000000000000813
refcount=1}
at org.apache.solr.update.TransactionLog.incref(TransactionLog.java:494)
at org.apache.solr.update.UpdateLog.getRecentUpdates(UpdateLog.java:1022)
at
org.apache.solr.handler.component.RealTimeGetComponent.processGetVersions(RealTimeGetComponent.java:530)
at
org.apache.solr.handler.component.RealTimeGetComponent.process(RealTimeGetComponent.java:91)
at
org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:208)
at
org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
at org.apache.solr.core.SolrCore.execute(SolrCore.java:1859)
at
org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:710)
at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:413)
at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:197)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:680)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1009)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589)
at
org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:1810)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)


-- 
All the best

Liu Bo