Date: Thu, 26 Feb 2004 03:11:52 +0100 (CET) From: Toni Andjelkovic <toni@soth.at> To: FreeBSD-gnats-submit@FreeBSD.org Subject: kern/63375: Unplugging USB devices panics RELENG_5_2 via devfs vnops Message-ID: <200402260211.i1Q2BqZr001148@shaft.soth.at> Resent-Message-ID: <200402260220.i1Q2KE4W011692@freefall.freebsd.org>
next in thread | raw e-mail | index | archive | help
>Number: 63375
>Category: kern
>Synopsis: Unplugging USB devices panics RELENG_5_2 via devfs vnops
>Confidential: no
>Severity: critical
>Priority: high
>Responsible: freebsd-bugs
>State: open
>Quarter:
>Keywords:
>Date-Required:
>Class: sw-bug
>Submitter-Id: current-users
>Arrival-Date: Wed Feb 25 18:20:14 PST 2004
>Closed-Date:
>Last-Modified:
>Originator: Toni Andjelkovic
>Release: FreeBSD 5.2.1-RELEASE i386
>Organization:
>Environment:
System: FreeBSD shaft.soth.at 5.2.1-RELEASE FreeBSD 5.2.1-RELEASE #0: Thu Feb 26 01:18:13 CET 2004 toni@kiste.soth.at:/usr/src/sys/i386/compile/GENERIC i386
>Description:
Several devfs vnode functions (devfs_getattr, devfs_setattr, devfs_access,
possibly others) may cause panics by dereferencing NULL pointers produced
by devfs_populate.
>How-To-Repeat:
1. Plug in a USB device. I tested with ugen (smartcard reader,
webcam) and ums (mouse).
2. Run the following script:
#!/usr/local/bin/python
import os, time
fd = os.open("/dev/ugen0", os.O_RDONLY)
while 1:
print os.fstat(fd)
time.sleep(1)
3. Unplug the USB device.
4. From another window, enter "ls `tty`" or do anything else that
invokes devfs_lookup or devfs_readdir - log in with ssh, ...
5. Fatal trap 12: page fault while in kernel mode.
in <devfs_getattr+0x48>
>Fix:
Maybe the devfs vnop functions should return ENXIO if ap->a_vp->v_data
is NULL. The error would be returned to the user process, where it can
be handled appropriately.
When the user process closes the descriptor for ugen0, vp->v_usecount
becomes 0 and the vnode goes to the vnode_free_list via devfs_reclaim.
Index: fs/devfs/devfs_vnops.c
===================================================================
RCS file: /home/ncvs/src/sys/fs/devfs/devfs_vnops.c,v
retrieving revision 1.67
diff -u -r1.67 devfs_vnops.c
--- fs/devfs/devfs_vnops.c 20 Oct 2003 15:08:10 -0000 1.67
+++ fs/devfs/devfs_vnops.c 25 Feb 2004 23:43:42 -0000
@@ -183,6 +183,8 @@
int error;
de = vp->v_data;
+ if (!de)
+ return (ENXIO);
if (vp->v_type == VDIR)
de = de->de_dir;
@@ -216,6 +218,8 @@
dev_t dev;
de = vp->v_data;
+ if (!de)
+ return (ENXIO);
if (vp->v_type == VDIR)
de = de->de_dir;
bzero((caddr_t) vap, sizeof(*vap));
@@ -747,6 +751,8 @@
}
de = vp->v_data;
+ if (!de)
+ return (ENXIO);
if (vp->v_type == VDIR)
de = de->de_dir;
Analysis:
When a USB device is removed, the corresponding USB_DETACH driver
function is called. This function calls destroy_dev, which calls
devfs_destroy, which nulls out the device's dev_t in the array
devfs_inot:
# ---
(gdb) break devfs_destroy
Breakpoint 1 at 0xc05effff: file ../../../fs/devfs/devfs_devs.c, line 434.
(gdb) c
Continuing.
# unplug the USB device
Breakpoint 1, devfs_destroy (dev=0xc2083600)
at ../../../fs/devfs/devfs_devs.c:434
434 ino = dev->si_inode;
(gdb) bt
#0 devfs_destroy (dev=0xc2083600) at ../../../fs/devfs/devfs_devs.c:434
#1 0xc061ba0a in destroy_dev (dev=0xc2083600) at
../../../kern/kern_conf.c:464
#2 0xc05cea4f in ugen_detach (self=0xc2083600) at ../../../dev/usb/ugen.c:908
#3 0xc0655df6 in device_detach (dev=0xc20f8f00) at device_if.h:48
#4 0xc0655145 in device_delete_child (dev=0xc2083600, child=0xc20f8f00)
at ../../../kern/subr_bus.c:1037
#5 0xc05df644 in usb_disconnect_port (up=0xc20473b0, parent=0xc2083600)
at ../../../dev/usb/usb_subr.c:1374
#6 0xc05d4cb3 in uhub_explore (dev=0xc2047500) at ../../../dev/usb/uhub.c:428
#7 0xc05dce45 in usb_discover (v=0xc2019700) at ../../../dev/usb/usb.c:716
#8 0xc05dc848 in usb_event_thread (arg=0xc2019700)
at ../../../dev/usb/usb.c:409
#9 0xc0628a84 in fork_exit (callout=0xc05dc7e0 <usb_event_thread>,
arg=0xc2083600, frame=0xc2083600) at ../../../kern/kern_fork.c:793
(gdb) p dev->si_name
$1 = 0xc2083690 "ugen0"
(gdb) p dev->si_usecount
$2 = 1
(gdb) p devfs_inot[dev->si_inode]
$3 = 0xc2083600
(gdb) p dev->si_inode
$4 = 91
(gdb) break ../../../fs/devfs/devfs_devs.c:442
Breakpoint 2 at 0xc05f0049: file ../../../fs/devfs/devfs_devs.c, line 442.
(gdb) c
Continuing.
Breakpoint 2, devfs_destroy (dev=0xc2083600)
at ../../../fs/devfs/devfs_devs.c:442
442 if (ino < i)
(gdb) p devfs_inot[dev->si_inode]
$5 = 0x0
(gdb) del br 2
(gdb) c
Continuing.
Breakpoint 1, devfs_destroy (dev=0xc20d3300)
at ../../../fs/devfs/devfs_devs.c:434
434 ino = dev->si_inode;
(gdb) p dev->si_name
$6 = 0xc20d3390 "ugen0.2"
(gdb) p dev->si_usecount
$7 = 0
(gdb) p dev->si_inode
$8 = 88
(gdb) c
Continuing.
Breakpoint 1, devfs_destroy (dev=0xc20d3100)
at ../../../fs/devfs/devfs_devs.c:434
434 ino = dev->si_inode;
(gdb) p dev->si_name
$9 = 0xc20d3190 "ugen0.4"
(gdb) p dev->si_usecount
$10 = 0
(gdb) p dev->si_inode
$11 = 89
# ---
In the trace above, devfs_destroy is being called three times, once
for each devfs file. ugen devices usually create several devfs files -
one for the control endpoint (ugen0) and one for each device endpoint
(ugen0.2 and ugen0.4). All of these are destroyed on detach of the driver.
Now that the devices are destroyed, the corresponding dev_t entries
in devfs_inot contain NULL. This is an important detail because
devfs_populate makes a decision based on it:
# ---
(gdb) del br 1
(gdb) br ../../../fs/devfs/devfs_devs.c:314
Breakpoint 3 at 0xc05efc82: file ../../../fs/devfs/devfs_devs.c, line 314.
(gdb) c
Continuing.
# An unrelated stat() call on /dev/ad0s1a
Breakpoint 3, devfs_populate (dm=0xc20ae680)
at ../../../fs/devfs/devfs_devs.c:314
314 de->de_vnode->v_data = NULL;
(gdb) bt
#0 devfs_populate (dm=0xc20ae680) at ../../../fs/devfs/devfs_devs.c:314
#1 0xc05f1b1e in devfs_lookupx (ap=0xc20fd180)
at ../../../fs/devfs/devfs_vnops.c:356
#2 0xc05f1feb in devfs_lookup (ap=0xc95adb90)
at ../../../fs/devfs/devfs_vnops.c:450
#3 0xc0692632 in lookup (ndp=0xc95adc28) at vnode_if.h:52
#4 0xc069201e in namei (ndp=0xc95adc28) at ../../../kern/vfs_lookup.c:183
#5 0xc069f8d2 in stat (td=0xc2029c80, uap=0xc95add14)
at ../../../kern/vfs_syscalls.c:1994
#6 0xc07f8cd0 in syscall (frame=
{tf_fs = 47, tf_es = 47, tf_ds = 47, tf_edi = 672328506, tf_esi =
672398144, tf_ebp = -1077942936, tf_isp = -916791948, tf_ebx = 672383264,
tf_edx = -1077943232, tf_ecx = 672398152, tf_eax = 188, tf_trapno = 12, tf_err
= 2, tf_eip = 671876239, tf_cs = 31, tf_eflags = 582, tf_esp = -1077943556,
tf_ss = 47})
at ../../../i386/i386/trap.c:1010
#7 0xc07e3d3d in Xint0x80_syscall () at {standard input}:136
#8 0x280bb332 in ?? ()
#9 0x280bb61b in ?? ()
#10 0x0804a565 in ?? ()
#11 0x08049085 in ?? ()
#12 0x08048e22 in ?? ()
(gdb) p 0xc95add14
$12 = 3378175252
(gdb) pt 0xc95add14
type = unsigned int
(gdb) frame 5
#5 0xc069f8d2 in stat (td=0xc2029c80, uap=0xc95add14)
at ../../../kern/vfs_syscalls.c:1994
1994 if ((error = namei(&nd)) != 0)
(gdb) p *uap
$13 = {path_l_ = 0xc95add14 "@û\023(ðä¿¿\003",
path = 0x2813fb40 "/dev/ad0s1a", path_r_ = 0xc95add18 "ðä¿¿\003",
ub_l_ = 0xc95add18 "ðä¿¿\003", ub = 0xbfbfe4f0, ub_r_ = 0xc95add1c "\003"}
(gdb) frame 0
#0 devfs_populate (dm=0xc20ae680) at ../../../fs/devfs/devfs_devs.c:314
314 de->de_vnode->v_data = NULL;
(gdb) list *$eip
0xc05efc82 is in devfs_populate (../../../fs/devfs/devfs_devs.c:314).
309 if (dev == NULL && de != NULL) {
310 dd = de->de_dir;
311 *dep = NULL;
312 TAILQ_REMOVE(&dd->de_dlist, de,
de_list);
313 if (de->de_vnode)
314 de->de_vnode->v_data = NULL;
315 FREE(de, M_DEVFS);
316 devfs_dropref(i);
317 continue;
318 }
(gdb) p *de->de_vnode->v_un->vu_spec->vu_cdev
$16 = {si_flags = 0, si_atime = {tv_sec = 1077744672, tv_nsec = 132892000},
si_ctime = {tv_sec = 1077744672, tv_nsec = 132892000}, si_mtime = {
tv_sec = 1077744672, tv_nsec = 132892000}, si_udev = 29184, si_hash = {
le_next = 0x0, le_prev = 0xc091c72c}, si_hlist = {slh_first = 0xc2258d34},
si_children = {lh_first = 0x0}, si_siblings = {le_next = 0x0,
le_prev = 0x0}, si_parent = 0x0, si_inode = 0,
si_name = 0xc2083690 "ugen0", si_drv1 = 0x0, si_drv2 = 0x0, si_devsw = 0x0,
si_iosize_max = 65536, si_stripesize = 0, si_stripeoffset = 0, si_uid = 0,
si_gid = 5, si_mode = 420, si_usecount = 1, __si_u = {__si_tty = {
__sit_tty = 0x0}, __si_disk = {__sid_mountpoint = 0x0,
__sid_bsize_phys = 0, __sid_bsize_best = 0, __sid_snapshots = {
tqh_first = 0x0, tqh_last = 0x0}, __sid_snaplistsize = 0,
__sid_snapblklist = 0x0, __sid_copyonwrite = 0}},
__si_namebuf = "ugen0", '\0' <repeats 58 times>}
(gdb) p de->de_vnode->v_usecount
$17 = 1
(gdb) p de->de_vnode
$18 = (struct vnode *) 0xc2258d34
(gdb) p de->de_vnode->v_data
$19 = (void *) 0xc20f9100
(gdb) p &de->de_vnode->v_data
$20 = (void **) 0xc2258ddc
# ---
In the dump above, devfs_populate gets called due to an unrelated
lookup in devfs (here: "/dev/ad0s1a"). devfs_populate iterates over
all entries in devfs_inot and checks if the dev_t is NULL. If yes,
the corresponding devfs_dirent * is also cleared (devfs_devs.c:311).
However, in devfs_devs.c:314, the v_data member of the dirent vnode
gets overwritten with NULL, although the vnode is in use by the python
process, which continuously calls fstat() on the file descriptor.
This is followed by a panic in the next step:
# ---
(gdb) c
Continuing.
Program received signal SIGSEGV, Segmentation fault.
devfs_getattr (ap=0xc95b0ba8) at ../../../fs/devfs/devfs_vnops.c:223
223 vap->va_uid = de->de_uid;
(gdb) bt
#0 devfs_getattr (ap=0xc95b0ba8) at ../../../fs/devfs/devfs_vnops.c:223
#1 0xc06a5204 in vn_stat (vp=0xc2258d34, sb=0xc95b0c78,
active_cred=0xc95b0ba8, file_cred=0xc21dbc00, td=0xc2029dc0)
at vnode_if.h:330
#2 0xc06a516d in vn_statfile (fp=0xc20f7cc0, sb=0xc95b0ba8,
active_cred=0xc95b0ba8, td=0xc2029dc0) at ../../../kern/vfs_vnops.c:616
#3 0xc061dd19 in fstat (td=0xc2029dc0, uap=0xc20f7cc0)
at ../../../sys/file.h:283
#4 0xc07f8cd0 in syscall (frame=
{tf_fs = 47, tf_es = 47, tf_ds = 47, tf_edi = 5, tf_esi = 0, tf_ebp =
-1077942216, tf_isp = -916779660, tf_ebx = 672356020, tf_edx = 5, tf_ecx =
-1077942236, tf_eax = 189, tf_trapno = 22, tf_err = 2, tf_eip = 673621103,
tf_cs = 31, tf_eflags = 582, tf_esp = -1077942260, tf_ss = 47})
at ../../../i386/i386/trap.c:1010
#5 0xc07e3d3d in Xint0x80_syscall () at {standard input}:136
#6 0x080c5d2e in ?? ()
#7 0x080d9d72 in ?? ()
#8 0x080a1345 in ?? ()
#9 0x0809f31f in ?? ()
#10 0x080a028f in ?? ()
#11 0x0809ccd7 in ?? ()
#12 0x080bc16e in ?? ()
#13 0x080bc116 in ?? ()
---Type <return> to continue, or q <return> to quit---
#14 0x080bc0ce in ?? ()
#15 0x080bb238 in ?? ()
#16 0x080babdb in ?? ()
#17 0x08054841 in ?? ()
#18 0x080540e9 in ?? ()
#19 0x08053fe2 in ?? ()
(gdb) list *$eip
0xc05f16b8 is in devfs_getattr (../../../fs/devfs/devfs_vnops.c:223).
218 de = vp->v_data;
219 if (vp->v_type == VDIR)
220 de = de->de_dir;
221 bzero((caddr_t) vap, sizeof(*vap));
222 vattr_null(vap);
223 vap->va_uid = de->de_uid;
224 vap->va_gid = de->de_gid;
225 vap->va_mode = de->de_mode;
226 if (vp->v_type == VLNK)
227 vap->va_size = de->de_dirent->d_namlen;
(gdb) x/i $eip
0xc05f16b8 <devfs_getattr+72>: mov 0x28(%edi),%eax
(gdb) info reg
eax 0xc95b0ba8 -916780120
ecx 0x0 0
edx 0xc206a600 -1039751680
ebx 0xc95b0ba8 -916780120
esp 0xc95b0b64 0xc95b0b64
ebp 0xc95b0b78 0xc95b0b78
esi 0xc2258d34 -1037726412
edi 0x0 0
eip 0xc05f16b8 0xc05f16b8
eflags 0x10246 66118
cs 0x8 8
ss 0x10 16
ds 0xc0850010 -1065025520
es 0xc0660010 -1067057136
fs 0x0 0
gs 0x0 0
fctrl 0x0 0
fstat 0x0 0
ftag 0x0 0
fiseg 0x0 0
fioff 0x0 0
foseg 0x0 0
fooff 0x0 0
---Type <return> to continue, or q <return> to quit---
fop 0x0 0
(gdb) p vp
$28 = (struct vnode *) 0xc2258d34
(gdb) p vp->v_data
$29 = (void *) 0x0
(gdb) p &vp->v_data
$30 = (void **) 0xc2258ddc
(gdb) p vp->v_usecount
$31 = 1
(gdb) p ((struct proc *) 0xc21af000)->p_fd->fd_ofiles[5]->f_vnode
$32 = (struct vnode *) 0xc2258d34
# ---
Since the v_data member of the devfs dirent vnode has been overwritten
in the previous step, it contains NULL. However, devfs_getattr()
assumes that this pointer is always valid and tries to dereference it,
which results in a page fault.
Several devfs vnop functions are affected by this bug, at least
devfs_getattr, devfs_setattr and devfs_access.
>Release-Note:
>Audit-Trail:
>Unformatted:
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200402260211.i1Q2BqZr001148>