Add filter for measuring request response time - #101
Conversation
📝 WalkthroughWalkthroughA new timing filter has been added to measure HTTP request processing duration. The TimingFilter class records the start time, delegates to the filter chain, calculates elapsed time, and logs the request method, path, and duration in milliseconds. Changes
Sequence DiagramsequenceDiagram
actor Client
participant TimingFilter
participant FilterChain
participant Server
Client->>TimingFilter: HTTP Request
Note over TimingFilter: Record start time
TimingFilter->>FilterChain: doFilter(request, response, chain)
FilterChain->>Server: Process request
Server-->>FilterChain: Response ready
FilterChain-->>TimingFilter: Return
Note over TimingFilter: Calculate elapsed time<br/>Log method, path, duration
TimingFilter-->>Client: HTTP Response
Estimated code review effort🎯 2 (Simple) | ⏱️ ~8 minutes Poem
🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ 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 |
jesperlarsson1910
left a comment
There was a problem hiding this comment.
Looks like a smart and well implemented filter.
Two questions:
For best accuracy this should be the first filter, but that's something the filterchain should handle right?
Could this maybe be incorporate the LoggingFilter given that they do similar things allthough with different timing and outputs, like adding the system.out between the timestamp and dofilter. Or is it best to keep them seperate?
|
You need to sign thiscommit: Added TimingFilter to measure request duration and log ms Think its possible to do with git rebase, then in the editor you can change that commit to edit and then --amend -5 to sign that specific commit and rebase --continue and push --force, because the merging is blocked due to that specific commit :) |
|
Or you can squash all commits to one, or you can drop that specific commit and commit it again |
eb1265e
d00d7fd to
eb1265e
Compare
There was a problem hiding this comment.
Actionable comments posted: 3
🧹 Nitpick comments (1)
src/main/java/org/juv25d/filter/TimingFilter.java (1)
20-20: Integer division silently drops sub-millisecond precision.For fast paths (< 1 ms),
(System.nanoTime() - start) / 1_000_000always produces0 ms, which is misleading. Consider using floating-point or logging in microseconds for finer resolution.♻️ Proposed fix
- long durationMs = (System.nanoTime() - start) / 1_000_000; - logger.info(req.method() + " " + req.path() + " took " + durationMs + " ms"); + double durationMs = (System.nanoTime() - start) / 1_000_000.0; + logger.info(req.method() + " " + req.path() + " took " + String.format("%.3f", durationMs) + " ms");🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@src/main/java/org/juv25d/filter/TimingFilter.java` at line 20, The current Duration calculation in TimingFilter uses integer division when computing durationMs (long durationMs = (System.nanoTime() - start) / 1_000_000), which drops sub-millisecond precision; change durationMs to a floating-point value (e.g., double durationMs = (System.nanoTime() - start) / 1_000_000.0) or compute and log microseconds instead, and update any logging/formatting that references durationMs to accept the new type (look for the durationMs variable and its use in TimingFilter).
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.
Inline comments:
In `@src/main/java/org/juv25d/App.java`:
- Line 42: TimingFilter is being added after other filters so it runs last and
doesn't measure their latency; change the registration order or priority so
TimingFilter wraps the full request lifecycle: move the
pipeline.addGlobalFilter(new TimingFilter(), 0) call to execute before
registering SecurityHeadersFilter, RedirectFilter, IpFilter, and LoggingFilter,
or give TimingFilter a higher priority (e.g., a lower numeric value if smaller
means earlier) when calling pipeline.addGlobalFilter to ensure TimingFilter
executes first and captures end-to-end timing.
In `@src/main/java/org/juv25d/filter/TimingFilter.java`:
- Around line 16-21: In TimingFilter, ensure the timing and logger.info call
always runs by wrapping the chain.doFilter(req, res) call in a try-finally:
record start with the existing start variable, call chain.doFilter(req, res)
inside try, compute duration and call logger.info(req.method() + " " +
req.path() + " took " + durationMs + " ms") in finally so timing is logged even
when chain.doFilter throws, and rethrow the exception (do not swallow it).
- Line 21: The log entry in TimingFilter (logger.info using req.method(),
req.path(), durationMs) is vulnerable to log injection because req.path() may
contain CR/LF; sanitize the path before logging by removing or escaping CR and
LF characters (e.g., replace CR/LF with nothing or an escape) or introduce a
small helper like sanitizeLog(String) and use it when composing the message so
the final logger.info uses the sanitized path instead of raw req.path().
---
Nitpick comments:
In `@src/main/java/org/juv25d/filter/TimingFilter.java`:
- Line 20: The current Duration calculation in TimingFilter uses integer
division when computing durationMs (long durationMs = (System.nanoTime() -
start) / 1_000_000), which drops sub-millisecond precision; change durationMs to
a floating-point value (e.g., double durationMs = (System.nanoTime() - start) /
1_000_000.0) or compute and log microseconds instead, and update any
logging/formatting that references durationMs to accept the new type (look for
the durationMs variable and its use in TimingFilter).
|
@Cavve please merge ASAP so we dont get more conflicts and have to re-review :=) |
Implemented a filter that measures how long each incoming HTTP request takes to process. The filter should record the start time before delegating to the next filter in the chain, then calculate the elapsed time once the response is ready. It should log the total duration in milliseconds together with the request method and path.
Closes #92
Summary by CodeRabbit