[Varnish] #699: Varnishncsa Will Not Log Certain Requests Due to Out of Sequence (ReqEnd, SessionClose)
Varnish
varnish-bugs at varnish-cache.org
Tue May 11 03:10:33 CEST 2010
#699: Varnishncsa Will Not Log Certain Requests Due to Out of Sequence (ReqEnd,
SessionClose)
----------------------+-----------------------------------------------------
Reporter: osterman | Type: defect
Status: new | Priority: normal
Milestone: | Component: varnishncsa
Version: trunk | Severity: major
Keywords: |
----------------------+-----------------------------------------------------
Varnishncsa assumes that a ReqEnd will always happen before a
SessionClose. Very frequently, a SessionClose happens after a ReqEnd,
which casues lp->bogus to be set and the log event dropped. This has been
a problem for us sometime.
The fix we have implemented is to not rely on the ordering of
ReqEnd/SessionClose, but instead rely on SessionOpen. When we get a
SessionOpen, we initialize the *lp pointer, thereby resetting everything.
Since I'm not that familiar with the varnish source code, I'm not
submitting a patch as our solution might not be the best.
Below, you will see ReqEnd before SessionClose. The output was generated
using varnishlog.
16 TxProtocol c HTTP/1.1
16 TxStatus c 200
16 TxResponse c OK
16 TxHeader c Server: Varnish
16 TxHeader c Retry-After: 0
16 TxHeader c X-Cacheable-URL: /health_check.html
16 TxHeader c Content-Type: text/plain; charset=utf-8
16 TxHeader c Cache-Control: no-cache, must-revalidate
16 TxHeader c Expires: Mon, 26 Jul 1997 05:00:00 GMT
16 TxHeader c Content-Length: 2
16 TxHeader c Date: Tue, 11 May 2010 00:12:33 GMT
16 TxHeader c X-Varnish: 176572510
16 TxHeader c Age: 0
16 TxHeader c Via: 1.1 varnish
16 TxHeader c Connection: close
16 TxHeader c X-Served-By: domU-12-31-39-0E-41-C2
16 TxHeader c X-Cache: MISS
16 ReqEnd c 176572510 1273536753.646451950 1273536753.646547079
0.000028849 0.000061035 0.000034094
16 SessionClose c error
16 StatSess c 10.240.61.192 35698 0 1 1 0 0 0 387 2
0 Backend_health - s3_varnish_prod Still healthy 4--X-RH 5 3 5
0.008935 0.011059 HTTP/1.1 200 OK
16 SessionOpen c 127.0.0.1 33707 :80
16 ReqStart c 127.0.0.1 33707 176572511
16 RxRequest c GET
16 RxURL c /s2?q=test
16 RxProtocol c HTTP/1.1
16 RxHeader c Host: www-qa.host.com
16 RxHeader c User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X
10.6; en-US; rv:1.9.2.3) Gecko/20100401 Firefox/3.6.3
16 RxHeader c Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
16 RxHeader c Accept-Language: en-us,en;q=0.5
16 RxHeader c Accept-Encoding: gzip,deflate
16 RxHeader c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
16 RxHeader c Keep-Alive: 115
16 RxHeader c Connection: keep-alive
--
Ticket URL: <http://www.varnish-cache.org/ticket/699>
Varnish <http://varnish-cache.org/>
The Varnish HTTP Accelerator
More information about the varnish-bugs
mailing list