[ https://issues.apache.org/jira/browse/OOZIE-2385?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14948148#comment-14948148 ]
Hadoop QA commented on OOZIE-2385: ---------------------------------- Testing JIRA OOZIE-2385 Cleaning local git workspace ---------------------------- {color:green}+1 PATCH_APPLIES{color} {color:green}+1 CLEAN{color} {color:green}+1 RAW_PATCH_ANALYSIS{color} . {color:green}+1{color} the patch does not introduce any @author tags . {color:green}+1{color} the patch does not introduce any tabs . {color:green}+1{color} the patch does not introduce any trailing spaces . {color:green}+1{color} the patch does not introduce any line longer than 132 . {color:green}+1{color} the patch does adds/modifies 1 testcase(s) {color:green}+1 RAT{color} . {color:green}+1{color} the patch does not seem to introduce new RAT warnings {color:green}+1 JAVADOC{color} . {color:green}+1{color} the patch does not seem to introduce new Javadoc warnings {color:green}+1 COMPILE{color} . {color:green}+1{color} HEAD compiles . {color:green}+1{color} patch compiles . {color:green}+1{color} the patch does not seem to introduce new javac warnings {color:green}+1 BACKWARDS_COMPATIBILITY{color} . {color:green}+1{color} the patch does not change any JPA Entity/Colum/Basic/Lob/Transient annotations . {color:green}+1{color} the patch does not modify JPA files {color:red}-1 TESTS{color} - patch does not compile, cannot run testcases {color:green}+1 DISTRO{color} . {color:green}+1{color} distro tarball builds with the patch ---------------------------- {color:red}*-1 Overall result, please check the reported -1(s)*{color} The full output of the test-patch run is available at . https://builds.apache.org/job/oozie-trunk-precommit-build/2575/ > org.apache.oozie.TestCoordinatorEngineStreamLog.testCoordLogStreaming is > flakey > ------------------------------------------------------------------------------- > > Key: OOZIE-2385 > URL: https://issues.apache.org/jira/browse/OOZIE-2385 > Project: Oozie > Issue Type: Bug > Components: tests > Affects Versions: trunk > Reporter: Robert Kanter > Assignee: Robert Kanter > Fix For: trunk > > Attachments: OOZIE-2385.001.patch > > > {{org.apache.oozie.TestCoordinatorEngineStreamLog.testCoordLogStreaming}} is > flakey. > It can fail with an error like this: > {noformat} > junit.framework.ComparisonFailure: expected:<Tue Oct 06 16:27:2[5] PDT 2015> > but was:<Tue Oct 06 16:27:2[4] PDT 2015> > at junit.framework.Assert.assertEquals(Assert.java:85) > at junit.framework.Assert.assertEquals(Assert.java:91) > at > org.apache.oozie.TestCoordinatorEngineStreamLog.__CLR4_0_38acukov0f(TestCoordinatorEngineStreamLog.java:202) > at > org.apache.oozie.TestCoordinatorEngineStreamLog.testCoordLogStreaming(TestCoordinatorEngineStreamLog.java:103) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at junit.framework.TestCase.runTest(TestCase.java:168) > at junit.framework.TestCase.runBare(TestCase.java:134) > at junit.framework.TestResult$1.protect(TestResult.java:110) > at junit.framework.TestResult.runProtected(TestResult.java:128) > at junit.framework.TestResult.run(TestResult.java:113) > at junit.framework.TestCase.run(TestCase.java:124) > at junit.framework.TestSuite.runTest(TestSuite.java:243) > at junit.framework.TestSuite.run(TestSuite.java:238) > at > org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83) > at org.junit.runners.Suite.runChild(Suite.java:128) > at org.junit.runners.Suite.runChild(Suite.java:24) > at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) > at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at java.util.concurrent.FutureTask.run(FutureTask.java:262) > 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:744) > {noformat} > This was tricky to track down. The problem is essentially that the filtering > API uses minute granularity but the actions are seconds, or even milliseconds > apart, so there are some edge cases here. The code takes minute granularity, > goes back to milliseconds when querying the DB, and then uses seconds when > checking that the test worked correctly. > This can lead to a situation like this example: > \@1 created/nominal time: Oct 06 16:27:24 <and some milliseconds> > \@2 created/nominal time: Oct 06 16:27:25 <and some milliseconds> > The test passes \@2's created time as the starting time argument to the > filter, converted with {{DateUtill's}} UTC MASK (i.e. minutes granularity): > - Oct 06 16:27 > This gets parsed back to a Date object, which seconds/milliseconds assumed to > be 0's > - Oct 06 16:27:00 0000 > This gets turned into a TimeStamp object, and used in the DB filtering query > - gets all actions with created time > Oct 06 16:27:00, which includes \@1 > CoordinatorEngine sorts by action ID (i.e. \@#) and uses created time of > smallest, which is \@1 > - Oct 06 16:27:24 > The test checks that \@2’s created time is equal to previously determined > time from filter (i.e. \@1’s created time) > - Does a toString(), which uses seconds —-> not equal > Note: The filter querying is actually done against the nominal times, but the > example is simpler without all that and conveys the same idea. > The actions get created within 100s of milliseconds during the test (at least > on my machine), so most of them time, they have the same seconds, and the > toString() comparison is equal. When the timing works out that the first and > second action are created at different clock seconds (even if less than a > second apart), it fails. I couldn’t reproduce this on my machine, but is > more likely to happen on the generally slower Jenkins machines we run because > the time between action creations will be longer. > Basically the problem is that the filtering works at a minute granularity but > the actions are seconds, if not milliseconds, apart. In the real world this > isn’t a big deal because the API takes minutes and we simply use that, but to > verify the test is working we should simply make the actions minutes apart. > To fix this, we can just directly insert the job and actions into the DB > instead of actually running it so we can space the actions apart by minutes; > this should also make the test faster as well (the test takes about 6 minutes > on my machine as-is, but only 1 minute and 30 seconds with the fix). -- This message was sent by Atlassian JIRA (v6.3.4#6332)