Why can REST Assured's RequestLoggingFilter output differ from what the server actually receives?

seniorshould knowfreq 46%

answer

prints before ctx.next(...)
specification, not the socket
later filters still mutate the request
HttpClient adds Host and Content-Length

basics

~20 s

REST Assured's RequestLoggingFilter prints the request specification, not the bytes on the wire. It prints before calling ctx.next(...), so later filters can still change the request, and the HTTP client adds headers afterwards. Treat the output as intent, not evidence.

solid answer

~50 s

RequestLoggingFilter runs first in its own filter(...) method: it calls RequestPrinter.print(...) on the FilterableRequestSpecification and only then calls ctx.next(...). Two gaps open up from that ordering. First, every filter registered after it -- a CookieFilter replaying stored cookies, an authentication filter adding a header -- mutates the request after the log was written, so those additions are invisible. Second, the request that leaves the process is built by Apache HttpClient, which adds Host, Content-Length, Connection and transfer headers the specification never held. So on a museum ticketing suite, a POST /v1/tickets log showing no session cookie does not prove the cookie was missing. For genuine wire evidence you need HttpClient's own logging or a network capture. Register the logger last among the filters that touch the request if you want the fullest picture it can give.

`RequestLoggingFilter` runs first in its own `filter(...)` method: it calls `RequestPrinter.print(...)` on the `FilterableRequestSpecification` and only then calls `ctx.next(...)`. Two gaps open up from that ordering. First, every filter registered after it -- a `CookieFilter` replaying stored cookies, an authentication filter adding a header -- mutates the request *after* the log was written, so those additions are invisible. Second, the request that leaves the process is built by Apache HttpClient, which adds `Host`, `Content-Length`, `Connection` and transfer headers the specification never held. So on a museum ticketing suite, a `POST /v1/tickets` log showing no session cookie does not prove the cookie was missing. For genuine wire evidence you need HttpClient's own logging or a network capture. Register the logger last among the filters that touch the request if you want the fullest picture it can give.

code

java · 31 lines

java

import io.restassured.filter.cookie.CookieFilter;
import io.restassured.filter.log.RequestLoggingFilter;

import static io.restassured.RestAssured.given;

public class LogOrderingMatters {

    private final CookieFilter cookies = new CookieFilter();

    // logger first: the replayed session cookie is NOT in the printed output
    public void misleadingOrder() {
        given()
                .baseUri("https://api.museum.example")
                .filter(new RequestLoggingFilter())
                .filter(cookies)
                .post("/v1/visits/{code}/check-in", "TKT-7741")
        .then()
                .statusCode(200);
    }

    // logger last: the cookie filter has already added its header
    public void honestOrder() {
        given()
                .baseUri("https://api.museum.example")
                .filter(cookies)
                .filter(new RequestLoggingFilter())
                .post("/v1/visits/{code}/check-in", "TKT-7741")
        .then()
                .statusCode(200);
    }
}

go deeper

for a junior

Use the request log for what it is good at: checking that a parameter landed as a query value, that a body serialised as expected, and that a path placeholder was filled in.

for a middle

Explain the ordering. The filter prints and then calls ctx.next(...), so anything registered after it changes the request afterwards, and the HTTP client adds transport headers later still.

for a senior

Show the diagnostic discipline: before trusting a log to prove an absence, ask whether the log could have observed it. Reorder the filters, or reach for client-level logging or a capture when you need wire truth.

for a principal

Set the team's expectation about what harness output can and cannot prove, and make sure failure evidence that people will act on is captured where it is actually true rather than where it is easy.

RequestLoggingFilter is the most-used of REST Assured's shipped filters and the most-misread. The output looks like a transcript of an HTTP request, so people treat it as one. It is not. It is a rendering of the request specification -- the object REST Assured has built so far -- printed at one specific moment in the filter chain, and both halves of that sentence create a gap between what you read and what the server got.

What the filter actually does

Its filter(...) method is short enough to reason about completely:

It reads requestSpec.getURI(), and optionally URL-decodes it when the filter was constructed with showUrlEncodedUri false.
It calls RequestPrinter.print(...) with the method, the URI, the chosen LogDetail and the blacklisted-header set.
It returns ctx.next(requestSpec, responseSpec).

Step 2 happens before step 3. That single ordering fact is the whole answer, and it splits into two distinct causes of drift.

Cause one: later filters mutate the request

REST Assured sorts filters by precedence -- all seven shipped filters take the default of 1000 -- and the sort is stable, so registration order decides among them. Anything registered after RequestLoggingFilter runs after the log was already written:

A CookieFilter registered second replays every stored cookie that matches the request origin, adding them to the specification. Your log shows no Cookie header; the server sees one.
A SessionFilter registered second attaches the stored session identifier the same way, and the same way invisibly.
REST Assured's own internal form-authentication and CSRF filters run inside the chain too, and can add a token field the log never shows.

The cure is ordering: register RequestLoggingFilter last among the filters that touch the request, so it prints the most complete specification. That still does not close the second gap.

Cause two: the HTTP client is not the specification

The specification is a REST Assured object. The actual message is assembled by Apache HttpClient, which adds and normalises headers on its own:

Host, derived from the target URI.
Content-Length or Transfer-Encoding, decided by how the body is written.
Connection, Accept-Encoding and User-Agent defaults.
Authentication headers produced by a challenge round trip, since a scheme that waits for a 401 has not yet sent anything at logging time.
Redirect handling: if the client follows a 302, the second request never passes through your filter chain at all.

None of that appears in RequestLoggingFilter's output, because none of it exists yet when the filter runs. The library's own documentation is explicit that you cannot regard the logged details as what was actually sent.

What this means for a museum ticketing suite

Consider a failing POST /v1/visits/{ticketCode}/check-in that returns 401. The log shows the URI, the JSON body and an Accept header, and no Cookie. The tempting conclusion -- "the session cookie was not sent" -- is unsupported by that evidence, because a CookieFilter registered after the logger would have added it silently. Three moves separate diagnosis from guessing:

Reorder. Put the logging filter after the cookie filter and rerun; if the cookie now appears, the log was the problem, not the request.
Introspect. Read the built specification back rather than reading a printed rendering of it, which is a different mechanism from logging and answers a different question.
Capture. Turn on the HTTP client's own logging, or capture the traffic outside the process. Only that tells you what the socket carried.

The habit this should leave you with

There is a general discipline underneath the specific class, and it is what a senior answer is really demonstrating:

Know at which point in a chain an observability hook runs, because a log written early is a log of intent.
Distinguish evidence about what the harness built from evidence about what the system received; they answer different questions and they fail differently.
When a test fails on something the log seems to prove, check whether the log could even have seen it before you start changing the code.

RequestLoggingFilter is genuinely useful -- it is the fastest way to see whether your parameters landed as query or form values, whether your body serialised the way you expected, and whether a path placeholder was filled. Used for that, it is exactly right. Used as proof of what crossed the network, it will eventually cost you an afternoon.

The compact version: the filter prints the specification, before ctx.next(...), and the client adds more afterwards -- so it shows intent, and only a wire capture shows fact.

`RequestLoggingFilter` is the most-used of REST Assured's shipped filters and the most-misread. The output looks like a transcript of an HTTP request, so people treat it as one. It is not. It is a rendering of the **request specification** -- the object REST Assured has built so far -- printed at one specific moment in the filter chain, and both halves of that sentence create a gap between what you read and what the server got. ## What the filter actually does Its `filter(...)` method is short enough to reason about completely: 1. It reads `requestSpec.getURI()`, and optionally URL-decodes it when the filter was constructed with `showUrlEncodedUri` false. 2. It calls `RequestPrinter.print(...)` with the method, the URI, the chosen `LogDetail` and the blacklisted-header set. 3. It returns `ctx.next(requestSpec, responseSpec)`. Step 2 happens **before** step 3. That single ordering fact is the whole answer, and it splits into two distinct causes of drift. ## Cause one: later filters mutate the request REST Assured sorts filters by precedence -- all seven shipped filters take the default of `1000` -- and the sort is stable, so registration order decides among them. Anything registered after `RequestLoggingFilter` runs after the log was already written: - A `CookieFilter` registered second replays every stored cookie that matches the request origin, adding them to the specification. Your log shows no `Cookie` header; the server sees one. - A `SessionFilter` registered second attaches the stored session identifier the same way, and the same way invisibly. - REST Assured's own internal form-authentication and CSRF filters run inside the chain too, and can add a token field the log never shows. The cure is ordering: register `RequestLoggingFilter` **last** among the filters that touch the request, so it prints the most complete specification. That still does not close the second gap. ## Cause two: the HTTP client is not the specification The specification is a REST Assured object. The actual message is assembled by Apache HttpClient, which adds and normalises headers on its own: - `Host`, derived from the target URI. - `Content-Length` or `Transfer-Encoding`, decided by how the body is written. - `Connection`, `Accept-Encoding` and `User-Agent` defaults. - Authentication headers produced by a challenge round trip, since a scheme that waits for a 401 has not yet sent anything at logging time. - Redirect handling: if the client follows a 302, the second request never passes through your filter chain at all. None of that appears in `RequestLoggingFilter`'s output, because none of it exists yet when the filter runs. The library's own documentation is explicit that you cannot regard the logged details as what was actually sent. ## What this means for a museum ticketing suite Consider a failing `POST /v1/visits/{ticketCode}/check-in` that returns 401. The log shows the URI, the JSON body and an `Accept` header, and no `Cookie`. The tempting conclusion -- *"the session cookie was not sent"* -- is unsupported by that evidence, because a `CookieFilter` registered after the logger would have added it silently. Three moves separate diagnosis from guessing: - **Reorder.** Put the logging filter after the cookie filter and rerun; if the cookie now appears, the log was the problem, not the request. - **Introspect.** Read the built specification back rather than reading a printed rendering of it, which is a different mechanism from logging and answers a different question. - **Capture.** Turn on the HTTP client's own logging, or capture the traffic outside the process. Only that tells you what the socket carried. ## The habit this should leave you with There is a general discipline underneath the specific class, and it is what a senior answer is really demonstrating: 1. Know at which point in a chain an observability hook runs, because a log written early is a log of intent. 2. Distinguish evidence about **what the harness built** from evidence about **what the system received**; they answer different questions and they fail differently. 3. When a test fails on something the log seems to prove, check whether the log could even have seen it before you start changing the code. `RequestLoggingFilter` is genuinely useful -- it is the fastest way to see whether your parameters landed as query or form values, whether your body serialised the way you expected, and whether a path placeholder was filled. Used for that, it is exactly right. Used as proof of what crossed the network, it will eventually cost you an afternoon. The compact version: the filter prints the specification, before `ctx.next(...)`, and the client adds more afterwards -- so it shows intent, and only a wire capture shows fact.

If the request log is not the wire, what would you use to see the real bytes?
Apache HttpClient's own logging, since it sits below REST Assured and writes the message it assembles, or a network capture outside the process. Both show the headers the client adds and the follow-up request after a redirect, neither of which passes through REST Assured's filter chain.
How would you make RequestLoggingFilter show as much of the truth as it can?
Register it last among the filters that modify the request, so cookie, session and authentication filters have already run. Keep it on a shared request specification rather than per test so the ordering is consistent, and remember that client-added headers such as `Host` and `Content-Length` still never appear.

It is the photocopy you take of a parcel's paperwork before handing it to the courier: accurate about what you wrote, silent about the labels and weight stickers the depot adds afterwards.

saying these in an interview costs you the question

Treating the request log as proof of what the server received
Assuming no Cookie line in the log means no cookie was sent
Thinking the filter prints after the request has been sent
Forgetting that Apache HttpClient adds headers of its own
Believing a redirect's second request also passes through the filters

Why can REST Assured's RequestLoggingFilter output differ from what the server actually receives?

§ answer

basics

solid answer

code

§ go deeper

▾level notes4 levels

▾deep dive~4 min

What the filter actually does

Cause one: later filters mutate the request

Cause two: the HTTP client is not the specification

What this means for a museum ticketing suite

The habit this should leave you with

▾common follow-ups2 questions

▾analogy~10 s

▾red flags5 flags

What the filter actually does

Cause one: later filters mutate the request

Cause two: the HTTP client is not the specification

What this means for a museum ticketing suite

The habit this should leave you with

answer

go deeper