[Varnish] #784: Varnish crash at HSH_Lookup()

[Varnish]

#784: Varnish crash at HSH_Lookup()
----------------------+-----------------------------------------------------
 Reporter:  censored  |       Owner:  phk                     
     Type:  defect    |      Status:  new                     
 Priority:  normal    |   Milestone:                          
Component:  varnishd  |     Version:  2.1.3                   
 Severity:  critical  |    Keywords:  varnishd HSH_Lookup died
----------------------+-----------------------------------------------------
Description changed by phk:

Old description:

> On debian 5.0, Linux 2.6.33.7. varnishd crashes in HSH_Lookup().
>
> {{{
> -a :55555
> -T localhost:4092
> -f /etc/varnish/default.vcl
> -s malloc,880G
> -p thread_pools=4
> -p thread_pool_min=200
> -p thread_pool_max=2400
> -p thread_pool_add_delay=2
> -p lru_interval=20"
>
> --default.vcl--
>  backend default {
>      .host = "6.6.6.6";
>      .port = "80";
>  }
>
>  sub vcl_recv {
>      unset req.http.cookie;
>
>      if (req.request == "HEAD") {
>          return(pass);
>      }
>  }
> --EOF--
>
> syslog.1:Sep 27 03:40:28 varnish1 varnishd[7667]: Child (25316) not
> responding to ping, killing it.
> syslog.1:Sep 27 03:40:28 varnish1 varnishd[7667]: Child (25316) died
> signal=6
> syslog.1:Sep 27 03:40:28 varnish1 varnishd[7667]: Child (25316) Panic
> message: Assert error in HSH_Lookup(), cache_hash.c line 374:#012
> Condition((o)->magic == 0x32851d42) not true.#012thread = (cache-
> worker)#012ident =
> Linux,2.6.33.7,x86_64,-smalloc,-hcritbit,epoll#012Backtrace:#012
> 0x424608: /usr/sbin/varnishd [0x424608]#012  0x41e2df:
> /usr/sbin/varnishd(HSH_Lookup+0x2ff) [0x41e2df]#012  0x412c9b:
> /usr/sbin/varnishd [0x412c9b]#012  0x4151ad:
> /usr/sbin/varnishd(CNT_Session+0x38d) [0x4151ad]#012  0x426a48:
> /usr/sbin/varnishd [0x426a48]#012  0x425d23: /usr/sbin/varnishd
> [0x425d23]#012  0x7fe04e3aafc7: /lib/libpthread.so.0 [0x7fe04e3aafc7]#012
> 0x7fe04dc8564d: /lib/libc.so.6(clone+0x6d) [0x7fe04dc8564d]#012sp =
> 0x7fdede746008 {#012  fd = 198, id = 198, xid = 159666020,#012  client =
> 1.1.1.1:25723,#012  step = STP_LOOKUP,#012  handling = hash,#012
> restarts = 0, esis = 0#012  ws = 0x7fdede746078 { #012    id =
> "sess",#012    {s,f,r,e} = {0x7fdede746cd0,+288,(nil),+65536},#012
> },#012  http[req] = {#012    ws = 0x7fdede746078[sess]#012
> "GET",#012      "/static/file.png",#012      "HTTP/1.1",#012
> "Accept-Encoding: gzip",#012      "User-Agent: Jakarta Commons-
> HttpClient/3.1",#012      "Host: foo.bar.com",#012      "X-Forwarded-For:
> 4.4.4.4, 1.1.1.1",#012  },#012  worker = 0x7fccc53a3e70 {#012    ws =
> 0x7fccc53a3fe0 { #012      id = "wrk",#012      {s,f,r,e} =
> {0x7fccc5391e10,0x7fccc5391e10,(nil),+65536},#012    },#012    },#012
> vcl = {#012      srcname = {#012        "input",#012
> "Default",#012      },#012    },#012},#012
> syslog.1:Sep 27 03:40:28 varnish1 varnishd[7667]: Child cleanup complete
> syslog.1:Sep 27 03:40:28 varnish1 varnishd[7667]: child (2662) Started
> }}}

New description:

 On debian 5.0, Linux 2.6.33.7. varnishd crashes in HSH_Lookup().

 {{{
 -a :55555
 -T localhost:4092
 -f /etc/varnish/default.vcl
 -s malloc,880G
 -p thread_pools=4
 -p thread_pool_min=200
 -p thread_pool_max=2400
 -p thread_pool_add_delay=2
 -p lru_interval=20"

 --default.vcl--
  backend default {
      .host = "6.6.6.6";
      .port = "80";
  }

  sub vcl_recv {
      unset req.http.cookie;

      if (req.request == "HEAD") {
          return(pass);
      }
  }
 --EOF--

 syslog.1:Sep 27 03:40:28 varnish1 varnishd[7667]: Child (25316) not
 responding to ping, killing it.
 syslog.1:Sep 27 03:40:28 varnish1 varnishd[7667]: Child (25316) died
 signal=6
 syslog.1:Sep 27 03:40:28 varnish1 varnishd[7667]: Child (25316)
 Panic message: Assert error in HSH_Lookup(), cache_hash.c line 374:#012
   Condition((o)->magic == 0x32851d42) not true.#012
 thread = (cache-worker)#012
 ident = Linux,2.6.33.7,x86_64,-smalloc,-hcritbit,epoll#012
 Backtrace:#012

 0x424608: /usr/sbin/varnishd [0x424608]#012
   0x41e2df: /usr/sbin/varnishd(HSH_Lookup+0x2ff) [0x41e2df]#012
   0x412c9b: /usr/sbin/varnishd [0x412c9b]#012
   0x4151ad: /usr/sbin/varnishd(CNT_Session+0x38d) [0x4151ad]#012
   0x426a48: /usr/sbin/varnishd [0x426a48]#012
   0x425d23: /usr/sbin/varnishd [0x425d23]#012
   0x7fe04e3aafc7: /lib/libpthread.so.0 [0x7fe04e3aafc7]#012
   0x7fe04dc8564d: /lib/libc.so.6(clone+0x6d) [0x7fe04dc8564d]#012
 sp = 0x7fdede746008 {#012
   fd = 198, id = 198, xid = 159666020,#012
   client = 1.1.1.1:25723,#012  step = STP_LOOKUP,#012
   handling = hash,#012
   restarts = 0, esis = 0#012
   ws = 0x7fdede746078 { #012
     id = "sess",#012
     {s,f,r,e} = {0x7fdede746cd0,+288,(nil),+65536},#012  },#012
   http[req] = {#012
     ws = 0x7fdede746078[sess]#012
       "GET",#012
       "/static/file.png",#012
       "HTTP/1.1",#012
       "Accept-Encoding: gzip",#012
       "User-Agent: Jakarta Commons-HttpClient/3.1",#012
       "Host: foo.bar.com",#012
       "X-Forwarded-For: 4.4.4.4, 1.1.1.1",#012
   },#012
   worker = 0x7fccc53a3e70 {#012
     ws = 0x7fccc53a3fe0 { #012
       id = "wrk",#012
       {s,f,r,e} = {0x7fccc5391e10,0x7fccc5391e10,(nil),+65536},#012
     },#012
     },#012
     vcl = {#012
       srcname = {#012
         "input",#012
         "Default",#012
       },#012
     },#012
 },#012

 syslog.1:Sep 27 03:40:28 varnish1 varnishd[7667]: Child cleanup complete
 syslog.1:Sep 27 03:40:28 varnish1 varnishd[7667]: child (2662) Started
 }}}

--

-- 
Ticket URL: <http://varnish-cache.org/trac/ticket/784#comment:2>
Varnish <http://varnish-cache.org/>
The Varnish HTTP Accelerator