Skip to content
This repository has been archived by the owner on Jan 24, 2024. It is now read-only.

[BUG] Stuck CI on TransactionWithOAuthBearerAuthTest #1630

Open
eolivelli opened this issue Dec 16, 2022 · 0 comments · May be fixed by #1632
Open

[BUG] Stuck CI on TransactionWithOAuthBearerAuthTest #1630

eolivelli opened this issue Dec 16, 2022 · 0 comments · May be fixed by #1632
Labels

Comments

@eolivelli
Copy link
Contributor

Describe the bug

After the upgrade to the Kafka clients 2.8.0 in my CI (my fork) it happens very often that the tests become stuck after this error:

23:13:09.362 [kafka-expiring-relogin-thread-undefined:org.apache.kafka.common.security.oauthbearer.OAuthBearerLoginModule@318] ERROR org.apache.kafka.common.security.oauthbearer.OAuthBearerLoginModule - java.lan>
java.io.IOException: java.lang.InterruptedException
at io.streamnative.pulsar.handlers.kop.security.oauth.ClientCredentialsFlow.authenticate(ClientCredentialsFlow.java:89) ~[oauth-client-2.10.0.8-SNAPSHOT.jar:?]
at io.streamnative.pulsar.handlers.kop.security.oauth.OauthLoginCallbackHandler.handleCallback(OauthLoginCallbackHandler.java:82) ~[oauth-client-2.10.0.8-SNAPSHOT.jar:?]
at io.streamnative.pulsar.handlers.kop.security.oauth.OauthLoginCallbackHandler.handle(OauthLoginCallbackHandler.java:67) ~[oauth-client-2.10.0.8-SNAPSHOT.jar:?]
at org.apache.kafka.common.security.oauthbearer.OAuthBearerLoginModule.identifyToken(OAuthBearerLoginModule.java:316) [kafka-clients-2.8.0.jar:?]
at org.apache.kafka.common.security.oauthbearer.OAuthBearerLoginModule.login(OAuthBearerLoginModule.java:301) [kafka-clients-2.8.0.jar:?]
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:747) [?:?]
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:672) [?:?]
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:670) [?:?]
at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:670) [?:?]
at javax.security.auth.login.LoginContext.login(LoginContext.java:581) [?:?]
at org.apache.kafka.common.security.oauthbearer.internals.expiring.ExpiringCredentialRefreshingLogin.reLogin(ExpiringCredentialRefreshingLogin.java:390) [kafka-clients-2.8.0.jar:?]
at org.apache.kafka.common.security.oauthbearer.internals.expiring.ExpiringCredentialRefreshingLogin.access$600(ExpiringCredentialRefreshingLogin.java:40) [kafka-clients-2.8.0.jar:?]
at org.apache.kafka.common.security.oauthbearer.internals.expiring.ExpiringCredentialRefreshingLogin$Refresher.run(ExpiringCredentialRefreshingLogin.java:106) [kafka-clients-2.8.0.jar:?]
at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: java.lang.InterruptedException
at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:385) ~[?:?]
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999) ~[?:?]
at org.asynchttpclient.netty.NettyResponseFuture.get(NettyResponseFuture.java:201) ~[async-http-client-2.12.1.jar:?]
at io.streamnative.pulsar.handlers.kop.security.oauth.ClientCredentialsFlow.authenticate(ClientCredentialsFlow.java:76) ~[oauth-client-2.10.0.8-SNAPSHOT.jar:?]
... 14 more

After that every creation of Producer becomes stuck, and I see this thread dump produced by the test listener:
"TestNG-method=basicRecoveryAbortedTransaction-1" #271 prio=5 os_prio=0 cpu=4.31ms elapsed=20.04s tid=0x00007fde9a04b800 nid=0x4097 waiting for monitor entry [0x00007fde33ad1000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.kafka.common.security.authenticator.LoginManager.acquireLoginManager(LoginManager.java:100)
- waiting to lock <0x0000000088681498> (a java.lang.Class for org.apache.kafka.common.security.authenticator.LoginManager)
at org.apache.kafka.common.network.SaslChannelBuilder.configure(SaslChannelBuilder.java:170)
at org.apache.kafka.common.network.ChannelBuilders.create(ChannelBuilders.java:192)
at org.apache.kafka.common.network.ChannelBuilders.clientChannelBuilder(ChannelBuilders.java:81)
at org.apache.kafka.clients.ClientUtils.createChannelBuilder(ClientUtils.java:105)
at org.apache.kafka.clients.producer.KafkaProducer.newSender(KafkaProducer.java:448)
at org.apache.kafka.clients.producer.KafkaProducer.(KafkaProducer.java:429)
at org.apache.kafka.clients.producer.KafkaProducer.(KafkaProducer.java:291)
at org.apache.kafka.clients.producer.KafkaProducer.(KafkaProducer.java:318)
at org.apache.kafka.clients.producer.KafkaProducer.(KafkaProducer.java:303)
at io.streamnative.pulsar.handlers.kop.TransactionTest.buildTransactionProducer(TransactionTest.java:719)
at io.streamnative.pulsar.handlers.kop.TransactionTest.buildTransactionProducer(TransactionTest.java:701)
at io.streamnative.pulsar.handlers.kop.TransactionTest.basicRecoveryAbortedTransaction(TransactionTest.java:478)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.17/Native Method)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.17/NativeMethodAccessorImpl.java:62)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.17/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.17/Method.java:566)
at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:124)
at org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:54)
at org.testng.internal.InvokeMethodRunnable.run(InvokeMethodRunnable.java:44)
at java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.17/Executors.java:515)
at java.util.concurrent.FutureTask.run(java.base@11.0.17/FutureTask.java:264)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.17/ThreadPoolExecutor.java:1128)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.17/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.17/Thread.java:829)

"TestNG-method=basicRecoveryAbortedTransaction-1" #271 prio=5 os_prio=0 cpu=4.31ms elapsed=20.04s tid=0x00007fde9a04b800 nid=0x4097 waiting for monitor entry [0x00007fde33ad1000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.kafka.common.security.authenticator.LoginManager.acquireLoginManager(LoginManager.java:100)
- waiting to lock <0x0000000088681498> (a java.lang.Class for org.apache.kafka.common.security.authenticator.LoginManager)
at org.apache.kafka.common.network.SaslChannelBuilder.configure(SaslChannelBuilder.java:170)
at org.apache.kafka.common.network.ChannelBuilders.create(ChannelBuilders.java:192)
at org.apache.kafka.common.network.ChannelBuilders.clientChannelBuilder(ChannelBuilders.java:81)
at org.apache.kafka.clients.ClientUtils.createChannelBuilder(ClientUtils.java:105)
at org.apache.kafka.clients.producer.KafkaProducer.newSender(KafkaProducer.java:448)
at org.apache.kafka.clients.producer.KafkaProducer.(KafkaProducer.java:429)
at org.apache.kafka.clients.producer.KafkaProducer.(KafkaProducer.java:291)
at org.apache.kafka.clients.producer.KafkaProducer.(KafkaProducer.java:318)
at org.apache.kafka.clients.producer.KafkaProducer.(KafkaProducer.java:303)
at io.streamnative.pulsar.handlers.kop.TransactionTest.buildTransactionProducer(TransactionTest.java:719)
at io.streamnative.pulsar.handlers.kop.TransactionTest.buildTransactionProducer(TransactionTest.java:701)
at io.streamnative.pulsar.handlers.kop.TransactionTest.basicRecoveryAbortedTransaction(TransactionTest.java:478)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.17/Native Method)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.17/NativeMethodAccessorImpl.java:62)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.17/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.17/Method.java:566)
at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:124)
at org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:54)
at org.testng.internal.InvokeMethodRunnable.run(InvokeMethodRunnable.java:44)
at java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.17/Executors.java:515)
at java.util.concurrent.FutureTask.run(java.base@11.0.17/FutureTask.java:264)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.17/ThreadPoolExecutor.java:1128)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.17/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.17/Thread.java:829)
.....
this happens for all the test methods

To Reproduce
This behaviour happens very often in my fork https://
I am investigating, maybe the 2.8.0 OAuth client implementation has some bugs

Expected behavior
No stuck CI

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

Successfully merging a pull request may close this issue.

1 participant