edgent-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Dale LaBossiere (JIRA)" <j...@apache.org>
Subject [jira] [Closed] (EDGENT-258) testMultiTopologyPollWithError failure; CME in TrackingScheduledExecutor.cancelAllAsyncTasks()
Date Mon, 06 Nov 2017 17:34:01 GMT

     [ https://issues.apache.org/jira/browse/EDGENT-258?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Dale LaBossiere closed EDGENT-258.
----------------------------------
    Resolution: Duplicate

Duplicate of EDGENT-435

> testMultiTopologyPollWithError failure; CME in TrackingScheduledExecutor.cancelAllAsyncTasks()
> ----------------------------------------------------------------------------------------------
>
>                 Key: EDGENT-258
>                 URL: https://issues.apache.org/jira/browse/EDGENT-258
>             Project: Edgent
>          Issue Type: Bug
>          Components: Runtime, Test
>            Reporter: Dale LaBossiere
>
> This happened in an (ant) travis-ci run.
> The DirectTStreamTest.testMultiTopologyPollWithError() test failed with a CancellationException
(end of the traces below).  Perhaps that was fallout from a CME reported within TrackingScheduledExecutor.cancelAllAsyncTasks()
on the iteration of asyncTasks @ TrackingScheduledExecutor:121 which is the line:
>             for (RunnableScheduledFuture<?> task : asyncTasks) {
> (there's also an InterruptedException below)
> But I don't see how that CME can happen.  asyncTasks is a (private) SynchronizedSet and
all iteration on it in TrackingScheduledExecutor does the required "synchronized(asyncTasks)
{ iterate... }" pattern.  The SynchronizedSet methods all synchronize on the SynchronizedSet
object (asyncTasks) too so 
> an operation like add() or remove() can't occur during that synchronized iteration. All
access to the underlying set is via the SynchronizedSet.  So how can that CME happen???
> The only possible non-CME-inducing flaw I see is in removeTrack() where there's the non-synchronized
sequential access:
>     asyncTasks.remove();
>     if (asyncTasks.isEmpty() ...   // hence may not reflect state following preceeding
remove()
> Note, there should normally only be 4 instances reporting "Expected Test Exception" but
there a 8 (maybe due to removeTrack()?).  Trust me, they're all from this test method execution.
 I've triple checked :-)
> I'm also confused a bit by the thread pool/thread ids reported on those 8 instances.
 Would have expected them to all be associated with the test's allocated fixed thread pool
and would have expected that to have a single pool with 4 thread.  But that doesn't seem to
be the case?
> Here's the various msgs from the test's execution.  Maybe someone else can figure it
out.  From https://travis-ci.org/apache/incubator-edgent/builds/164076026
>     [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.TrackingScheduledExecutor
afterExecute
>     [junit] SEVERE: Thread: pool-5-thread-7-0a765e86-37c1-4299-9655-118420e3f1be: task
terminated with exception : 
>     [junit] java.lang.RuntimeException: java.lang.RuntimeException: Expected Test Exception
>     [junit] 	at org.apache.edgent.oplet.core.PeriodicSource.run(PeriodicSource.java:83)
>     [junit] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>     [junit] 	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
>     [junit] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
>     [junit] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
>     [junit] 	at org.apache.edgent.runtime.etiao.TrackingScheduledExecutor$TrackedFuture.run(TrackingScheduledExecutor.java:205)
>     [junit] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>     [junit] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>     [junit] 	at org.apache.edgent.runtime.etiao.ThreadFactoryTracker$2.run(ThreadFactoryTracker.java:87)
>     [junit] 	at java.lang.Thread.run(Thread.java:745)
>     [junit] Caused by: java.lang.RuntimeException: Expected Test Exception
>     [junit] 	at org.apache.edgent.test.topology.TStreamTest.lambda$null$5f279479$1(TStreamTest.java:774)
>     [junit] 	at org.apache.edgent.test.topology.TStreamTest$$Lambda$8/2070622949.accept(Unknown
Source)
>     [junit] 	at org.apache.edgent.function.Functions$ThreadSafeConsumer.accept(Functions.java:204)
>     [junit] 	at org.apache.edgent.runtime.etiao.SettableForwarder.accept(SettableForwarder.java:54)
>     [junit] 	at org.apache.edgent.oplet.core.FanOut.accept(FanOut.java:50)
>     [junit] 	at org.apache.edgent.runtime.etiao.SettableForwarder.accept(SettableForwarder.java:54)
>     [junit] 	at org.apache.edgent.oplet.core.Source.submit(Source.java:47)
>     [junit] 	at org.apache.edgent.oplet.functional.SupplierPeriodicSource.fetchTuples(SupplierPeriodicSource.java:52)
>     [junit] 	at org.apache.edgent.oplet.core.PeriodicSource.run(PeriodicSource.java:81)
>     [junit] 	... 9 more
>    [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.ThreadFactoryTracker
trackedThreadUncaughtException
>     [junit] SEVERE: Uncaught exception in thread pool-5-thread-7-0a765e86-37c1-4299-9655-118420e3f1be
>     [junit] java.util.ConcurrentModificationException
>     [junit] 	at java.util.HashMap$HashIterator.nextNode(HashMap.java:1429)
>     [junit] 	at java.util.HashMap$KeyIterator.next(HashMap.java:1453)
>     [junit] 	at org.apache.edgent.runtime.etiao.TrackingScheduledExecutor.cancelAllAsyncTasks(TrackingScheduledExecutor.java:121)
>     [junit] 	at org.apache.edgent.runtime.etiao.TrackingScheduledExecutor.cleanup(TrackingScheduledExecutor.java:115)
>     [junit] 	at org.apache.edgent.runtime.etiao.TrackingScheduledExecutor.afterExecute(TrackingScheduledExecutor.java:88)
>     [junit] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1150)
>     [junit] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>     [junit] 	at org.apache.edgent.runtime.etiao.ThreadFactoryTracker$2.run(ThreadFactoryTracker.java:87)
>     [junit] 	at java.lang.Thread.run(Thread.java:745)
>     [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.TrackingScheduledExecutor
afterExecute
>     [junit] SEVERE: Thread: pool-4-thread-15-79a62c35-c201-4800-b5fe-0981a922a901: task
terminated with exception : 
>     [junit] java.lang.RuntimeException: java.lang.RuntimeException: Expected Test Exception
> ...  like the first above
>     [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.TrackingScheduledExecutor
afterExecute
>     [junit] SEVERE: Thread: pool-5-thread-11-0a765e86-37c1-4299-9655-118420e3f1be: task
terminated with exception : 
>     [junit] java.lang.RuntimeException: java.lang.RuntimeException: Expected Test Exception
> ...
>     [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.Executable invokeAction
>     [junit] SEVERE: Exception caught while waiting for future to complete
>     [junit] java.lang.InterruptedException
>     [junit] 	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
>     [junit] 	at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
>     [junit] 	at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:462)
>     [junit] 	at java.util.concurrent.ExecutorCompletionService.poll(ExecutorCompletionService.java:202)
>     [junit] 	at org.apache.edgent.runtime.etiao.Executable.invokeAction(Executable.java:222)
>     [junit] 	at org.apache.edgent.runtime.etiao.Executable.start(Executable.java:180)
>     [junit] 	at org.apache.edgent.runtime.etiao.EtiaoJob.stateChange(EtiaoJob.java:107)
>     [junit] 	at org.apache.edgent.providers.direct.DirectTopology.execute(DirectTopology.java:110)
>     [junit] 	at org.apache.edgent.providers.direct.DirectTopology.access$000(DirectTopology.java:46)
>     [junit] 	at org.apache.edgent.providers.direct.DirectTopology$1.call(DirectTopology.java:89)
>     [junit] 	at org.apache.edgent.providers.direct.DirectTopology$1.call(DirectTopology.java:85)
>     [junit] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>     [junit] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>     [junit] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>     [junit] 	at org.apache.edgent.runtime.etiao.TrackingScheduledExecutor$TrackedFuture.run(TrackingScheduledExecutor.java:205)
>     [junit] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>     [junit] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>     [junit] 	at org.apache.edgent.runtime.etiao.ThreadFactoryTracker$2.run(ThreadFactoryTracker.java:87)
>     [junit] 	at java.lang.Thread.run(Thread.java:745)
>    [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.TrackingScheduledExecutor
afterExecute
>     [junit] SEVERE: Thread: pool-5-thread-9-0a765e86-37c1-4299-9655-118420e3f1be: task
terminated with exception : 
>     [junit] java.lang.RuntimeException: java.lang.RuntimeException: Expected Test Exception
> ...
>    [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.TrackingScheduledExecutor
afterExecute
>     [junit] SEVERE: Thread: pool-4-thread-7-79a62c35-c201-4800-b5fe-0981a922a901: task
terminated with exception : 
>     [junit] java.lang.RuntimeException: java.lang.RuntimeException: Expected Test Exception
> ... 
>    [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.TrackingScheduledExecutor
afterExecute
>     [junit] SEVERE: Thread: pool-5-thread-8-0a765e86-37c1-4299-9655-118420e3f1be: task
terminated with exception : 
>     [junit] java.lang.RuntimeException: java.lang.RuntimeException: Expected Test Exception
> ...
>     [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.TrackingScheduledExecutor
afterExecute
>     [junit] SEVERE: Thread: pool-4-thread-8-79a62c35-c201-4800-b5fe-0981a922a901: task
terminated with exception : 
>     [junit] java.lang.RuntimeException: java.lang.RuntimeException: Expected Test Exception
> ...
>    [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.TrackingScheduledExecutor
afterExecute
>     [junit] SEVERE: Thread: pool-4-thread-1-79a62c35-c201-4800-b5fe-0981a922a901: task
terminated with exception : 
>     [junit] java.lang.RuntimeException: java.lang.RuntimeException: Expected Test Exception
> ...
>    [junit] Sep 30, 2016 4:37:46 PM org.apache.edgent.runtime.etiao.TrackingScheduledExecutor
afterExecute
>     [junit] SEVERE: Thread: pool-2-thread-1-b0a11f1a-309f-48d3-a0cc-72ccd245fefd: task
terminated with exception : 
>     [junit] java.lang.RuntimeException: java.lang.RuntimeException: Expected Test Exception
> ... 
> ==================================
> Reported test failure:
>     [junit] Testcase: testMultiTopologyPollWithError(org.apache.edgent.test.providers.direct.topology.DirectTStreamTest):
Caused an ERROR
>     [junit] java.util.concurrent.CancellationException
>     [junit] java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException
>     [junit] 	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
>     [junit] 	at java.util.concurrent.FutureTask.get(FutureTask.java:192)
>     [junit] 	at org.apache.edgent.test.topology.TStreamTest.waitForCompletion(TStreamTest.java:867)
>     [junit] 	at org.apache.edgent.test.topology.TStreamTest.testMultiTopologyPollWithError(TStreamTest.java:781)
>     [junit] Caused by: java.util.concurrent.CancellationException
>     [junit] 	at java.util.concurrent.FutureTask.report(FutureTask.java:121)
>     [junit] 	at java.util.concurrent.FutureTask.get(FutureTask.java:206)
>     [junit] 	at org.apache.edgent.runtime.etiao.TrackingScheduledExecutor$TrackedFuture.get(TrackingScheduledExecutor.java:255)
>     [junit] 	at org.apache.edgent.topology.spi.tester.AbstractTester.complete(AbstractTester.java:46)
>     [junit] 	at org.apache.edgent.test.topology.TopologyAbstractTest.complete(TopologyAbstractTest.java:72)
>     [junit] 	at org.apache.edgent.test.topology.TopologyAbstractTest.complete(TopologyAbstractTest.java:76)
>     [junit] 	at org.apache.edgent.test.topology.TStreamTest.lambda$testMultiTopologyPollWithError$2(TStreamTest.java:777)
>     [junit] 	at org.apache.edgent.test.topology.TStreamTest$$Lambda$1/1233595751.call(Unknown
Source)
>     [junit] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>     [junit] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>     [junit] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>     [junit] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>     [junit] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>     [junit] 	at java.lang.Thread.run(Thread.java:745)
>     [junit] 



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

Mime
View raw message