easyforgood / mockito

Automatically exported from code.google.com/p/mockito
0 stars 0 forks source link

ConcurrentModificationException in verify with times+timeout #322

Closed GoogleCodeExporter closed 8 years ago

GoogleCodeExporter commented 8 years ago
What steps will reproduce the problem?
1. Just run the junit test here below :-)

What is the expected output? What do you see instead?

the expected behavior would be a verify pass or verify exception
I get a stack trace thrown instead :

java.util.ConcurrentModificationException
    at java.util.LinkedList$LinkIterator.next(LinkedList.java:119)
    at java.util.LinkedList.addAll(LinkedList.java:380)
    at java.util.LinkedList.<init>(LinkedList.java:257)
    at org.mockito.internal.verification.RegisteredInvocations.getAll(RegisteredInvocations.java:36)
    at org.mockito.internal.stubbing.InvocationContainerImpl.getInvocations(InvocationContainerImpl.java:117)
    at org.mockito.internal.verification.VerificationDataImpl.getAllInvocations(VerificationDataImpl.java:28)
    at org.mockito.internal.verification.Times.verify(Times.java:36)
    at org.mockito.internal.verification.VerificationWithTimeoutImpl.verify(VerificationWithTimeoutImpl.java:28)
    at org.mockito.verification.Timeout.verify(Timeout.java:44)
    at org.mockito.internal.verification.MockAwareVerificationMode.verify(MockAwareVerificationMode.java:21)
    at org.mockito.internal.MockHandler.handle(MockHandler.java:80)
    at org.mockito.internal.InvocationNotifierHandler.handle(InvocationNotifierHandler.java:36)
    at org.mockito.internal.creation.MethodInterceptorFilter.intercept(MethodInterceptorFilter.java:48)
    at mockitoconcurr.MockitoConcurrentTest$ITarget$$EnhancerByMockitoWithCGLIB$$12dac83.targetMethod(<generated>)
    at mockitoconcurr.MockitoConcurrentTest.testInvocationConcurrently(MockitoConcurrentTest.java:37)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
    at java.lang.reflect.Method.invoke(Method.java:611)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
    at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)

What version of the product are you using? On what operating system?
Mockito 1.9.0 on Linux (RHEL 6.2, IBM Java 6 SR10)

Please provide any additional information below.

testcase that throws the problem

package mockitoconcurr;

import static org.mockito.Mockito.reset;
import static org.mockito.Mockito.timeout;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.verifyNoMoreInteractions;

import java.util.concurrent.Callable;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

import org.junit.Before;
import org.junit.Test;
import org.mockito.Mockito;

public class MockitoConcurrentTest {

    int nThreads = 1;
    static final int TEST_MILLIS = 1000;
    static final int INTERVAL_MILLIS = 10;
    static final int TIMES = TEST_MILLIS / INTERVAL_MILLIS;

    ITarget target = Mockito.mock(ITarget.class);
    ExecutorService fixedThreadPool;

    @Before
    public void setUp() {
        target = Mockito.mock(ITarget.class);
        fixedThreadPool = Executors.newFixedThreadPool(nThreads);
    }

    @Test
    public void testInvocationConcurrently() throws Exception {
        reset(target);
        startInvocations();
        verify(target, timeout(TEST_MILLIS).times(TIMES*nThreads)).targetMethod("arg");
        verifyNoMoreInteractions(target);
    }

    private void startInvocations() throws InterruptedException,
            ExecutionException {

        for(int i=0; i<nThreads; i++) {
            fixedThreadPool.submit(new TargetInvoker(i));
        }

    }

    public class TargetInvoker implements Callable<Object> {

        private final int seq;

        TargetInvoker(int seq) {
            this.seq = seq;
        }

        @Override
        public Object call() throws Exception {
            System.err.println("started " + seq);
            for (int i = 0; i < TIMES; i++) {
                Thread.yield();
                target.targetMethod("arg");
                Thread.sleep((long) INTERVAL_MILLIS);
            }
            System.err.println("finished" + seq);
            return seq;
        }

    }

    public static interface ITarget {

        public String targetMethod(String arg);
    }

}

Original issue reported on code.google.com by edoco...@gmail.com on 29 Feb 2012 at 2:22

GoogleCodeExporter commented 8 years ago
The problem goes away by adding a synchronization lock :

changing
org.mockito.internal.verification.RegisteredInvocations

from

    public List<Invocation> getAll() {
        return ListUtil.filter(new LinkedList<Invocation>(invocations), new RemoveToString());
    }

to

    public List<Invocation> getAll() {
        synchronized (invocations) {
        return ListUtil.filter(new LinkedList<Invocation>(invocations), new RemoveToString());
        }
    }

Original comment by edoco...@gmail.com on 29 Feb 2012 at 2:54

GoogleCodeExporter commented 8 years ago
please also note that even though the invocations field in 
RegisteredInvocations is a synchronized list:

public class RegisteredInvocations implements Serializable {
...
    private final List<Invocation> invocations = Collections.synchronizedList(new LinkedList<Invocation>());

any iterations on it still must be synchronized 

http://docs.oracle.com/javase/6/docs/api/java/util/Collections.html#synchronized
List%28java.util.List%29

I suppose my proposed patch could be refined by synchronizing only in creating 
the new list copy, then releasing the lock and then returning the filtered 
copy. 

Original comment by edoco...@gmail.com on 29 Feb 2012 at 3:25

GoogleCodeExporter commented 8 years ago
public List<Invocation> getAll() {
        LinkedList<Invocation> invocationsCopy;
        synchronized (invocations) {
            invocationsCopy = new LinkedList<Invocation>(invocations);
        }
        return ListUtil.filter(invocationsCopy, new RemoveToString());
    }

Original comment by edoco...@gmail.com on 29 Feb 2012 at 3:27

GoogleCodeExporter commented 8 years ago
Well spotted. Thx a lot for the report and the possible fix.

Original comment by brice.du...@gmail.com on 29 Feb 2012 at 4:50

GoogleCodeExporter commented 8 years ago
I just added this fix in the attached patch. 

Original comment by Jose.Pau...@gmail.com on 7 Mar 2012 at 7:56

Attachments:

GoogleCodeExporter commented 8 years ago
@edocomar With José and Eric we tried to reproduce with your test, but we 
didn't success, we had different OS and JVMs, tried different values in your 
test.
Do you have an actual values that would make this issue visible.

However we all definitely agree on the proposed fix.

Original comment by brice.du...@gmail.com on 9 Mar 2012 at 4:38

GoogleCodeExporter commented 8 years ago
Hi
 the values I posted made the ConcurrentModificationException happen for me.

I just tried on a Mac 10.7.4, java.runtime.version=1.6.0_29-b11-402-11D50b
and no matter what values I use the CME never occurs.

maybe it's down to how the real threading occurs, how many cpus/cores.

Original comment by edoco...@gmail.com on 9 Mar 2012 at 5:22

GoogleCodeExporter commented 8 years ago
Mac 10.7.3

Original comment by edoco...@gmail.com on 9 Mar 2012 at 5:22

GoogleCodeExporter commented 8 years ago
Yeah I got the very same version of OSX and JVM. And I have a dual core 
machine. However it is noteworthy that we didn't test it on a RHEL and 
especially on an IBM JVM. That would be awesome if you could verify that as we 
don't have acces to an IBM JVM.

Original comment by brice.du...@gmail.com on 9 Mar 2012 at 5:30

GoogleCodeExporter commented 8 years ago
I had verified it on RHEL when I posted ... will try again just for making sure.

Original comment by edoco...@gmail.com on 9 Mar 2012 at 8:31

GoogleCodeExporter commented 8 years ago
ok, I tried again I can confirm that 
without the patch my test fails with the CME above and with the patch, my test 
passes.

java.fullversion=JRE 1.6.0 IBM J9 2.6 Linux amd64-64 20111113_94967  (JIT 
enabled, AOT enabled)

Linux  2.6.32-220.4.2.el6.x86_64 #1 SMP Mon Feb 6 16:39:28 EST 2012 x86_64 
x86_64 x86_64 GNU/Linux

Original comment by edoco...@gmail.com on 9 Mar 2012 at 9:31

GoogleCodeExporter commented 8 years ago
OK, great, thank you very much for the time you spent validating the issue.
We can comment the test with these details now, as it was not reproductible 
under other circumstances.

Original comment by brice.du...@gmail.com on 9 Mar 2012 at 9:47

GoogleCodeExporter commented 8 years ago

Original comment by szcze...@gmail.com on 13 May 2012 at 3:37

GoogleCodeExporter commented 8 years ago

Original comment by szcze...@gmail.com on 3 Jun 2012 at 2:06