503 (Service Unavailable) from Varnish on POST request using Digest Authentication
Dridi Boukelmoune
dridi at varni.sh
Fri May 11 14:15:10 UTC 2018
On Fri, May 11, 2018 at 3:58 PM, Sergio Rus <sergio at sergiorus.com> wrote:
> I would like to validate my theory over a weird issue I had with Varnish 3.
It's reached EOL for a long while now, we aren't supporting Varnish 3...
> So we have an endpoint on the server using Digest Authentication and I send
> a POST request to that endpoint without including the auth header:
>
> curl --data-urlencode foobar@/home/foo/bar.txt
> https://www.example.com/foobar/
>
> Varnish is set up to pass all the requests going to that endpoint. By
> default POST requests are passed too, and I didn't change that behaviour. So
> we can assume Varnish is not trying to cache anything here.
>
> I would expect to get the response 401 UNAUTHORIZED from the server, but
> instead I get a 503 coming from Varnish. This is the log in Varnish for that
> request:
>
> SessionOpen c 127.0.0.1 34005 localhost:6081
> ReqStart c 127.0.0.1 34005 1873165756
> RxRequest c POST
> RxURL c /foobar/
> RxProtocol c HTTP/1.0
> RxHeader c Host: www.example.com
> RxHeader c X-Real-IP: 123.123.123.123
> RxHeader c X-Forwarded-For: 123.123.123.123
> RxHeader c X-Forwarded-Protocol: https
> RxHeader c X-SSL-Protocol: TLSv1.2
> RxHeader c X-Forwarded-Proto: https
> RxHeader c X-Url-Scheme: https
> RxHeader c Connection: close
> RxHeader c Content-Length: 7811
> RxHeader c User-Agent: foobar
> RxHeader c Accept: */*
> RxHeader c Content-Type: application/x-www-form-urlencoded
> VCL_call c recv pass
> VCL_call c hash
> Hash c /foobar/
> Hash c www.example.com
> VCL_return c hash
> VCL_call c pass pass
> Backend c 17 default default
> TTL c 1873165756 RFC -1 -1 -1 1526037072 0 1526037072 0 0
> VCL_call c fetch
> TTL c 1873165756 VCL -1 3600 -1 1526037072 -0
> TTL c 1873165756 VCL 120 3600 -1 1526037072 -0
> VCL_return c hit_for_pass
> ObjProtocol c HTTP/1.1
> ObjResponse c UNAUTHORIZED
> ObjHeader c Server: foobar
> ObjHeader c Date: Fri, 11 May 2018 11:11:12 GMT
> ObjHeader c Content-Type: text/html; charset=utf-8
> ObjHeader c WWW-Authenticate: Digest
> nonce="1526677072.03:1636:cb98ghghgh49495f1174226f25a2f02c79",
> realm="foobar", algorithm="MD5",
> opaque="9cbc87eb65454ff85bff73b2b38c06c34343e8", qop="auth", stale="false"
> ObjHeader c Content-Language: en-us
> ObjHeader c Vary: Accept-Encoding, Cookie, User-Agent
> VCL_call c error deliver
According to this log record you could have a return(error) in your
VCL, could it be that your larger object triggers some condition in
your VCL that leads to a return(error) statement?
> VCL_call c deliver deliver
> TxProtocol c HTTP/1.1
> TxStatus c 503
> TxResponse c Service Unavailable
> TxHeader c Server: Varnish
> TxHeader c Content-Type: text/html; charset=utf-8
> TxHeader c Retry-After: 5
> TxHeader c Content-Length: 419
> TxHeader c Accept-Ranges: bytes
> TxHeader c Date: Fri, 11 May 2018 11:11:12 GMT
> TxHeader c X-Varnish: 1873165756
> TxHeader c Age: 0
> TxHeader c Via: 1.1 varnish
> TxHeader c Connection: close
> Length c 419
> ReqEnd c 1873165756 1526037072.059784174 1526037072.061955214
> 0.000038624 0.002078533 0.000092506
>
> But reducing the size of the payload a little bit, it works:
>
> SessionOpen c 127.0.0.1 36019 localhost:6081
> ReqStart c 127.0.0.1 36019 1873166315
> RxRequest c POST
> RxURL c /foobar/
> RxProtocol c HTTP/1.0
> RxHeader c Host: www.example.com
> RxHeader c X-Real-IP: 123.123.123.123
> RxHeader c X-Forwarded-For: 123.123.123.123
> RxHeader c X-Forwarded-Protocol: https
> RxHeader c X-SSL-Protocol: TLSv1.2
> RxHeader c X-Forwarded-Proto: https
> RxHeader c X-Url-Scheme: https
> RxHeader c Connection: close
> RxHeader c Content-Length: 7261
> RxHeader c User-Agent: foobar
> RxHeader c Accept: */*
> RxHeader c Content-Type: application/x-www-form-urlencoded
> VCL_call c recv pass
> VCL_call c hash
> Hash c /foobar/
> Hash c www.example.com
> VCL_return c hash
> VCL_call c pass pass
> Backend c 17 default default
> TTL c 1873166315 RFC -1 -1 -1 1526037112 0 1526037112 0 0
> VCL_call c fetch
> TTL c 1873166315 VCL -1 3600 -1 1526037112 -0
> TTL c 1873166315 VCL 120 3600 -1 1526037112 -0
> VCL_return c hit_for_pass
> ObjProtocol c HTTP/1.1
> ObjResponse c UNAUTHORIZED
> ObjHeader c Server: gunicorn/19.0.0
> ObjHeader c Date: Fri, 11 May 2018 11:11:52 GMT
> ObjHeader c Content-Type: text/html; charset=utf-8
> ObjHeader c WWW-Authenticate: Digest
> nonce="15260334112.14:3917:d3d558ed34342e8e723d8219bf3b20fc38",
> realm="foobar", algorithm="MD5",
> opaque="b32cd3f7b82213212397ded88c00ea06f111a29c", qop="auth", stale="false"
> ObjHeader c Content-Language: en-us
> ObjHeader c Vary: Accept-Encoding, Cookie, User-Agent
> VCL_call c deliver deliver
> TxProtocol c HTTP/1.1
> TxStatus c 401
> TxResponse c UNAUTHORIZED
> TxHeader c Server: gunicorn/19.0.0
> TxHeader c Content-Type: text/html; charset=utf-8
> TxHeader c WWW-Authenticate: Digest
> nonce="15260334112.14:3917:d3d558ed34342e8e723d8219bf3b20fc38",
> realm="foobar", algorithm="MD5",
> opaque="b32cd3f7b82213212397ded88c00ea06f111a29c", qop="auth", stale="false"
> TxHeader c Content-Language: en-us
> TxHeader c Vary: Accept-Encoding, Cookie, User-Agent
> TxHeader c Content-Length: 0
> TxHeader c Accept-Ranges: bytes
> TxHeader c Date: Fri, 11 May 2018 11:11:52 GMT
> TxHeader c X-Varnish: 1873166315
> TxHeader c Age: 0
> TxHeader c Via: 1.1 varnish
> TxHeader c Connection: close
> Length c 0
> ReqEnd c 1873166315 1526037112.192578554 1526037112.194519758
> 0.000039816 0.001864910 0.000076294
>
> Why is that happening? Well, I have my own theory and this is what I would
> like to validate here. I think it's because there is some sort of limit set
> in Varnish for the size of the objects to keep in memory, so when the
> request size (headers + payload) is bigger than a threshold, and the request
> can not be delivered to the backend, it fails with 503. But if the request
> is smaller, Varnish keeps the object in memory and just sends to the client
> the response from the backend.
>
> Anyone here that could help me understand this weird behaviour?
If it's the size of the response, only headers count, not the body. In
which case you do have knobs to allow larger HTTP responses:
https://varnish-cache.org/docs/3.0/reference/varnishd.html#run-time-parameters
See http_resp_size and http_resp_hdr_len for respectively the size of
the whole set of response headers and the size of individual headers.
Dridi
More information about the varnish-misc
mailing list