[jira] [Created] (OAK-2144) Intermittent Node not found at given revision with DocumentNodeStore

["Chetan Mehrotra (JIRA)" <ji...@apache.org>]

Chetan Mehrotra created OAK-2144:
------------------------------------

             Summary: Intermittent Node not found at given revision with DocumentNodeStore
                 Key: OAK-2144
                 URL: https://issues.apache.org/jira/browse/OAK-2144
             Project: Jackrabbit Oak
          Issue Type: Bug
          Components: mongomk
            Reporter: Chetan Mehrotra
             Fix For: 1.1, 1.0.7


In a cluster deployment intermittent issue related to node not found at given revision are observed. Mostly such logs are coming from Onservation logic which performs diff and read node from two different revision. 

{noformat}
24.09.2014 09:11:45.513 *WARN* [pool-5-thread-5] org.apache.jackrabbit.oak.jcr.observation.ChangeProcessor Error while dispatching observation events
java.lang.NullPointerException: Node at [/var/eventing/jobs/assigned/62f1f24b-027e-4434-b1ef-a7a3c2c90e16/logouttopic/2014/9/24/15/12] not found for fromRev [r148a837accc-0-4]
	at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:236)
{noformat}

For the timings (all converted to UTC)
* Log - 2014-09-24T16:11:45.513 UTC 
* Read Revision r148a837accc-0-4 - 2014-09-24T15:11:34.092 UTC (T1)
* Created Revision r148a83824e4-0-2 - 2014-09-24T15:12:04.836 UTC (T2)

As can be seen that node is actually created at time T2 > T1. Now DocumentNodeStore has a logic [1] which determines the revision based on prevision revision seen for a given cluster instance. Now it can happen that when some read call fetches child for a given path then it records that those child exist at given readRevision and this readRevision might be in past. Later when revision node cache gets purged and revision child node cache still retains the entry call to read node at given revision would fail.

{noformat}
qa:PRIMARY> db.nodes.findOne({_id: "11:/var/eventing/jobs/assigned/62f1f24b-027e-4434-b1ef-a7a3c2c90e16/logouttopic/2014/9/24/15/12" })
{
        "_id" : "11:/var/eventing/jobs/assigned/62f1f24b-027e-4434-b1ef-a7a3c2c90e16/logouttopic/2014/9/24/15/12",
        "_lastRev" : {
                "r0-0-2" : "r148a873e2ee-0-2",
                "r0-0-1" : "r148a8b3ffa7-0-1"
        },
        "jcr:primaryType" : {
                "r148a83824e4-0-2" : "\"nam:sling:Folder\"",
                "r148a8b3ffa7-0-1" : null
        },
        "_commitRoot" : {
                "r148a83824e4-0-2" : "0",
                "r148a8382505-0-2" : "0",
                "r148a8b3ffa7-0-1" : "0"
        },
        "_modified" : NumberLong(1411579640),
        "jcr:createdBy" : {
                "r148a83824e4-0-2" : "\"admin\"",
                "r148a8b3ffa7-0-1" : null
        },
        "_deleted" : {
                "r148a83824e4-0-2" : "false",
                "r148a8b3ffa7-0-1" : "true"
        },
        "sling:resourceType" : {
                "r148a83824e4-0-2" : "\"sling:Folder\"",
                "r148a8b3ffa7-0-1" : null
        },
        "jcr:created" : {
                "r148a83824e4-0-2" : "\"dat:2014-09-24T15:12:04.825Z\"",
                "r148a8b3ffa7-0-1" : null
        },
        "_modCount" : NumberLong(42),
        "_children" : true,
        "_deletedOnce" : true
}

{noformat}

[1] https://github.com/apache/jackrabbit-oak/blob/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/Revision.java#L543-615



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)