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

Flaky test: org.keycloak.testsuite.federation.sync.SyncFederationTest#test03ConcurrentSync #17430

Closed
stianst opened this issue Mar 3, 2023 · 9 comments · Fixed by #19095
Closed
Assignees
Labels
area/ci Indicates an issue on the CI flaky-test kind/bug Categorizes a PR related to a bug team/continuous-testing

Comments

@stianst
Copy link
Contributor

stianst commented Mar 3, 2023

org.keycloak.testsuite.federation.sync.SyncFederationTest#test03ConcurrentSync

Keycloak CI - Base IT (5) / Pull Request #17378

javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.handleErrorStatus(ClientInvocation.java:278)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.extractResult(ClientInvocation.java:240)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.extractors.BodyEntityExtractor.extractEntity(BodyEntityExtractor.java:64)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:154)
...
@stianst stianst added kind/bug Categorizes a PR related to a bug area/ci Indicates an issue on the CI flaky-test labels Mar 3, 2023
@stianst
Copy link
Contributor Author

stianst commented Mar 3, 2023

Happened here as well: #17419

@ghost
Copy link

ghost commented Mar 3, 2023

org.keycloak.testsuite.federation.sync.SyncFederationTest#test03ConcurrentSync

Keycloak CI - Base IT (5) / Pull Request #17429

javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.handleErrorStatus(ClientInvocation.java:278)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.extractResult(ClientInvocation.java:240)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.extractors.BodyEntityExtractor.extractEntity(BodyEntityExtractor.java:64)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:154)
...

@ghost
Copy link

ghost commented Mar 7, 2023

org.keycloak.testsuite.federation.sync.SyncFederationTest#test03ConcurrentSync

Keycloak CI - Base IT (5) / Pull Request #17490

javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.handleErrorStatus(ClientInvocation.java:278)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.extractResult(ClientInvocation.java:240)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.extractors.BodyEntityExtractor.extractEntity(BodyEntityExtractor.java:64)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:154)
...

@tkyjovsk
Copy link
Contributor

Managed to reproduce this locally using numactl --physcpubind=0 -- mvn -f testsuite/integration-arquillian/tests/base/ verify -Dtest=SyncFederationTest (limitting CPU to one core).

Here's a more detailed trace:

Test set: org.keycloak.testsuite.federation.sync.SyncFederationTest
-------------------------------------------------------------------------------
Tests run: 4, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 44.57 s <<< FAILURE! - in org.keycloak.testsuite.federation.sync.SyncFederationTest
org.keycloak.testsuite.federation.sync.SyncFederationTest.test03ConcurrentSync  Time elapsed: 2.249 s  <<< ERROR!
javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.handleErrorStatus(ClientInvocation.java:278)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.extractResult(ClientInvocation.java:240)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.extractors.BodyEntityExtractor.extractEntity(BodyEntityExtractor.java:64)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:154)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invoke(ClientInvoker.java:115)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientProxy.invoke(ClientProxy.java:76)
	at com.sun.proxy.$Proxy147.runOnServer(Unknown Source)
	at org.keycloak.testsuite.client.KeycloakTestingClient$Server.run(KeycloakTestingClient.java:154)
	at org.keycloak.testsuite.federation.sync.SyncFederationTest.test03ConcurrentSync(SyncFederationTest.java:316)
	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.jboss.arquillian.junit.Arquillian$8$1.invokeMethod(Arquillian.java:325)
	at org.jboss.arquillian.junit.MethodInvoker$1.invoke(MethodInvoker.java:18)
	at org.jboss.arquillian.container.test.impl.execution.LocalTestExecuter.execute(LocalTestExecuter.java:57)
	at org.keycloak.testsuite.arquillian.ModelTestExecutor.execute(ModelTestExecutor.java:51)
	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.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:103)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:90)
	at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:133)
	at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:105)
	at org.jboss.arquillian.core.impl.EventImpl.fire(EventImpl.java:62)
	at org.jboss.arquillian.container.test.impl.execution.ClientTestExecuter.execute(ClientTestExecuter.java:50)
	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.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:103)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:90)
	at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createContext(ContainerEventController.java:128)
	at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createTestContext(ContainerEventController.java:118)
	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.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:95)
	at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:116)
	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.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:95)
	at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:83)
	at jdk.internal.reflect.GeneratedMethodAccessor315.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:95)
	at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:69)
	at jdk.internal.reflect.GeneratedMethodAccessor314.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:95)
	at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:133)
	at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.test(EventTestRunnerAdaptor.java:139)
	at org.jboss.arquillian.junit.MethodInvoker.invoke(MethodInvoker.java:15)
	at org.jboss.arquillian.junit.Arquillian$8.evaluate(Arquillian.java:332)
	at org.jboss.arquillian.junit.Arquillian$4.evaluate(Arquillian.java:204)
	at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:350)
	at org.jboss.arquillian.junit.Arquillian.access$200(Arquillian.java:54)
	at org.jboss.arquillian.junit.Arquillian$5.evaluate(Arquillian.java:215)
	at org.jboss.arquillian.junit.Arquillian$7$1.invoke(Arquillian.java:279)
	at org.jboss.arquillian.container.test.impl.execution.ClientBeforeAfterLifecycleEventExecuter.execute(ClientBeforeAfterLifecycleEventExecuter.java:88)
	at org.jboss.arquillian.container.test.impl.execution.ClientBeforeAfterLifecycleEventExecuter.on(ClientBeforeAfterLifecycleEventExecuter.java:66)
	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.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:103)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:90)
	at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createContext(ContainerEventController.java:128)
	at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createBeforeContext(ContainerEventController.java:114)
	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.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:95)
	at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:116)
	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.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:95)
	at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:83)
	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.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:95)
	at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:69)
	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.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:86)
	at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:95)
	at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:133)
	at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:105)
	at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.fireCustomLifecycle(EventTestRunnerAdaptor.java:159)
	at org.jboss.arquillian.junit.Arquillian$7.evaluate(Arquillian.java:273)
	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.jboss.arquillian.junit.Arquillian$2.evaluate(Arquillian.java:166)
	at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:350)
	at org.jboss.arquillian.junit.Arquillian.access$200(Arquillian.java:54)
	at org.jboss.arquillian.junit.Arquillian$3.evaluate(Arquillian.java:177)
	at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:54)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
	at org.jboss.arquillian.junit.Arquillian.run(Arquillian.java:115)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:377)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:284)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:248)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:167)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:456)
	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:169)
	at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:595)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:581)

@ghost
Copy link

ghost commented Mar 16, 2023

org.keycloak.testsuite.federation.sync.SyncFederationTest#test03ConcurrentSync

Keycloak CI - Base IT (5) / Pull Request #19058

javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.handleErrorStatus(ClientInvocation.java:278)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.extractResult(ClientInvocation.java:240)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.extractors.BodyEntityExtractor.extractEntity(BodyEntityExtractor.java:64)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:154)
...

@rmartinc
Copy link
Contributor

I cannot make it fail in my env, even using one cpu only. But my feeling is that the provider cannot be removed because the other transaction in the sync is still doing things. For example:

Caused by: org.h2.jdbc.JdbcSQLTransactionRollbackException: Deadlock detected. The current transaction was rolled back. Details: "COMPONENT"; SQL statement:
2023-03-03T09:21:31.4998678Z SyncFederationTest ++ delete from COMPONENT where ID=? [40001-214]
...
2023-03-03T09:21:31.5006943Z SyncFederationTest ++ Caused by: org.h2.mvstore.MVStoreException: Transaction 1 has been chosen as a deadlock victim. Details:
2023-03-03T09:21:31.5007451Z SyncFederationTest ++ Transaction 1 attempts to update map <table.93> entry with key <476> modified by transaction 2(1286) OPEN 31
2023-03-03T09:21:31.5007939Z SyncFederationTest ++ Transaction 2 attempts to update map <table.417> entry with key <2732> modified by transaction 1(1288) OPEN 25

So I'm going to modify a bit the test, and the exception in the delete will be swallowed. The next test is going to use another provider name to avoid issues if it cannot be removed.

@ghost
Copy link

ghost commented Mar 17, 2023

org.keycloak.testsuite.federation.sync.SyncFederationTest#test03ConcurrentSync

Keycloak CI - Base IT (5) / Pull Request #19098

javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.handleErrorStatus(ClientInvocation.java:278)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.extractResult(ClientInvocation.java:240)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.extractors.BodyEntityExtractor.extractEntity(BodyEntityExtractor.java:64)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:154)
...

2 similar comments
@ghost
Copy link

ghost commented Mar 17, 2023

org.keycloak.testsuite.federation.sync.SyncFederationTest#test03ConcurrentSync

Keycloak CI - Base IT (5) / Pull Request #19098

javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.handleErrorStatus(ClientInvocation.java:278)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.extractResult(ClientInvocation.java:240)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.extractors.BodyEntityExtractor.extractEntity(BodyEntityExtractor.java:64)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:154)
...

@ghost
Copy link

ghost commented Mar 21, 2023

org.keycloak.testsuite.federation.sync.SyncFederationTest#test03ConcurrentSync

Keycloak CI - Base IT (5) / Pull Request #19098

javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.handleErrorStatus(ClientInvocation.java:278)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.extractResult(ClientInvocation.java:240)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.extractors.BodyEntityExtractor.extractEntity(BodyEntityExtractor.java:64)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:154)
...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/ci Indicates an issue on the CI flaky-test kind/bug Categorizes a PR related to a bug team/continuous-testing
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants