Fwd: varnish 2.0.4 backend errors

[Lazy]

2009/7/15 Lazy <lazy404 at gmail.com>:
> 2009/7/14 Ken Brownfield <kb+varnish at slide.com>:
>> On Jul 14, 2009, at 3:05 AM, Kristian Lyngstol wrote:
>>> On Tue, Jul 14, 2009 at 11:46:58AM +0200, Lazy wrote:
>>>> the site is usually not so busy, but it has sometimes spikes of
>>>> static
>>>> traffic (about 50Mbps) that's why i upped the thread limit, 3000 was
>>>> to low
>>>
>>> I seriously doubt 3k was too low. More likely, the min threads was
>>> hurting
>>> you. Three thousand threads is quite a bit. Remember that these are
>>> actual
>>> requests being handled, not keep-alive connections and the like.
>>
>> I just wanted to humbly second this good advice; if you're familiar
>> with Apache, this is akin to making sure your MinSpareServers is set
>> to a high enough level to handle any transient spikes by avoiding the
>> cost of spawning new processes.  Varnish will handle 10x the traffic
>> you're seeing in <64 threads.  Anything you're seeing is more likely a
>
> but if backend is slow, (there will be many POSTS form ajax app)
> threads wil get used fast if php starts lagging behind,
> now there are 200 threads running, without raises in overflowed work
> requests, and still there are 503 errors,
> i will uppp min threads later and see if it helps
>
>> concurrency spike causing a temporary slowdown while threads are
>> spawned, or Varnish is simply passing on fail or slowness from your
>> back-end.
> i hope this is it, i will find out tommorrow

setting 500 as min threads didn't make any diference, funny thing is
that failed requests are in logged in apache as succesful

09:23:50.563934 IP x.x.x.x.51235 > x.x.x.x.88: S
1066103134:1066103134(0) win 32792 <mss 16396,sackOK,timestamp
552835403 0,nop,wscale 7>
09:23:50.563940 IP x.x.x.x.88 > x.x.x.x.51235: S
1060616380:1060616380(0) ack 1066103135 win 32768 <mss
16396,sackOK,timestamp 552835403 552835403,nop,wscale 7>
09:23:50.563946 IP x.x.x.x.51235 > x.x.x.x.88: . ack 1 win 257
<nop,nop,timestamp 552835403 552835403>
09:23:54.163755 IP x.x.x.x.88 > x.x.x.x.51235: S
1060616380:1060616380(0) ack 1066103135 win 32768 <mss
16396,sackOK,timestamp 552836303 552835403,nop,wscale 7>
09:23:54.163765 IP x.x.x.x.51235 > x.x.x.x.88: . ack 1 win 257
<nop,nop,timestamp 552836303 552836303,nop,nop,sack 1 {0:1}>
09:23:55.563738 IP x.x.x.x.51235 > x.x.x.x.88: P 1:886(885) ack 1 win
257 <nop,nop,timestamp 552836653 552836303>
09:23:55.563756 IP x.x.x.x.88 > x.x.x.x.51235: . ack 886 win 270
<nop,nop,timestamp 552836653 552836653>
09:23:55.563838 IP x.x.x.x.51235 > x.x.x.x.88: F 886:886(0) ack 1 win
257 <nop,nop,timestamp 552836653 552836653>
09:23:55.567177 IP x.x.x.x.88 > x.x.x.x.51235: P 1:2882(2881) ack 887
win 270 <nop,nop,timestamp 552836653 552836653>
09:23:55.567196 IP x.x.x.x.51235 > x.x.x.x.88: R 1066104021:1066104021(0) win 0


successful POST in apache logs,

in varnishlog

14 Backend      c 15 default default
  15 TxRequest    b POST
  15 TxURL        b /quiz/question
  15 TxProtocol   b HTTP/1.1
  15 TxHeader     b x-requested-with: XMLHttpRequest
  15 TxHeader     b Accept-Language: pl
  15 TxHeader     b Accept: text/html, */*
  15 TxHeader     b Content-Type: application/x-www-form-urlencoded
  15 TxHeader     b UA-CPU: x86
  15 TxHeader     b Accept-Encoding: gzip, deflate
  15 TxHeader     b User-Agent: Mozilla/4.0 (compatible; MSIE 7.0;
Windows NT 5.1; .NET CLR 2.0.50727; .NET CLR 3.0.04506.30)
  15 TxHeader     b Host:
  15 TxHeader     b Content-Length: 8
  15 TxHeader     b Cookie: xxx
  15 TxHeader     b X-Varnish: 782633863
  15 TxHeader     b X-Forwarded-For: xxx
  15 BackendClose b default
  14 VCL_call     c error
  14 VCL_return   c restart
  14 VCL_call     c recv
  14 VCL_return   c pass
  14 VCL_call     c error
  14 VCL_return   c restart
  14 VCL_call     c recv
...
  14 Length       c 465
  14 VCL_call     c deliver
  14 VCL_return   c deliver
  14 TxProtocol   c HTTP/1.1
  14 TxStatus     c 503
  14 TxResponse   c Service Unavailable
  14 TxHeader     c Server: Varnish
  14 TxHeader     c Retry-After: 0
  14 TxHeader     c Content-Type: text/html; charset=utf-8
  14 TxHeader     c Content-Length: 465
  14 TxHeader     c Date: Wed, 15 Jul 2009 07:23:55 GMT
  14 TxHeader     c X-Varnish: 782633863
  14 TxHeader     c Age: 20
  14 TxHeader     c Via: 1.1 varnish
  14 TxHeader     c Connection: close
  14 ReqEnd       c 782633863 1247642615.566063166
1247642635.564052582 0.006083488 19.997969866 0.000019550
  14 SessionClose c error

restart shouldn't make another backend connection if current one got closed ?

a can't find any subsequent retries in tcpdump

and sometime's restart works

--
Michal Grzedzicki