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.
WalkthroughReplaces chained per-property callbacks with a listener-based RequestLog event system. Adds RequestLogListener and addListener APIs, updates DefaultRequestLog propagation to notify listeners on property availability, adjusts RequestLogProperty lifecycle flags, and migrates ObservationClient/ObservationService to use the new listener model. Changes
Sequence Diagram(s)sequenceDiagram
participant App as Application
participant Log as DefaultRequestLog
participant Listener as RequestLogListener
participant Observer as Observation (Client/Service)
App->>Log: addListener(listener)
Note over Log: register listener (idempotent wrapper)
alt Properties already available
Log->>Listener: onEvent(property, log) for each available property
end
Note over Log: I/O progress produces properties
Log->>Log: REQUEST_FIRST_BYTES_TRANSFERRED_TIME becomes available
Log->>Listener: onEvent(REQUEST_FIRST_BYTES_TRANSFERRED_TIME, log)
Listener->>Observer: emit WIRE_SEND
Log->>Log: RESPONSE_FIRST_BYTES_TRANSFERRED_TIME becomes available
Log->>Listener: onEvent(RESPONSE_FIRST_BYTES_TRANSFERRED_TIME, log)
Listener->>Observer: emit WIRE_RECEIVE
Log->>Log: ALL_COMPLETE becomes available
Log->>Listener: onEvent(ALL_COMPLETE, log)
Listener->>Observer: store response / stop observation
Estimated code review effort🎯 4 (Complex) | ⏱️ ~45 minutes
Suggested reviewers
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.24% -0.22%
- Complexity 22234 23450 +1216
============================================
Files 1963 2106 +143
Lines 82437 87883 +5446
Branches 10764 11517 +753
============================================
+ Hits 61385 65250 +3865
- Misses 15918 17133 +1215
- Partials 5134 5500 +366 ☔ 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);
}
}There was a problem hiding this comment.
The callback of RequestLogFuture are already executed on event loops, so long running tasks in either RequestLogFuture or RequestLogListener would block event loops in a similar way. Since the lock is created per a request, I didn't expect it to become a bottleneck easily.
However, the idea of implementing CachingRequestLogListener in a non-blocking way sounds good. I will work on it.
| 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.
There was a problem hiding this comment.
Actionable comments posted: 0
🧹 Nitpick comments (2)
core/src/test/java/com/linecorp/armeria/common/logging/IdempotentRequestLogListenerTest.java (1)
28-41: Test coverage looks good for the basic case.The test correctly verifies the idempotent behavior by sending duplicate events and asserting only unique ones are forwarded. Consider adding edge cases for completeness:
- Test with all
RequestLogPropertyvalues to ensure the bitwise flag logic handles all properties correctly- Test concurrent calls to
onEventto verify thread-safetycore/src/main/java/com/linecorp/armeria/common/logging/DefaultRequestLog.java (1)
290-298: Helper method is correct but has minor optimization potential.The method iterates all
RequestLogProperty.values()on each call. While this works correctly, for performance-sensitive scenarios you could consider caching the result ofvalues()as a static field. However, given the small number of properties and that this isn't on the critical request path, this is acceptable.
📜 Review details
Configuration used: Path: .coderabbit.yaml
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (3)
core/src/main/java/com/linecorp/armeria/common/logging/DefaultRequestLog.java(40 hunks)core/src/main/java/com/linecorp/armeria/common/logging/IdempotentRequestLogListener.java(1 hunks)core/src/test/java/com/linecorp/armeria/common/logging/IdempotentRequestLogListenerTest.java(1 hunks)
🧰 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/common/logging/DefaultRequestLog.javacore/src/test/java/com/linecorp/armeria/common/logging/IdempotentRequestLogListenerTest.javacore/src/main/java/com/linecorp/armeria/common/logging/IdempotentRequestLogListener.java
🧬 Code graph analysis (1)
core/src/main/java/com/linecorp/armeria/common/logging/IdempotentRequestLogListener.java (2)
core/src/main/java/com/linecorp/armeria/common/logging/DefaultRequestLog.java (1)
DefaultRequestLog(101-1969)core/src/main/java/com/linecorp/armeria/internal/common/util/ReentrantShortLock.java (1)
ReentrantShortLock(28-41)
⏰ 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). (14)
- GitHub Check: Kubernetes Chaos test
- GitHub Check: build-ubicloud-standard-16-jdk-17-leak
- GitHub Check: build-ubicloud-standard-16-jdk-17-min-java-11
- GitHub Check: build-ubicloud-standard-16-jdk-21-snapshot-blockhound
- GitHub Check: build-windows-latest-jdk-25
- GitHub Check: build-ubicloud-standard-16-jdk-17-min-java-17-coverage
- GitHub Check: build-ubicloud-standard-16-jdk-8
- GitHub Check: build-macos-latest-jdk-25
- GitHub Check: build-ubicloud-standard-16-jdk-11
- GitHub Check: flaky-tests
- GitHub Check: build-ubicloud-standard-16-jdk-25
- GitHub Check: site
- GitHub Check: lint
- GitHub Check: Summary
🔇 Additional comments (8)
core/src/main/java/com/linecorp/armeria/common/logging/IdempotentRequestLogListener.java (1)
26-50: Well-structured idempotent wrapper implementation.The design correctly:
- Protects flag state with a lock
- Releases the lock before calling the delegate (avoiding potential deadlocks or blocking)
- Uses efficient bitwise flag tracking
This addresses the concern from the past review about isolating locks for each listener.
core/src/main/java/com/linecorp/armeria/common/logging/DefaultRequestLog.java (7)
1516-1526: The listener registration handles races correctly.The
IdempotentRequestLogListenerwrapper is essential here—it prevents duplicate notifications that could occur due to the race between adding the listener and reading the current flags. The sequence (add to list first, then notify existing properties) combined with the idempotent wrapper ensures no events are missed or duplicated.
448-483: Flag management for completion properties is well-designed.The automatic setting of
REQUEST_COMPLETE,RESPONSE_COMPLETE, andALL_COMPLETEflags based on their constituent flags ensures consistency. The listener notification correctly computes newly added flags to avoid redundant notifications.
614-661: Listener-based propagation is cleaner and more maintainable.The switch-based approach consolidates all property handling in one place, replacing what would have been multiple
whenAvailablechains. Good documentation of the intentional omission ofrequestCausepropagation for retry scenarios.
681-718: Response-side propagation mirrors the request-side pattern correctly.Note that
responseTrailersis set both in theRESPONSE_TRAILERScase (line 705) and inRESPONSE_COMPLETE(line 711). This redundancy is safe—the method returns early if already available—and ensures trailers are propagated regardless of event ordering.
1956-1962: Correct handling for already-complete logs.Since
CompleteRequestLogrepresents a fully finished log with all properties available, iterating allRequestLogProperty.values()and notifying immediately is the right approach. The absence ofIdempotentRequestLogListenerwrapping is acceptable here since no new properties will ever be set on a complete log.
1528-1534: Good defensive exception handling for listener callbacks.Wrapping the listener invocation in a try-catch prevents misbehaving listeners from breaking the request log system. Warning-level logging with the listener reference aids debugging.
264-266: Visibility change to package-private is appropriate.The
hasInterestedFlagsmethod visibility was changed fromprivateto package-private to allowIdempotentRequestLogListenerto use it. This is a sensible encapsulation choice—it keeps the method within the package while enabling code reuse.
minwoox
left a comment
minwoox
left a comment
There was a problem hiding this comment.
Looks great, thanks! 👍 👍 👍
3 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.