we use a fresh ubuntu install, with only one client making the request and we have the same results.
Fresh Ubuntu 12.04 and last varnish 3.0.5. imac-de-cesar:~ csepulveda$ wget --limit-rate=1k http://10.0.1.78/thumbs/538907ff2982d00322387b34/2014711/thumb_53c0285317259d33326158f2_original_1768s.jpg --2014-08-11 14:32:36-- http://10.0.1.78/thumbs/538907ff2982d00322387b34/2014711/thumb_53c0285317259d33326158f2_original_1768s.jpg Connecting to 10.0.1.78:80... connected. HTTP request sent, awaiting response... 200 OK Length: 18111 (18K) [image/jpeg] Saving to: ‘thumb_53c0285317259d33326158f2_original_1768s.jpg.9’ 100%[=====================================================================================>] 18,111 1024B/s * in 18s* 2014-08-11 14:32:53 (1024 B/s) - ‘thumb_53c0285317259d33326158f2_original_1768s.jpg.9’ saved [18111/18111] ....... 11 SessionOpen c 10.0.1.135 60525 :80 11 ReqStart c 10.0.1.135 60525 1340317141 11 RxRequest c GET 11 RxURL c /thumbs/538907ff2982d00322387b34/2014711/thumb_53c0285317259d33326158f2_original_1768s.jpg 11 RxProtocol c HTTP/1.1 11 RxHeader c User-Agent: Wget/UNKNOWN (darwin12.2.0) 11 RxHeader c Accept: */* 11 RxHeader c Host: 10.0.1.78 11 RxHeader c Connection: Keep-Alive 11 VCL_call c recv lookup 11 VCL_call c hash 11 Hash c /thumbs/538907ff2982d00322387b34/2014711/thumb_53c0285317259d33326158f2_original_1768s.jpg 11 Hash c 10.0.1.78 11 VCL_return c hash 11 Hit c 1340317139 11 VCL_call c hit deliver 11 VCL_call c deliver deliver 11 TxProtocol c HTTP/1.1 11 TxStatus c 200 11 TxResponse c OK 11 TxHeader c Content-Type: image/jpeg 11 TxHeader c Last-Modified: Fri, 11 Jul 2014 18:09:25 GMT 11 TxHeader c Expires: Thu, 31 Dec 2037 23:55:55 GMT 11 TxHeader c Cache-Control: max-age=315360000, public, must-revalidate, proxy-revalidate 11 TxHeader c Pragma: public 11 TxHeader c Content-Length: 18111 11 TxHeader c Accept-Ranges: bytes 11 TxHeader c Date: Mon, 11 Aug 2014 18:32:36 GMT 11 TxHeader c X-Varnish: 1340317141 1340317139 11 TxHeader c Age: 2451 11 TxHeader c Via: 1.1 varnish 11 TxHeader c Connection: keep-alive 11 Length c 18111 11 ReqEnd c 1340317141 1407781956.576860905 1407781956.577031851 0.000064373 0.000036240 *0.000134706* 11 Debug c herding 11 SessionClose c timeout 11 StatSess c 10.0.1.135 60525 0 1 1 0 0 0 393 18111 ubuntu 12.04 and last varnish 4.0.1-2 * << Request >> 2 - Begin req 1 rxreq - Timestamp Start: 1407782319.675061 0.000000 0.000000 - Timestamp Req: 1407782319.675061 0.000000 0.000000 - ReqStart 10.0.1.135 60616 - ReqMethod GET - ReqURL /thumbs/538907ff2982d00322387b34/2014711/thumb_53c0285317259d33326158f2_original_1768s.jpg - ReqProtocol HTTP/1.1 - ReqHeader User-Agent: Wget/UNKNOWN (darwin12.2.0) - ReqHeader Accept: */* - ReqHeader Host: 10.0.1.78 - ReqHeader Connection: Keep-Alive - ReqHeader X-Forwarded-For: 10.0.1.135 - VCL_call RECV - VCL_return hash - VCL_call HASH - VCL_return lookup - Debug "XXXX MISS" - VCL_call MISS - VCL_return fetch - Link bereq 3 fetch - Timestamp Fetch: 1407782319.683342 0.008281 0.008281 - RespProtocol HTTP/1.1 - RespStatus 200 - RespReason OK - RespHeader Content-Type: image/jpeg - RespHeader Last-Modified: Fri, 11 Jul 2014 18:09:25 GMT - RespHeader Expires: Thu, 31 Dec 2037 23:55:55 GMT - RespHeader Cache-Control: max-age=315360000, public, must-revalidate, proxy-revalidate - RespHeader Pragma: public - RespHeader Date: Mon, 11 Aug 2014 18:38:39 GMT - RespHeader X-Varnish: 2 - RespHeader Age: 2814 - RespHeader Via: 1.1 varnish-v4 - VCL_call DELIVER - VCL_return deliver - Timestamp Process: 1407782319.700854 0.025793 0.017512 - RespHeader Content-Length: 18111 - Debug "RES_MODE 2" - RespHeader Connection: keep-alive - RespHeader Accept-Ranges: bytes - Timestamp Resp: 1407782319.701260 0.026199 0.000406 - Debug "XXX REF 2" - ReqAcct 202 0 202 376 18111 18487 - End We need the most real Time taken to serve the request, do you know if i can get it from another place? Thanks!. -- César Sepúlveda Jefe de Plataforma Mediastream Chile Email: [email protected] Teléfono: +56 2 24029750 2014-08-11 9:19 GMT-04:00 César Sepúlveda <[email protected]>: > 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
