[Varnish] #241: Varnish gets stuck, stops responding

Varnish varnish-bugs at projects.linpro.no
Wed May 21 15:36:22 CEST 2008


#241: Varnish gets stuck, stops responding
----------------------+-----------------------------------------------------
 Reporter:  anders    |       Owner:  phk  
     Type:  defect    |      Status:  new  
 Priority:  high      |   Milestone:       
Component:  varnishd  |     Version:  trunk
 Severity:  normal    |    Keywords:       
----------------------+-----------------------------------------------------
 I am running Varnish/trunk up to date to commit 2625, on FreeBSD/amd64
 7.0-RELEASE with SCHED_ULE on Intel hardware. Today, my Varnish server
 stopped responding (just getting timeouts) while spending 100% CPU usage
 on one CPU (this is a SMP system with two cores):

 {{{
 last pid: 54762;  load averages:  1.02,  1.02,  0.98   up 47+23:32:28
 15:18:54
 33 processes:  2 running, 31 sleeping
 CPU states:     % user,     % nice,     % system,     % interrupt,     %
 idle
 Mem: 940M Active, 4784K Inact, 204M Wired, 51M Cache, 214M Buf, 1762M Free
 Swap: 6144M Total, 76K Used, 6144M Free

   PID USERNAME  THR PRI NICE   SIZE    RES STATE  C   TIME   WCPU COMMAND
  6894 root        6   4    0 41235M   909M sbwait 1  19.2H 100.00%
 varnishd
 }}}

 My VCL:

 {{{
 backend ai {
         .host = "192.168.37.230";
         .port = "80";
 }
 backend tux {
         .host = "192.168.38.10";
         .port = "80";
 }
 backend tjenester {
         .host = "192.168.38.4";
         .port = "80";
 }
 backend tux2 {
         .host = "192.168.38.12";
         .port = "80";
 }
 backend tux3 {
         .host = "192.168.38.13";
         .port = "80";
 }

 acl aipurge {
         "192.168.37.211"/32; /* aicache1 */
         "192.168.40.240"/32; /* aicacheadmin1 */
         "192.168.40.241"/32; /* aicacheadmin2 */
         "192.168.33.33"/32; /* home.schibsted.no (nagios) */
 }

 sub vcl_recv {
         set req.grace = 1m;
         if (req.http.host ~
 "^(aicache.+.aftenposten.no|cache.aftenposten.no|www.aftenposten.no|aftenposten.no|forbruker.no|www.forbruker.no|oslopuls.no|www.oslopuls.no|e24.no|www.e24.no|hyttemag.no|www.hyttemag.no|www.ap.no|ap.no|www.golf.no|golf.no)$")
 {
                 set req.backend = ai;
         } elsif (req.http.host ~ "^(tuxcache.aftenposten.no)$") {
                 set req.backend = tux;
         } elsif (req.http.host ~ "^(tjenestercache.aftenposten.no)$") {
                 set req.backend = tjenester;
         } elsif (req.http.host ~
 "^(www.aguiden.no|aguiden.no|www.aftenpostenguiden.no|aftenpostenguiden.no)$")
 {
                 set req.backend = tux2;
         } elsif (req.http.host ~
 "^(www.adressaguiden.no|adressaguiden.no|www.btguiden.no|btguiden.no|www.f-guiden.no|f-guiden.no|www.aftenbladguiden.no|aftenbladguiden.no|www.t-aguiden.no|t-aguiden.no)$")
 {
                 set req.backend = tux3;
         } else {
                 error 403 "Access denied. Contact
 cacheadmin at aftenposten.no if you have problems. Please indicate which OS,
 browser, browser version and URL you are using.";
         }

         if (req.request == "GET" || req.request == "HEAD") {
                 if (req.http.Expect) {
                         pipe;
                 }
                 if (req.http.Authenticate) {
                         pass;
                 }
                 lookup;
         } elsif (req.request == "PURGE") {
                 if (client.ip ~ aipurge) {
                         lookup;
                 } else {
                         error 405 "Not allowed.";
                 }
         } else {
                 pipe;
         }
 }

 sub vcl_miss {
         if (req.request == "PURGE") {
                 error 404 "Not in cache.";
         } else {
                 fetch;
         }
 }

 sub vcl_hit {
         if (req.request == "PURGE") {
                 set obj.ttl = 0s;
                 error 200 "Purged.";
         } else {
                 if (!obj.cacheable) {
                         pass;
                 } else {
                         deliver;
                 }
         }
 }

 sub vcl_fetch {
         set obj.grace = 1m;
         if (obj.status == 404 || obj.status == 503) {
                 pass;
         }

         if (obj.http.host ~
 "^(aicache.+.aftenposten.no|cache.aftenposten.no|www.aftenposten.no|aftenposten.no|forbruker.no|www.forbruker.no|oslopuls.no|www.oslopuls.no|e24.no|www.e24.no|hyttemag.no|www.hyttemag.no|www.ap.no|ap.no|www.golf.no|golf.no)$")
 {
                 if (obj.http.Set-Cookie) {
                         remove obj.http.Set-Cookie;
                 }
         }

         if (!obj.valid) {
                 error obj.status;
         }
         if (!obj.cacheable) {
                 pass;
         }
         if (obj.ttl < 120s) {
                 set obj.ttl = 120s;
         }
         insert;
 }

 sub vcl_hash {
         set req.hash += req.url;
         if (req.http.host ~ "^(aicache.*|cache).aftenposten.no$") {
                 set req.hash += "www.aftenposten.no";
         } else {
                 set req.hash += req.http.host;
         }
         hash;
 }
 }}}

 Backtrace:

 {{{
 [New Thread 0x12070e0290 (LWP 100265)]
 [New Thread 0x800f016e0 (LWP 100228)]
 [New Thread 0x800f01570 (LWP 100227)]
 [New Thread 0x800f01400 (LWP 100226)]
 [New Thread 0x800f01290 (LWP 100203)]
 [New Thread 0x800f01120 (LWP 100136)]
 Loaded symbols for /lib/libthr.so.3
 Reading symbols from /lib/libm.so.5...done.
 Loaded symbols for /lib/libm.so.5
 Reading symbols from /lib/libc.so.7...done.
 Loaded symbols for /lib/libc.so.7
 Error while reading shared library symbols:
 ./vcl.1P9zoqAU.o: No such file or directory.
 Reading symbols from /libexec/ld-elf.so.1...done.
 Loaded symbols for /libexec/ld-elf.so.1
 [Switching to Thread 0x12070e0290 (LWP 100265)]
 0x0000000800d98d5a in read () from /lib/libc.so.7
 (gdb) bt
 #0  0x0000000800d98d5a in read () from /lib/libc.so.7
 #1  0x0000000800a92710 in read () from /lib/libthr.so.3
 #2  0x0000000000415927 in HTC_Rx (htc=0x7ffff57aa9f0) at
 cache_httpconn.c:171
 #3  0x0000000000410cda in Fetch (sp=0x1207879008) at cache_fetch.c:356
 #4  0x000000000040c723 in cnt_fetch (sp=0x1207879008) at
 cache_center.c:338
 #5  0x000000000040d462 in CNT_Session (sp=0x1207879008) at steps.h:41
 #6  0x00000000004172c8 in wrk_do_one (w=0x7ffff57acad0) at
 cache_pool.c:194
 #7  0x000000000041758d in wrk_thread (priv=0x800f0f160) at
 cache_pool.c:247
 #8  0x0000000800a93a38 in pthread_getprio () from /lib/libthr.so.3
 #9  0x00007ffff55ad000 in ?? ()
 Error accessing memory address 0x7ffff57ad000: Bad address.
 (gdb) frame 3
 #3  0x0000000000410cda in Fetch (sp=0x1207879008) at cache_fetch.c:356
 356                     i = HTC_Rx(htc);
 (gdb) print *hp
 $1 = {magic = 1680389577, ws = 0x1206915018, conds = 0 '\0', logtag =
 HTTP_Tx,
   status = 0, hd = {{b = 0x430182 "GET", e = 0x430185 ""}, {
       b = 0x12078797a7 "/jobbflash/prodFinn.jsp", e = 0x12078797be ""}, {
       b = 0x4301fd "HTTP/1.1", e = 0x430205 ""}, {b = 0x0, e = 0x0}, {b =
 0x0,
       e = 0x0}, {b = 0x12078797c9 "Accept: */*", e = 0x12078797d4 ""}, {
       b = 0x12078797d6 "Accept-Language: nb-NO", e = 0x12078797ec ""}, {
       b = 0x12078797ee "Referer:
 http://tuxcache.aftenposten.no/jobbflash/flash/bannerResize.swf", e =
 0x1207879836 ""}, {
       b = 0x1207879838 "x-flash-version: 9,0,115,0", e = 0x1207879852 ""},
 {
       b = 0x1207879854 "UA-CPU: x86", e = 0x120787985f ""}, {
       b = 0x1207879861 "Accept-Encoding: gzip, deflate", e = 0x120787987f
 ""},
     {
       b = 0x1207879881 "User-Agent: Mozilla/4.0 (compatible; MSIE 7.0;
 Windows NT 5.1; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR
 3.0.04506.30)",
       e = 0x12078798fd ""}, {b = 0x12078798ff "Host:
 tuxcache.aftenposten.no",
       e = 0x120787991c ""}, {
       b = 0x1207879936 "Cookie: RMID=3e65ce3448106fa0;
 RMFL=011JyLWHU20OWI|U20Oib;
 __utma=132922206.360310670.1209112880.1211366073.1211369561.66;
 __utmz=132922206.1211369561.66.65.utmcsr=startsiden.no|utmccn=(referral)|utmc"...,
       e = 0x1207879a99 ""}, {b = 0x1206915298 "X-Varnish: 307859345",
       e = 0x12069152ac ""}, {
       b = 0x12069152ad "X-Forwarded-for: 62.101.206.52", e = 0x12069152cb
 ""},
     {b = 0x0, e = 0x0} <repeats 16 times>}, hdf = '\0' <repeats 31 times>,
   nhd = 16}
 (gdb) print *sp
 $2 = {magic = 741317722, fd = 122, id = 122, xid = 307859345, restarts =
 0,
   esis = 0, wrk = 0x7ffff57acad0, sockaddrlen = 16, mysockaddrlen = 128,
   sockaddr = 0x1207879690, mysockaddr = 0x1207879710,
   addr = 0x1207879790 "62.101.206.52", port = 0x120787979e "9744",
   srcaddr = 0x1207035ed0, doclose = 0x0, http = 0x12078791e8,
   http0 = 0x1207879430, ws = {{magic = 905626964, id = 0x433f78 "sess",
       s = 0x1207879790 "62.101.206.52",
       f = 0x1207879b05 ": Wed, 21 May 2008 11:33:55 GMT", r = 0x0,
       e = 0x120787b790 "", overflow = 0}}, ws_ses = 0x12078797a3 "GET",
   ws_req = 0x1207879a9d "", htc = {{magic = 1041886673, fd = 122,
       ws = 0x1207879070, rxbuf = {b = 0x12078797a3 "GET",
         e = 0x1207879a9d ""}, pipeline = {b = 0x0, e = 0x0}}},
   t_open = 1211369635.5090055, t_req = 1211369635.5951691,
   t_resp = nan(0x8000000000000), t_end = 1211369635.5090055, grace = 60,
   step = STP_FETCH, cur_method = 0, handling = 32, sendbody = 0 '\0',
   wantbody = 1 '\001', err_code = 0, err_reason = 0x0, list = {
     vtqe_next = 0x1207767008, vtqe_prev = 0x1207d34130},
   director = 0x800f16348, backend = 0x800f40320, bereq = 0x1206915000,
   obj = 0x807824000, objhead = 0x0, vcl = 0x1206705480, mem =
 0x1207879000,
   workreq = {list = {vtqe_next = 0x0, vtqe_prev = 0x0}, sess =
 0x1207879008},
   acct = {first = 1211369635.4965239, sess = 1, req = 1, pipe = 0, pass =
 0,
     fetch = 0, hdrbytes = 176, bodybytes = 0}, nhashptr = 12, ihashptr =
 4,
   lhashptr = 49, hashptr = 0x1207879aa0}
 }}}

-- 
Ticket URL: <http://varnish.projects.linpro.no/ticket/241>
Varnish <http://varnish.projects.linpro.no/>
The Varnish HTTP Accelerator


More information about the varnish-bugs mailing list