You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@oozie.apache.org by "Hadoop QA (JIRA)" <ji...@apache.org> on 2015/10/08 08:25:26 UTC
[jira] [Commented] (OOZIE-2385)
org.apache.oozie.TestCoordinatorEngineStreamLog.testCoordLogStreaming is
flakey
[ 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)