Re: haproxy 1.3.14.2 "bad request" outage

From: Willy Tarreau <w#1wt.eu>
Date: Fri, 24 Apr 2009 22:29:06 +0200


Hi,

On Fri, Apr 24, 2009 at 09:36:34AM +0200, Jean-Baptiste Quenot wrote:
> Hi there,
>
> This morning I noticed interesting problems regarding haproxy
> (1.3.14.2 here, yes I know archeology might be involved, I must
> upgrade). I have to say that we had a blackout during a few hours
> this night on our site, and servers restarted when power supply came
> back. This may be one of the reasons, network problems might also be
> involved.
>
> The problem only happened on one of the remote backends (WAN setup).
> An haproxy reload fixed the problem. FWIW note that the related URLs
> were protected with Basic authentication.
>
> Here are the offending logs (with name of host and frontend changed):
>
> Apr 24 07:38:27 myhost haproxy[4499]: 127.0.0.1:51565
> [24/Apr/2009:07:38:27.139] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 206/206/0/0 0/0 {} "<BADREQ>"
> Apr 24 07:38:49 myhost haproxy[4499]: 127.0.0.1:44142
> [24/Apr/2009:07:38:49.177] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 206/206/0/0 0/0 {} "<BADREQ>"
> Apr 24 07:42:07 myhost haproxy[4499]: 127.0.0.1:48588
> [24/Apr/2009:07:42:07.351] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 204/204/0/0 0/0 {} "<BADREQ>"
> Apr 24 07:42:39 myhost haproxy[4499]: 127.0.0.1:49220
> [24/Apr/2009:07:42:39.231] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 205/205/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:06:12 myhost haproxy[4499]: 127.0.0.1:55251
> [24/Apr/2009:08:06:12.106] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 202/202/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:14:48 myhost haproxy[4499]: 127.0.0.1:59733
> [24/Apr/2009:08:14:48.979] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 201/201/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:30:50 myhost haproxy[4499]: 127.0.0.1:50823
> [24/Apr/2009:08:30:50.775] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 205/205/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:30:59 myhost haproxy[4499]: 127.0.0.1:51282
> [24/Apr/2009:08:30:59.542] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 205/205/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:31:29 myhost haproxy[4499]: 127.0.0.1:52191
> [24/Apr/2009:08:31:29.621] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 199/199/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:31:32 myhost haproxy[4499]: 127.0.0.1:52423
> [24/Apr/2009:08:31:32.993] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 200/200/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:31:34 myhost haproxy[4499]: 127.0.0.1:52628
> [24/Apr/2009:08:31:34.124] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 199/199/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:32:58 myhost haproxy[4499]: 127.0.0.1:55046
> [24/Apr/2009:08:32:58.916] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 201/201/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:33:01 myhost haproxy[4499]: 127.0.0.1:55351
> [24/Apr/2009:08:33:01.277] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 203/203/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:33:01 myhost haproxy[4499]: 127.0.0.1:55546
> [24/Apr/2009:08:33:01.558] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 201/201/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:33:01 myhost haproxy[4499]: 127.0.0.1:55740
> [24/Apr/2009:08:33:01.641] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 200/200/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:33:08 myhost haproxy[4499]: 127.0.0.1:56143
> [24/Apr/2009:08:33:08.816] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 202/202/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:33:09 myhost haproxy[4499]: 127.0.0.1:56354
> [24/Apr/2009:08:33:09.096] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 204/204/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:33:12 myhost haproxy[4499]: 127.0.0.1:56607
> [24/Apr/2009:08:33:12.120] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 205/205/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:33:32 myhost haproxy[4499]: 127.0.0.1:57102
> [24/Apr/2009:08:33:32.116] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 205/205/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:33:41 myhost haproxy[4499]: 127.0.0.1:47058
> [24/Apr/2009:08:33:41.125] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 207/207/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:33:55 myhost haproxy[4499]: 127.0.0.1:47752
> [24/Apr/2009:08:33:55.918] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 202/202/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:34:22 myhost haproxy[4499]: 127.0.0.1:48586
> [24/Apr/2009:08:34:22.053] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 203/203/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:35:31 myhost haproxy[4499]: 127.0.0.1:50471
> [24/Apr/2009:08:35:31.359] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 204/204/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:36:47 myhost haproxy[4499]: 127.0.0.1:52694
> [24/Apr/2009:08:36:47.769] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 201/201/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:36:49 myhost haproxy[4499]: 127.0.0.1:52910
> [24/Apr/2009:08:36:49.838] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 198/198/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:37:19 myhost haproxy[4499]: 127.0.0.1:53877
> [24/Apr/2009:08:37:19.243] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 199/199/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:37:19 myhost haproxy[4499]: 127.0.0.1:54083
> [24/Apr/2009:08:37:19.318] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 397/397/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:42:53 myhost haproxy[4499]: 127.0.0.1:55385
> [24/Apr/2009:08:42:53.186] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 205/205/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:44:56 myhost haproxy[4499]: 127.0.0.1:45957
> [24/Apr/2009:08:44:56.152] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 207/207/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:47:41 myhost haproxy[4499]: 127.0.0.1:51606
> [24/Apr/2009:08:47:41.643] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 205/205/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:49:47 myhost haproxy[4499]: 127.0.0.1:47812
> [24/Apr/2009:08:49:47.204] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 204/204/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:52:12 myhost haproxy[4499]: 127.0.0.1:52770
> [24/Apr/2009:08:52:12.259] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 209/209/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:57:17 myhost haproxy[4499]: 127.0.0.1:53900
> [24/Apr/2009:08:57:17.844] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 204/204/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:57:18 myhost haproxy[4499]: 127.0.0.1:54096
> [24/Apr/2009:08:57:18.146] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 206/206/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:57:18 myhost haproxy[4499]: 127.0.0.1:54301
> [24/Apr/2009:08:57:18.567] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 205/205/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:58:39 myhost haproxy[4499]: 127.0.0.1:56581
> [24/Apr/2009:08:58:39.152] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 198/198/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:58:39 myhost haproxy[4499]: 127.0.0.1:56767
> [24/Apr/2009:08:58:39.565] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 197/197/0/0 0/0 {} "<BADREQ>"
> Apr 24 08:58:41 myhost haproxy[4499]: 127.0.0.1:41944
> [24/Apr/2009:08:58:41.916] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 198/198/0/0 0/0 {} "<BADREQ>"
> Apr 24 09:04:25 myhost haproxy[4499]: 127.0.0.1:35048
> [24/Apr/2009:09:04:25.179] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 205/205/0/0 0/0 {} "<BADREQ>"
> Apr 24 09:04:37 myhost haproxy[4499]: 127.0.0.1:35633
> [24/Apr/2009:09:04:37.551] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 197/197/0/0 0/0 {} "<BADREQ>"
> Apr 24 09:04:52 myhost haproxy[4499]: 127.0.0.1:36621
> [24/Apr/2009:09:04:52.868] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 200/200/0/0 0/0 {} "<BADREQ>"
> Apr 24 09:05:00 myhost haproxy[4499]: 127.0.0.1:37203
> [24/Apr/2009:09:05:00.227] abc abc/<NOSRV> -1/-1/-1/-1/0 400 187 - -
> PR-- 200/200/0/0 0/0 {} "<BADREQ>"
>
> I read in another similar thread that upgrading haproxy might help?
> BTW, I don't understand why the IP address is always 127.0.0.1, I'm
> sure requests came from a remote IP. Maybe it's a side effect of what
> is considered a "bad request"?

The IP address cannot be "invented", however I think that what might have been happening is an early read timeout caused by a system time change after haproxy was started (the monotonic internal clock was introduced in 1.3.16). Also, please check in your conf whether it is possible that haproxy would send TCP health checks to its own listeners (eg, if some servers IPs are defined by names and not IP, and these host names are different in /etc/hosts and in your DNS). Just random guesses...

If you want to stay on 1.3.14, at least you should upgrade to 1.3.14.12 which has fixed quite a lot of bugs.

Regards,
Willy Received on 2009/04/24 22:29

This archive was generated by hypermail 2.2.0 : 2009/04/24 22:30 CEST