Re: Delay when fetching a page without Content-Length

[Dag-Erling Smørgrav]

[EMAIL PROTECTED] (Adam Sjøgren) writes:
> (Where can I read about meaning of these? I have scanned through
> vcl(7), varnishd(1) and the FAQ).

The latest version of vcl(7) in Subversion describes this in far
better detail than the version in 1.0.3:

http://varnish.projects.linpro.no/svn/trunk/varnish-cache/man/vcl.7

DES
-- 
Dag-Erling Smørgrav
Senior Software Developer
Linpro AS - www.linpro.no
___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc

Re: Delay when fetching a page without Content-Length

[dwetzel]

 Hello,
 I had a smilar issue testing varnish last friday,
 the backend was sending a 302 with a Transfert-Encoding:chunked,
 Using tcpdump i noticed that varnish was trying to open a new tcp
 connection with the backend, 3 attempts were made (delay ~15s) before
varnish
 gave up and forwarded back the 302 to the client.
 there were no authorisation header.
Best Regards,

> On Sat, 31 Mar 2007 17:17:10 +, Poul-Henning wrote:
>
>> Which version of Varnish are you running ?
>
> The one from Debian unstable backported to stable, i.e. 1.0.3:
>
>  $ /usr/sbin/varnishd -V
>  varnishd (varnish-1.0.3)
>  Copyright (c) 2006 Linpro AS / Verdens Gang AS
>  $
>
>> Can you send me the output from varnishlog for the transaction ?
>
> Sure:
>
>  $ varnishlog
>  0 CLIRd ping
>  0 CLIWr 0 200 PONG 1175364221
> 13 SessionOpen  c 192.168.1.160 52579
>  0 CLIRd ping
>  0 CLIWr 0 200 PONG 1175364224
>  0 CLIRd ping
>  0 CLIWr 0 200 PONG 1175364227
>  0 CLIRd ping
>  0 CLIWr 0 200 PONG 1175364230
>  0 CLIRd ping
>  0 CLIWr 0 200 PONG 1175364233
>  0 CLIRd ping
>  0 CLIWr 0 200 PONG 1175364236
> 13 ReqStart c 192.168.1.160 52579 1997137143
> 13 RxRequestc GET
> 13 RxURLc /stats/
> 13 RxProtocol   c HTTP/1.0
> 13 RxHeader c User-Agent: Wget/1.10.2
> 13 RxHeader c Accept: */*
> 13 RxHeader c Host: www.koldfront.local
> 13 RxHeader c Connection: Keep-Alive
> 13 VCL_call c recv
> 13 VCL_return   c lookup
> 13 VCL_call c miss
> 13 VCL_return   c fetch
> 17 BackendOpen  b default 127.0.0.1 1027 127.0.0.1 8080
> 17 BackendXID   b 1997137143
> 13 Backend  c 17 default
> 17 TxRequestb GET
> 17 TxURLb /stats/
> 17 TxProtocol   b HTTP/1.1
> 17 TxHeader b User-Agent: Wget/1.10.2
> 17 TxHeader b Accept: */*
> 17 TxHeader b Host: www.koldfront.local
> 17 TxHeader b X-Varnish: 1997137143
> 17 TxHeader b X-Forwarded-for: 192.168.1.160
> 17 RxProtocol   b HTTP/1.1
> 17 RxStatus b 401
> 17 RxResponse   b Authorization Required
> 17 RxHeader b Date: Sat, 31 Mar 2007 18:03:42 GMT
> 17 RxHeader b Server: Apache/1.3.33 (Debian GNU/Linux)
> mod_fastcgi/2.4.2 mod_perl/1.29
> 17 RxHeader b WWW-Authenticate: Basic realm="Statistics"
> 17 RxHeader b Transfer-Encoding: chunked
> 17 RxHeader b Content-Type: text/html; charset=iso-8859-1
> 13 TTL  c 1997137143 RFC 120 1175364222 1175364222 0 0 0
> 13 VCL_call c fetch
> 13 VCL_return   c pass
> 13 RxProtocol   c HTTP/1.1
> 13 RxStatus c 401
> 13 RxResponse   c Authorization Required
> 13 RxHeader c Date: Sat, 31 Mar 2007 18:03:42 GMT
> 13 RxHeader c Server: Apache/1.3.33 (Debian GNU/Linux)
> mod_fastcgi/2.4.2 mod_perl/1.29
> 13 RxHeader c WWW-Authenticate: Basic realm="Statistics"
> 13 RxHeader c Content-Type: text/html; charset=iso-8859-1
> 13 RxHeader c X-Varnish: 1997137143
> 13 RxHeader c X-Forwarded-for: 192.168.1.160
> 13 RxHeader c Transfer-Encoding: chunked
> 17 BackendReuse b default
> 13 ReqEnd   c 1997137143 1175364222.294967044 1175364238.516689601
> 0.000751112 0.001383653 16.220338904
>  0 StatAddr   192.168.1.160 0 8161 36 37 0 20 11 11486 92507
> 13 HttpErrorc Received errno 104
> 13 SessionClose c no request
> 13 StatSess c 192.168.1.160 52579 16 1 1 0 1 0 322 529
>  0 CLIRd ping
>  0 CLIWr 0 200 PONG 1175364239
>  0 CLIRd ping
>  0 CLIWr 0 200 PONG 1175364242
>  ^C
>  $
>
> (If I run ngrep I see the request being sent to Apache and the reply
> back immediately, and then the pause).
>
>
> Let me know if I should supply more information.
>
>
>   Best regards,
>
> Adam
>
> --
>  "we push onward. to you, it is 2005, to us, it isAdam Sjøgren
>   2011. we are always far ahead."[EMAIL PROTECTED]
>
> ___
> varnish-misc mailing list
> varnish-misc@projects.linpro.no
> http://projects.linpro.no/mailman/listinfo/varnish-misc
>


___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc

Re: Delay when fetching a page without Content-Length

[Adam Sjøgren]

On Sat, 31 Mar 2007 19:22:37 +, Poul-Henning wrote:

>> if (req.http.authorization) {

> Should have been:  req.http.authenticate

Well, no such header is ever sent, from what I can see, but I'll give
it a go.

No difference - still ~16s delay.


First the browser asks for the page and the server answers with
WWW-Authenticate: Basic realm="...". The browser then asks me for
username and password, and goes on to retry the request, this time
with an Authorization: Basic ... header added.

The delay occurs on the first request.


  Best regards,

 Adam

-- 
 "Yakka foob mog. Grug pubbawup zink wattoom gazork.  Adam Sjøgren
  Chumble spuzz."[EMAIL PROTECTED]

___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc

Re: Delay when fetching a page without Content-Length

[Poul-Henning Kamp]

In message <[EMAIL PROTECTED]>, Adam =?iso-8859-1?Q?Sj=F8gren?= writes:
>On Sat, 31 Mar 2007 18:18:36 +, Poul-Henning wrote:
>
>> Hmm, you're running into a bug in the pass implementation which
>> have since been fixed.
>
>Ah, great.
>
>(Where can I read about meaning of these? I have scanned through
>vcl(7), varnishd(1) and the FAQ).
>
>> Try using pipe mode for authenticated requests instead, by putting
>> this in your vcl_recv function:
>
>>  if (req.http.Authenticate || req.http.Cookie) {
>>  pipe;
>>  }
>
>Hm. I think I have done something wrong, because that made it worse:
>
> sub vcl_recv {
> if (req.http.authorization) {

Should have been:  req.http.authenticate

-- 
Poul-Henning Kamp   | UNIX since Zilog Zeus 3.20
[EMAIL PROTECTED] | TCP/IP since RFC 956
FreeBSD committer   | BSD since 4.3-tahoe
Never attribute to malice what can adequately be explained by incompetence.
___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc

Re: Delay when fetching a page without Content-Length

[Adam Sjøgren]

On Sat, 31 Mar 2007 18:18:36 +, Poul-Henning wrote:

> Hmm, you're running into a bug in the pass implementation which
> have since been fixed.

Ah, great.

(Where can I read about meaning of these? I have scanned through
vcl(7), varnishd(1) and the FAQ).

> Try using pipe mode for authenticated requests instead, by putting
> this in your vcl_recv function:

>   if (req.http.Authenticate || req.http.Cookie) {
>   pipe;
>   }

Hm. I think I have done something wrong, because that made it worse:

 $ time wget -S http://www.koldfront.dk/stats/
 --20:28:26--  http://www.koldfront.dk/stats/
=> `index.html'
 Resolving www.koldfront.dk... 192.168.1.111
 Connecting to www.koldfront.dk|192.168.1.111|:80... connected.
 HTTP request sent, awaiting response... No data received.
 Retrying.

 --20:28:27--  http://www.koldfront.dk/stats/
   (try: 2) => `index.html'
 Connecting to www.koldfront.dk|192.168.1.111|:80... connected.
 HTTP request sent, awaiting response... No data received.
 Retrying.
 [...]

 $ varnishlog
 0 CLIRd ping
 0 CLIWr 0 200 PONG 1175365706
 0 WorkThread 0xb4391830 start
13 SessionOpen  c 192.168.1.160 40834
 0 Debug  "INCOMPLETE AT: cnt_fetch(332)"
 0 CLIRd vcl.load boot /tmp/vcl.XXZGJC2j
 0 CLIWr 0 200 Loaded "/tmp/vcl.XXZGJC2j" as "boot"

 0 CLIRd vcl.use boot
 0 CLIWr 0 200 
 0 CLIRd start
 0 CLIWr 0 200 
 0 WorkThread 0xb4391830 start
13 SessionOpen  c 192.168.1.160 40835
 0 Debug  "INCOMPLETE AT: cnt_fetch(332)"
 0 CLIRd vcl.load boot /tmp/vcl.XXZGJC2j
 0 CLIWr 0 200 Loaded "/tmp/vcl.XXZGJC2j" as "boot"

The modified vcl.conf I was using looks like this:

 # This is a basic vcl.conf file for varnish.
 # Modifying this file should be where you store your modifications to
 # varnish. Settnigs here will override defaults.

 backend default {
 set backend.host = "127.0.0.1";
 set backend.port = "8080";   
 }

 sub vcl_recv {
 if (req.http.authorization) {
 #   pass;
 pipe;
 }

 if (req.request == "POST") {
 pipe;
 }

 # force lookup even when cookies are present
 #if (req.request == "GET" && req.http.cookie) {
 #lookup;
 #}
 }

 sub vcl_fetch {
 if (resp.http.www-authenticate) {
 #   pass;
 pipe;
 }

 # force minimum ttl of 180 seconds
 if (obj.ttl < 180s) {
 set obj.ttl = 180s;
 }
 }


I will check out from svn and give that a spin...


  Best regards,

Adam

-- 
 "Från och med nu så är 'så snart som möjligt' 53 Adam Sjøgren
  timmar!"   [EMAIL PROTECTED]

___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc

Re: Delay when fetching a page without Content-Length

[Poul-Henning Kamp]

In message <[EMAIL PROTECTED]>, Adam =?iso-8859-1?Q?Sj=F8gren?= writes:
>On Sat, 31 Mar 2007 17:17:10 +, Poul-Henning wrote:
>
>> Which version of Varnish are you running ?
>
>The one from Debian unstable backported to stable, i.e. 1.0.3:
>
>13 VCL_call c fetch
>13 VCL_return   c pass

Hmm, you're running into a bug in the pass implementation which
have since been fixed.

Try using pipe mode for authenticated requests instead, by putting
this in your vcl_recv function:

if (req.http.Authenticate || req.http.Cookie) {
pipe;
}
 


-- 
Poul-Henning Kamp   | UNIX since Zilog Zeus 3.20
[EMAIL PROTECTED] | TCP/IP since RFC 956
FreeBSD committer   | BSD since 4.3-tahoe
Never attribute to malice what can adequately be explained by incompetence.
___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc

Re: Delay when fetching a page without Content-Length

[Adam Sjøgren]

On Sat, 31 Mar 2007 17:17:10 +, Poul-Henning wrote:

> Which version of Varnish are you running ?

The one from Debian unstable backported to stable, i.e. 1.0.3:

 $ /usr/sbin/varnishd -V
 varnishd (varnish-1.0.3)
 Copyright (c) 2006 Linpro AS / Verdens Gang AS
 $ 

> Can you send me the output from varnishlog for the transaction ?

Sure:

 $ varnishlog
 0 CLIRd ping
 0 CLIWr 0 200 PONG 1175364221
13 SessionOpen  c 192.168.1.160 52579
 0 CLIRd ping
 0 CLIWr 0 200 PONG 1175364224
 0 CLIRd ping
 0 CLIWr 0 200 PONG 1175364227
 0 CLIRd ping
 0 CLIWr 0 200 PONG 1175364230
 0 CLIRd ping
 0 CLIWr 0 200 PONG 1175364233
 0 CLIRd ping
 0 CLIWr 0 200 PONG 1175364236
13 ReqStart c 192.168.1.160 52579 1997137143
13 RxRequestc GET
13 RxURLc /stats/
13 RxProtocol   c HTTP/1.0
13 RxHeader c User-Agent: Wget/1.10.2
13 RxHeader c Accept: */*
13 RxHeader c Host: www.koldfront.local
13 RxHeader c Connection: Keep-Alive
13 VCL_call c recv
13 VCL_return   c lookup
13 VCL_call c miss
13 VCL_return   c fetch
17 BackendOpen  b default 127.0.0.1 1027 127.0.0.1 8080
17 BackendXID   b 1997137143
13 Backend  c 17 default
17 TxRequestb GET
17 TxURLb /stats/
17 TxProtocol   b HTTP/1.1
17 TxHeader b User-Agent: Wget/1.10.2
17 TxHeader b Accept: */*
17 TxHeader b Host: www.koldfront.local
17 TxHeader b X-Varnish: 1997137143
17 TxHeader b X-Forwarded-for: 192.168.1.160
17 RxProtocol   b HTTP/1.1
17 RxStatus b 401
17 RxResponse   b Authorization Required
17 RxHeader b Date: Sat, 31 Mar 2007 18:03:42 GMT
17 RxHeader b Server: Apache/1.3.33 (Debian GNU/Linux) 
mod_fastcgi/2.4.2 mod_perl/1.29
17 RxHeader b WWW-Authenticate: Basic realm="Statistics"
17 RxHeader b Transfer-Encoding: chunked
17 RxHeader b Content-Type: text/html; charset=iso-8859-1
13 TTL  c 1997137143 RFC 120 1175364222 1175364222 0 0 0
13 VCL_call c fetch
13 VCL_return   c pass
13 RxProtocol   c HTTP/1.1
13 RxStatus c 401
13 RxResponse   c Authorization Required
13 RxHeader c Date: Sat, 31 Mar 2007 18:03:42 GMT
13 RxHeader c Server: Apache/1.3.33 (Debian GNU/Linux) 
mod_fastcgi/2.4.2 mod_perl/1.29
13 RxHeader c WWW-Authenticate: Basic realm="Statistics"
13 RxHeader c Content-Type: text/html; charset=iso-8859-1
13 RxHeader c X-Varnish: 1997137143
13 RxHeader c X-Forwarded-for: 192.168.1.160
13 RxHeader c Transfer-Encoding: chunked
17 BackendReuse b default
13 ReqEnd   c 1997137143 1175364222.294967044 1175364238.516689601 
0.000751112 0.001383653 16.220338904
 0 StatAddr   192.168.1.160 0 8161 36 37 0 20 11 11486 92507
13 HttpErrorc Received errno 104
13 SessionClose c no request
13 StatSess c 192.168.1.160 52579 16 1 1 0 1 0 322 529
 0 CLIRd ping
 0 CLIWr 0 200 PONG 1175364239
 0 CLIRd ping
 0 CLIWr 0 200 PONG 1175364242
 ^C
 $ 

(If I run ngrep I see the request being sent to Apache and the reply
back immediately, and then the pause).


Let me know if I should supply more information.


  Best regards,

Adam

-- 
 "we push onward. to you, it is 2005, to us, it isAdam Sjøgren
  2011. we are always far ahead."[EMAIL PROTECTED]

___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc

Re: Delay when fetching a page without Content-Length

[Poul-Henning Kamp]

Hi Adam,

Which version of Varnish are you running ?

Can you send me the output from varnishlog for the transaction ?

-- 
Poul-Henning Kamp   | UNIX since Zilog Zeus 3.20
[EMAIL PROTECTED] | TCP/IP since RFC 956
FreeBSD committer   | BSD since 4.3-tahoe
Never attribute to malice what can adequately be explained by incompetence.
___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc

Delay when fetching a page without Content-Length

[Adam Sjøgren]

In my experiments, I've run into a long(ish) delay when I ask for a
url behind http auth:

 $ time wget -S http://www.koldfront.local/stats/
 [...¹]
 real0m16.799s
 [...]

Going directly to Apache:

 $ time wget -S http://www.koldfront.local:8080/stats/
 [...²]
 real0m0.013s
 [...]

I have previously observed such delays on pages where I didn't return
a Content-Length header (or, embarrassingly, did it wrong) - is this
related, or should it just work when Apache sends 'Transfer-Encoding:
chunked'?


(I have configured Varnish to 'pass' if there is an WWW-Authenticate
or Authorization-header³ - I hope that is correct).


  Best regards,

Adam


¹  --18:27:24--  http://www.koldfront.local/stats/
=> `index.html'
 Resolving www.koldfront.local... 192.168.1.111
 Connecting to www.koldfront.local|192.168.1.111|:80... connected.
 HTTP request sent, awaiting response... 
   HTTP/1.1 401 Authorization Required
   Date: Sat, 31 Mar 2007 16:27:26 GMT
   Server: Apache/1.3.33 (Debian GNU/Linux) mod_fastcgi/2.4.2 mod_perl/1.29
   WWW-Authenticate: Basic realm="Statistics"
   Content-Type: text/html; charset=iso-8859-1
   X-Varnish: 1997136530
   X-Forwarded-for: 192.168.1.160
   Transfer-Encoding: chunked
 Authorization failed.

²  --18:28:14--  http://www.koldfront.local:8080/stats/
=> `index.html'
 Resolving www.koldfront.local... 192.168.1.111
 Connecting to www.koldfront.local|192.168.1.111|:8080... connected.
 HTTP request sent, awaiting response... 
   HTTP/1.1 401 Authorization Required
   Date: Sat, 31 Mar 2007 16:28:17 GMT
   Server: Apache/1.3.33 (Debian GNU/Linux) mod_fastcgi/2.4.2 mod_perl/1.29
   WWW-Authenticate: Basic realm="Statistics"
   Connection: close
   Content-Type: text/html; charset=iso-8859-1
   X-Pad: avoid browser bug
 Authorization failed.

³ 

-- 
 "Subdued flamboyance"Adam Sjøgren
 [EMAIL PROTECTED]

___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc