Hello,
I did not mention it but all servers in c_backend have a httpchk
configured. There is nothing in the HAProxy logs indicating the servers or
the backend was not available during the time of the request. Indeed the
stats page shows only 4 health checks did not pass on each server since
HAProxy started and I know they were triggered by application deployment to
the servers. This is rock solid. The servers in the backend handle
thousands of requests during a day and log lines like these occur about 50
times a day.
I tried to replicate the termination state in my lab but I failed. I got
only CC--, CR-- and CD-- and http status is always set correctly (not to
-1). The origin log line has CH-- which indicates HAProxy was waiting for
reponse headers from a server so (this implies?) it connected somewhere. So
why server is marked as <NOSRV> ?
Regards,
Michal
On Thu, Oct 11, 2018 at 1:00 PM Aleksandar Lazic <al-hapr...@none.at> wrote:
> Am 11.10.2018 um 10:33 schrieb Michał Pasierb:
> > Hello,
> >
> > I have a problem understanding a particular log line from HAProxy 1.7.11
> in
> > production system. My clients report problems from time to time. They
> make
> > another request and all is OK. This is the log format used:
> >
> > log-format %tr\ %ci:%cp\ %ft\ %b/%s\ %TR/%Tw/%Tc/%Tr/%Ta\ %ST\ %B\ %CC\
> %CS\
> > %tsc\ %ac/%fc/%bc/%sc/%rc\ %sq/%bq\ %hr\ %hs\ %{+Q}r\ %ID\ %U\
> %[res.comp]
> >
> > and the problematic log line:
> >
> > 02/Oct/2018:09:55:14.997 <ip-redacted>:46007 http-in c_backend/<NOSRV>
> > 44/-1/-1/-1/44 -1 25 - - CHNN 143/36/2/0/3 0/0 {} {} "PUT /api/xyz/status
> > HTTP/1.1" <id-redacted> 764 0
> >
> > I can see that c_backend was properly selected based on acls. I can see
> that
> > client sent 764 bytes to HAProxy. The termination code is CH - client
> aborted
> > connection while HAProxy was waiting for headers from server. What
> server ?
> > There is <NOSRV> and connection time of -1. There were 3 connection
> retries.
> > HAProxy got 25 bytes from a server. The config contains:
> >
> > defaults
> > retries 3
> > option redispatch
> >
> > Yet the retries is not +3 so it seems the redispatch did not take place.
> >
> > This is all confusing evidence. Can you explain what really happened ?
>
> None of the c_backend servers are reachable.
> I assume that the -1 value is the status_code.
>
> Cite from
> https://cbonte.github.io/haproxy-dconv/1.7/configuration.html#8.2.3
>
> ###
>
> - "status_code" is the HTTP status code returned to the client. This
> status
> is generally set by the server, but it might also be set by haproxy
> when
> the server cannot be reached or when its response is blocked by
> haproxy.
>
> ...
>
> - "server_name" is the name of the last server to which the connection
> was
> sent, which might differ from the first one if there were connection
> errors
> and a redispatch occurred. Note that this server belongs to the backend
> which processed the request. If the request was aborted before
> reaching a
> server, "<NOSRV>" is indicated instead of a server name. If the
> request was
> intercepted by the stats subsystem, "<STATS>" is indicated instead.
> ###
>
> I suggest to use some checks for the c_backend for example
>
>
> https://cbonte.github.io/haproxy-dconv/1.7/configuration.html#4-option%20httpchk
>
> > Thanks,
> > Michal
>
> Best regards
> Aleks
>
