Re: confused by HAProxy log line
The NOSRV can simply mean you have received a request that does not match
your backend selection acls, common to bots probing for wordpress login
page etc.
On Fri, 12 Oct 2018 12:23 am Michał Pasierb
wrote:
> 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 ?
>
> Regards,
> Michal
>
> On Thu, Oct 11, 2018 at 1:00 PM Aleksandar Lazic
> 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 :46007 http-in c_backend/
>> > 44/-1/-1/-1/44 -1 25 - - CHNN 143/36/2/0/3 0/0 {} {} "PUT
>> /api/xyz/status
>> > HTTP/1.1" 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 and connection time of -1. There were 3 connection
>> retries.
>> > HAProxy got 25 bytes from a server. The config contains:
>> >
>> > defaults
>> > retries 3
>> > optionredispatch
>> >
>> > 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, "" is indicated instead of a server name. If the
>> request was
>> intercepted by the stats subsystem, "" 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
>>
>
Re: confused by HAProxy log line
Hi.
Well there are only several cases when NOSRV will be set.
http://git.haproxy.org/?p=haproxy-1.7.git=search=HEAD=grep=NOSRV
Please can you share the status page and some stats from the os.
It could be also that you hit some OS limits.
Please also share your confi, os, tcp settings as my crystal ball is at
maintenance :-)
Regards
Aleks
Ursprüngliche Nachricht
Von: "Michał Pasierb"
Gesendet: 11. Oktober 2018 15:21:26 MESZ
An: al-hapr...@none.at
CC: haproxy@formilux.org
Betreff: Re: confused by HAProxy log line
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 ?
Regards,
Michal
On Thu, Oct 11, 2018 at 1:00 PM Aleksandar Lazic 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 :46007 http-in c_backend/
> > 44/-1/-1/-1/44 -1 25 - - CHNN 143/36/2/0/3 0/0 {} {} "PUT /api/xyz/status
> > HTTP/1.1" 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 and connection time of -1. There were 3 connection
> retries.
> > HAProxy got 25 bytes from a server. The config contains:
> >
> > defaults
> > retries 3
> > optionredispatch
> >
> > 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, "" is indicated instead of a server name. If the
> request was
> intercepted by the stats subsystem, "" 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
>
Re: confused by HAProxy log line
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 ?
Regards,
Michal
On Thu, Oct 11, 2018 at 1:00 PM Aleksandar Lazic 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 :46007 http-in c_backend/
> > 44/-1/-1/-1/44 -1 25 - - CHNN 143/36/2/0/3 0/0 {} {} "PUT /api/xyz/status
> > HTTP/1.1" 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 and connection time of -1. There were 3 connection
> retries.
> > HAProxy got 25 bytes from a server. The config contains:
> >
> > defaults
> > retries 3
> > optionredispatch
> >
> > 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, "" is indicated instead of a server name. If the
> request was
> intercepted by the stats subsystem, "" 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
>
Re: confused by HAProxy log line
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 :46007 http-in c_backend/
> 44/-1/-1/-1/44 -1 25 - - CHNN 143/36/2/0/3 0/0 {} {} "PUT /api/xyz/status
> HTTP/1.1" 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 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, "" is indicated instead of a server name. If the request was
intercepted by the stats subsystem, "" 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
confused by HAProxy log line
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 :46007 http-in c_backend/
44/-1/-1/-1/44 -1 25 - - CHNN 143/36/2/0/3 0/0 {} {} "PUT /api/xyz/status
HTTP/1.1" 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 and connection time of -1. There were 3
connection retries. HAProxy got 25 bytes from a server. The config contains:
defaults
retries 3
optionredispatch
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 ?
Thanks,
Michal
