[Varnish] #391: Panic message: Assert error in cnt_lookup(), cache_center.c

[Varnish]

#391: Panic message: Assert error in cnt_lookup(), cache_center.c
----------------------+-----------------------------------------------------
 Reporter:  vrobert   |       Owner:  phk
     Type:  defect    |      Status:  new
 Priority:  high      |   Milestone:     
Component:  varnishd  |     Version:  2.0
 Severity:  major     |    Keywords:     
----------------------+-----------------------------------------------------
 Hello,

 we are a french company, we have 4 varnish server v2.0.2. Each server have
 about 500 req/s. Sometime a server hang with this message:



 {{{
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (25913) died signal=6
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (25913) Panic message:
 Assert error in cnt_lookup(), cache_center.c line 625:
 Condition(sp->objhead != NULL) not true.  thread = (cache-worker)sp =
 0x2ab5ecd73008 {   fd = 5, id = 5, xid = 948877249,   client =
 192.168.7.86:44306,   step = STP_FETCH,   handling = FETCH,   ws =
 0x2ab5ecd73078 {      id = "sess",     {s,f,r,e} =
 {0x2ab5ecd737b0,,+564,(nil),+8192},   },     worker = 0x58d3dc10 {     },
 vcl = {       srcname = {         "/etc/varnish/production.vcl",
 "Default",       },     },   obj = 0x2aab77d40000 {     refcnt = 1, xid =
 948877249,     ws = 0x2aab77d40028 {        id = "obj",       {s,f,r,e} =
 {0x2aab77d40358,,0x2aab77d40358,(nil),+7336},     },     http = {       ws
 = 0x2aab77d40028 {          id = "obj",         {s,f,r,e} =
 {0x2aab77d40358,,0x2aab77d40358,(nil),+7336},       },     },     len = 0,
 store = {     },   }, },
 Nov 26 15:13:41 tatooine varnishd[25912]: child (7207) Started
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Closed fds: 4
 5 6 10 11 13 14
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Child starts
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said managed to
 mmap 48318382080 bytes of 48318382080
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Ready
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Probe("GET
 /index.html HTTP/1.1
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Host:
 192.168.7.83
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Connection:
 close
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said ", 0.1, 1)
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Probe("GET
 /index.html HTTP/1.1
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Host:
 192.168.7.84
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Connection:
 close
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said ", 0.1, 1)
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Probe("GET
 /index.html HTTP/1.1
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Host:
 192.168.7.88
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Connection:
 close
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said ", 0.1, 1)
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Probe("GET
 /index.html HTTP/1.1
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Host:
 192.168.7.87
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Connection:
 close
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said ", 0.1, 1)
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Probe("GET
 /index.html HTTP/1.1
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Host:
 192.168.7.90
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Connection:
 close
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said ", 0.1, 1)
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Probe("GET
 /index.html HTTP/1.1
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Host:
 192.168.7.91
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Connection:
 close
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said ", 0.1, 1)
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Probe("GET
 /index.html HTTP/1.1
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Host:
 192.168.7.219
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Connection:
 close
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said ", 0.1, 1)
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Probe("GET
 /index.html HTTP/1.1
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Host:
 192.168.7.224
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said Connection:
 close
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said
 Nov 26 15:13:41 tatooine varnishd[25912]: Child (7207) said ", 0.1, 1)
 }}}


 Our configuration:

 {{{
 DAEMON_OPTS="-a :80 \
              -T localhost:6082 \
              -f /etc/varnish/production.vcl \
              -u varnish -g varnish \
              -s file,/cache/varnish_storage.bin,45G \
              -p lru_interval=60 \
              -p thread_pool_max=2000 \
              -p listen_depth=2048 \
              -t 0 \
              -h classic,500009"

 }}}

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