[SOLR-11378] Solr can leak transaction logs if a commit happens during unload

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Assignee: Unassigned
• Reporter: Shalin Shekhar Mangar
• Created: 20/Sep/17 00:14
• Updated: 22/Feb/22 15:11

Description

I have a test called AutoscalingHistoryHandlerTest in the feature/autoscaling branch that fails fairly frequently due to the ObjectReleaseTracker complaining about TransactionLog not being closed. This happens because the solr core in question is being moved and is therefore unloaded but an auto-commit was in progress during this time. The commit does not succeed because a new searcher could not be opened and I think that causes the tlog reference to be leaked.

It should be possible to isolate this problem into a smaller test by continuously indexing documents with a commitWithin and unloading the core in the middle of indexing.

Here are the relevant stack traces:

21106 ERROR (commitScheduler-48-thread-1) [n:127.0.0.1:54191_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.u.CommitTracker auto commit error...:org.apache.solr.common.SolrException: Error opening new searcher
	at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:2076)
	at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:2196)
	at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1933)
	at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:710)
	at org.apache.solr.update.CommitTracker.run(CommitTracker.java:222)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.solr.common.SolrException: openNewSearcher called on closed core
	at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:2063)
	... 11 more

java.lang.AssertionError: ObjectTracker found 1 object(s) that were not released!!! [TransactionLog]
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.update.TransactionLog
	at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
	at org.apache.solr.update.TransactionLog.<init>(TransactionLog.java:190)
	at org.apache.solr.update.UpdateLog.newTransactionLog(UpdateLog.java:446)
	at org.apache.solr.update.UpdateLog.ensureLog(UpdateLog.java:1259)
	at org.apache.solr.update.UpdateLog.add(UpdateLog.java:532)
	at org.apache.solr.update.UpdateLog.add(UpdateLog.java:517)
	at org.apache.solr.update.DirectUpdateHandler2.doNormalUpdate(DirectUpdateHandler2.java:347)
	at org.apache.solr.update.DirectUpdateHandler2.addDoc0(DirectUpdateHandler2.java:266)
	at org.apache.solr.update.DirectUpdateHandler2.addDoc(DirectUpdateHandler2.java:216)
	at org.apache.solr.update.processor.RunUpdateProcessor.processAdd(RunUpdateProcessorFactory.java:67)
	at org.apache.solr.update.processor.UpdateRequestProcessor.processAdd(UpdateRequestProcessor.java:55)
	at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalAdd(DistributedUpdateProcessor.java:991)
	at org.apache.solr.update.processor.DistributedUpdateProcessor.versionAdd(DistributedUpdateProcessor.java:1207)
	at org.apache.solr.update.processor.DistributedUpdateProcessor.processAdd(DistributedUpdateProcessor.java:753)
	at org.apache.solr.update.processor.LogUpdateProcessorFactory$LogUpdateProcessor.processAdd(LogUpdateProcessorFactory.java:103)
	at org.apache.solr.handler.loader.JavabinLoader$1.update(JavabinLoader.java:98)
	at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec$1.readOuterMostDocIterator(JavaBinUpdateRequestCodec.java:188)
	at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec$1.readIterator(JavaBinUpdateRequestCodec.java:144)
	at org.apache.solr.common.util.JavaBinCodec.readObject(JavaBinCodec.java:311)
	at org.apache.solr.common.util.JavaBinCodec.readVal(JavaBinCodec.java:256)
	at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec$1.readNamedList(JavaBinUpdateRequestCodec.java:130)
	at org.apache.solr.common.util.JavaBinCodec.readObject(JavaBinCodec.java:276)
	at org.apache.solr.common.util.JavaBinCodec.readVal(JavaBinCodec.java:256)
	at org.apache.solr.common.util.JavaBinCodec.unmarshal(JavaBinCodec.java:178)
	at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec.unmarshal(JavaBinUpdateRequestCodec.java:195)
	at org.apache.solr.handler.loader.JavabinLoader.parseAndLoadDocs(JavabinLoader.java:108)
	at org.apache.solr.handler.loader.JavabinLoader.load(JavabinLoader.java:55)
	at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:97)
	at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
	at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:177)
	at org.apache.solr.core.SolrCore.execute(SolrCore.java:2484)
	at org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:720)
	at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:526)
	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:382)
	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)

Issue Links

• is related to: SOLR-15695 "openNewSearcher called on closed core" SolrException on shutdown