New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Intermittent java.lang.IllegalStateException: Not in the recording phase #263

Closed
ishah opened this Issue Mar 1, 2016 · 8 comments

Comments

3 participants
@ishah

ishah commented Mar 1, 2016

  • Version of JMockit that was used: 1.21
  • Description of the problem or enhancement request:

One of our tests keeps failing occasionally on the CI build with the exception as below. We are running our tests using maven-surefire-plugin with forkMode set to always. Tests are not running in parallel.

java.lang.IllegalStateException: Not in the recording phase
    at com.dummy.DummyTest$1.<init>(DummyTest.java:67)
    at com.dummyDummyTest.setup(DummyTest.java:64)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:53)
    at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:119)
    at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:101)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.apache.maven.surefire.booter.ProviderFactory$ClassLoaderProxy.invoke(ProviderFactory.java:103)
    at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:150)
    at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcess(SurefireStarter.java:74)
    at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:69)

Its not reproducible on local as i mentioned it happens occasionally. The class tries to test the partially mocked class. The method where it fails looks like below

public class DummyTest {

    @Mocked Context ctx;

      ClassToBeTested cls;

 @Before
    public void setup() throws QBOException {
        cls = new SubClassToBeTested(); 
        new NonStrictExpectations() {
            {
                Context.getAuthenticatedContext();
                result = ctx;  //it fails here occasionally line no: 67
            }
            {
                ctx.getSomeMethod;
                result = "someString";
            }

        };
.........
}

The above test definitely need some refactoring but was wondering why does it fail occasionally and not always. I noticed similar issue being reported by someone at https://groups.google.com/forum/#!topic/jmockit-users/LknMgexD_jE

@ishah

This comment has been minimized.

Show comment
Hide comment
@ishah

ishah Mar 1, 2016

While debugging the test from eclipse by attaching jmockit source code to the debugger, I noticed that whenever new NonStrictExpectations() is called, it creates an instance of RecordAndReplayExecution and set the reference in currentRecordAndReplay in ExecutingTest. In our case as seen above in setup(), the constructor of SubClassToBeTested() is called which makes call to DB class(which is not mocked) and where there is this finalize() method as below

public class DB{
  protected void finalize() throws Throwable {
      if (Context.getUnAuthenticatedContext() != null && Context.getUnAuthenticatedContext()   ).getSomeMethod()!=null}{
.....
     }
  }
}

While debugging by setting breakpoints in jmockit classes, at some point I noticed, GC got triggered by JVM which invoked the above finalize() code in a "Daemon thread [finalizer]" and as it references Context which is mocked, it called below method

RecordAndReplayExecution.recordOrReplay(Object, int, String, String, String, int, Object[]) 

whereas main thread was executing new NonStrictExpectations() in setup() and was inside the constructor as below

public RecordAndReplayExecution(
      @Nonnull Expectations targetObject, @Nullable Object... classesOrInstancesToBePartiallyMocked)

I assume, here's when the race condition happened where Daemon thread and main thread ended up calling executingTest.setRecordAndReplay() at the same time with the different instance of RecordAndReplayExecution and hence overwriting recordPhase to null which was set by NonStrictExpectations() ie. by main thread. We are running our tests sequentially but as DB wasnt mocked and finalize() method runs in daemon thread, it seems it might be failing our test intermittently.

We can refactor the test to avoid this but was wondering if this is a bug in jmockit? I see below snippets in the RecordAndReplayExecution and it seems it clears currentRecordAndReplay first, then calls setRecordAndReplay() and then sets the lock TEST_ONLY_PHASE_LOCK.lock() in the end.

public RecordAndReplayExecution(
      @Nonnull Expectations targetObject, @Nullable Object... classesOrInstancesToBePartiallyMocked)
....  
       RecordAndReplayExecution previous = executingTest.getPreviousRecordAndReplay();

      ;;;
         recordPhase = new RecordPhase(this, strict, nonStrict);
         executingTest.setRecordAndReplay(this);
     ;;;
         //noinspection LockAcquiredButNotSafelyReleased
         TEST_ONLY_PHASE_LOCK.lock();
;;;;
}

where as RecordAndReplayExecution.recordOrReplay() checks for TEST_ONLY_PHASE_LOCK.lock() followed by checking currentRecordAndReplay if null which can possibly lead into the race condition or overwriting each other's value if Replay phase and Record phase both gets executed at the same time by main thread/daemon thread.

Also, this made me think if jmockit support running tests in parallel?

ishah commented Mar 1, 2016

While debugging the test from eclipse by attaching jmockit source code to the debugger, I noticed that whenever new NonStrictExpectations() is called, it creates an instance of RecordAndReplayExecution and set the reference in currentRecordAndReplay in ExecutingTest. In our case as seen above in setup(), the constructor of SubClassToBeTested() is called which makes call to DB class(which is not mocked) and where there is this finalize() method as below

public class DB{
  protected void finalize() throws Throwable {
      if (Context.getUnAuthenticatedContext() != null && Context.getUnAuthenticatedContext()   ).getSomeMethod()!=null}{
.....
     }
  }
}

While debugging by setting breakpoints in jmockit classes, at some point I noticed, GC got triggered by JVM which invoked the above finalize() code in a "Daemon thread [finalizer]" and as it references Context which is mocked, it called below method

RecordAndReplayExecution.recordOrReplay(Object, int, String, String, String, int, Object[]) 

whereas main thread was executing new NonStrictExpectations() in setup() and was inside the constructor as below

public RecordAndReplayExecution(
      @Nonnull Expectations targetObject, @Nullable Object... classesOrInstancesToBePartiallyMocked)

I assume, here's when the race condition happened where Daemon thread and main thread ended up calling executingTest.setRecordAndReplay() at the same time with the different instance of RecordAndReplayExecution and hence overwriting recordPhase to null which was set by NonStrictExpectations() ie. by main thread. We are running our tests sequentially but as DB wasnt mocked and finalize() method runs in daemon thread, it seems it might be failing our test intermittently.

We can refactor the test to avoid this but was wondering if this is a bug in jmockit? I see below snippets in the RecordAndReplayExecution and it seems it clears currentRecordAndReplay first, then calls setRecordAndReplay() and then sets the lock TEST_ONLY_PHASE_LOCK.lock() in the end.

public RecordAndReplayExecution(
      @Nonnull Expectations targetObject, @Nullable Object... classesOrInstancesToBePartiallyMocked)
....  
       RecordAndReplayExecution previous = executingTest.getPreviousRecordAndReplay();

      ;;;
         recordPhase = new RecordPhase(this, strict, nonStrict);
         executingTest.setRecordAndReplay(this);
     ;;;
         //noinspection LockAcquiredButNotSafelyReleased
         TEST_ONLY_PHASE_LOCK.lock();
;;;;
}

where as RecordAndReplayExecution.recordOrReplay() checks for TEST_ONLY_PHASE_LOCK.lock() followed by checking currentRecordAndReplay if null which can possibly lead into the race condition or overwriting each other's value if Replay phase and Record phase both gets executed at the same time by main thread/daemon thread.

Also, this made me think if jmockit support running tests in parallel?

@rliesenfeld rliesenfeld added the question label Mar 1, 2016

@ishah

This comment has been minimized.

Show comment
Hide comment
@ishah

ishah Mar 2, 2016

Any input on the above issue??

ishah commented Mar 2, 2016

Any input on the above issue??

@rliesenfeld rliesenfeld added bug and removed question labels Mar 6, 2016

@rliesenfeld rliesenfeld self-assigned this Mar 6, 2016

@rliesenfeld

This comment has been minimized.

Show comment
Hide comment
@rliesenfeld

rliesenfeld Mar 6, 2016

Member

Fixing so it behaves the same as when a mocked JRE class is called from a finalize() method.

Member

rliesenfeld commented Mar 6, 2016

Fixing so it behaves the same as when a mocked JRE class is called from a finalize() method.

@ishah

This comment has been minimized.

Show comment
Hide comment
@ishah

ishah Mar 7, 2016

Thanks Rogerio for fixing this. Also, thanks for providing us with great library.

The only thing I find missing is the support for parallel execution. Is it in priority to add or do you accept contribution?

ishah commented Mar 7, 2016

Thanks Rogerio for fixing this. Also, thanks for providing us with great library.

The only thing I find missing is the support for parallel execution. Is it in priority to add or do you accept contribution?

@rliesenfeld

This comment has been minimized.

Show comment
Hide comment
@rliesenfeld

rliesenfeld Mar 7, 2016

Member

Adding support for parallel execution is not a priority. The project is open for contributions, of course.

Member

rliesenfeld commented Mar 7, 2016

Adding support for parallel execution is not a priority. The project is open for contributions, of course.

@ishah

This comment has been minimized.

Show comment
Hide comment
@ishah

ishah Mar 8, 2016

Thanks. I'll try to work on adding parallel execution support and get your feedback. will start another thread on this.

Just to make sure with the above issue, @Mocked/MockUp doesnt mock finalize() method, right? any workaround to mock finalize() method until we get this fix?

ishah commented Mar 8, 2016

Thanks. I'll try to work on adding parallel execution support and get your feedback. will start another thread on this.

Just to make sure with the above issue, @Mocked/MockUp doesnt mock finalize() method, right? any workaround to mock finalize() method until we get this fix?

@sshekhar89

This comment has been minimized.

Show comment
Hide comment
@sshekhar89

sshekhar89 Aug 31, 2016

which version of JMockit has the fix ?

sshekhar89 commented Aug 31, 2016

which version of JMockit has the fix ?

@rliesenfeld

This comment has been minimized.

Show comment
Hide comment
@rliesenfeld

rliesenfeld Aug 31, 2016

Member

@sshekhar89 See the release notes; look for the issue number.

Member

rliesenfeld commented Aug 31, 2016

@sshekhar89 See the release notes; look for the issue number.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment