context-propagation-quickstart fails after "Use MethodHandle" changes #45346

rsvoboda · 2025-01-03T07:45:01Z

Describe the bug

context-propagation-quickstart fails after "Use MethodHandle" changes

This quickstart fails since https://github.com/quarkusio/quarkus-quickstarts/actions/runs/12424359109 which has December 20, 2024 03:24 timestamp

I bisect commits and identified the last commit where the quickstrtart worked and it's 069c5a0

It fails after after "Use MethodHandle" changes

When I used main and reverted 38d776a and e430fbb context-propagation-quickstart was still failing.

There must be other changes that trigger hang of the execution of context-propagation-quickstart cc @geoand

Quickstart hangs the execution and prints this in logs after one minute:

2025-01-03 08:41:01,465 WARN  [com.arj.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check processing TX 0:ffff0a141eec:d97b:67779451:0 in state  RUN
2025-01-03 08:41:01,467 WARN  [com.arj.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[#180,Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffff0a141eec:d97b:67779451:0

Expected behavior

context-propagation-quickstart works with Quarkus main

Actual behavior

context-propagation-quickstart fails with Quarkus main

How to Reproduce?

Run context-propagation-quickstart from https://github.com/quarkusio/quarkus-quickstarts development branch

mvn clean verify -pl context-propagation-quickstart -Dquarkus.platform.version=3.17.5 works well

Output of `uname -a` or `ver`

macOS

Output of `java -version`

Java 21

Quarkus version or git rev

Quarkus main

Build tool (ie. output of `mvnw --version` or `gradlew --version`)

No response

Additional information

No response

The text was updated successfully, but these errors were encountered:

quarkus-bot · 2025-01-03T07:45:04Z

/cc @FroMage (context-propagation), @manovotn (context-propagation)

geoand · 2025-01-03T07:50:31Z

I could not reproduce this.

rsvoboda · 2025-01-03T08:45:17Z

@geoand latest GH Action run: https://github.com/quarkusio/quarkus-quickstarts/actions/runs/12591744899/job/35095307992

2025-01-03 03:12:11,384 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, hibernate-orm, hibernate-orm-panache, jdbc-postgresql, kafka-client, messaging, messaging-kafka, narayana-jta, rest, rest-jackson, smallrye-context-propagation, vertx]
[Hibernate] 
    select
        p1_0.id,
        p1_0.value 
    from
        Price p1_0
2025-01-03 03:13:13,087 WARN  [com.arj.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check processing TX 0:ffff0a01005c:a7bf:6777558d:0 in state  RUN
2025-01-03 03:13:13,088 WARN  [com.arj.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffff0a01005c:a7bf:6777558d:0
@QuarkusTest has detected a hang, as there has been no test activity in PT10M
To configure this timeout use the quarkus.test.hang-detection-timeout config property
A stack trace is below to help diagnose the potential hang
....

...
2025-01-03 03:42:13,161 INFO  [org.apa.htt.imp.exe.RetryExec] (sse-event-source(http://localhost:8081/prices)-thread-1) I/O exception (org.apache.http.NoHttpResponseException) caught when processing request to {}->http://localhost:8081: The target server failed to respond
2025-01-03 03:42:13,161 INFO  [org.apa.htt.imp.exe.RetryExec] (sse-event-source(http://localhost:8081/prices)-thread-1) Retrying request to {}->http://localhost:8081
2025-01-03 03:42:13,162 WARN  [com.arj.ats.arjuna] (vert.x-eventloop-thread-1) ARJUNA012077: Abort called on already aborted atomic action 0:ffff0a01005c:a7bf:6777558d:0
2025-01-03 03:42:13,162 ERROR [io.qua.mut.run.MutinyInfrastructure] (vert.x-eventloop-thread-1) Mutiny had to drop the following exception: java.lang.RuntimeException: jakarta.transaction.RollbackException: ARJUNA016102: The transaction is not active! Uid is 0:ffff0a01005c:a7bf:6777558d:0
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.lambda$handleAsync$8(TransactionalInterceptorBase.java:305)
	at io.smallrye.context.impl.wrappers.SlowContextualRunnable.run(SlowContextualRunnable.java:19)
	at io.smallrye.mutiny.groups.MultiOnTerminate.lambda$invoke$0(MultiOnTerminate.java:52)
	at io.smallrye.mutiny.operators.multi.MultiOnTerminationInvoke$MultiOnTerminationInvokeProcessor.execute(MultiOnTerminationInvoke.java:72)
	at io.smallrye.mutiny.operators.multi.MultiOnTerminationInvoke$MultiOnTerminationInvokeProcessor.cancel(MultiOnTerminationInvoke.java:63)
	at org.jboss.resteasy.reactive.server.handlers.PublisherResponseHandler$AbstractMultiSubscriber.lambda$new$0(PublisherResponseHandler.java:268)
	at org.jboss.resteasy.reactive.server.vertx.VertxResteasyReactiveRequestContext$2.handle(VertxResteasyReactiveRequestContext.java:97)
	at org.jboss.resteasy.reactive.server.vertx.VertxResteasyReactiveRequestContext$2.handle(VertxResteasyReactiveRequestContext.java:94)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:270)
	at io.vertx.core.http.impl.Http1xServerResponse.handleClosed(Http1xServerResponse.java:710)
	at io.vertx.core.http.impl.Http1xServerResponse.handleException(Http1xServerResponse.java:677)
	at io.vertx.core.http.impl.Http1xServerRequest.handleException(Http1xServerRequest.java:711)
	at io.vertx.core.http.impl.Http1xServerConnection.lambda$handleClosed$7(Http1xServerConnection.java:501)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:327)
	at io.vertx.core.impl.DuplicatedContext.execute(DuplicatedContext.java:158)
	at io.vertx.core.impl.ContextInternal.execute(ContextInternal.java:207)
	at io.vertx.core.http.impl.Http1xServerConnection.handleClosed(Http1xServerConnection.java:500)
	at io.vertx.core.net.impl.VertxHandler.channelInactive(VertxHandler.java:143)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274)
	at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81)
	at io.netty.handler.timeout.IdleStateHandler.channelInactive(IdleStateHandler.java:280)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274)
	at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:412)
	at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:377)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.lambda$handleAsync$8(TransactionalInterceptorBase.java:305)
	at io.smallrye.context.impl.wrappers.SlowContextualRunnable.run(SlowContextualRunnable.java:19)
	at io.smallrye.mutiny.groups.MultiOnTerminate.lambda$invoke$0(MultiOnTerminate.java:52)
	at io.smallrye.mutiny.operators.multi.MultiOnTerminationInvoke$MultiOnTerminationInvokeProcessor.execute(MultiOnTerminationInvoke.java:72)
	at io.smallrye.mutiny.operators.multi.MultiOnTerminationInvoke$MultiOnTerminationInvokeProcessor.cancel(MultiOnTerminationInvoke.java:63)
	at org.jboss.resteasy.reactive.server.handlers.PublisherResponseHandler$AbstractMultiSubscriber.lambda$new$0(PublisherResponseHandler.java:268)
	at org.jboss.resteasy.reactive.server.vertx.VertxResteasyReactiveRequestContext$2.handle(VertxResteasyReactiveRequestContext.java:97)
	at org.jboss.resteasy.reactive.server.vertx.VertxResteasyReactiveRequestContext$2.handle(VertxResteasyReactiveRequestContext.java:94)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:270)
	at io.vertx.core.http.impl.Http1xServerResponse.handleClosed(Http1xServerResponse.java:710)
	at io.vertx.core.http.impl.Http1xServerResponse.handleException(Http1xServerResponse.java:677)
	at io.vertx.core.http.impl.Http1xServerRequest.handleException(Http1xServerRequest.java:711)
	at io.vertx.core.http.impl.Http1xServerConnection.lambda$handleClosed$7(Http1xServerConnection.java:501)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:327)
	at io.vertx.core.impl.DuplicatedContext.execute(DuplicatedContext.java:158)
	at io.vertx.core.impl.ContextInternal.execute(ContextInternal.java:207)
	at io.vertx.core.http.impl.Http1xServerConnection.handleClosed(Http1xServerConnection.java:500)
	at io.vertx.core.net.impl.VertxHandler.channelInactive(VertxHandler.java:143)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274)
	at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81)
	at io.netty.handler.timeout.IdleStateHandler.channelInactive(IdleStateHandler.java:280)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274)
	at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:412)
	at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:377)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1352)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:301)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281)
	at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:850)
	at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:811)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: jakarta.transaction.RollbackException: ARJUNA016102: The transaction is not active! Uid is 0:ffff0a01005c:a7bf:6777558d:3
	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1297)
	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:104)
	at io.quarkus.narayana.jta.runtime.NotifyingTransactionManager.commit(NotifyingTransactionManager.java:70)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:406)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.lambda$handleAsync$7(TransactionalInterceptorBase.java:300)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.doInTransaction(TransactionalInterceptorBase.java:324)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.lambda$handleAsync$8(TransactionalInterceptorBase.java:300)
	... 43 more

rsvoboda · 2025-01-03T08:47:50Z

Log from the run: https://productionresultssa3.blob.core.windows.net/actions-results/e742632f-6fdf-407e-9da2-5b276300ba04/workflow-job-run-ce72c9ee-9c5a-59dd-21db-b6f2cdc114f0/logs/job/job-logs.txt?rsct=text%2Fplain&se=2025-01-03T08%3A57%3A20Z&sig=ntDOgP7%2F2udETcx1%2BZ66t4kx7tDT0PffYVwsEmRPu3U%3D&ske=2025-01-03T18%3A23%3A57Z&skoid=ca7593d4-ee42-46cd-af88-8b886a2f84eb&sks=b&skt=2025-01-03T06%3A23%3A57Z&sktid=398a6654-997b-47e9-b12b-9515b896b4de&skv=2024-11-04&sp=r&spr=https&sr=b&st=2025-01-03T08%3A47%3A15Z&sv=2024-11-04

rsvoboda · 2025-01-03T15:42:43Z

I could not reproduce this.

Have you run the quickstart against latest Quarkus main / development branch?

geoand · 2025-01-03T15:45:01Z

Yup

rsvoboda · 2025-01-03T15:51:25Z

Pretty strange, GH actions are failing since December 20 on this quickstart, I was able to reproduce it locally too ...

geoand · 2025-01-03T19:11:42Z

I'll have another look next week

rsvoboda · 2025-01-06T16:56:19Z

@geoand I have update for you :) I found the true regression commit. I got fooled by "Merge pull request" commits when I looked into GitHub for commits history, not necessarily using the same commits tree. PRs for commits mentioned in the description were merged on Dec 21st.

Commit which causes the fail of context-propagation-quickstart is f0e1e4e9c92 which came in #44903 PR.
When I used Quarkus main from today and reverted f0e1e4e9c92 I got passing run of the problematic quickstart.

Should be the PR reverted or will you look into new adjustments?

geoand · 2025-01-06T17:26:03Z

That's interesting, thanks for the update.

I was off today so I still haven't looked at this issue.

geoand · 2025-01-07T10:56:36Z

@rsvoboda I looked into this and indeed #44903 contains a subtle change that could be break some cases (like the one implicitly used in the quickstart) so I opened #45406

rsvoboda added the kind/bug Something isn't working label Jan 3, 2025

quarkus-bot bot added the area/context-propagation label Jan 3, 2025

rsvoboda mentioned this issue Jan 3, 2025

swapi.dev is down, use swapi.tech quarkusio/quarkus-quickstarts#1484

Merged

10 tasks

geoand mentioned this issue Jan 7, 2025

Revert "Take RestMulti headers and status into account when using SSE resource method" #45406

Merged

geoand mentioned this issue Jan 7, 2025

Setting headers for SSE annotated Multi resources is ignoring headers #44902

Open

geoand closed this as completed in #45406 Jan 7, 2025

quarkus-bot bot added this to the 3.18 - main milestone Jan 7, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

context-propagation-quickstart fails after "Use MethodHandle" changes #45346

context-propagation-quickstart fails after "Use MethodHandle" changes #45346

rsvoboda commented Jan 3, 2025 •

edited

Loading

quarkus-bot bot commented Jan 3, 2025

geoand commented Jan 3, 2025 •

edited

Loading

rsvoboda commented Jan 3, 2025 •

edited

Loading

rsvoboda commented Jan 3, 2025

rsvoboda commented Jan 3, 2025

geoand commented Jan 3, 2025

rsvoboda commented Jan 3, 2025

geoand commented Jan 3, 2025

rsvoboda commented Jan 6, 2025

geoand commented Jan 6, 2025

geoand commented Jan 7, 2025

context-propagation-quickstart fails after "Use MethodHandle" changes #45346

context-propagation-quickstart fails after "Use MethodHandle" changes #45346

Comments

rsvoboda commented Jan 3, 2025 • edited Loading

Describe the bug

Expected behavior

Actual behavior

How to Reproduce?

Output of uname -a or ver

Output of java -version

Quarkus version or git rev

Build tool (ie. output of mvnw --version or gradlew --version)

Additional information

quarkus-bot bot commented Jan 3, 2025

geoand commented Jan 3, 2025 • edited Loading

rsvoboda commented Jan 3, 2025 • edited Loading

rsvoboda commented Jan 3, 2025

rsvoboda commented Jan 3, 2025

geoand commented Jan 3, 2025

rsvoboda commented Jan 3, 2025

geoand commented Jan 3, 2025

rsvoboda commented Jan 6, 2025

geoand commented Jan 6, 2025

geoand commented Jan 7, 2025

rsvoboda commented Jan 3, 2025 •

edited

Loading

Output of `uname -a` or `ver`

Output of `java -version`

Build tool (ie. output of `mvnw --version` or `gradlew --version`)

geoand commented Jan 3, 2025 •

edited

Loading

rsvoboda commented Jan 3, 2025 •

edited

Loading