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)
