[jira] [Assigned] (SLING-6945) avoid unnecessary log.error when OakViewChecker is deactivated

["Stefan Egli (JIRA)" <ji...@apache.org>]

     [ https://issues.apache.org/jira/browse/SLING-6945?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Stefan Egli reassigned SLING-6945:
----------------------------------

    Assignee: Stefan Egli

> avoid unnecessary log.error when OakViewChecker is deactivated
> --------------------------------------------------------------
>
>                 Key: SLING-6945
>                 URL: https://issues.apache.org/jira/browse/SLING-6945
>             Project: Sling
>          Issue Type: Improvement
>          Components: Extensions
>    Affects Versions: Discovery Base 2.0.0
>            Reporter: Stefan Egli
>            Assignee: Stefan Egli
>             Fix For: Discovery Base 2.0.2
>
>
> The following series of log messages has been noticed:
> {noformat}06.06.2017 11:47:41.774 *INFO* [Discovery-AsyncEventSender] org.apache.sling.discovery.oak.pinger.OakViewChecker triggerAsyncConnectorPing: firing job to trigger heartbeat
> 06.06.2017 11:47:41.811 *INFO* [OsgiInstallerImpl] org.apache.sling.discovery.oak.pinger.OakViewChecker deactivate: deactivated slingId: c2caefd0-7aab-4fbb-a120-985d6174d7ea, this: org.apache.sling.discovery.oak.pinger.OakViewChecker@7a9f2f75
> 06.06.2017 11:47:41.812 *ERROR* [sling-default-3-discovery.connectors.common.runner.c2caefd0-7aab-4fbb-a120-985d6174d7ea490b04a4-42f2-464a-ab15-15520e78e3a3] org.apache.sling.discovery.oak.pinger.OakViewChecker announcementRegistry is null
> 06.06.2017 11:47:45.339 *INFO* [OsgiInstallerImpl] org.apache.sling.discovery.oak Service [org.apache.sling.discovery.oak.pinger.OakViewChecker,10971, [org.apache.sling.discovery.oak.pinger.OakViewChecker]] ServiceEvent UNREGISTERING
> 06.06.2017 11:47:50.753 *INFO* [OsgiInstallerImpl] org.apache.sling.discovery.oak Service [org.apache.sling.discovery.oak.pinger.OakViewChecker,14874, [org.apache.sling.discovery.oak.pinger.OakViewChecker]] ServiceEvent REGISTERED
> 06.06.2017 11:47:50.757 *INFO* [OsgiInstallerImpl] org.apache.sling.discovery.oak.pinger.OakViewChecker doActivate: activated with runtimeId: 82b0e439-6040-44d0-abd7-6c0cbbb62339, slingId: c2caefd0-7aab-4fbb-a120-985d6174d7ea
> {noformat}
> Or in other words:
>  * {{11:47:41.774}} a topology event triggering a heartbeat (a normal, low-level operation) happens
>  * {{11:47:41.811}} OakViewChecker deactivate
>  * {{11:47:41.812}} the heartbeat that was triggered before is now executed asynchronously (via scheduler) and fails because deactivate already {{null}}-ed the {{announcementRegistry}}
> So this means {{OakViewChecker.deactivate}} didn't stop an already scheduled, asynchronous heartbeat - which then subsequently fails because deactivate has already happened.
> Or, put slightly differently, {{deactivate}} and {{heartbeatAndCheckView}} are not synchronized (due to SLING-3365).
> As a simple measure {{BaseViewChecker.doCheckView}} should be made thread-safe, ie it should be aware that deactivate can be called concurrently.
> And the log.error should probably be lowered to log.info



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)