Hi all, Further to my previous message to the list I can now reliably reproduce the behaviour where certain requests using authentication headers receive 503 responses from HAProxy 1.7.3.
We’re making a request twice, once without basic auth (checking that basic auth is prompted on the URL) and then a second, identical, request but with the the basic auth Authorization header set. The request body is textual file content, so these requests are larger than average GET/POST requests (Content-Length > 3500). We don't see this problem with smaller requests. The two requests happen on a single connection to HAProxy as we have keepalive enabled. The first request is always sent to the backend successfully and but the second request receives a 503 status from HAProxy whenever the request size is over a Content-Length of 3500. Just below this size the 503’s are sporadic and at very small body sizes it doesn’t happen at all - the request is sent to the backend succesfully. There are no errors visible by catting the stats socket, and the second request/503 response is not present in logs at all (using option httplog). We don't get this behaviour when keeping all other variables the same (client, request body & HAProxy configuration) using HAProxy 1.6.11. Thanks in advance for any help anyone can provide. Jon Relevant parts of a client log. Our app server runs IIS/8.5, the 503 Service Unavailable is from our HAProxy 503 template. 2017/03/02 12:14:02:133 UTC [DEBUG] DefaultHttpClient - Attempt 1 to execute request 2017/03/02 12:14:02:133 UTC [DEBUG] DefaultClientConnection - Sending request: POST /v1/expost/check HTTP/1.1 2017/03/02 12:14:02:134 UTC [DEBUG] wire - >> "POST /v1/expost/check HTTP/1.1[\r][\n]" 2017/03/02 12:14:02:134 UTC [DEBUG] wire - >> "Content-Length: 3634[\r][\n]" 2017/03/02 12:14:02:151 UTC [DEBUG] wire - << "HTTP/1.1 401 Unauthorized[\r][\n]" 2017/03/02 12:14:02:152 UTC [DEBUG] wire - << "Server: Microsoft-IIS/8.5[\r][\n]” 2017/03/02 12:14:02:157 UTC [DEBUG] DefaultHttpClient - Connection can be kept alive indefinitely 2017/03/02 12:14:02:158 UTC [DEBUG] DefaultHttpClient - Authentication required 2017/03/02 12:14:02:159 UTC [DEBUG] DefaultHttpClient - XXX:443 requested authentication 2017/03/02 12:14:02:170 UTC [DEBUG] RequestTargetAuthentication - Target auth state: CHALLENGED 2017/03/02 12:14:02:171 UTC [DEBUG] RequestTargetAuthentication - Generating response to an authentication challenge using basic scheme 2017/03/02 12:14:02:179 UTC [DEBUG] DefaultHttpClient - Attempt 2 to execute request 2017/03/02 12:14:02:179 UTC [DEBUG] DefaultClientConnection - Sending request: POST /v1/expost/check HTTP/1.1 2017/03/02 12:14:02:179 UTC [DEBUG] wire - >> "POST /v1/expost/check HTTP/1.1[\r][\n]" 2017/03/02 12:14:02:182 UTC [DEBUG] wire - >> "Content-Length: 3634[\r][\n]" 2017/03/02 12:14:02:196 UTC [DEBUG] wire - << "HTTP/1.0 503 Service Unavailable[\r][\n]" 2017/03/02 12:14:02:196 UTC [DEBUG] wire - << "Cache-Control: no-cache[\r][\n]" 2017/03/02 12:14:02:196 UTC [DEBUG] wire - << "Connection: close[\r][\n]" On 21 February 2017 at 18:36:21, Jon Simpson ([email protected]) wrote: Hi all, We’re experiencing a problem with clients receiving 503 responses when making a request to a backend with a Authorisation header set (basic authentication) using HAProxy 1.7.2. We didn't experience this with HAProxy 1.6.11. The HAProxy stats page shows that the backends in question have no downtime (what I would usually expect to see in cases where 503 statuses are returned). Only certain clients are affected by this behaviour - a number have been completely unaffected. The behaviour we're seeing shares some similarities to one that reported in 1.7.1 ( https://www.mail-archive.com/[email protected]/msg24613.html) but we're not seeing any useful output from show errors and the code is 503. We do know that packet reordering/retranmission is happening in at least one case. Our clients can retry these requests and occasionally get them to succeed. Additionally, they found putting delays between the post of data and close of the connection did lead to successes in making the connection. We're sure HAProxy is the source of our client's 503 errors as the clients are getting the text of our custom 503 page (rather than a 503 from the IIS service behind). For context - we have an ELB in TCP-only mode in front of the HAProxy (to distribute connections across multiple HAProxy instances) if that's relevant. We're using the latest HAProxy 1.7 Ubuntu PPA's ( https://launchpad.net/~vbernat/+archive/ubuntu/haproxy-1.7). Logging is enabled, with the following format string (we capture the Host request header with a len of 64 for +Q) - log-format %ci:%cp\ [%t]\ %ft\ %b/%s\ %Tq/%Tw/%Tc/%Tr/%Tt\ %ST\ %B\ %CC\ %CS\ %tsc\ %ac/%fc/%bc/%sc/%rc\ %sq/%bq\ %hr\ %hs\ %{+Q}r\ %ID but we don't appear to be seeing the requests that are receiving 503 responses being logged. We do use 'option dontlognull' as these HAProxy instances are behind ELB, and hence get checked for TCP liveness but as these are valid HTTPS requests being returned 503 I would expect them to be in our main haproxy log. I'd really appreciate any input you could give on further triage steps (especially being able to identify in log when clients are receiving 503 responses) or potential causes we can look at. Thanks, Jon
