API returns an unexpected Content-Length with a 304 Not Modified

[feinoujc]

Version: 4.7.1

We are experiencing an issue where we have ServiceControl behind a reverse proxy (nginx) and every other request in a browser is failing. We think we have tracked it down to the api returning a non-zero Content-Length when it returns a 304. This is (probably?) incorrect behavior, and NGINX chokes on this and ends up returning a 504

A simulation in curl is below

curl --head -XGET http://servicecontrol.particular.svc.cluster.local:33333/api/recoverability/group/Endpoint%20Name?classifierFilter=email

HTTP/1.1 200 OK
Cache-Control: max-age=0, private
Transfer-Encoding: chunked
Content-Type: application/json; charset=utf-8
ETag: "2A524415-3AB3-3A99-98A8-D2B8EEAD4A91"
Vary: Accept
Server: Microsoft-HTTPAPI/2.0
X-Particular-Version: 4.7.1
Date: Wed, 21 Oct 2020 15:20:04 GMT

Now the cache hit....

curl --head -XGET --header 'If-None-Match: "2A524415-3AB3-3A99-98A8-D2B8EEAD4A91"' http://servicecontrol.particular.svc.cluster.local:33333/api/recoverability/groups/Endpoint%20Name?classifierFilter=email

HTTP/1.1 304 Not Modified
Cache-Control: max-age=0, private
Content-Length: 2
Content-Type: application/json; charset=utf-8
ETag: "2A524415-3AB3-3A99-98A8-D2B8EEAD4A91"
Vary: Accept
Server: Microsoft-HTTPAPI/2.0
X-Particular-Version: 4.7.1
Date: Wed, 21 Oct 2020 15:21:33 GMT

Note the Content-Length: 2

The best I can tell, there is, in fact, no body

Here is that again, with full --verbose on

curl --verbose --header 'If-None-Match: "2A524415-3AB3-3A99-98A8-D2B8EEAD4A91"' http://servicecontrol.particular.svc.cluster.local:33333/api/recoverability/groups/Endpoint%20Name?classifierFilter=email

output

* Expire in 0 ms for 6 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 0 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 1 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 2 ms for 1 (transfer 0x561b2737ff50)
* Expire in 4 ms for 1 (transfer 0x561b2737ff50)
* Expire in 3 ms for 1 (transfer 0x561b2737ff50)
* Expire in 3 ms for 1 (transfer 0x561b2737ff50)
* Expire in 4 ms for 1 (transfer 0x561b2737ff50)
* Expire in 4 ms for 1 (transfer 0x561b2737ff50)
* Expire in 4 ms for 1 (transfer 0x561b2737ff50)
* Expire in 4 ms for 1 (transfer 0x561b2737ff50)
* Expire in 5 ms for 1 (transfer 0x561b2737ff50)
* Expire in 5 ms for 1 (transfer 0x561b2737ff50)
* Expire in 4 ms for 1 (transfer 0x561b2737ff50)
* Expire in 6 ms for 1 (transfer 0x561b2737ff50)
* Expire in 6 ms for 1 (transfer 0x561b2737ff50)
* Expire in 8 ms for 1 (transfer 0x561b2737ff50)
* Expire in 7 ms for 1 (transfer 0x561b2737ff50)
* Expire in 7 ms for 1 (transfer 0x561b2737ff50)
* Expire in 8 ms for 1 (transfer 0x561b2737ff50)
* Expire in 8 ms for 1 (transfer 0x561b2737ff50)
* Expire in 8 ms for 1 (transfer 0x561b2737ff50)
* Expire in 16 ms for 1 (transfer 0x561b2737ff50)
* Expire in 10 ms for 1 (transfer 0x561b2737ff50)
* Expire in 10 ms for 1 (transfer 0x561b2737ff50)
* Expire in 16 ms for 1 (transfer 0x561b2737ff50)
* Expire in 14 ms for 1 (transfer 0x561b2737ff50)
* Expire in 14 ms for 1 (transfer 0x561b2737ff50)
* Expire in 50 ms for 1 (transfer 0x561b2737ff50)
*   Trying 172.21.169.149...
* TCP_NODELAY set
* Expire in 200 ms for 4 (transfer 0x561b2737ff50)
* Connected to servicecontrol.particular.svc.cluster.local (172.21.169.149) port 33333 (#0)
> GET /api/recoverability/groups/Endpoint%20Name?classifierFilter=email HTTP/1.1
> Host: servicecontrol.particular.svc.cluster.local:33333
> User-Agent: curl/7.64.0
> Accept: */*
> If-None-Match: "2A524415-3AB3-3A99-98A8-D2B8EEAD4A91"
>
< HTTP/1.1 304 Not Modified
< Cache-Control: max-age=0, private
< Content-Length: 2
< Content-Type: application/json; charset=utf-8
< ETag: "2A524415-3AB3-3A99-98A8-D2B8EEAD4A91"
< Vary: Accept
< Server: Microsoft-HTTPAPI/2.0
< X-Particular-Version: 4.7.1
< Date: Wed, 21 Oct 2020 15:30:45 GMT
<
* Excess found in a non pipelined read: excess = 2 url = /api/recoverability/groups/Endpoint%20Name (zero-length body)
* Connection #0 to host servicecontrol.particular.svc.cluster.local left intact

It even throws curl off a bit
Excess found in a non pipelined read: excess = 2

[danielmarbach]

@feinoujc Did you recently update from ServiceControl versions older than 4.4? I'm asking because we have replaced the guts of ServiceControl in how we service web requests and I think it might be not properly handling 304 cases in the middleware.

[feinoujc]

@danielmarbach thanks for the reply. No we've always been on version 4.7.1

[danielmarbach]

@feinoujc So it seems we are violating RFC2616 then due to

The 304 response MUST NOT contain a message-body, and thus is always terminated by the first empty line after the header fields.

https://www.w3.org/Protocols/rfc2616/rfc2616-sec10.html#sec10.3.5

so that means we should not be returning either Content-Type or Content-Length that probably trips up NGINX. As a temporary workaround is it possible for you to rewrite what you get from ServiceControl in NGINX and see if it works when the length is removed?

[feinoujc]

As a temporary workaround...

We've actually already worked around the issue for now by stripping the ETag header from all replies proxied for servicecontrol

proxy_hide_header ETag;

Obviously this breaks caching, but we are finding the performance to be acceptable for now

[danielmarbach]

I found now the updated RFC

The server generating a 304 response MUST generate any of the
following header fields that would have been sent in a 200 (OK)
response to the same request: Cache-Control, Content-Location, Date,
ETag, Expires, and Vary.

Since the goal of a 304 response is to minimize information transfer
when the recipient already has one or more cached representations, a
sender SHOULD NOT generate representation metadata other than the
above listed fields unless said metadata exists for the purpose of
guiding cache updates (e.g., Last-Modified might be useful if the
response does not have an ETag field).

https://tools.ietf.org/html/rfc7232#section-4.1

Can you clarify why you hide the Etag header?

I see the real culprit on our side is that we are adding string.Empty to the NotModified response which then sets the Content-Length to 2 as well as the content-type header. Writing the ETag should still be fine according to the specification.

It also seems part of our code is not correct because we assume we can set the last-modified but that is not possible in the version of ASP we are using when there is no content. Flagging this as a bug. I'll keep you posted

[feinoujc]

Can you clarify why you hide the Etag header?

It prevents the browser/client from sending the If-None-Match header in the first place, side-stepping the issue

The symptom I originally was seeing is the "every other" browser page load was failing. First it gets the 200 with an ETag, sends the etag on the next request as If-None-Match, servicecontrol returns a 304 and it all goes south from there between servicecontrol, the reverse proxy and the client

As I mentioned, though, this breaks caching as it was intended to be used here

[danielmarbach]

@feinoujc I've raised #2241 for now. I'll keep you posted about the next steps

[danielmarbach]

@feinoujc we are going to bring the fix into 4.13.3 that should go out soonish