Hi. I tested this on repo.varnish-cache.org:
$ time wget --limit-rate=100k http://repo.varnish-cache.org/debian/pool/varnish-4.0/v/varnish/varnish_4.0.0.orig.tar.gz ... real 0m23.472s Then from Varnishlog: .. 22 ReqEnd c 315341679 1407768801.649216652 1407768818.704510689 0.000195265 0.037013054 *17.018280983* .. So. Your findings make sense. I think, but I'm not 100% certain, that the difference in time is due to buffering, especially on the server end. The kernel will swallow up a lot of writes that Varnish do and the thread then thinks it is actually done. Since the thread doesn't close the connection it won't block the worker. I think the kernel will block on connection close to make sure the client has gotten all the data but at that point the connection has been handed back to the pool. As I said, I'm not 100% that this is the correct explanation. But I'm pretty certain it works like this and if I'm right it is not a bug, strictly speaking. On Mon, Aug 11, 2014 at 3:19 PM, César Sepúlveda <[email protected]> wrote: > Hi guys. > > Anyone can help me, or has the same issue? > > Thanks!!. > > -- > César Sepúlveda > Jefe de Plataforma > Mediastream Chile > > Email: [email protected] > Teléfono: +56 2 24029750 > > > 2014-08-08 10:31 GMT-04:00 César Sepúlveda <[email protected]>: > > a video... my english is not too good. >> >> https://copy.com/uaaM3nMGVAuZ8ntk >> >> -- >> César Sepúlveda >> Jefe de Plataforma >> Mediastream Chile >> >> Email: [email protected] >> Teléfono: +56 2 24029750 >> >> >> 2014-08-08 10:21 GMT-04:00 César Sepúlveda <[email protected]>: >> >> Hi guys!. >>> >>> we are using varnish 3.0.5 and have an issue with Time taken to serve >>> the request parameter (%D) >>> >>> we realized that the varnishncsa log is written before the download is >>> complete: example >>> >>> >>> the download: >>> imac-de-cesar:~ csepulveda$ wget --limit-rate=100k >>> http://xxx.xxx.com/assets/img/promo-win.jpg >>> --2014-08-08 09:55:27-- http://xxxx.xxxx.com/assets/img/promo-win.jpg >>> Resolving xxx.xxx.com... xx.xx.xx.xx. >>> Connecting to xxx. xxx.com|xx.xx.xx.xx|:80... connected. >>> HTTP request sent, awaiting response... 200 OK >>> Length: 383810 (375K) [image/jpeg] >>> Saving to: ‘promo-win.jpg.2’ >>> >>> 100%[=========================================================================>] >>> 383,810 101KB/s in 3.7s >>> >>> 2014-08-08 09:55:31 (101 KB/s) - ‘promo-win.jpg.2’ saved [383810/383810] >>> >>> >>> The log: >>> xx.xx.xx.xx "xx.xx.xx.xx" - [08/Aug/2014:13:55:33 +0000] "GET >>> http://xxx.xxxx.com/assets/img/promo-win.jpg HTTP/1.0" 200 383810 "-" >>> "Wget/UNKNOWN (darwin12.2.0)" 0.401839018 miss 0.785520 >>> >>> The download take 3.7 seconds but varnishncsa show 0.785520.watching >>> this with tail -f we see the log is writen when the download go on 5 or 8 >>> percent. >>> >>> The varnishncsa format is this: >>> FORMAT="%h \"%{X-Forwarded-For}i\" %u %t \"%r\" %s %b \"%{Referer}i\" >>> \"%{User-agent}i\" %{Varnish:time_firstbyte}x %{Varnish:handling}x %D" >>> >>> what we are doing wrong? >>> can you help us? >>> >>> Thanks!. >>> >>> -- >>> César Sepúlveda >>> Jefe de Plataforma >>> Mediastream Chile >>> >>> Email: [email protected] >>> Teléfono: +56 2 24029750 >>> >> >> > > _______________________________________________ > varnish-misc mailing list > [email protected] > https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc > -- <http://www.varnish-software.com/> *Per Buer* CTO | Varnish Software Phone: +47 958 39 117 | Skype: per.buer We Make Websites Fly! Winner of the Red Herring Top 100 Global Award 2013
_______________________________________________ varnish-misc mailing list [email protected] https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
