[mkouba]

• emit JFR events so that shutdown actions can be observed with standard profiling tools
• monitored actions include: ShutdownContext.addShutdownTask(), ShutdownContext.addLastShutdownTask(), ShutdownListener, CDI Singleton and ApplicationScoped beans, CDI Singleton and Application contexts

[mkouba]

Note that from JPMS perspective this adds the dependency on the jdk.jfr module to the quarkus-core and arc. I'm not sure if that's handled automatically? @dmlloyd

[mkouba]

Note that from JPMS perspective this adds the dependency on the jdk.jfr module to the quarkus-core and arc. I'm not sure if that's handled automatically? @dmlloyd

Actually, I'm not even sure we want to depend on a jdk.* module. In practice, every major distribution includes it but it's not guaranteed. 🤔

[manovotn]

Note that from JPMS perspective this adds the dependency on the jdk.jfr module to the quarkus-core and arc. I'm not sure if that's handled automatically? @dmlloyd

Actually, I'm not even sure we want to depend on a jdk.* module. In practice, every major distribution includes it but it's not guaranteed. 🤔

I would say it is fine.

[Ladicek]

Agree that depending on jdk.jfr is fine. But the implementation looks ugly as hell :-)

I wanna step back: what are you trying to achieve here? There's no linked issue, so I have no idea. And tracing specifically shutdown doesn't look like an ideal place to begin at.

[mkouba]

I wanna step back: what are you trying to achieve here? There's no linked issue, so I have no idea. And tracing specifically shutdown doesn't look like an ideal place to begin at.

The ultimate goal of this PR is to trace the shutdown sequence, nothing more. I ran into this issue while exploring our (graceful)shutdown APIs - and I realized that there's no easy way to identify components that contribute to the shutdown logic. My original solution used logging, but then (after a discussion during F2F) I switched to JFR.

This is the JFR output in Azul Mission Control:

But the implementation looks ugly as hell :-)

I agree that it's not a very nice piece of code. Not sure if "ugly as hell", I've seen much worse and I wonder what you would call it ;-). In any case, if you have a better idea, feel free to edit this pull request.

[cescoffier]

🤖 Automatically associated with the WG - Graceful Shutdown Working Group based on AI classification.

[Ladicek]

Hi @mkouba, I took a stab as simplifying this. Find my code over here: https://github.com/Ladicek/quarkus/commits/shutdown-seq/

You'll note that 90% of what I did was peeling off the abstraction layers you introduced. The only thing they do is add overhead. The inline code isn't that longer than what you had.

I also adopted the pattern used by @dmlloyd in smallrye/smallrye-modules#7:

FooEvent foo = new FooEvent();
if (foo.isEnabled()) {
    foo.bar = "foobar";
    foo.begin();
} else {
    foo = null;
}
try {
    ...
} finally {
    if (foo != null) {
        foo.commit();
    }
}

Seems overall a little shorter and more obvious.

Do what you want with it :-)

[mkouba]

Hi @mkouba, I took a stab as simplifying this. Find my code over here: https://github.com/Ladicek/quarkus/commits/shutdown-seq/

You'll note that 90% of what I did was peeling off the abstraction layers you introduced. The only thing they do is add overhead. The inline code isn't that longer than what you had.

I also adopted the pattern used by @dmlloyd in smallrye/smallrye-modules#7:

FooEvent foo = new FooEvent();
if (foo.isEnabled()) {
    foo.bar = "foobar";
    foo.begin();
} else {
    foo = null;
}
try {
    ...
} finally {
    if (foo != null) {
        foo.commit();
    }
}

Seems overall a little shorter and more obvious.

Do what you want with it :-)

Well, I don't see how the snippet above is shorter/less error-prone than:

ShutdownSequence.run(new Runnable() {
                @Override
                public void run() {
                    i.shutdown(new LatchShutdownNotification(shutdown));
                }
            }, ActionType.SHUTDOWN_LISTENER_SHUTDOWN, i.getClass().getName());

It could even be (but we have some weird rules to avoid using lambdas at runtime at all cost 🤷):

ShutdownSequence.run(() -> i.shutdown(new LatchShutdownNotification(shutdown)),
   ActionType.SHUTDOWN_LISTENER_SHUTDOWN, 
   i.getClass().getName());

The reason why I introduced the "abstraction layer" was to minimize the risk of copy&paste error, i.e. define the JFR "ceremony" in one place.

But I agree that it's not nice. I will take a second look later this week.

[mkouba]

So I renamed ShutdownSequence to ShutdownAction (and ArcShutdownSequence to ArcShutdownAction), and redesigned them from static utility classes into enums where each constant represents an action type. The enum's run(info, action) method wraps the given Runnable with JFR tracing. A typical workflow now looks like ShutdownAction.SHUTDOWN_LISTENER_SHUTDOWN.run(info, runnable). It's not ideal, but I think that the "abstraction layer" that implements the JFR event dispatch is still useful.

[Ladicek]

Whatever floats your boat. BTW I still hate the way you changed EventImpl and I'm gonna claim my change is better :-)

[mkouba]

Whatever floats your boat.

It does float but I'm definitely not proud of it.

BTW I still hate the way you changed EventImpl and I'm gonna claim my change is better :-)

Hm, I don't think there's such a big difference...

[ozangunalp]

I verified with a couple of apps that the JFR events are ok.

As for the pattern of how this is set up, I've seen in a couple of places in the JDK that the Event class itself has a singleton event that is used to check if it is enabled or not:

public final class ThreadSleepEvent extends Event {
    private static final ThreadSleepEvent EVENT = new ThreadSleepEvent();

    /**
     * Returns {@code true} if event is enabled, {@code false} otherwise.
     */
    public static boolean isTurnedOn() {
        return EVENT.isEnabled();
    }

    public long time;
}

Then, instead of having a run(info, runnable) method on the action enum, which requires a Runnable, we could have beforeAction(info), which returns the Event (or null if it is not turned on), and afterAction(event) that handles the null case.

It would be something like:

  ArcShutdownActionEvent event = actionType.beforeAction(info);
  try {
      om.notify(ec);
  } finally {
      ArcShutdownAction.afterAction(event);
  }

This is, of course, nitpicking. We have all different types of uses of shouldCommit, etc., in the code base. Maybe this discussion would also serve as a rationalisation of all that.

[mkouba]

@Ladicek I've removed some "ugliness" from the EventImpl (BiConsumer etc.).

@ozangunalp the JDK pattern makes sense for hot paths but for shutdown tracing it's unnecessary complexity.

I'm not going to spend more time with this PR. If someone approves it, I will merge it. Honestly, I'm not very proud of this code but it could be helpful.

[Ladicek]

EventImpl looks much better indeed 👍

I still don't like introducing abstraction around code that is supposed to have near-zero overhead, but I might be overly cautious here 🤷

[manovotn]

FWIW I think the PR is fine and ready to be merged.
It is certainly better than what we have right now (or rather, what we lack right now!).

I still don't like introducing abstraction around code that is supposed to have near-zero overhead, but I might be overly cautious here 🤷

I am not too worried there - this code path is executed once during shutdown which IMO makes it way less critical than it may initially appear.

[quarkus-bot]

Status for workflow Quarkus CI

This is the status report for running Quarkus CI on commit 610fc0f.

Failing Jobs

Status	Name	Step	Failures	Logs	Raw logs	Build scan
✔️	JVM Tests - JDK 21			Logs	Raw logs	🚧
✔️	JVM Tests - JDK 25			Logs	Raw logs	🚧
✔️	JVM Tests - JDK 25 Semeru			Logs	Raw logs	🚧
❌	JVM Tests - JDK 21 Windows	Build	Failures	Logs	Raw logs	🚧

Failures

⚙️ JVM Tests - JDK 21 Windows #

- Failing: extensions/grpc/deployment 
! Skipped: extensions/liquibase/liquibase-mongodb/deployment extensions/micrometer-opentelemetry/deployment extensions/micrometer-registry-prometheus/deployment and 11 more

📦 extensions/grpc/deployment

❌ Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:3.5.6:test (default-test) on project quarkus-grpc-deployment: There was a timeout in the fork

---

Flaky tests - Develocity

⚙️ JVM Tests - JDK 25

📦 extensions/redis-client/runtime

❌ io.quarkus.redis.datasource.PubSubTest.testWithMultipleChannelsAndASinglePattern - History

• io.smallrye.mutiny.TimeoutException

Details

io.smallrye.mutiny.TimeoutException
	at io.smallrye.mutiny.operators.uni.UniBlockingAwait.await(UniBlockingAwait.java:65)
	at io.smallrye.mutiny.groups.UniAwait.atMost(UniAwait.java:76)
	at io.quarkus.redis.datasource.PubSubTest.testWithMultipleChannelsAndASinglePattern(PubSubTest.java:101)

---

⚙️ JVM Tests - JDK 25 Semeru

📦 extensions/aesh/websocket/deployment

❌ io.quarkus.aesh.websocket.deployment.AeshWebSocketConnectionTest.testWebSocketConnection - History

• [Expected to receive 'Hello World!' in WebSocket output within 30s. Received: ] Expecting value to be true but was false - org.opentest4j.AssertionFailedError

Details

org.opentest4j.AssertionFailedError: 
[Expected to receive 'Hello World!' in WebSocket output within 30s. Received: ] 
Expecting value to be true but was false
	at io.quarkus.aesh.websocket.deployment.AeshWebSocketConnectionTest.testWebSocketConnection(AeshWebSocketConnectionTest.java:67)

❌ io.quarkus.aesh.websocket.deployment.AeshWebSocketRolesAllowedTest.testCorrectRoleSucceeds - History

• [Expected to receive 'Hello World!' in WebSocket output within 30s. Received: ] Expecting value to be true but was false - org.opentest4j.AssertionFailedError

Details

org.opentest4j.AssertionFailedError: 
[Expected to receive 'Hello World!' in WebSocket output within 30s. Received: ] 
Expecting value to be true but was false
	at io.quarkus.aesh.websocket.deployment.AeshWebSocketRolesAllowedTest.testCorrectRoleSucceeds(AeshWebSocketRolesAllowedTest.java:109)

📦 extensions/redis-client/runtime

❌ io.quarkus.redis.datasource.PubSubCommandsTest.subscribeToSingleWithMulti - History

• Assertion condition defined as a Lambda expression in io.quarkus.redis.datasource.PubSubCommandsTest Expecting empty but was: [channel-test] within 10 seconds. - org.awaitility.core.ConditionTimeoutException

Details

org.awaitility.core.ConditionTimeoutException: 
Assertion condition defined as a Lambda expression in io.quarkus.redis.datasource.PubSubCommandsTest 
Expecting empty but was: [channel-test] within 10 seconds.
	at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:167)
	at org.awaitility.core.AssertionCondition.await(AssertionCondition.java:119)
	at org.awaitility.core.AssertionCondition.await(AssertionCondition.java:31)
	at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:1160)
	at org.awaitility.core.ConditionFactory.untilAsserted(ConditionFactory.java:790)

❌ io.quarkus.redis.datasource.PubSubCommandsTest.subscribeToSingleWithMultiAsMessages - History

• Assertion condition defined as a Lambda expression in io.quarkus.redis.datasource.PubSubCommandsTest Expecting empty but was: [channel-test] within 10 seconds. - org.awaitility.core.ConditionTimeoutException

Details

org.awaitility.core.ConditionTimeoutException: 
Assertion condition defined as a Lambda expression in io.quarkus.redis.datasource.PubSubCommandsTest 
Expecting empty but was: [channel-test] within 10 seconds.
	at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:167)
	at org.awaitility.core.AssertionCondition.await(AssertionCondition.java:119)
	at org.awaitility.core.AssertionCondition.await(AssertionCondition.java:31)
	at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:1160)
	at org.awaitility.core.ConditionFactory.untilAsserted(ConditionFactory.java:790)

• Condition with Lambda expression in io.quarkus.redis.datasource.PubSubCommandsTest was not fulfilled within 10 seconds. - org.awaitility.core.ConditionTimeoutException

Details

org.awaitility.core.ConditionTimeoutException: Condition with Lambda expression in io.quarkus.redis.datasource.PubSubCommandsTest was not fulfilled within 10 seconds.
	at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:167)
	at org.awaitility.core.CallableCondition.await(CallableCondition.java:78)
	at org.awaitility.core.CallableCondition.await(CallableCondition.java:26)
	at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:1160)
	at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:1129)
	at io.quarkus.redis.datasource.PubSubCommandsTest.subscribeToSingleWithMultiAsMessages(PubSubCommandsTest.java:354)

❌ io.quarkus.redis.datasource.PubSubCommandsTest.testSubscribeAsMessages - History

• Condition with Lambda expression in io.quarkus.redis.datasource.PubSubCommandsTest was not fulfilled within 10 seconds. - org.awaitility.core.ConditionTimeoutException

Details

org.awaitility.core.ConditionTimeoutException: Condition with Lambda expression in io.quarkus.redis.datasource.PubSubCommandsTest was not fulfilled within 10 seconds.
	at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:167)
	at org.awaitility.core.CallableCondition.await(CallableCondition.java:78)
	at org.awaitility.core.CallableCondition.await(CallableCondition.java:26)
	at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:1160)
	at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:1129)
	at io.quarkus.redis.datasource.PubSubCommandsTest.testSubscribeAsMessages(PubSubCommandsTest.java:383)
	Suppressed: org.awaitility.core.ConditionTimeoutException: Assertion condition defined as a Lambda expression in io.quarkus.redis.datasource.PubSubCommandsTest