panic in soabort

[Robert N. M. Watson]

On 1 Oct 2009, at 12:24, pluknet wrote:

>>> If you run into this again, let me know.  Also, are you using  
>>> accept filters
>>> on the box?
>>>
>>
>> Got it again (this time on 6.4-p5).
>
> P.S.
> It's funny to say: I got it on two boxes nearly simultaneously.
> Both from proftpd. See also my first mail (the same).

I'll take a further look at this today sometime, but it is my belief  
(FYI) that the new socket life cycle in 7.x closes many possible races  
along these lines. As such, while we can try to track down and resolve  
this, you might find it simply "goes away" if you move to 7. If you do  
see it in 7 then I would be especially interested :-).

There are two sockets involved here, and I'd like to get some  
debugging information on both. First, it looks like close() is being  
called on a listen socket -- could something be killing the proftpd  
instance on both your boxes at about the same time, perhaps due to  
shutdown or some admin event?

For both sockets, the one passed to soclose and the one passed to  
soabort, could you provide structure dumps of:

(1) *so
(2) *(struct inpcb *)(so->so_pcb)
(3) Depending on whether INP_TIMEWAIT is set in the inp_flags field,  
either *(struct tcpcb)((struct inpcb *)(so->so_pcb)->inp_ppcb) or the  
same cast but struct tcptw if it is in timewait.

It seems likely we're dealing with a race condition in which close()  
on a listen socket aborts a pending connection at the same time as a  
network event, such as a received reset/fin/etc.

Robert

>
>>
>> Fatal trap 12: page fault while in kernel mode
>> cpuid = 2; apic id = 02
>> fault virtual address   = 0x104
>> fault code              = supervisor read, page not present
>> instruction pointer     = 0x20:0xc06a3425
>> stack pointer           = 0x28:0xef764bb0
>> frame pointer           = 0x28:0xef764bbc
>> code segment            = base 0x0, limit 0xfffff, type 0x1b
>>                       = DPL 0, pres 1, def32 1, gran 1
>> processor eflags        = resume, IOPL = 0
>> current process         = 74303 (proftpd)
>>
>> db> bt 74303
>> Tracing pid 74303 tid 101039 td 0xcaa08820
>> _mtx_lock_sleep(ccd50768,caa08820,0,0,0) at _mtx_lock_sleep+0x9d
>> soabort(ccd506f4) at soabort+0x82
>> soclose(d1aa8b20) at soclose+0x21a
>> soo_close(c9f50a20,caa08820) at soo_close+0x63
>> fdrop_locked(c9f50a20,caa08820,caf78a00,ef764ca8,c06875f3,...) at
>> fdrop_locked+0xd0
>> fdrop(c9f50a20,caa08820,caa08820,ef764c64,c0689055,...) at fdrop+0x41
>> closef(c9f50a20,caa08820,0,ef764d38,cad8f648,...) at closef+0x42f
>> kern_close(caa08820,a,ef764d30,c08e1d4b,caa08820,...) at kern_close 
>> +0x20d
>> close(caa08820,ef764d04) at close+0x10
>> syscall(bfbf003b,3b,bfbf003b,8150034,811a434,...) at syscall+0x2bf
>> Xint0x80_syscall() at Xint0x80_syscall+0x1f
>> --- syscall (6, FreeBSD ELF32, close), eip = 0x2832230f, esp =
>> 0xbfbfe6bc, ebp = 0xbfbfe6d8 ---
>> db> show proc 74303
>> Process 74303 (proftpd) at 0xcad8f648:
>> state: NORMAL
>> uid: 36830  gids: 36830
>> parent: pid 95478 at 0xc8e60000
>> ABI: FreeBSD ELF32
>> arguments: proftpd: fatich_1 - 93.118.217.18: IDLE
>> threads: 1
>> 101039                   Run     CPU 2               proftpd
>>
>> (gdb) list *(soabort+0x82)
>> 0xc06ea2a6 is in soabort (/usr/src/sys/kern/uipc_socket.c:510).
>> 505             int error;
>> 506
>> 507             error = (*so->so_proto->pr_usrreqs->pru_abort)(so);
>> 508             if (error) {
>> 509                     ACCEPT_LOCK();
>> 510                     SOCK_LOCK(so);
>> 511                     sotryfree(so);  /* note: does not decrement
>> the ref count */
>> 512                     return error;
>> 513             }
>> 514             return (0);
>>
>> --
>> wbr,
>> pluknet
>>
>
>
>
> -- 
> wbr,
> pluknet