Varnish 503ing on ~1/100 POSTs

[Ronan Mullally]

After further tuning and tweaking I've managed to reduce the incidence
of this problem to about 1/1500 POSTs:

  Hour   GETs     Fails   POSTs     Fails
 01:00  39750   0 (0.00%)   530   0 (0.00%)
 02:00  30733   0 (0.00%)   419   0 (0.00%)
 03:00  28696   0 (0.00%)   361   0 (0.00%)
 04:00  25687   0 (0.00%)   348   0 (0.00%)
 05:00  27207   0 (0.00%)   310   0 (0.00%)
 06:00  31298   0 (0.00%)   344   0 (0.00%)
 07:00  35533   0 (0.00%)   324   1 (0.31%)
 08:00  41602   0 (0.00%)   360   0 (0.00%)
 09:00  49797   0 (0.00%)   441   0 (0.00%)
 10:00  55202   0 (0.00%)   521   0 (0.00%)
 11:00  65108   0 (0.00%)   729   1 (0.14%)
 12:00  70108   0 (0.00%)   684   1 (0.15%)
 13:00  76969   0 (0.00%)   739   1 (0.14%)
 14:00  73088   0 (0.00%)   781   0 (0.00%)
 15:00  73698   0 (0.00%)   798   0 (0.00%)
 16:00  80874   0 (0.00%)   912   0 (0.00%)
 17:00 109908   0 (0.00%)  1203   0 (0.00%)
 18:00 113348   0 (0.00%)  1374   2 (0.15%)
 19:00  97369   0 (0.00%)  1059   1 (0.09%)
 20:00  90987   0 (0.00%)   950   0 (0.00%)
 21:00  88719   0 (0.00%)  1084   0 (0.00%)
 22:00  79641   0 (0.00%)   943   2 (0.21%)
 23:00  67361   0 (0.00%)   815   0 (0.00%)

Increasing the Keepalive time on apache on the backends from 1 to 5
seconds made the biggest impact.  I suspect this suggests that the
problem occurs when Varnish tries to direct a POST to a connection
which apache has just closed.


-Ronan


On Fri, 25 Mar 2011, Ronan Mullally wrote:

> I am still encountering this problem - about 1% on average of POSTs are
> failing with a 503 when there is no problem apparent on the back-ends.
> GETs are not affected:
>
>   Hour   GETs     Fails   POSTs     Fails
>  00:00  38060   0 (0.00%)   480   2 (0.42%)
>  01:00  34051   0 (0.00%)   412   0 (0.00%)
>  02:00  29881   0 (0.00%)   383   2 (0.52%)
>  03:00  25741   0 (0.00%)   374   1 (0.27%)
>  04:00  22296   0 (0.00%)   326   2 (0.61%)
>  05:00  22594   0 (0.00%)   349  20 (5.73%)
>  06:00  31422   0 (0.00%)   408   6 (1.47%)
>  07:00  58746   0 (0.00%)   656   6 (0.91%)
>  08:00  74307   0 (0.00%)   870   4 (0.46%)
>  09:00  87386   0 (0.00%)  1280   8 (0.62%)
>  10:00  51744   0 (0.00%)   741   8 (1.08%)
>  11:00  50060   0 (0.00%)   825   1 (0.12%)
>  12:00  58573   0 (0.00%)   664   5 (0.75%)
>  13:00  60548   0 (0.00%)   735   7 (0.95%)
>  14:00  60242   0 (0.00%)   875   8 (0.91%)
>  15:00  61427   0 (0.00%)   778   3 (0.39%)
>  16:00  66480   0 (0.00%)   810   4 (0.49%)
>  17:00  65749   0 (0.00%)   836  12 (1.44%)
>  18:00  64312   0 (0.00%)   732   3 (0.41%)
>  19:00  60930   0 (0.00%)   652   5 (0.77%)
>  20:00  59646   0 (0.00%)   626   1 (0.16%)
>  21:00  61218   0 (0.00%)   674   3 (0.45%)
>  22:00  55908   0 (0.00%)   598   3 (0.50%)
>  23:00  45173   0 (0.00%)   560   1 (0.18%)
>
> There was another poster on this thread with the same problem which
> suggests a possible varnish problem rather than anything specific to
> my setup.
>
> Does anybody have any ideas?
>