DragonFlyBSD

[...]

#7 0xc018cb85 in fill_kinfo_proc (p=0xe8c21ba0, kp=0xec319628) at /usr/src/sys/kern/kern_kinfo.c:66

It looks like p->p_pgrp == NULL.

p_pgrp is checked against NULL in several other places in the kernel
(and in fbsd too), so a fix could be to do the same in
fill_kinfo_proc().

However, I don't understand how p_pgrp can be NULL. AFAIU, it is
inherited from the parent process and set to NULL only when the
process is about to die (leaveprgp() called from kern_wait() just
before deleting the proc structure). Could there be some race
condition?

:2007/10/16, Peter Avalos <pavalos@theshell.com>:
:> Just had this one last night:
:>
:> Fatal trap 12: page fault while in kernel mode
:[...]
:> #7 0xc018cb85 in fill_kinfo_proc (p=0xe8c21ba0, kp=0xec319628) at /usr/src/sys/kern/kern_kinfo.c:66
:
:It looks like p->p_pgrp == NULL.
:
:p_pgrp is checked against NULL in several other places in the kernel
:(and in fbsd too), so a fix could be to do the same in
:fill_kinfo_proc().
:
:However, I don't understand how p_pgrp can be NULL. AFAIU, it is
:inherited from the parent process and set to NULL only when the
:process is about to die (leaveprgp() called from kern_wait() just
:before deleting the proc structure). Could there be some race
:condition?

I thought I fixed that one.

Yes, kinfo_proc can race against an exiting process.  An exiting process
    will be in a partially deallocated state and p_pgrp could very well be
    NULL as of the moment kinfo_proc tries to access it.

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

:Just had this one last night:
:
:...
:#7 0xc018cb85 in fill_kinfo_proc (p=3D0xe8c21ba0, kp=3D0xec319628) at /usr=
:/src/sys/kern/kern_kinfo.c:66

I have committed a fix for what I believe the problem was.

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

Got another from sources with your fix in it:

Fatal trap 12: page fault while in kernel mode
mp_lock = 00000000; cpuid = 0; lapic.id = 00000000
fault virtual address = 0xa00
fault code = supervisor read, page not present
instruction pointer = 0x8:0xc018cc02
stack pointer = 0x10:0xe91065f4
frame pointer = 0x10:0xe9106610
code segment = base 0x0, limit 0xfffff, type 0x1b = DPL 0, pres 1, def32 1, gran 1
processor eflags = interrupt enabled, resume, IOPL = 0
current process = 1119 (devilator)
current thread = pri 10
<- SMP: XXX
trap number = 12
panic: page fault
mp_lock = 00000000; cpuid = 0
boot() called on cpu#0
Uptime: 1d10h38m2s

dumping to dev #da/0x20001, blockno 378927

(kgdb) bt
#0 dumpsys () at thread.h:83
#1 0xc019ba82 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:371
#2 0xc019bd9f in panic (fmt=Variable "fmt" is not available.
) at /usr/src/sys/kern/kern_shutdown.c:796
#3 0xc02e4a00 in trap_fatal (frame=0xe91065ac, eva=Variable "eva" is not available.
) at /usr/src/sys/platform/pc32/i386/trap.c:1096
#4 0xc02e4b58 in trap_pfault (frame=0xe91065ac, usermode=0, eva=2560) at /usr/src/sys/platform/pc32/i386/trap.c:997
#5 0xc02e5210 in trap (frame=0xe91065ac) at /usr/src/sys/platform/pc32/i386/trap.c:680
#6 0xc02d1246 in calltrap () at /usr/src/sys/platform/pc32/i386/exception.s:783
#7 0xc018cc02 in fill_kinfo_proc (p=0xe9297860, kp=0xe9106628) at /usr/src/sys/kern/kern_kinfo.c:87
#8 0xc0193efd in sysctl_out_proc (p=0xe9297860, req=0xe9106bf4, flags=0) at /usr/src/sys/kern/kern_proc.c:653
#9 0xc01948b6 in sysctl_kern_proc (oidp=0xc033d9e0, arg1=0x0, arg2=0, req=0xe9106bf4) at /usr/src/sys/kern/kern_proc.c:782
#10 0xc01ab7b5 in sysctl_root (oidp=Variable "oidp" is not available.
) at /usr/src/sys/kern/kern_sysctl.c:1194
#11 0xc01ab8cd in userland_sysctl (name=0xe9106c7c, namelen=3, old=0x2841e000, oldlenp=0xbfbff954, inkernel=0, new=0x0, newlen=0, retval=0xe9106c78)
at /usr/src/sys/kern/kern_sysctl.c:1269
#12 0xc01abb39 in sys___sysctl (uap=0xe9106cf0) at /usr/src/sys/kern/kern_sysctl.c:1212
#13 0xc02e58d9 in syscall2 (frame=0xe9106d40) at /usr/src/sys/platform/pc32/i386/trap.c:1339
#14 0xc02d12e5 in Xint0x80_syscall () at /usr/src/sys/platform/pc32/i386/exception.s:872
#15 0x280c6c9c in ?? ()
#16 0xbfbff8bc in ?? ()
#17 0x0000002f in ?? ()
#18 0x00000000 in ?? ()
#19 0x00000000 in ?? ()
#20 0x00000000 in ?? ()
#21 0x00000000 in ?? ()
#22 0x773cd000 in ?? ()
#23 0x00000002 in ?? ()
#24 0xc035bae4 in intr_info_ary ()
#25 0xe9106420 in ?? ()
#26 0xe9106404 in ?? ()
#27 0xe8d6d500 in ?? ()
#28 0xc01a3571 in lwkt_preempt (ntd=0xbfbff954, critpri=Cannot access memory at address 0xbfbff8f4
) at /usr/src/sys/kern/lwkt_thread.c:893
Previous frame inner to this frame (corrupt stack?)

I'm having problems with my laptop right now (it has my ssh key) so I'm not
able to upload the core right away.

--Peter

I'm trying to understand exactly how this race occurs and I've got a few
questions about preemption. Could you confirm/infirm the following please?

1/ On a UP system, there can be at most one non-sleeping thread running
kernel-side and this thread can be preempted if and only if it explicitly
relinquishes the cpu, for example by calling tsleep().

2/ On a MP system, several threads can run kernel-side concurrently (one per
cpu) as long as the MP lock is not held.

3/ The MP lock is taken automatically when executing syscalls not tagged with
SYF_MPSAFE in sysent[].

4/ sysctl() kernel-side entry point is sys____sysctl() which is not MP safe.

5/ The race condition occurs if the call to vm_waitproc() in kern_wait() blocks
and another thread enters the kernel to handle a sysctl() call.

Thanks in advance,

2007/10/21, Peter Avalos <pavalos@theshell.com>:
[...]

Got another from sources with your fix in it:

Fatal trap 12: page fault while in kernel mode
mp_lock = 00000000; cpuid = 0; lapic.id = 00000000
fault virtual address = 0xa00
fault code = supervisor read, page not present
instruction pointer = 0x8:0xc018cc02

[...]

#7 0xc018cc02 in fill_kinfo_proc (p=0xe9297860, kp=0xe9106628) at /usr/src/sys/kern/kern_kinfo.c:87
#8 0xc0193efd in sysctl_out_proc (p=0xe9297860, req=0xe9106bf4, flags=0) at /usr/src/sys/kern/kern_proc.c:653
#9 0xc01948b6 in sysctl_kern_proc (oidp=0xc033d9e0, arg1=0x0, arg2=0, req=0xe9106bf4) at /usr/src/sys/kern/kern_proc.c:782

It looks like p_sigsagts NULL. Presumably, p_sigsagts could be tested for
NULL in fill_kinfo_proc() (as p_pgrp).

However, the problem may be higher up in the call stack. sysctl_kern_proc()
contains two calls to sysctl_out_proc(). One is protected by PHOLD/PRELE, the
other isn't. I reckon both calls should be protected to delay reaping until
sysctl() processing completes.

The following patch is UNTESTED as I don't know how to reproduce the original
problem.

Index: kern_proc.c
=================================================================
RCS file: /home/dcvs/src/sys/kern/kern_proc.c,v
retrieving revision 1.39
diff u -5 -r1.39 kern_proc.c
-- kern_proc.c 12 Aug 2007 16:32:13 0000 1.39
++ kern_proc.c 21 Oct 2007 10:34:28 -0000
@ -714,11 +714,13 @
p = pfind((pid_t)name⁰);
if (!p)
return (0);
if (!PRISON_CHECK(cr1, p>p_ucred))
return (0);
PHOLD;
error = sysctl_out_proc(p, req, flags);
+ PRELE;
return (error);
}

if (!req->oldptr) {
         /* overestimate by 5 procs */

:1/ On a UP system, there can be at most one non-sleeping thread running
:kernel-side and this thread can be preempted if and only if it explicitly
:relinquishes the cpu, for example by calling tsleep().
:...
:
:5/ The race condition occurs if the call to vm_waitproc() in kern_wait() blocks
:and another thread enters the kernel to handle a sysctl() call.
:
:Thanks in advance,

Not exactly.  You hit the answer in #1 ... the keyword there is 
    non-sleeping.

Many things in the kernel can cause a process to block for short periods
    of time.  There are many points in the exit code where a process can
    block.  When this occurs, another process can run and 'see' the exiting
    process in its half-torn-down state.  This can happen as easily on a UP
    system as on a MP system.

One thing that cannot cause a thread to block is an interrupt.  An
    interrupt thread can preempt the currently running thread, but the
    preemption never actually deschedules the original thread.  If the
    interrupt thread finishes or blocks or does anything that causes it
    to lose control, then control is immediately returned to the original
    thread.

This means that the sort of blockages we are talking about in mainline
    threads, for example in the exit code, are explicitly in the exit code
    and cannot be caused by events external to that code.

For example, when the exit code close()'s all of a process's file
    descriptors the act of closing those descriptors might require temporary
    vnode and other locks, all of which can temporarily block the exiting
    process.

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

:It looks like p_sigsagts NULL. Presumably, p_sigsagts could be tested for
:NULL in fill_kinfo_proc() (as p_pgrp).
:
:However, the problem may be higher up in the call stack. sysctl_kern_proc()
:contains two calls to sysctl_out_proc(). One is protected by PHOLD/PRELE, the
:other isn't. I reckon both calls should be protected to delay reaping until
:sysctl() processing completes.
:
:The following patch is UNTESTED as I don't know how to reproduce the original
:problem.

Yes, you are correct, both should be protected and your patch looks
    correct.

However, even though both should be protected this particular bit of
    code is for special kernel processes, and special kernel processes
    typically do not exit so I do not think it can be the cause.  It needs
    to be fixed anyway, though!  I will commit your patch as soon as I
    test it a little.

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

:Index: kern_proc.c
:=================================================================
:RCS file: /home/dcvs/src/sys/kern/kern_proc.c,v
:retrieving revision 1.39
:diff u -5 -r1.39 kern_proc.c
:-- kern_proc.c 12 Aug 2007 16:32:13 0000 1.39
:+++ kern_proc.c 21 Oct 2007 10:34:28 -0000
:@ -714,11 +714,13 @
: p = pfind((pid_t)name⁰);
: if (!p)
: return (0);
: if (!PRISON_CHECK(cr1, p>p_ucred))
: return (0);
:+ PHOLD;
: error = sysctl_out_proc(p, req, flags);
:+ PRELE;
: return (error);
: }
:
: if (!req->oldptr) {
: /* overestimate by 5 procs */
:

:Got another from sources with your fix in it:

More structural pointer dereferences without checks.  Committing a fix
    right now.

:#7 0xc018cc02 in fill_kinfo_proc (p=3D0xe9297860, kp=3D0xe9106628) at /usr=
:/src/sys/kern/kern_kinfo.c:87

From sys/proc.h :

#define p_sigignore     p_sigacts->ps_sigignore
    #define p_sigcatch      p_sigacts->ps_sigcatch
    #define p_rlimit        p_limit->pl_rlimit
    #define p_session       p_pgrp->pg_session
    #define p_pgid          p_pgrp->pg_id

	
-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

Just got this, and it appears similar to the previous one:

Fatal trap 12: page fault while in kernel mode
mp_lock = 00000001; cpuid = 1; lapic.id = 06000000
fault virtual address = 0x4
fault code = supervisor read, page not present
instruction pointer = 0x8:0xc019b833
stack pointer = 0x10:0xe926c5f4
frame pointer = 0x10:0xe926c610
code segment = base 0x0, limit 0xfffff, type 0x1b = DPL 0, pres 1, def32 1, gran 1
processor eflags = interrupt enabled, resume, IOPL = 0
current process = 1072 (devilator)
current thread = pri 10
<- SMP: XXX
trap number = 12
panic: page fault
mp_lock = 00000001; cpuid = 1
boot() called on cpu#1
Uptime: 30d16h20m42s

dumping to dev #da/0x20001, blockno 378927

(kgdb) bt
#0 dumpsys () at thread.h:83
#1 0xc01aa8b1 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:372
#2 0xc01aabce in panic (fmt=Variable "fmt" is not available.
) at /usr/src/sys/kern/kern_shutdown.c:797
#3 0xc0349650 in trap_fatal (frame=0xe926c5ac, eva=Variable "eva" is not available.
) at /usr/src/sys/platform/pc32/i386/trap.c:1096
#4 0xc03497a8 in trap_pfault (frame=0xe926c5ac, usermode=0, eva=4) at /usr/src/sys/platform/pc32/i386/trap.c:997
#5 0xc0349e60 in trap (frame=0xe926c5ac) at /usr/src/sys/platform/pc32/i386/trap.c:680
#6 0xc0335e76 in calltrap () at /usr/src/sys/platform/pc32/i386/exception.s:783
#7 0xc019b833 in fill_kinfo_proc (p=0xe8bd1ee0, kp=0xe926c628) at /usr/src/sys/kern/kern_kinfo.c:97
#8 0xc01a2d1d in sysctl_out_proc (p=0xe8bd1ee0, req=0xe926cbf4, flags=0) at /usr/src/sys/kern/kern_proc.c:653
#9 0xc01a36e2 in sysctl_kern_proc (oidp=0xc03b15a0, arg1=0x0, arg2=0, req=0xe926cbf4) at /usr/src/sys/kern/kern_proc.c:784
#10 0xc01ba6f5 in sysctl_root (oidp=Variable "oidp" is not available.
) at /usr/src/sys/kern/kern_sysctl.c:1194
#11 0xc01ba80d in userland_sysctl (name=0xe926cc7c, namelen=3, old=0x2b609000, oldlenp=0xbfbffb94, inkernel=0, new=0x0, newlen=0, retval=0xe926cc78)
at /usr/src/sys/kern/kern_sysctl.c:1269
#12 0xc01baa79 in sys___sysctl (uap=0xe926ccf0) at /usr/src/sys/kern/kern_sysctl.c:1212
#13 0xc034a529 in syscall2 (frame=0xe926cd40) at /usr/src/sys/platform/pc32/i386/trap.c:1339
#14 0xc0335f15 in Xint0x80_syscall () at /usr/src/sys/platform/pc32/i386/exception.s:872
#15 0x280c6c2c in ?? ()
#16 0xbfbffafc in ?? ()
#17 0x0000002f in ?? ()
#18 0x00000000 in ?? ()
#19 0x00000000 in ?? ()
#20 0x00000000 in ?? ()
#21 0x00000000 in ?? ()
#22 0x35df6000 in ?? ()
#23 0xe8c7b100 in ?? ()
#24 0xff808000 in ?? ()
#25 0xe926c3c0 in ?? ()
#26 0xe926c380 in ?? ()
#27 0xd6ff0000 in ?? ()
#28 0xc01b2da2 in lwkt_switch () at /usr/src/sys/kern/lwkt_thread.c:752
Previous frame inner to this frame (corrupt stack?)

This happened with the system doing some serious paging. Sources are
from Dec. 6th. kernel and vmcore available on leaf:~pavalos/crash/9/.

--Peter

:Just got this, and it appears similar to the previous one:
:
:dumping to dev #da/0x20001, blockno 378927
:
:(kgdb) bt
:#7 0xc019b833 in fill_kinfo_proc (p=3D0xe8bd1ee0, kp=3D0xe926c628) at /usr=
:/src/sys/kern/kern_kinfo.c:97
:..
:
:This happened with the system doing some serious paging. Sources are
:=66rom Dec. 6th. kernel and vmcore available on leaf:~pavalos/crash/9/.
:
:--Peter

I'll get it fixed.  More issues trying to get info on zombied 
     processes which are in a state of being torn down.

In this case p->p_ucred is NULL.

I'll do a run through of the procedure and fix this any other
     potential NULL dereferences that I see.

-Matt

I think we should simply prevent these almost reaped processes from
staying in the zombie list. I suggest the attached fix (not yet tested).

cheers
simon

:I think we should simply prevent these almost reaped processes from
:staying in the zombie list. I suggest the attached fix (not yet tested).
:
:cheers
: simon

It is probably a good idea to remove it from the list before or
    after the "reap3" sleep loop.  That particular patch may break
    the code at line 785 kern/kern_exit.c, though.

For now I'd say we should mess with it as little as possible.  We're
    getting too close to the release to accidently break something in the
    scheduler.

-Matt

I just got another one very similar to this with HEAD sources from about 10 days
ago. kernel and vmcore (*.21) are being uploaded to leaf right now.

Unread portion of the kernel message buffer:
panic: vm_fault: unrecoverable fault at 0xdeadc000 in entry 0xc04293a0
mp_lock = 00000000; cpuid = 0
Trace beginning at frame 0xee0764d4
panic(ee0764f8,ee076520,ee076524,ee076544,ee076554) at panic+0x14d
panic(c0377c0c,deadc000,c04293a0,135c7b0,c2a00190) at panic+0x14d
vm_fault(c0426000,deadc000,1,0,deadcade) at vm_fault+0xe2
trap_pfault(a,f1f9b800,da35c7b0,da35c7b0,ed11bd50) at trap_pfault+0xd9
trap(ee0765d0) at trap+0x4ab
calltrap() at calltrap+0xd
--- trap 0, eip = 0, esp = 0xee076614, ebp = 0xdeadcade ---
panic: vm_fault: unrecoverable fault at 0xdeadc000 in entry 0xc04293a0
mp_lock = 00000000; cpuid = 0
boot() called on cpu#0
Uptime: 10d18h51m39s

(kgdb) bt
#0 dumpsys () at ./machine/thread.h:83
#1 0xc01b39b1 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:375
#2 0xc01b3c74 in panic (fmt=0xc0377c0c "vm_fault: unrecoverable fault at %p in
entry %p") at /usr/src/sys/kern/kern_shutdown.c:800
#3 0xc02b7ceb in vm_fault (map=0xc0426000, vaddr=3735928832, fault_type=1
'\001', fault_flags=0) at /usr/src/sys/vm/vm_fault.c:301
#4 0xc032291d in trap_pfault (frame=0xee0763cc, usermode=0, eva=0) at
/usr/src/sys/platform/pc32/i386/trap.c:1029
#5 0xc0322f9c in trap (frame=0xee0763cc) at
/usr/src/sys/platform/pc32/i386/trap.c:721
#6 0xc03101b7 in calltrap () at /usr/src/sys/platform/pc32/i386/exception.s:785
#7 0xc030f25f in db_read_bytes (addr=3735931618, size=4, data=0xee076430
"Åü0À") at /usr/src/sys/platform/pc32/i386/db_interface.c:207
#8 0xc0151554 in db_get_value (addr=3735931618, size=4, is_signed=0) at
/usr/src/sys/ddb/db_access.c:58
#9 0xc030fe07 in db_stack_trace_cmd (addr=-301505324, have_addr=1, count=1018,
modif=0x0) at /usr/src/sys/platform/pc32/i386/db_trace.c:132
#10 0xc031006e in db_print_backtrace () at
/usr/src/sys/platform/pc32/i386/db_trace.c:443
#11 0xc01b3c58 in panic (fmt=0xc0377c0c "vm_fault: unrecoverable fault at %p in
entry %p") at /usr/src/sys/kern/kern_shutdown.c:796
#12 0xc02b7ceb in vm_fault (map=0xc0426000, vaddr=3735928832, fault_type=1
'\001', fault_flags=0) at /usr/src/sys/vm/vm_fault.c:301
#13 0xc032291d in trap_pfault (frame=0xee0765d0, usermode=0, eva=0) at
/usr/src/sys/platform/pc32/i386/trap.c:1029
#14 0xc0322f9c in trap (frame=0xee0765d0) at
/usr/src/sys/platform/pc32/i386/trap.c:721
#15 0xc03101b7 in calltrap () at /usr/src/sys/platform/pc32/i386/exception.s:785
#16 0xc01a5e09 in fill_kinfo_proc (p=0xda308598, kp=0xee07664c) at
/usr/src/sys/kern/kern_kinfo.c:88
#17 0xc01ac836 in sysctl_out_proc (p=0xda308598, req=0xee076c00, flags=0) at
/usr/src/sys/kern/kern_proc.c:651
#18 0xc01ad2a8 in sysctl_kern_proc (oidp=0xc0394620, arg1=0x0, arg2=0,
req=0xee076c00) at /usr/src/sys/kern/kern_proc.c:779
#19 0xc01c2f02 in sysctl_root (oidp=<value optimized out>, arg1=<value optimized
out>, arg2=3, req=0xee076c00) at /usr/src/sys/kern/kern_sysctl.c:1193
#20 0xc01c2ff4 in userland_sysctl (name=0xee076c88, namelen=3, old=0x281b1000,
oldlenp=0xbfbff0c4, inkernel=0, new=0x0, newlen=0, retval=0xee076c84) at
/usr/src/sys/kern/kern_sysctl.c:1268
#21 0xc01c31f5 in sys___sysctl (uap=0xee076cf0) at
/usr/src/sys/kern/kern_sysctl.c:1211
#22 0xc03236b3 in syscall2 (frame=0xee076d40) at
/usr/src/sys/platform/pc32/i386/trap.c:1386
#23 0xc0310266 in Xint0x80_syscall () at
/usr/src/sys/platform/pc32/i386/exception.s:876
#24 0x28123428 in ?? ()
Backtrace stopped: previous frame inner to this frame (corrupt stack?)

(kgdb) fr 16
#16 0xc01a5e09 in fill_kinfo_proc (p=0xda308598, kp=0xee07664c) at
/usr/src/sys/kern/kern_kinfo.c:88
88 kp->kp_sigignore = p->p_sigignore; /* p_sigacts-> */
(kgdb) print p->p_sigacts
$3 = (struct sigacts *) 0xdeadc0de

fixed in various commits