A few users see a blank page
Erik Torlen
duja at torlen.net
Tue Feb 12 20:00:34 CET 2008
Hi,
I have seen the same behaviour on my Apache2 server with php5 installed.
Many users got blank pages
when navigating around the website. I couldn't figure out what the
problem was so I simply removed varnish
and the problem disappeared.
Another problem I had was that php's X-FORWARDED-FOR was empty at random
times. I looked in the
apache2 log and saw some empty fields their too. Couldn't find a
solution for it :(
/ Erik
Marco Molinari skrev:
> I can now reproduce it and I found a lot of info.
>
> I wrote a simple script that keeps on reloading itself, adding some
> chars each time; I disabled compression both in Apache and in PHP and
> I connect my browser through a 2.6 Squid proxy; and now I can't see
> PHP pages larger than 8000 bytes. I also found an interesting
> connection with cookies.
>
> Here are the log lines for Varnish requesting two pages to Apache:
>
> Apache:
> 127.0.0.1, 10.0.2.2 - - [12/Feb/2008:14:24:26 +0100] "GET
> /test_varnish2.php?n=10&t=1202822659 HTTP/1.0" 200 8000 "-"
> "{MY-USER-AGENT}"
> 127.0.0.1, 10.0.2.2 - - [12/Feb/2008:14:24:29 +0100] "GET
> /test_varnish2.php?n=11&t=1202822659 HTTP/1.0" 200 8001 "-"
> "{MY-USER-AGENT}"
>
> Varnish:
> 10.0.2.2 - - [12/Feb/2008:14:24:26 +0100] "GET
> http://dev.{MY-SITE}:2280/test_varnish2.php?n=10&t=1202822659
> HTTP/1.0" 200 8000 "-" "{MY-USER-AGENT}"
> 10.0.2.2 - - [12/Feb/2008:14:24:29 +0100] "GET
> http://dev.{MY-SITE}:2280/test_varnish2.php?n=11&t=1202822659
> HTTP/1.0" 200 0 "-" "{MY-USER-AGENT}"
>
>
> As you can see Varnish logs a 0 size for the 8001 bytes request.
>
>
> Here is the extended log (as per varnishlog) for those requests (sorry
> for the length):
>
> 15 ReqStart c 10.0.2.2 43859 67671826
> 15 RxRequest c GET
> 15 RxURL c /test_varnish2.php?n=10&t=1202822659
> 15 RxProtocol c HTTP/1.0
> 15 RxHeader c Host: dev.{MY-SITE}:2280
> 15 RxHeader c User-Agent: {MY-USER-AGENT}
> 15 RxHeader c Accept:
> text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
> 15 RxHeader c Accept-Language: en-us,en;q=0.5
> 15 RxHeader c Accept-Encoding: gzip,deflate
> 15 RxHeader c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
> 15 RxHeader c Cookie:
> __utma=xxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.23;
> __utmz=xxxxxxxx.xxxxxxxxxx.21.5.utmcsr=mail.google.com|utmccn=(referral)|utmcmd=referral|utmcct=%2Fmail%2F;
> __utmz=xxxxxxxx.xxxxxxxxxx.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(non
> 15 RxHeader c Via: 1.1 virtual:3129 (squid/2.6.STABLE14)
> 15 RxHeader c X-Forwarded-For: 127.0.0.1
> 15 RxHeader c Cache-Control: max-age=259200
> 15 RxHeader c Connection: keep-alive
> 15 VCL_call c recv
> 15 VCL_return c pass
> 15 VCL_call c pass
> 15 VCL_return c pass
> 18 BackendOpen b default 127.0.0.1 32988 127.0.0.1 8080
> 18 BackendXID b 67671826
> 15 Backend c 18 default
> 18 TxRequest b GET
> 18 TxURL b /test_varnish2.php?n=10&t=1202822659
> 18 TxProtocol b HTTP/1.0
> 18 TxHeader b Host: dev.{MY-SITE}:2280
> 18 TxHeader b User-Agent: {MY-USER-AGENT}
> 18 TxHeader b Accept:
> text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
> 18 TxHeader b Accept-Language: en-us,en;q=0.5
> 18 TxHeader b Accept-Encoding: gzip,deflate
> 18 TxHeader b Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
> 18 TxHeader b Cookie:
> __utma=xxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.23;
> __utmz=xxxxxxxx.xxxxxxxxxx.21.5.utmcsr=mail.google.com|utmccn=(referral)|utmcmd=referral|utmcct=%2Fmail%2F;
> __utmz=xxxxxxxxxx.xxxxxxxxxx.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(non
> 18 TxHeader b Via: 1.1 virtual:3129 (squid/2.6.STABLE14)
> 18 TxHeader b X-Forwarded-For: 127.0.0.1
> 18 TxHeader b X-Varnish: 67671826
> 18 TxHeader b X-Forwarded-for: 10.0.2.2
> 18 RxProtocol b HTTP/1.1
> 18 RxStatus b 200
> 18 RxResponse b OK
> 18 RxHeader b Date: Tue, 12 Feb 2008 13:24:26 GMT
> 18 RxHeader b Server: Apache/2.0.52 (CentOS)
> 18 RxHeader b X-Powered-By: PHP/4.3.9
> 18 RxHeader b Content-Length: 8000
> 18 RxHeader b Connection: close
> 18 RxHeader b Content-Type: text/html; charset=UTF-8
> 15 ObjProtocol c HTTP/1.1
> 15 ObjStatus c 200
> 15 ObjResponse c OK
> 15 ObjHeader c Date: Tue, 12 Feb 2008 13:24:26 GMT
> 15 ObjHeader c Server: Apache/2.0.52 (CentOS)
> 15 ObjHeader c X-Powered-By: PHP/4.3.9
> 15 ObjHeader c Content-Type: text/html; charset=UTF-8
> 18 BackendClose b default
> 15 TTL c 67671826 RFC 120 1202822666 1202822666 0 0 0
> 15 VCL_call c fetch
> 15 VCL_return c insert
> 15 Length c 8000
> 15 VCL_call c deliver
> 15 VCL_return c deliver
> 15 TxProtocol c HTTP/1.1
> 15 TxStatus c 200
> 15 TxResponse c OK
> 15 TxHeader c Server: Apache/2.0.52 (CentOS)
> 15 TxHeader c X-Powered-By: PHP/4.3.9
> 15 TxHeader c Content-Type: text/html; charset=UTF-8
> 15 TxHeader c Content-Length: 8000
> 15 TxHeader c Date: Tue, 12 Feb 2008 13:24:26 GMT
> 15 TxHeader c X-Varnish: 67671826
> 15 TxHeader c Age: 0
> 15 TxHeader c Via: 1.1 varnish
> 15 TxHeader c Connection: keep-alive
> 15 ReqEnd c 67671826 1202822666.438220024
> 1202822666.440738916 3.759930134 0.002374887 0.000144005
> 0 StatAddr 10.0.2.2 0 4217 31 171 0 0 171 41937 1114752
> 0 CLI Rd ping
> 0 CLI Wr 0 200 PONG 1202822669
>
> second request:
>
> 15 ReqStart c 10.0.2.2 43859 67671827
> 15 RxRequest c GET
> 15 RxURL c /test_varnish2.php?n=11&t=1202822659
> 15 RxProtocol c HTTP/1.0
> 15 RxHeader c Host: dev.{MY-SITE}:2280
> 15 RxHeader c User-Agent: {MY-USER-AGENT}
> 15 RxHeader c Accept:
> text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
> 15 RxHeader c Accept-Language: en-us,en;q=0.5
> 15 RxHeader c Accept-Encoding: gzip,deflate
> 15 RxHeader c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
> 15 RxHeader c Cookie:
> __utma=xxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.23;
> __utmz=xxxxxxxx.xxxxxxxxxx.21.5.utmcsr=mail.google.com|utmccn=(referral)|utmcmd=referral|utmcct=%2Fmail%2F;
> __utmz=xxxxxxxxxx.xxxxxxxxxx.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(non
> 15 RxHeader c Via: 1.1 virtual:3129 (squid/2.6.STABLE14)
> 15 RxHeader c X-Forwarded-For: 127.0.0.1
> 15 RxHeader c Cache-Control: max-age=259200
> 15 RxHeader c Connection: keep-alive
> 15 VCL_call c recv
> 15 VCL_return c pass
> 15 VCL_call c pass
> 15 VCL_return c pass
> 18 BackendOpen b default 127.0.0.1 32989 127.0.0.1 8080
> 18 BackendXID b 67671827
> 15 Backend c 18 default
> 18 TxRequest b GET
> 18 TxURL b /test_varnish2.php?n=11&t=1202822659
> 18 TxProtocol b HTTP/1.0
> 18 TxHeader b Host: dev.{MY-SITE}:2280
> 18 TxHeader b User-Agent: {MY-USER-AGENT}
> 18 TxHeader b Accept:
> text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
> 18 TxHeader b Accept-Language: en-us,en;q=0.5
> 18 TxHeader b Accept-Encoding: gzip,deflate
> 18 TxHeader b Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
> 18 TxHeader b Cookie:
> __utma=xxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.xxxxxxxxxx.23;
> __utmz=xxxxxxxx.xxxxxxxxxx.21.5.utmcsr=mail.google.com|utmccn=(referral)|utmcmd=referral|utmcct=%2Fmail%2F;
> __utmz=xxxxxxxxxx.xxxxxxxxxx.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(non
> 18 TxHeader b Via: 1.1 virtual:3129 (squid/2.6.STABLE14)
> 18 TxHeader b X-Forwarded-For: 127.0.0.1
> 18 TxHeader b X-Varnish: 67671827
> 18 TxHeader b X-Forwarded-for: 10.0.2.2
> 18 RxProtocol b HTTP/1.1
> 18 RxStatus b 200
> 18 RxResponse b OK
> 18 RxHeader b Date: Tue, 12 Feb 2008 13:24:29 GMT
> 18 RxHeader b Server: Apache/2.0.52 (CentOS)
> 18 RxHeader b X-Powered-By: PHP/4.3.9
> 18 RxHeader b Connection: close
> 18 RxHeader b Content-Type: text/html; charset=UTF-8
> 15 ObjProtocol c HTTP/1.1
> 15 ObjStatus c 200
> 15 ObjResponse c OK
> 15 ObjHeader c Date: Tue, 12 Feb 2008 13:24:29 GMT
> 15 ObjHeader c Server: Apache/2.0.52 (CentOS)
> 15 ObjHeader c X-Powered-By: PHP/4.3.9
> 15 ObjHeader c Content-Type: text/html; charset=UTF-8
> 18 BackendClose b default
> 15 TTL c 67671827 RFC 120 1202822669 1202822669 0 0 0
> 15 VCL_call c fetch
> 15 VCL_return c insert
> 15 Length c 0
> 15 VCL_call c deliver
> 15 VCL_return c deliver
> 15 TxProtocol c HTTP/1.1
> 15 TxStatus c 200
> 15 TxResponse c OK
> 15 TxHeader c Server: Apache/2.0.52 (CentOS)
> 15 TxHeader c X-Powered-By: PHP/4.3.9
> 15 TxHeader c Content-Type: text/html; charset=UTF-8
> 15 TxHeader c Date: Tue, 12 Feb 2008 13:24:29 GMT
> 15 TxHeader c X-Varnish: 67671827
> 15 TxHeader c Age: 0
> 15 TxHeader c Via: 1.1 varnish
> 15 TxHeader c Connection: keep-alive
> 15 ReqEnd c 67671827 1202822669.762167931
> 1202822669.765445948 3.321429014 0.003173113 0.000104904
> 0 StatAddr 10.0.2.2 0 4221 31 172 0 0 172 42161 1114752
> 0 CLI Rd ping
> 0 CLI Wr 0 200 PONG 1202822672
> 15 SessionClose c timeout
> 15 StatSess c 10.0.2.2 43859 11 1 4 0 0 4 962 23995
>
> As you can see in the 8001 bytes request there seems to be no
> Content-Length header in the Apache response, but I checked with
> LiveHttpHeaders (without Squid) and the header is there.
>
> You can also notice that cookies in the extended logs are cut (I
> replaced the numbers with "xxx"); so I tried to disable the cookies in
> the browser, and everything works!
>
> 15 ReqStart c 10.0.2.2 57522 67671865
> 15 RxRequest c GET
> 15 RxURL c /test_varnish2.php?n=11&t=1202823345
> 15 RxProtocol c HTTP/1.0
> 15 RxHeader c Host: dev.{MY-SITE}:2280
> 15 RxHeader c User-Agent: {MY-USER-AGENT}
> 15 RxHeader c Accept:
> text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
> 15 RxHeader c Accept-Language: en-us,en;q=0.5
> 15 RxHeader c Accept-Encoding: gzip,deflate
> 15 RxHeader c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
> 15 RxHeader c Via: 1.1 virtual:3129 (squid/2.6.STABLE14)
> 15 RxHeader c X-Forwarded-For: 127.0.0.1
> 15 RxHeader c Cache-Control: max-age=259200
> 15 RxHeader c Connection: keep-alive
> 15 VCL_call c recv
> 15 VCL_return c lookup
> 15 VCL_call c hash
> 15 VCL_return c hash
> 15 VCL_call c miss
> 15 VCL_return c fetch
> 18 BackendOpen b default 127.0.0.1 33028 127.0.0.1 8080
> 18 BackendXID b 67671865
> 15 Backend c 18 default
> 18 TxRequest b GET
> 18 TxURL b /test_varnish2.php?n=11&t=1202823345
> 18 TxProtocol b HTTP/1.1
> 18 TxHeader b Host: dev.{MY-SITE}:2280
> 18 TxHeader b User-Agent: {MY-USER-AGENT}
> 18 TxHeader b Accept:
> text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
> 18 TxHeader b Accept-Language: en-us,en;q=0.5
> 18 TxHeader b Accept-Encoding: gzip,deflate
> 18 TxHeader b Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
> 18 TxHeader b Via: 1.1 virtual:3129 (squid/2.6.STABLE14)
> 18 TxHeader b X-Forwarded-For: 127.0.0.1
> 18 TxHeader b X-Varnish: 67671865
> 18 TxHeader b X-Forwarded-for: 10.0.2.2
> 18 RxProtocol b HTTP/1.1
> 18 RxStatus b 200
> 18 RxResponse b OK
> 18 RxHeader b Date: Tue, 12 Feb 2008 13:35:57 GMT
> 18 RxHeader b Server: Apache/2.0.52 (CentOS)
> 18 RxHeader b X-Powered-By: PHP/4.3.9
> 18 RxHeader b Connection: close
> 18 RxHeader b Transfer-Encoding: chunked
> 18 RxHeader b Content-Type: text/html; charset=UTF-8
> 15 ObjProtocol c HTTP/1.1
> 15 ObjStatus c 200
> 15 ObjResponse c OK
> 15 ObjHeader c Date: Tue, 12 Feb 2008 13:35:57 GMT
> 15 ObjHeader c Server: Apache/2.0.52 (CentOS)
> 15 ObjHeader c X-Powered-By: PHP/4.3.9
> 15 ObjHeader c Content-Type: text/html; charset=UTF-8
> 18 BackendClose b default
> 15 TTL c 67671865 RFC 120 1202823357 1202823357 0 0 0
> 15 VCL_call c fetch
> 15 VCL_return c insert
> 15 Length c 8001
> 15 VCL_call c deliver
> 15 VCL_return c deliver
> 15 TxProtocol c HTTP/1.1
> 15 TxStatus c 200
> 15 TxResponse c OK
> 15 TxHeader c Server: Apache/2.0.52 (CentOS)
> 15 TxHeader c X-Powered-By: PHP/4.3.9
> 15 TxHeader c Content-Type: text/html; charset=UTF-8
> 15 TxHeader c Content-Length: 8001
> 15 TxHeader c Date: Tue, 12 Feb 2008 13:35:57 GMT
> 15 TxHeader c X-Varnish: 67671865
> 15 TxHeader c Age: 0
> 15 TxHeader c Via: 1.1 varnish
> 15 TxHeader c Connection: keep-alive
> 15 ReqEnd c 67671865 1202823357.593729973
> 1202823357.596472979 3.786515951 0.002630949 0.000112057
> 0 StatAddr 10.0.2.2 0 4908 34 210 0 0 210 52216 1395936
>
>
> This could explain why the problem seems so erratic, as a user can see
> a page or not depending on the page length and their cookies.
>
> My configuration:
> - web server: Centos 4 + Apache 2.0.52 + PHP 4.3.9 + Varnish 1.1.2
> (everything installed through rpms)
> - proxy server: Ubuntu 7.10 + Squid 2.6
> - client: Ubuntu 7.10 + Firefox (actually it's the same pc that runs
> the proxy server)
>
>
>
> Uncommented parts in my vcl:
> backend default {
> set backend.host = "127.0.0.1";
> set backend.port = "8080";
> }
>
> sub vcl_recv {
> if (req.http.Pragma == "no-cache") {
> pipe;
> }
>
> if (req.request == "GET" && req.url ~
> "\.(gif|jpg|swf|css|js|swf|flv|png|jpeg)$") {
> lookup;
> }
>
> if (req.request != "GET" && req.request != "HEAD") {
> pipe;
> }
>
> if (req.http.Expect) {
> pipe;
> }
>
> if (req.http.Authenticate || req.http.Cookie) {
> pass;
> }
>
> lookup;
> }
>
>
> Is this enough to post a bug report?
>
> Thanks
> Marco
> _______________________________________________
> varnish-misc mailing list
> varnish-misc at projects.linpro.no
> http://projects.linpro.no/mailman/listinfo/varnish-misc
>
>
More information about the varnish-misc
mailing list