[Varnish] #162: Varnish trunk dies with assert error in SES_Delete()

[Varnish]

#162: Varnish trunk dies with assert error in SES_Delete()
---------------------------------------------------------+------------------
 Reporter:  anders                                       |        Owner:  phk  
     Type:  defect                                       |       Status:  new  
 Priority:  high                                         |    Milestone:       
Component:  varnishd                                     |      Version:  trunk
 Severity:  normal                                       |   Resolution:       
 Keywords:  varnishd core dump SES_Delete cache_session  |  
---------------------------------------------------------+------------------
Comment (by anders):

 For the record. Using this patch with trunk/2095:

 {{{
 --- cache_acceptor_kqueue.c     (revision 2088)
 +++ cache_acceptor_kqueue.c     (working copy)
 @@ -28,9 +28,6 @@
   *
   * $Id$
   *
 - * XXX: We need to pass sessions back into the event engine when they are
 - * reused.  Not sure what the most efficient way is for that.  For now
 - * write the session pointer to a pipe which the event engine monitors.
   */

  #if defined(HAVE_KQUEUE)
 @@ -141,8 +138,12 @@
                 assert(n >= 1 && n <= NKEV);
                 nki = 0;
                 for (kp = ke, j = 0; j < n; j++, kp++) {
 -                       if (kp->flags & EV_ERROR)
 +                       if (kp->flags & EV_ERROR) {
 +VSL(SLT_Debug, 0, "KQTROUBLE id %p filt %d flags %d fflags %d data %d ptr
 %p\n"
 ,
 +       (void*)kp->ident, kp->filter, kp->flags, kp->fflags,
 +       kp->data, kp->udata);
                                 continue;
 +}
                         if (kp->filter == EVFILT_TIMER) {
                                 dotimer = 1;
                                 continue;
 }}}

 I got these KQTROUBLE messages:

 {{{
     0 Debug          "KQTROUBLE id 0x212 filt -1 flags 16384 fflags 0 data
 9 ptr 0x1a86008%0a"
     0 Debug          "KQTROUBLE id 0x276 filt -1 flags 16384 fflags 0 data
 9 ptr 0x241d008%0a"
     0 Debug          "KQTROUBLE id 0xd7 filt -1 flags 16384 fflags 0 data
 9 ptr 0x4141008%0a"
     0 Debug          "KQTROUBLE id 0x2f7 filt -1 flags 16384 fflags 0 data
 9 ptr 0x2d7f008%0a"
     0 Debug          "KQTROUBLE id 0x540 filt -1 flags 16384 fflags 0 data
 9 ptr 0x2e41008%0a"
     0 Debug          "KQTROUBLE id 0x1a filt -1 flags 16384 fflags 0 data
 9 ptr 0x1cf9008%0a"
     0 Debug          "KQTROUBLE id 0x78 filt -1 flags 16384 fflags 0 data
 9 ptr 0xd16008%0a"
     0 Debug          "KQTROUBLE id 0x294 filt -1 flags 16384 fflags 0 data
 9 ptr 0x118d008%0a"
     0 Debug          "KQTROUBLE id 0x3de filt -1 flags 16384 fflags 0 data
 9 ptr 0x3435008%0a"
     0 Debug          "KQTROUBLE id 0x40e filt -1 flags 16384 fflags 0 data
 9 ptr 0x2941008%0a"
     0 Debug          "KQTROUBLE id 0x18e filt -1 flags 16384 fflags 0 data
 9 ptr 0x3512008%0a"
 }}}

 On the console:

 {{{
 Child said (2, 66296): <<Assert error in SES_Delete(), cache_session.c
 line 338:
   Condition((sp->obj) == 0) not true.
   errno = 9 (Bad file descriptor)
 }}}

 Backtrace:

 {{{
 Program received signal SIGABRT, Aborted.
 [Switching to Thread 0x541e00 (LWP 100236)]
 0x0000000800c3373c in thr_kill () at thr_kill.S:2
 2       thr_kill.S: No such file or directory.
         in thr_kill.S
 Current language:  auto; currently asm
 (gdb) bt
 #0  0x0000000800c3373c in thr_kill () at thr_kill.S:2
 #1  0x00000008009a569f in _thr_send_sig (thread=0x541e00, sig=6)
     at /usr/src/lib/libthr/thread/thr_kern.c:91
 #2  0x000000080099aff8 in _raise (sig=6)
     at /usr/src/lib/libthr/thread/thr_syscalls.c:357
 #3  0x0000000800ce5216 in abort () at /usr/src/lib/libc/stdlib/abort.c:69
 #4  0x0000000800678ba9 in lbv_assert (func=0x4313d8 "SES_Delete",
     file=0x431152 "cache_session.c", line=338, cond=0x43140a "(sp->obj) ==
 0",
     err=9) at assert.c:58
 #5  0x000000000041a522 in SES_Delete (sp=0x2b5a008) at cache_session.c:338
 #6  0x000000000040856a in vca_kev (kp=0x7fffff5fb350)
     at cache_acceptor_kqueue.c:109
 #7  0x0000000000408889 in vca_kqueue_main (arg=0x0)
     at cache_acceptor_kqueue.c:152
 #8  0x000000080099dc71 in thread_start (curthread=0x541e00)
     at /usr/src/lib/libthr/thread/thr_create.c:246
 #9  0x0000000000000000 in ?? ()
 Error accessing memory address 0x7fffff5fc000: Bad address.
 (gdb) frame 5
 #5  0x000000000041a522 in SES_Delete (sp=0x2b5a008) at cache_session.c:338
 338             AZ(sp->obj);
 Current language:  auto; currently c
 (gdb) print sp->id
 $1 = 163
 }}}

-- 
Ticket URL: <http://varnish.projects.linpro.no/ticket/162#comment:13>
Varnish <http://varnish.projects.linpro.no/>
The Varnish HTTP Accelerator