ArC - add debug logging for the request context manipulation

docs/src/main/asciidoc/cdi-reference.adoc

@@ -354,6 +354,18 @@ The request context is destroyed:
 
 NOTE: An event with qualifier `@Initialized(RequestScoped.class)` is fired when the request context is initialized for an observer notification. Moreover, the events with qualifiers `@BeforeDestroyed(RequestScoped.class)` and `@Destroyed(RequestScoped.class)` are fired when the request context is destroyed.
 
+==== How to Enable Trace Logging for Request Context Activation
+
+You can set the `TRACE` level for the logger `io.quarkus.arc.requestContext` and try to analyze the log output afterwards.
+
+.`application.properties` Example
+[source,properties]
+----
+quarkus.log.category."io.quarkus.arc.requestContext".min-level=TRACE <1>
+quarkus.log.category."io.quarkus.arc.requestContext".level=TRACE
+----
+<1> You also need to adjust the minimum log level for the relevant category.
+
 === Qualified Injected Fields
 
 In CDI, if you declare a field injection point you need to use `@Inject` and optionally a set of qualifiers.

independent-projects/arc/runtime/src/main/java/io/quarkus/arc/impl/RequestContext.java

@@ -31,19 +31,23 @@
  */
 class RequestContext implements ManagedContext {
 
-    private static final Logger LOGGER = Logger.getLogger(RequestContext.class.getPackage().getName());
+    private static final Logger LOG = Logger.getLogger("io.quarkus.arc.requestContext");
 
     private final CurrentContext<RequestContextState> currentContext;
 
     private final LazyValue<Notifier<Object>> initializedNotifier;
     private final LazyValue<Notifier<Object>> beforeDestroyedNotifier;
     private final LazyValue<Notifier<Object>> destroyedNotifier;
 
+    private final boolean traceEnabled;
+
     public RequestContext(CurrentContext<RequestContextState> currentContext) {
         this.currentContext = currentContext;
         this.initializedNotifier = new LazyValue<>(RequestContext::createInitializedNotifier);
         this.beforeDestroyedNotifier = new LazyValue<>(RequestContext::createBeforeDestroyedNotifier);
         this.destroyedNotifier = new LazyValue<>(RequestContext::createDestroyedNotifier);
+        // we do not need to check the effective log level
+        this.traceEnabled = LOG.isTraceEnabled();
     }
 
     @Override
@@ -122,6 +126,15 @@ public void destroy(Contextual<?> contextual) {
 
     @Override
     public void activate(ContextState initialState) {
+        if (traceEnabled) {
+            String stack = Arrays.stream(Thread.currentThread().getStackTrace())
+                    .skip(2)
+                    .limit(7)
+                    .map(se -> "\n\t" + se.toString())
+                    .collect(Collectors.joining());
+            LOG.tracef("Activate %s %s\n\t...",
+                    initialState != null ? Integer.toHexString(initialState.hashCode()) : "new", stack);
+        }
         if (initialState == null) {
             currentContext.set(new RequestContextState(new ConcurrentHashMap<>()));
             // Fire an event with qualifier @Initialized(RequestScoped.class) if there are any observers for it
@@ -151,6 +164,14 @@ public ContextState getStateIfActive() {
 
     @Override
     public void deactivate() {
+        if (traceEnabled) {
+            String stack = Arrays.stream(Thread.currentThread().getStackTrace())
+                    .skip(2)
+                    .limit(7)
+                    .map(se -> "\n\t" + se.toString())
+                    .collect(Collectors.joining());
+            LOG.tracef("Deactivate%s\n\t...", stack);
+        }
         currentContext.remove();
     }
 
@@ -161,6 +182,14 @@ public void destroy() {
 
     @Override
     public void destroy(ContextState state) {
+        if (traceEnabled) {
+            String stack = Arrays.stream(Thread.currentThread().getStackTrace())
+                    .skip(2)
+                    .limit(7)
+                    .map(se -> "\n\t" + se.toString())
+                    .collect(Collectors.joining());
+            LOG.tracef("Destroy %s%s\n\t...", state != null ? Integer.toHexString(state.hashCode()) : "", stack);
+        }
         if (state == null) {
             // nothing to destroy
             return;
@@ -174,15 +203,15 @@ public void destroy(ContextState state) {
                 try {
                     fireIfNotEmpty(beforeDestroyedNotifier);
                 } catch (Exception e) {
-                    LOGGER.warn("An error occurred during delivery of the @BeforeDestroyed(RequestScoped.class) event", e);
+                    LOG.warn("An error occurred during delivery of the @BeforeDestroyed(RequestScoped.class) event", e);
                 }
                 //Performance: avoid an iterator on the map elements
                 map.forEach(this::destroyContextElement);
                 // Fire an event with qualifier @Destroyed(RequestScoped.class) if there are any observers for it
                 try {
                     fireIfNotEmpty(destroyedNotifier);
                 } catch (Exception e) {
-                    LOGGER.warn("An error occurred during delivery of the @Destroyed(RequestScoped.class) event", e);
+                    LOG.warn("An error occurred during delivery of the @Destroyed(RequestScoped.class) event", e);
                 }
                 map.clear();
             }