Introduce RequestLogListener
#6543
Conversation
Motivation:
A single `RequestLogProperty` can be received through
`RequestLog.whenAvailable()`, but it is not straightforward to receive
all events published by `RequestLog` using `.whenAvailable()`.
To address the limitation, I propose introducing an interface that
listens to all events by adding it to `RequestLog`. This will also
simplify the integration of other implmentations used for collecting
metrics.
Motifications:
- Introduced `RequestLogListener` API that can be attached to
`RequestLog`.
- `RequestLogAccess.addListener()` API was added and
`DefaultRequestLog` implmemeted it.
- The listener will be notified whenever a new property is set to
`RequestLog`. If some properties have already been set, they will
notified of them immediately.
- Add `REQUEST_COMPLETE`, `RESPONSE_COMPLETE` and `ALL_COMPLETE` to
`RequestLogProperty`.
- Previously, there were APIs such as `whenRequestComplete()` and
`whenComplete()` that computed and signaled request or response
completion and but no explicit properties exists for them.
`RequestLogProperty` should represent all states in
`RequestLogListener`, I added the new completion properties.
- Simplied child log propagation in `DefaultRequestLog` and
the `Observation{Service,Client} implementations by using
`RequestLogListener`.
Result:
You can now use `RequestLogListener` to observe all `RequestLog` events.
WalkthroughA listener-based event system replaces chained callbacks in request logging. New RequestLogListener interface enables external components to subscribe to property availability events. Core logging in DefaultRequestLog refactors propagation logic to notify listeners when properties become available. ObservationClient and ObservationService adapt to use the new pattern. Changes
Sequence DiagramsequenceDiagram
participant App as Application
participant Log as DefaultRequestLog
participant Listener as RequestLogListener
participant Observer as Observation Service
App->>Log: addListener(listener)
Note over Log: Register listener for<br/>property events
Alt Listener Registration with Existing Properties
Log->>Listener: onEvent(property, log)<br/>for each available property
Listener-->>Log: ✓ callback returns
End
Note over Log: Async I/O Processing
Log->>Log: REQUEST_FIRST_BYTES_TRANSFERRED_TIME<br/>becomes available
Log->>Listener: onEvent(REQUEST_FIRST_BYTES_TRANSFERRED_TIME, log)
Listener->>Observer: emit(WIRE_SEND)
Log->>Log: RESPONSE_FIRST_BYTES_TRANSFERRED_TIME<br/>becomes available
Log->>Listener: onEvent(RESPONSE_FIRST_BYTES_TRANSFERRED_TIME, log)
Listener->>Observer: emit(WIRE_RECEIVE)
Log->>Log: ALL_COMPLETE flag set<br/>(request + response complete)
Log->>Listener: onEvent(ALL_COMPLETE, log)
Listener->>Observer: store response
Observer->>Observer: stop observation
Listener-->>Log: ✓ callback returns
Estimated Code Review Effort🎯 4 (Complex) | ⏱️ ~45 minutes
Poem
Pre-merge checks and finishing touches❌ Failed checks (1 warning)
✅ Passed checks (2 passed)
✨ Finishing touches
🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #6543 +/- ##
============================================
- Coverage 74.46% 74.23% -0.23%
- Complexity 22234 23454 +1220
============================================
Files 1963 2105 +142
Lines 82437 87873 +5436
Branches 10764 11516 +752
============================================
+ Hits 61385 65236 +3851
- Misses 15918 17147 +1229
- Partials 5134 5490 +356 ☔ View full report in Codecov by Sentry. 🚀 New features to boost your workflow:
|
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 0
🧹 Nitpick comments (5)
core/src/test/java/com/linecorp/armeria/common/logging/RequestLogListenerTest.java (1)
119-131: Consider usingpartial()for clearer comparison.The assertion
ctx.log()returnsRequestLogAccess, while the listener receivesRequestLog. This works becauseDefaultRequestLogimplements both interfaces, but could be clearer.- assertThat(receivedLogs.get(0)).isSameAs(ctx.log()); + assertThat(receivedLogs.get(0)).isSameAs(ctx.log().partial());Alternatively, if the intent is to verify the same underlying log instance, the current assertion is acceptable since they share the same reference.
core/src/main/java/com/linecorp/armeria/common/logging/RequestLogProperty.java (1)
140-144: Address the TODO comment or track it as a follow-up.The TODO asks whether
RESPONSE_LENGTHis actually used. Consider investigating this now or creating an issue to track.Would you like me to search the codebase for usages of
RESPONSE_LENGTHto determine if it's actively used?#!/bin/bash # Search for usages of RESPONSE_LENGTH property rg -n --type=java 'RESPONSE_LENGTH' -C 3core/src/main/java/com/linecorp/armeria/common/logging/DefaultRequestLog.java (3)
117-118: Consider adding@GuardedBy("lock")annotation.The
listenersfield is accessed under the lock (as seen inaddListenerandmaybeNotifyListeners). Adding the annotation would improve documentation consistency with other guarded fields likependingFutures.@Nullable +@GuardedBy("lock") private List<RequestLogListener> listeners;
655-692: Minor:responseTrailersis set twice.The
RESPONSE_TRAILERScase (line 679) and theRESPONSE_COMPLETEcase (line 685) both callresponseTrailers(log.responseTrailers()). While harmless (the setter is idempotent), the duplicate inRESPONSE_COMPLETEis unnecessary sinceRESPONSE_TRAILERSwill always fire beforeRESPONSE_COMPLETE.case RESPONSE_COMPLETE: responseContent(log.responseContent(), log.rawResponseContent()); responseLength(log.responseLength()); responseContentPreview(log.responseContentPreview()); - responseTrailers(log.responseTrailers()); endResponse0(log.responseCause(), log.responseEndTimeNanos()); break;
1939-1945:notifyListeneris called without holding the lock.The
notifyListenermethod's comment states "The lock should be held by the caller" (line 1510), butCompleteRequestLog.addListenercalls it without acquiring the lock. While this is safe because the log is already complete (immutable state), the inconsistency could confuse maintainers.Consider either:
- Updating the comment in
notifyListenerto clarify that the lock is only required for incomplete logs, or- Using a separate helper for the complete case.
📜 Review details
Configuration used: Path: .coderabbit.yaml
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (8)
core/src/main/java/com/linecorp/armeria/client/observation/ObservationClient.java(1 hunks)core/src/main/java/com/linecorp/armeria/common/logging/DefaultRequestLog.java(14 hunks)core/src/main/java/com/linecorp/armeria/common/logging/RequestLogAccess.java(1 hunks)core/src/main/java/com/linecorp/armeria/common/logging/RequestLogListener.java(1 hunks)core/src/main/java/com/linecorp/armeria/common/logging/RequestLogProperty.java(5 hunks)core/src/main/java/com/linecorp/armeria/server/observation/ObservationService.java(1 hunks)core/src/test/java/com/linecorp/armeria/common/logging/DefaultRequestLogTest.java(0 hunks)core/src/test/java/com/linecorp/armeria/common/logging/RequestLogListenerTest.java(1 hunks)
💤 Files with no reviewable changes (1)
- core/src/test/java/com/linecorp/armeria/common/logging/DefaultRequestLogTest.java
🧰 Additional context used
📓 Path-based instructions (1)
**/*.java
⚙️ CodeRabbit configuration file
**/*.java: - The primary coding conventions and style guide for this project are defined insite/src/pages/community/developer-guide.mdx. Please strictly adhere to this file as the ultimate source of truth for all style and convention-related feedback.2. Specific check for
@UnstableApi
- Review all newly added public classes and methods to ensure they have the
@UnstableApiannotation.- However, this annotation is NOT required under the following conditions:
- If the class or method is located in a package containing
.internalor.testing.- If the class or method is located in a test source set.
- If a public method is part of a class that is already annotated with
@UnstableApi.
Files:
core/src/main/java/com/linecorp/armeria/server/observation/ObservationService.javacore/src/main/java/com/linecorp/armeria/common/logging/RequestLogAccess.javacore/src/main/java/com/linecorp/armeria/client/observation/ObservationClient.javacore/src/main/java/com/linecorp/armeria/common/logging/RequestLogListener.javacore/src/test/java/com/linecorp/armeria/common/logging/RequestLogListenerTest.javacore/src/main/java/com/linecorp/armeria/common/logging/RequestLogProperty.javacore/src/main/java/com/linecorp/armeria/common/logging/DefaultRequestLog.java
🧬 Code graph analysis (1)
core/src/main/java/com/linecorp/armeria/common/logging/RequestLogListener.java (2)
core/src/main/java/com/linecorp/armeria/client/observation/ObservationClient.java (1)
UnstableApi(72-162)core/src/main/java/com/linecorp/armeria/server/observation/ObservationService.java (1)
UnstableApi(72-162)
⏰ Context from checks skipped due to timeout of 90000ms. You can increase the timeout in your CodeRabbit configuration to a maximum of 15 minutes (900000ms). (1)
- GitHub Check: Summary
🔇 Additional comments (21)
core/src/main/java/com/linecorp/armeria/server/observation/ObservationService.java (1)
142-160: Clean refactor to listener-based observation.The switch-based listener pattern is cleaner than chained callbacks. The asymmetric null check (
responseFirstBytesTransferredTimeNanos()check at line 148 but not for request) appears intentional since the property availability forREQUEST_FIRST_BYTES_TRANSFERRED_TIMEimplies the event occurred, whereas response bytes might not be transferred in all cases.core/src/main/java/com/linecorp/armeria/common/logging/RequestLogAccess.java (1)
233-238: LGTM! New API method properly annotated.The
addListenermethod is correctly annotated with@UnstableApias required for new public APIs. The Javadoc clearly describes when the listener will be invoked.core/src/main/java/com/linecorp/armeria/common/logging/RequestLogListener.java (1)
21-39: Well-designed listener interface with clear documentation.The interface is properly annotated with
@UnstableApiand@FunctionalInterface. The Javadoc appropriately warns users about I/O thread invocation and documents the immediate notification behavior for already-available properties. This enables clean event-driven integrations as intended by the PR.core/src/main/java/com/linecorp/armeria/client/observation/ObservationClient.java (1)
140-160: Consistent listener-based observation matching the server-side pattern.The implementation correctly mirrors
ObservationServicewith appropriate event mappings for client-side (WIRE_SEND for request, WIRE_RECEIVE for response). The retained TODO comment aboutClientConnectionTimings(lines 151-152) is acknowledged.core/src/test/java/com/linecorp/armeria/common/logging/RequestLogListenerTest.java (3)
54-84: Comprehensive test for listener notification ordering.The test effectively validates the property notification sequence from request start through response completion, including the
ALL_COMPLETEproperty. Good coverage of the listener lifecycle.
151-171: Good exception isolation test.This test is important to verify that a misbehaving listener doesn't break other listeners. It validates a key resilience property of the listener mechanism.
173-206: Thorough deferred properties test.This test covers the complex deferred content scenario well, verifying that
REQUEST_COMPLETE,RESPONSE_COMPLETE, andALL_COMPLETEare only notified after deferred properties are set.core/src/main/java/com/linecorp/armeria/common/logging/RequestLogProperty.java (5)
66-69: LGTM!The new
REQUEST_FIRST_BYTES_TRANSFERRED_TIMEproperty is correctly defined as a request property and properly documented with its corresponding accessor method.
96-104: LGTM!The
REQUEST_END_TIMEandREQUEST_COMPLETEproperties are correctly defined.REQUEST_COMPLETEserves as a synthetic completion marker for the new listener-based model.
108-112: LGTM!Good design decision to notify
RESPONSE_CAUSEbefore other response properties. The comment clearly explains this enables early propagation for retry logic and circuit breakers.
151-165: LGTM!The completion properties (
RESPONSE_END_TIME,RESPONSE_COMPLETE,ALL_COMPLETE) are well-defined and documented.ALL_COMPLETEcorrectly serves as the union of request and response completion states.
172-188: LGTM!The flag calculations correctly exclude the synthetic
*_COMPLETEproperties from their respective flag sets. This avoids circular dependencies—FLAGS_REQUEST_COMPLETErepresents the properties that must be set beforeREQUEST_COMPLETEcan be derived, not includingREQUEST_COMPLETEitself.core/src/main/java/com/linecorp/armeria/common/logging/DefaultRequestLog.java (9)
39-41: LGTM!Standard SLF4J logger initialization for listener error handling.
20-25: LGTM!Clean static imports for the new completion flags used throughout the class.
192-203: LGTM!The completion checks now use the dedicated
ALL_COMPLETEandREQUEST_COMPLETEproperties, which aligns with the new listener-based model.
268-276: LGTM!The
toPropertieshelper correctly maps a bitmask to the corresponding list ofRequestLogPropertyvalues. Acceptable overhead given the small enum size.
288-295: LGTM!Both methods correctly delegate to the new completion property flags.
426-457: Listener callbacks are invoked while holding the lock—verify this is acceptable.Invoking
maybeNotifyListeners(line 448) while holdinglockmeans listeners execute synchronously within the critical section. If a listener performs a slow operation or attempts to interact with thisRequestLogin complex ways, it could increase lock contention. WhileReentrantShortLockallows re-entry, long-held locks can degrade throughput in high-concurrency scenarios.Consider whether listener notification should be deferred outside the lock by collecting the notifications inside the lock and dispatching them afterward (similar to how
completeSatisfiedFuturesis handled via event loop). If this is intentional for ordering guarantees, a brief comment explaining the design choice would help future maintainers.
588-635: LGTM!Clean refactoring to listener-based propagation. The switch covers all relevant request properties, and the comment at lines 627-628 correctly explains why
requestCauseis not propagated to avoid marking retried requests as failed.
1101-1101: LGTM!Correctly uses
FLAGS_REQUEST_COMPLETEfor checking request completion prerequisites.
1490-1529: LGTM!The listener mechanism is well-implemented:
- Proper null-check and lazy initialization
- Immediate notification of already-available properties on registration
- Exceptions are caught and logged to prevent one faulty listener from affecting others
- Property-first iteration order in
maybeNotifyListenersensures consistent global ordering
jrhee17
left a comment
jrhee17
left a comment
There was a problem hiding this comment.
Left a small concern on notifying listeners/futures within the same lock as updating flags. The rest looks good to me
| */ | ||
| REQUEST_START_TIME(true), | ||
|
|
||
| /** |
There was a problem hiding this comment.
Note) Understood the reason for the reorder is to ensure properties are notified in the correct order
| } | ||
| break; | ||
| this.flags = newFlags; | ||
| maybeNotifyListeners(oldFlags, newFlags); |
There was a problem hiding this comment.
I'm unsure if locking flags and listeners is safe since flag updates may be blocked due to notifying futures, and flag updates are almost always done on event loops.
What do you think of isolating locks for each listener instead? This will incur additional memory, so I'm unsure which is a better approach, but leaving this as food for thought.
e.g.
public class CachingRequestLogListener implements RequestLogListener {
private final RequestLogListener delegate;
int notifiedFlags;
private final ReentrantLock lock = new ReentrantLock();
CachingRequestLogListener(RequestLogListener delegate) {
this.delegate = delegate;
}
@Override
public void onEvent(RequestLogProperty property, RequestLog log) {
lock.lock();
try {
if ((notifiedFlags & property.flag()) != 0) {
return;
}
notifiedFlags |= property.flag();
} finally {
lock.unlock();
}
delegate.onEvent(property, log);
}
}| FLAGS_REQUEST_COMPLETE = flags(REQUEST_PROPERTIES) & ~REQUEST_COMPLETE.flag(); | ||
| FLAGS_RESPONSE_COMPLETE = flags(RESPONSE_PROPERTIES) & ~RESPONSE_COMPLETE.flag(); |
There was a problem hiding this comment.
Understood *COMPLETE flags should not be updated directly using updateFlags now, but are computed based on other flags.
2 participants
Motivation:
A single
RequestLogPropertycan be received throughRequestLog.whenAvailable(), but it is not straightforward to receive all events published byRequestLogusing.whenAvailable().To address the limitation, I propose introducing an interface that listens to all events by adding it to
RequestLog. This will also simplify the integration of other implementations used for collecting metrics. Related: #6502Modifications:
RequestLogListenerAPI that can be attached toRequestLog.RequestLogAccess.addListener()API was added andDefaultRequestLogimplemented it.RequestLog. If some properties have already been set, it will notified of them immediately.REQUEST_COMPLETE,RESPONSE_COMPLETEandALL_COMPLETEtoRequestLogProperty.whenRequestComplete()andwhenComplete()that computed and signaled request or response completion and but no explicit properties exist for them.RequestLogPropertyshould represent all states inRequestLogListener, I added the new completion properties.DefaultRequestLogand theObservation{Service,Client}implementations by usingRequestLogListener.Result:
You can now use
RequestLogListenerto observe allRequestLogevents.