[jira] [Comment Edited] (OAK-6639) ObservationQueueFullWarnTest.testQueueFullThenFlushing fails sometimes

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

    [ https://issues.apache.org/jira/browse/OAK-6639?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16161365#comment-16161365 ] 

Stefan Egli edited comment on OAK-6639 at 9/11/17 2:39 PM:
-----------------------------------------------------------

Thanks [~catholicon] for spotting!
I've fixed this in rev [1808032|http://svn.apache.org/viewvc?rev=1808032&view=rev]
The issue was that when registering an Observer the Observable (typically, ours at least do) call contentChanged with an initial, empty commit info. That initial call still ends up on the BackgroundObserver's queue - so it actually occupies an additional entry - which was not correctly taken into account when designing the test. 
So the fix is to, after registering the listener (which is when the Observer is registered), sleep 2sec to give the BackgroundObserver enough time to process that initial contentChanged call.


was (Author: egli):
Thanks [~catholicon] for spotting!
I've fixed this in rev 1808032
The issue was that when registering an Observer the Observable (typically, ours at least do) call contentChanged with an initial, empty commit info. That initial call still ends up on the BackgroundObserver's queue - so it actually occupies an additional entry - which was not correctly taken into account when designing the test. 
So the fix is to, after registering the listener (which is when the Observer is registered), sleep 2sec to give the BackgroundObserver enough time to process that initial contentChanged call.

> ObservationQueueFullWarnTest.testQueueFullThenFlushing fails sometimes
> ----------------------------------------------------------------------
>
>                 Key: OAK-6639
>                 URL: https://issues.apache.org/jira/browse/OAK-6639
>             Project: Jackrabbit Oak
>          Issue Type: Test
>          Components: jcr
>            Reporter: Vikas Saurabh
>            Assignee: Stefan Egli
>            Priority: Minor
>             Fix For: 1.8, 1.7.8
>
>         Attachments: archive.zip, console.txt
>
>
> Very intermittently, {{ObservationQueueFullWarnTest.testQueueFullThenFlushing}} fails. It had failed once in one of our internal CI setups. And recently (thankfully??) on apache setup \[0] \[1] \[2].
> Description from Apache failure:
> ----
> h4. Error Message
> Just filled queue must not convert local->external expected:<6> but was:<4>
> h4. Stacktrace
> {noformat}
> java.lang.AssertionError: Just filled queue must not convert local->external expected:<6> but was:<4>
> 	at org.apache.jackrabbit.oak.jcr.observation.ObservationQueueFullWarnTest.testQueueFullThenFlushing(ObservationQueueFullWarnTest.java:312)
> {noformat}
> h4. Standard Output
> {noformat}
> storing: /testNode/local0
> storing: /testNode/local1
> storing: /testNode/local2
> storing: /testNode/local3
> storing: /testNode/local4
> storing: /testNode/local5
> GOT: 1 - COUNTER: 1
>  - Event{type=4, path=/testNode/local0, identifier=/testNode, info={jcr:primaryType=nt:unstructured, afterValue=0}, userID=admin, userData=null, date=1504862948917, external=false}
> GOT: 1 - COUNTER: 2
>  - Event{type=4, path=/testNode/local1, identifier=/testNode, info={jcr:primaryType=nt:unstructured, afterValue=1}, userID=admin, userData=null, date=1504862948918, external=false}
> GOT: 1 - COUNTER: 3
>  - Event{type=4, path=/testNode/local2, identifier=/testNode, info={jcr:primaryType=nt:unstructured, afterValue=2}, userID=admin, userData=null, date=1504862948919, external=false}
> GOT: 1 - COUNTER: 4
>  - Event{type=4, path=/testNode/local3, identifier=/testNode, info={jcr:primaryType=nt:unstructured, afterValue=3}, userID=admin, userData=null, date=1504862948919, external=false}
> GOT: 2 - COUNTER: 6
>  - Event{type=4, path=/testNode/local4, identifier=/testNode, info={jcr:primaryType=nt:unstructured, afterValue=4}, userID=oak:unknown, userData=null, date=1504862873156, external=true}
>  - Event{type=4, path=/testNode/local5, identifier=/testNode, info={jcr:primaryType=nt:unstructured, afterValue=5}, userID=oak:unknown, userData=null, date=1504862873156, external=true}
> {noformat}
> ----
> \[0]: https://lists.apache.org/thread.html/9c952201c132e2c6dce67b2d4fb13d9b0040d9874514885a9ed5bc9f@%3Coak-dev.jackrabbit.apache.org%3E
> \[1]: https://builds.apache.org/job/Jackrabbit%20Oak/722/
> \[2]: https://builds.apache.org/job/Jackrabbit%20Oak/722/org.apache.jackrabbit$oak-jcr/testReport/junit/org.apache.jackrabbit.oak.jcr.observation/ObservationQueueFullWarnTest/testQueueFullThenFlushing_SegmentTar_/



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