Skip to content
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

KubernetesMockServer regression in 6.3.0+ #4786

Closed
gyfora opened this issue Jan 23, 2023 · 12 comments
Closed

KubernetesMockServer regression in 6.3.0+ #4786

gyfora opened this issue Jan 23, 2023 · 12 comments

Comments

@gyfora
Copy link

gyfora commented Jan 23, 2023

Describe the bug

After upgrading to 6.3.0 or 6.4.0 from 6.2.0 we found a regression in the KubernetesMockServer.
After every test run we keep getting the following exception:

2023-01-23 09:38:55,822 i.f.k.c.o.OkHttpClientImpl     [DEBUG] Shutting down dispatcher okhttp3.Dispatcher@39b626e5
java.lang.Exception
	at io.fabric8.kubernetes.client.okhttp.OkHttpClientImpl.close(OkHttpClientImpl.java:248)
	at io.fabric8.kubernetes.client.impl.BaseClient.close(BaseClient.java:130)
	at io.fabric8.kubernetes.client.server.mock.KubernetesMockServerExtension.destroy(KubernetesMockServerExtension.java:110)
	at io.fabric8.kubernetes.client.server.mock.KubernetesMockServerExtension.afterEach(KubernetesMockServerExtension.java:60)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeAfterEachCallbacks$12(TestMethodTestDescriptor.java:257)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeAllAfterMethodsOrCallbacks$13(TestMethodTestDescriptor.java:273)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeAllAfterMethodsOrCallbacks$14(TestMethodTestDescriptor.java:273)

Furthermore the tests also run much longer.

OkHttp version: 4.10.0 (both before and after the fabric8 upgrade)

The regression occurs even if we don't have any logic in the tests.

Fabric8 Kubernetes Client version

6.4.0

Steps to reproduce

@EnableKubernetesMockClient(crud = true)
public class KubernetesClientUtilsTest {
    KubernetesMockServer mockServer;    

    @Test
    public void testNothing() {
    }
}

Expected behavior

With 6.2.0 the empty test simply runs without any errors and much faster:
6.2.0: 13ms
6.4.0: 18ms

Maybe the time diff here is not significant but on longer tests it is much worse (6s vs 38s)

Runtime

other (please specify in additional context)

Kubernetes API Server version

other (please specify in additional context)

Environment

macOS

Fabric8 Kubernetes Client Logs

2023-01-23 09:44:43,943 i.f.k.c.o.OkHttpClientImpl     [DEBUG] Shutting down dispatcher okhttp3.Dispatcher@12abdfb
java.lang.Exception
	at io.fabric8.kubernetes.client.okhttp.OkHttpClientImpl.close(OkHttpClientImpl.java:248)
	at io.fabric8.kubernetes.client.impl.BaseClient.close(BaseClient.java:130)
	at io.fabric8.kubernetes.client.server.mock.KubernetesMockServerExtension.destroy(KubernetesMockServerExtension.java:110)
	at io.fabric8.kubernetes.client.server.mock.KubernetesMockServerExtension.afterEach(KubernetesMockServerExtension.java:60)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeAfterEachCallbacks$12(TestMethodTestDescriptor.java:257)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeAllAfterMethodsOrCallbacks$13(TestMethodTestDescriptor.java:273)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeAllAfterMethodsOrCallbacks$14(TestMethodTestDescriptor.java:273)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeAllAfterMethodsOrCallbacks(TestMethodTestDescriptor.java:272)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeAfterEachCallbacks(TestMethodTestDescriptor.java:256)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:141)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:66)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:107)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:54)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:67)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:52)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:114)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:86)
	at org.junit.platform.launcher.core.DefaultLauncherSession$DelegatingLauncher.execute(DefaultLauncherSession.java:86)
	at org.junit.platform.launcher.core.SessionPerRequestLauncher.execute(SessionPerRequestLauncher.java:53)
	at com.intellij.junit5.JUnit5IdeaTestRunner.startRunnerWithArgs(JUnit5IdeaTestRunner.java:71)
	at com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
	at com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
	at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
	at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235)
	at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)
2023-01-23 09:44:43,948 i.f.k.c.o.OkHttpClientImpl     [DEBUG] Shutting down dispatcher okhttp3.Dispatcher@12abdfb
java.lang.Exception
	at io.fabric8.kubernetes.client.okhttp.OkHttpClientImpl.close(OkHttpClientImpl.java:248)
	at io.fabric8.kubernetes.client.impl.BaseClient.close(BaseClient.java:130)
	at io.fabric8.kubernetes.client.server.mock.KubernetesMockServerExtension.destroy(KubernetesMockServerExtension.java:110)
	at io.fabric8.kubernetes.client.server.mock.KubernetesMockServerExtension.afterAll(KubernetesMockServerExtension.java:67)
	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.lambda$invokeAfterAllCallbacks$16(ClassBasedTestDescriptor.java:447)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.lambda$invokeAfterAllCallbacks$17(ClassBasedTestDescriptor.java:447)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.invokeAfterAllCallbacks(ClassBasedTestDescriptor.java:447)
	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.after(ClassBasedTestDescriptor.java:229)
	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.after(ClassBasedTestDescriptor.java:80)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:161)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:161)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:107)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:54)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:67)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:52)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:114)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:86)
	at org.junit.platform.launcher.core.DefaultLauncherSession$DelegatingLauncher.execute(DefaultLauncherSession.java:86)
	at org.junit.platform.launcher.core.SessionPerRequestLauncher.execute(SessionPerRequestLauncher.java:53)
	at com.intellij.junit5.JUnit5IdeaTestRunner.startRunnerWithArgs(JUnit5IdeaTestRunner.java:71)
	at com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
	at com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
	at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
	at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235)
	at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)

Additional context

No response

@manusa
Copy link
Member

manusa commented Jan 23, 2023

I'm not sure there have been any changes to the KubernetesMockServer between those to versions. Or at least any significant changes that might relate to this issue.

I do remember refactoring the dispatcher, but I think that was before 6.2.

The only changes I can track are the ones from #4430.

@gyfora
Copy link
Author

gyfora commented Jan 23, 2023

If I simply change the fabric8 version the test slowness goes away. It is slow/errors in 6.3.0/6.4.0 but 6.2.0 completely fine

@manusa
Copy link
Member

manusa commented Jan 23, 2023

I get that, but it might be related to the change in the HttpClient implementation (client-side) instead of the server-side.

I'm assuming you are using the default OkHttp client implementation. Is it possible to try with the JDK implementation instead for example?

@shawkins
Copy link
Contributor

After every test run we keep getting the following exception:

It's at the debug level. The exception is just to show the full stacktrace. This was added as part of tracking down some inconsistent test runs, and was also intended for users who have several times opened issues / discussions about why they are getting rejected execution exceptions - the answer always is that the client has been closed, you just need to find out where.

@manusa
Copy link
Member

manusa commented Jan 23, 2023

LOG.debug("Shutting down dispatcher " + this.httpClient.dispatcher(), new Exception());

OT: This doesn't look right. Why are we instantiating an Exception and passing it in as an argument?

@shawkins
Copy link
Contributor

OT: This doesn't look right. Why are we instantiating an Exception and passing it in as an argument?

See the previous comment.

The only changes I can track are the ones from #4430.

An empty mock test won't engage with the server at all.

If I simply change the fabric8 version the test slowness goes away. It is slow/errors in 6.3.0/6.4.0 but 6.2.0 completely fine

If I repeat your test from the command line, I don't see nearly as fast of execution time end-to-end as what you are showing. How are you instrumenting your tests, and what time are you reporting - for the whole test class, a single method, etc.

Also are you always running your tests with debug engaged?

@manusa
Copy link
Member

manusa commented Jan 23, 2023

See the previous comment.

I missed the part about The exception is just to show the full stacktrace. But still not a big fan of this. Maybe adding a "Dummy exception to show the full stacktrace" message to the Exception or at least a comment can help recalling the intention of the Exception in the future.

An empty mock test won't engage with the server at all.

Added that for completeness, those changes should not affect performance at all.

@bachmanity1
Copy link
Contributor

bachmanity1 commented Mar 20, 2023

+1.
I'm seeing exactly the same behavior after upgrading from 6.2.0.

It's at the debug level. The exception is just to show the full stacktrace. This was added as part of tracking down some inconsistent test runs, and was also intended for users who have several times opened issues / discussions about why they are getting rejected execution exceptions - the answer always is that the client has been closed, you just need to find out where.

In my opinion, this debug message is quite confusing and makes users believe that there is something wrong with tests. This is especially confusing when there is actually something wrong with tests because exception stacktrace makes you think that problem is somehow related to the mock server.

@shawkins
Copy link
Contributor

In my opinion, this debug message is quite confusing and makes users believe that there is something wrong with tests.

For 6.5 the message has changed

to make it clear it's only a stacktrace, not an exception.

@bachmanity1
Copy link
Contributor

For 6.5 the message has changed

I've already upgraded to 6.5.0.
I'm running my tests in debug mode because it's more convenient and makes it easier to debug test problems.

to make it clear it's only a stacktrace, not an exception.

yes, I know it. I'm not really convinced that this stacktrace is helpful, maybe it would be enough to just print out a short log message instead?

@shawkins
Copy link
Contributor

yes, I know it. I'm not really convinced that this stacktrace is helpful, maybe it would be enough to just print out a short log message instead?

We routinely have received issues/discussions from users who have inadvertently closed their client and receive an obtuse error from okhttp. This message is to make where that is happening clear with debug enabled. If you want to exclude it from you debug logs, or use a different http client, you won't see this message. If you feel even more strongly about it, you can submit a patch for what behavior you would like to see.

@shawkins
Copy link
Contributor

The original issue was addressed under #4924

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants