Details
-
Bug
-
Status: Open
-
Major
-
Resolution: Unresolved
-
None
-
None
-
None
-
Mac os x yosemite v10.10.1
Description
ClockTest.testAlarmOrder test fails intermittently when I execute 'mvn clean package' ( about 1 failure per 5-10 executions )
log:
... ... Running org.apache.reef.wake.test.time.ClockTest May 12, 2015 12:23:15 AM org.apache.reef.wake.time.runtime.RuntimeClock <init> FINE: RuntimeClock instantiated. May 12, 2015 12:23:15 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Subscribe event handlers May 12, 2015 12:23:15 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Initiate runtime start May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.RuntimeStart[0] May 12, 2015 12:23:15 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Initiate start time May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.MissingStartHandlerHandler onNext WARNING: No binding to Clock.StartHandler. It is likely that the clock will immediately go idle and close. May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[0] May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[0] May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[100] May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[300] May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[600] May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[1000] May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[1500] May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[2100] May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[2800] May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[3600] May 12, 2015 12:23:15 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[4500] May 12, 2015 12:23:17 AM org.apache.reef.wake.time.runtime.RuntimeClock close INFO: Clock.close() May 12, 2015 12:23:17 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.event.StopTime[4501] May 12, 2015 12:23:17 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.RuntimeStop[4501] May 12, 2015 12:23:17 AM org.apache.reef.wake.time.runtime.RuntimeClock logThreads FINE: Threads running after exiting the clock main loop: process reaper, pool-14-thread-1, Signal Dispatcher, pool-8-thread-2, pool-18-thread-7, pool-18-thread-6, pool-8-thread-4, Thread-2056, pool-18-thread-1, Submitter-pool-9-thread-1, pool-18-thread-3, main, pool-8-thread-5, Finalizer, pool-18-thread-4, ForkJoinPool-1-worker-2, SingleThreadStage<org.apache.reef.wake.test.ThreadPoolStageTest$TestEventHandlerA>, pool-18-thread-5, pool-8-thread-3, pool-8-thread-1, Submitter-pool-9-thread-2, Submitter-pool-9-thread-3, pool-9-thread-1, pool-13-thread-1, Reference Handler, pool-18-thread-2, May 12, 2015 12:23:17 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Runtime clock exit May 12, 2015 12:23:17 AM org.apache.reef.wake.time.runtime.RuntimeClock <init> FINE: RuntimeClock instantiated. May 12, 2015 12:23:17 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Subscribe event handlers May 12, 2015 12:23:17 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Initiate runtime start May 12, 2015 12:23:17 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.RuntimeStart[0] May 12, 2015 12:23:17 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Initiate start time May 12, 2015 12:23:17 AM org.apache.reef.wake.impl.MissingStartHandlerHandler onNext WARNING: No binding to Clock.StartHandler. It is likely that the clock will immediately go idle and close. May 12, 2015 12:23:17 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[1000] May 12, 2015 12:23:19 AM org.apache.reef.wake.time.runtime.RuntimeClock close INFO: Clock.close() May 12, 2015 12:23:19 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.event.StopTime[1001] May 12, 2015 12:23:19 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.RuntimeStop[1001] May 12, 2015 12:23:19 AM org.apache.reef.wake.time.runtime.RuntimeClock <init> FINE: RuntimeClock instantiated. May 12, 2015 12:23:19 AM org.apache.reef.wake.time.runtime.RuntimeClock logThreads FINE: Threads running after exiting the clock main loop: process reaper, pool-14-thread-1, Signal Dispatcher, pool-8-thread-2, pool-18-thread-7, pool-18-thread-6, pool-8-thread-4, pool-18-thread-1, Submitter-pool-9-thread-1, pool-18-thread-3, main, pool-8-thread-5, Finalizer, pool-18-thread-4, Thread-2057, ForkJoinPool-1-worker-2, SingleThreadStage<org.apache.reef.wake.test.ThreadPoolStageTest$TestEventHandlerA>, pool-18-thread-5, pool-8-thread-3, pool-8-thread-1, Submitter-pool-9-thread-2, Submitter-pool-9-thread-3, pool-9-thread-1, pool-13-thread-1, Reference Handler, pool-18-thread-2, May 12, 2015 12:23:19 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Runtime clock exit May 12, 2015 12:23:19 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Subscribe event handlers May 12, 2015 12:23:19 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Initiate runtime start May 12, 2015 12:23:19 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.RuntimeStart[1431357799313] May 12, 2015 12:23:19 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Initiate start time May 12, 2015 12:23:19 AM org.apache.reef.wake.impl.MissingStartHandlerHandler onNext WARNING: No binding to Clock.StartHandler. It is likely that the clock will immediately go idle and close. May 12, 2015 12:23:24 AM org.apache.reef.wake.time.runtime.RuntimeClock close INFO: Clock.close() May 12, 2015 12:23:24 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.event.StopTime[1431357804315] May 12, 2015 12:23:24 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.RuntimeStop[1431357804316] May 12, 2015 12:23:24 AM org.apache.reef.wake.time.runtime.RuntimeClock <init> FINE: RuntimeClock instantiated. May 12, 2015 12:23:24 AM org.apache.reef.wake.time.runtime.RuntimeClock logThreads FINE: Threads running after exiting the clock main loop: pool-14-thread-1, Signal Dispatcher, pool-8-thread-2, pool-18-thread-7, pool-18-thread-6, pool-8-thread-4, pool-18-thread-1, Submitter-pool-9-thread-1, pool-18-thread-3, main, pool-8-thread-5, Finalizer, pool-18-thread-4, ForkJoinPool-1-worker-2, SingleThreadStage<org.apache.reef.wake.test.ThreadPoolStageTest$TestEventHandlerA>, pool-18-thread-5, pool-8-thread-3, pool-8-thread-1, Submitter-pool-9-thread-2, Submitter-pool-9-thread-3, pool-9-thread-1, Thread-2058, pool-13-thread-1, Reference Handler, pool-18-thread-2, May 12, 2015 12:23:24 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Runtime clock exit May 12, 2015 12:23:24 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Subscribe event handlers May 12, 2015 12:23:24 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Initiate runtime start May 12, 2015 12:23:24 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.RuntimeStart[1431357804321] May 12, 2015 12:23:24 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Initiate start time May 12, 2015 12:23:24 AM org.apache.reef.wake.impl.MissingStartHandlerHandler onNext WARNING: No binding to Clock.StartHandler. It is likely that the clock will immediately go idle and close. May 12, 2015 12:23:29 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.IdleClock[1431357809322] May 12, 2015 12:23:29 AM org.apache.reef.wake.time.runtime.RuntimeClock close INFO: Clock.close() Tests run: 4, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 14.585 sec <<< FAILURE! - in org.apache.reef.wake.test.time.ClockTest testAlarmOrder(org.apache.reef.wake.test.time.ClockTest) Time elapsed: 2.059 sec <<< FAILURE! org.junit.internal.ArrayComparisonFailure: arrays first differed at element [2]; expected:<200> but was:<300> at org.junit.internal.ComparisonCriteria.arrayEquals(ComparisonCriteria.java:50) at org.junit.Assert.internalArrayEquals(Assert.java:473) at org.junit.Assert.assertArrayEquals(Assert.java:394) at org.junit.Assert.assertArrayEquals(Assert.java:405) at org.apache.reef.wake.test.time.ClockTest.testAlarmOrder(ClockTest.java:158) Running org.apache.reef.wake.test.TimerStageTest May 12, 2015 12:23:29 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.event.StopTime[1431357809826] May 12, 2015 12:23:29 AM org.apache.reef.wake.impl.LoggingEventHandler onNext FINE: org.apache.reef.wake.time.runtime.event.RuntimeStop[1431357809826] TEST testTimerStage May 12, 2015 12:23:29 AM org.apache.reef.wake.time.runtime.RuntimeClock logThreads FINE: Threads running after exiting the clock main loop: pool-14-thread-1, Signal Dispatcher, pool-8-thread-2, pool-18-thread-7, pool-18-thread-6, pool-8-thread-4, pool-18-thread-1, Submitter-pool-9-thread-1, pool-18-thread-3, main, pool-8-thread-5, Finalizer, pool-18-thread-4, ForkJoinPool-1-worker-2, SingleThreadStage<org.apache.reef.wake.test.ThreadPoolStageTest$TestEventHandlerA>, pool-18-thread-5, pool-8-thread-3, pool-8-thread-1, Submitter-pool-9-thread-2, Submitter-pool-9-thread-3, pool-9-thread-1, Thread-2059, pool-13-thread-1, Reference Handler, pool-18-thread-2, May 12, 2015 12:23:29 AM org.apache.reef.wake.time.runtime.RuntimeClock run FINE: Runtime clock exit 1 org.apache.reef.wake.impl.PeriodicEvent@1865b0e5 scheduled event at 1431357809928 2 org.apache.reef.wake.impl.PeriodicEvent@1865b0e5 scheduled event at 1431357810932 3 org.apache.reef.wake.impl.PeriodicEvent@1865b0e5 scheduled event at 1431357811933 4 org.apache.reef.wake.impl.PeriodicEvent@1865b0e5 scheduled event at 1431357812931 5 org.apache.reef.wake.impl.PeriodicEvent@1865b0e5 scheduled event at 1431357813930 6 org.apache.reef.wake.impl.PeriodicEvent@1865b0e5 scheduled event at 1431357814929 7 org.apache.reef.wake.impl.PeriodicEvent@1865b0e5 scheduled event at 1431357815932 8 org.apache.reef.wake.impl.PeriodicEvent@1865b0e5 scheduled event at 1431357816933 9 org.apache.reef.wake.impl.PeriodicEvent@1865b0e5 scheduled event at 1431357817932 10 org.apache.reef.wake.impl.PeriodicEvent@1865b0e5 scheduled event at 1431357818929 Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 9.081 sec - in org.apache.reef.wake.test.TimerStageTest May 12, 2015 12:23:38 AM org.apache.reef.wake.impl.WakeSharedPool close INFO: ending pool stage: java.util.concurrent.ForkJoinPool@41917d6d[Running, parallelism = 10, size = 1, active = 0, running = 0, steals = 1000000, tasks = 0, submissions = 0] Results : Failed tests: ClockTest.testAlarmOrder:158 arrays first differed at element [2]; expected:<200> but was:<300> Tests run: 66, Failures: 1, Errors: 0, Skipped: 0