[
https://issues.apache.org/jira/browse/OAK-3923?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15123204#comment-15123204
]
Alex Parvulescu commented on OAK-3923:
--------------------------------------
+1 very nice! it took some time to walk though the patch, but it's made of the
good stuff :)
one very minor thing: a log.info message needs a an extra space: "[CLOSED
OK]Async indexing" -> "[CLOSED OK] Async indexing" :)
one thing I'm worried about is the verbosity of logging in the patch. Given the
frequency of the indexer(s) I imagine this will happen a lot, so does it make
sense to have it report almost all of these messages on _info_ / _warn_? My
suggestion is to minimize the noise as much as possible and set all logs from
{{run}} and {{close}} to _debug_. If the hard limit is reached there's going to
the the {{INTERRUPTED}} error in the logs anyway, that's plenty to signal
what's going on.
Thinking about the {{INTERRUPTED}} error, does it make sense to make it even
clearer that it is considered a normal operations process, and not a failure?
how about instead of 'Indexing stopped' we say 'Indexing forcibly stopped due
to shutdown', or something?
> Async indexing delayed by 30 minutes because stop order is incorrect
> --------------------------------------------------------------------
>
> Key: OAK-3923
> URL: https://issues.apache.org/jira/browse/OAK-3923
> Project: Jackrabbit Oak
> Issue Type: Bug
> Components: core
> Reporter: Thomas Mueller
> Assignee: Chetan Mehrotra
> Fix For: 1.4
>
> Attachments: OAK-3923-v1.patch
>
>
> The stop order of Oak components is incorrect, and this can lead to an async
> indexing delay of 30 minutes, because the indexing lease is not removed. The
> problem is that the node store is stopped before the async index is stopped,
> so that async indexing can still be in progress, and then when async indexing
> is done, the lease can not be removed because the node store is not available.
> From the log file:
> {noformat}
> error.log:
> 21.01.2016 11:53:56.898 *INFO* [FelixStartLevel]
> org.apache.jackrabbit.oak-tarmk-standby BundleEvent STOPPED
> 21.01.2016 11:53:56.900 *INFO* [FelixStartLevel]
> org.apache.jackrabbit.oak-solr-osgi Service
> [org.apache.jackrabbit.oak.plugins.index.solr.osgi.SolrIndexEditorProviderService,571,
> [org.apache.jackrabbit.oak.plugins.index.IndexEditorProvider]] ServiceEvent
> UNREGISTERING
> ...
> 21.01.2016 11:53:56.930 *INFO* [FelixStartLevel]
> org.apache.jackrabbit.oak-lucene BundleEvent STOPPING
> 21.01.2016 11:53:56.930 *INFO* [FelixStartLevel]
> org.apache.jackrabbit.oak-lucene BundleEvent STOPPED
> 21.01.2016 11:53:56.931 *INFO* [FelixStartLevel]
> org.apache.jackrabbit.oak-core Service
> [org.apache.jackrabbit.oak.plugins.index.property.PropertyIndexProvider,405,
> [org.apache.jackrabbit.oak.spi.query.QueryIndexProvider]] ServiceEvent
> UNREGISTERING
> ...
> 21.01.2016 11:53:56.936 *INFO* [FelixStartLevel]
> com.adobe.granite.repository.impl.SlingRepositoryManager stop: Repository
> still running, forcing shutdown
> ...
> 21.01.2016 11:53:56.960 *WARN* [FelixStartLevel]
> org.apache.jackrabbit.oak.osgi.OsgiWhiteboard Error unregistering service:
> com.adobe.granite.repository.impl.SlingRepositoryManager$1@7c052458 of type
> java.util.concurrent.Executor
> java.lang.IllegalStateException: Service already unregistered.
> at
> org.apache.felix.framework.ServiceRegistrationImpl.unregister(ServiceRegistrationImpl.java:136)
> at
> org.apache.jackrabbit.oak.osgi.OsgiWhiteboard$1.unregister(OsgiWhiteboard.java:81)
> at
> org.apache.jackrabbit.oak.spi.whiteboard.CompositeRegistration.unregister(CompositeRegistration.java:43)
> at org.apache.jackrabbit.oak.Oak$6.close(Oak.java:592)
> ...
> 21.01.2016 11:56:50.985 *INFO* [FelixStartLevel]
> org.apache.jackrabbit.oak-core Service [763,
> [org.apache.jackrabbit.oak.plugins.segment.SegmentStoreProvider]]
> ServiceEvent UNREGISTERING
>
> debug.log:
> 21.01.2016 11:56:51.964 *WARN* [sling-default-4]
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate [async] The index
> update failed
> java.lang.IllegalStateException: service must be activated when used
> at
> com.google.common.base.Preconditions.checkState(Preconditions.java:150)
> at
> org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStoreService.getNodeStore(SegmentNodeStoreService.java:233)
> at
> org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStoreService.getNodeStore(SegmentNodeStoreService.java:92)
> at
> org.apache.jackrabbit.oak.spi.state.ProxyNodeStore.getRoot(ProxyNodeStore.java:36)
> at
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate$AsyncUpdateCallback.close(AsyncIndexUpdate.java:266)
> at
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.updateIndex(AsyncIndexUpdate.java:451)
> at
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.run(AsyncIndexUpdate.java:351)
>
> error.log:
> 21.01.2016 11:56:51.965 *ERROR* [sling-default-4]
> org.apache.sling.commons.scheduler.impl.QuartzScheduler Exception during job
> execution of
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate@1706b18c : service
> must be activated when used
> java.lang.IllegalStateException: service must be activated when used
> at
> com.google.common.base.Preconditions.checkState(Preconditions.java:150)
> at
> org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStoreService.getNodeStore(SegmentNodeStoreService.java:233)
> at
> org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStoreService.getNodeStore(SegmentNodeStoreService.java:92)
> at
> org.apache.jackrabbit.oak.spi.state.ProxyNodeStore.release(ProxyNodeStore.java:90)
> at
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate.run(AsyncIndexUpdate.java:372)
> at
> org.apache.sling.commons.scheduler.impl.QuartzJobExecutor.execute(QuartzJobExecutor.java:115)
> at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
