Fixing Unexpected method calls: HttpSession.invalidate

[akatona84]

Summary

1. Why: The test failed sometimes with unexpected method calls.
2. What: The fix is preparing the test to accept invalidate method call too

Expected Behavior

Tests are running without failure

Actual Behavior

Tests are failing sometimes with unexpected method call.

Steps to Reproduce

1. setup repeated run on e.g. testCreateUserTask in IDE
2. observe failure after multiple successful runs (for me it was failing after around 250 successful runs)

Additional evidence

java.lang.AssertionError: On mock #2 (zero indexed): 
  Unexpected method calls:
    HttpSession.invalidate()
	at org.easymock.EasyMock.getAssertionError(EasyMock.java:2230)
	at org.easymock.EasyMock.verify(EasyMock.java:2058)
	at com.linkedin.kafka.cruisecontrol.servlet.UserTaskManagerTest.testCreateUserTask(UserTaskManagerTest.java:59)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.runTestClass(JUnitTestClassExecutor.java:112)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:58)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:40)
	at org.gradle.api.internal.tasks.testing.junit.AbstractJUnitTestClassProcessor.processTestClass(AbstractJUnitTestClassProcessor.java:60)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:52)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33)
	at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)
	at com.sun.proxy.$Proxy5.processTestClass(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker$2.run(TestWorker.java:176)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.executeAndMaintainThreadName(TestWorker.java:129)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.execute(TestWorker.java:100)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.execute(TestWorker.java:60)
	at org.gradle.process.internal.worker.child.ActionExecutionWorker.execute(ActionExecutionWorker.java:56)
	at org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:113)
	at org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:65)
	at worker.org.gradle.process.internal.worker.GradleWorkerMain.run(GradleWorkerMain.java:69)
	at worker.org.gradle.process.internal.worker.GradleWorkerMain.main(GradleWorkerMain.java:74)

Categorization

• bugfix
• new feature
• refactor
• CVE
• other

[akatona84]

Executed all fast test methods 5000 times - all succeeded, slow ones were run only a few times.

[viktorsomogyi]

@mhratson would you please review this?

[akatona84]

This is where invalidateSession is called. UserTaskManager schedules an UserTaskScanner which is invalidating the session in its every tick, but most of the time it happens after Easymock.verify.

Breakpoint reached
	at com.sun.proxy.$Proxy7.invalidate(Unknown Source:-1)
	at com.linkedin.kafka.cruisecontrol.servlet.ServletSession.invalidateSession(ServletSession.java:21)
	at com.linkedin.kafka.cruisecontrol.servlet.UserTaskManager$SessionKey.invalidateSession(UserTaskManager.java:578)
	at com.linkedin.kafka.cruisecontrol.servlet.UserTaskManager.expireOldSessions(UserTaskManager.java:303)
	at com.linkedin.kafka.cruisecontrol.servlet.UserTaskManager$UserTaskScanner.run(UserTaskManager.java:790)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305)
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:-1)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.lang.Thread.run(Thread.java:829)

[mhratson]

@akatona84 thanks for the fix!
Will take a look.

[mhratson]

@akatona84 can you help me reproduce?

$ for i in $(seq 10000); do echo "attempt: $i"; ./gradlew cruise-control:test --tests 'UserTaskManagerTest' --rerun; done|tee out.log
# …wait for few hours…
$ grep UserTaskManagerTest out.log |awk '{print $4}'|sort|uniq -c
   5224 PASSED

[akatona84]

I was testing with Idea jUnit, but this should work too. Actually it depends how busy the machine is while running. Let me try to put a sleep somewhere and see how i could make it consistently failing without this fix.

[akatona84]

It's pretty drastic, but this way at least it's consistently failing for me.

diff --git a/cruise-control/src/test/java/com/linkedin/kafka/cruisecontrol/servlet/UserTaskManagerTest.java b/cruise-control/src/test/java/com/linkedin/kafka/cruisecontrol/servlet/UserTaskManagerTest.java
index b27978a8..2c64c7b2 100644
--- a/cruise-control/src/test/java/com/linkedin/kafka/cruisecontrol/servlet/UserTaskManagerTest.java
+++ b/cruise-control/src/test/java/com/linkedin/kafka/cruisecontrol/servlet/UserTaskManagerTest.java
@@ -56,6 +56,7 @@ public class UserTaskManagerTest {
     Assert.assertEquals(userTaskHeader.getValue(), UserTaskManager.USER_TASK_HEADER_NAME);
     Assert.assertEquals(userTaskHeaderValue.getValue(), testUserTaskId.toString());
     Assert.assertEquals(future, future1);
+    Thread.sleep(10000);
     EasyMock.verify(mockUuidGenerator, mockHttpServletResponse, mockHttpSession);
     EasyMock.reset(mockHttpServletResponse);
     // test-case: get same future back using sessions

This created task should be executed right after the scheduling, but it's not getting processor time, just after the mock is verified in the test's thread:

cruise-control/cruise-control/src/main/java/com/linkedin/kafka/cruisecontrol/servlet/UserTaskManager.java

Line 107 in 85d6ca7

_userTaskScannerExecutor.scheduleAtFixedRate(new UserTaskScanner(),