g_io_request: usb related crash

[Andriy Gapon]

FreeBSD 6.2-RELEASE-p6 amd64

The following happened:
1. I inserted into a USB card-reader a write-protected miniSD card.

2. Tried to mount it (read-write) and that failed, the following
messages appeared in the system log:
(da0:umass-sim0:0:0:0): WRITE(10). CDB: 2a 0 0 0 1 19 0 0 8 0
(da0:umass-sim0:0:0:0): CAM Status: SCSI Status Error
(da0:umass-sim0:0:0:0): SCSI Status: Check Condition
(da0:umass-sim0:0:0:0): DATA PROTECT csi:0,aa,55,61 asc:27,0
(da0:umass-sim0:0:0:0): Write protected field replaceable unit: 1
(da0:umass-sim0:0:0:0): Unretryable error
g_vfs_done():da0s1[WRITE(offset=16384, length=4096)]error = 13
(da0:umass-sim0:0:0:0): WRITE(10). CDB: 2a 0 0 0 1 19 0 0 8 0
(da0:umass-sim0:0:0:0): CAM Status: SCSI Status Error
(da0:umass-sim0:0:0:0): SCSI Status: Check Condition
(da0:umass-sim0:0:0:0): DATA PROTECT csi:0,aa,55,61 asc:27,0
(da0:umass-sim0:0:0:0): Write protected field replaceable unit: 1
(da0:umass-sim0:0:0:0): Unretryable error
g_vfs_done():da0s1[WRITE(offset=16384, length=4096)]error = 13
fsync: giving up on dirty
0xffffff0020f7f7c0: tag devfs, type VCHR
usecount 1, writecount 0, refcount 487 mountedhere 0xffffff00265a5400
flags ()
v_object 0xffffff00254ef0e0 ref 0 pages 485
dev da0s1

3. Removed the card from the reader and got instant crash.

Crash info:
Fatal trap 12: page fault while in kernel mode
cpuid = 1; apic id = 01
fault virtual address   = 0x0
fault code              = supervisor read, page not present
instruction pointer     = 0x8:0xffffffff801e554c
stack pointer           = 0x10:0xffffffffb17c3a30
frame pointer           = 0x10:0xffffffffb17c3a70
code segment            = base 0x0, limit 0xfffff, type 0x1b
                        = DPL 0, pres 1, long 1, def32 0, gran 1
processor eflags        = interrupt enabled, resume, IOPL = 0
current process         = 41 (syncer)
trap number             = 12
panic: page fault
cpuid = 1
KDB: stack backtrace:
kdb_backtrace() at 0xffffffff8024f9e7 = kdb_backtrace+0x37
panic() at 0xffffffff80230861 = panic+0x1d1
trap_fatal() at 0xffffffff803b7588 = trap_fatal+0x3a8
trap_pfault() at 0xffffffff803b71ac = trap_pfault+0x24c
trap() at 0xffffffff803b6dd3 = trap+0x2f3
calltrap() at 0xffffffff803a158b = calltrap+0x5
--- trap 0xc, rip = 0xffffffff801e554c, rsp = 0xffffffffb17c3a30, rbp =
0xffffffffb17c3a70 ---
g_io_request() at 0xffffffff801e554c = g_io_request+0x2c
g_vfs_strategy() at 0xffffffff801e8628 = g_vfs_strategy+0x58
bufwrite() at 0xffffffff8028a68c = bufwrite+0x12c
bawrite() at 0xffffffff8028adb5 = bawrite+0x15
vop_stdfsync() at 0xffffffff802948e0 = vop_stdfsync+0x1d0
devfs_fsync() at 0xffffffff801ce25b = devfs_fsync+0x2b
VOP_FSYNC_APV() at 0xffffffff803f7a7c = VOP_FSYNC_APV+0x4c
sync_vnode() at 0xffffffff8029fb02 = sync_vnode+0x192
sched_sync() at 0xffffffff8029fe9c = sched_sync+0x2bc
fork_exit() at 0xffffffff80211b0a = fork_exit+0xaa
fork_trampoline() at 0xffffffff803a18ee = fork_trampoline+0xe

(kgdb) bt
#0  doadump () at pcpu.h:172
#1  0xffffffff80230459 in boot (howto=260) at
/usr/src/sys/kern/kern_shutdown.c:409
#2  0xffffffff80230924 in panic (fmt=0xffffff00799d3720 "\b\032\ry") at
/usr/src/sys/kern/kern_shutdown.c:565
#3  0xffffffff803b7588 in trap_fatal (frame=0xffffffffb17c3980, eva=0)
at /usr/src/sys/amd64/amd64/trap.c:660
#4  0xffffffff803b71ac in trap_pfault (frame=0xffffffffb17c3980,
usermode=0) at /usr/src/sys/amd64/amd64/trap.c:573
#5  0xffffffff803b6dd3 in trap (frame=
      {tf_rdi = -1097678795608, tf_rsi = -1098524564864, tf_rdx =
-1098524564816, tf_rcx = 0, tf_r8 = -1317259312, tf_r9 = -1613966144,
tf_rax = 2, tf_rbx = -1097678795608, tf_rbp = -1317258640, tf_r10 = 0,
tf_r11 = 140737488348584, tf_r12 = -1098524564864, tf_r13 = 0, tf_r14 =
-1098958506048, tf_r15 = 2097170, tf_trapno = 12, tf_addr = 0, tf_flags
= -1098885697312, tf_err = 0, tf_rip = -2145495732, tf_cs = 8, tf_rflags
= 66178, tf_rsp = -1317258688, tf_ss = 16})
    at /usr/src/sys/amd64/amd64/trap.c:352
#6  0xffffffff803a158b in calltrap () at
/usr/src/sys/amd64/amd64/exception.S:168
#7  0xffffffff801e554c in g_io_request (bp=0xffffff006d3ecca8,
cp=0xffffff003ad56280) at /usr/src/sys/geom/geom_io.c:299
#8  0xffffffff801e8628 in g_vfs_strategy (bo=0xffffff006d3ecca8,
bp=0xffffffff9fcd9d80) at /usr/src/sys/geom/geom_vfs.c:106
#9  0xffffffff8028a68c in bufwrite (bp=0xffffffff9fcd9d80) at buf.h:426
#10 0xffffffff8028adb5 in bawrite (bp=0xffffff006d3ecca8) at buf.h:410
#11 0xffffffff802948e0 in vop_stdfsync (ap=0xffffffffb17c3b80) at
/usr/src/sys/kern/vfs_default.c:431
#12 0xffffffff801ce25b in devfs_fsync (ap=0xffffffffb17c3b80) at
/usr/src/sys/fs/devfs/devfs_vnops.c:379
#13 0xffffffff803f7a7c in VOP_FSYNC_APV (vop=0x2, a=0xffffff003ad56280)
at vnode_if.c:1020
#14 0xffffffff8029fb02 in sync_vnode (bo=0xffffff0020f7f910,
td=0xffffff00799d3720) at vnode_if.h:537
#15 0xffffffff8029fe9c in sched_sync () at /usr/src/sys/kern/vfs_subr.c:1698
#16 0xffffffff80211b0a in fork_exit (callout=0xffffffff8029fbe0
<sched_sync>, arg=0x0, frame=0xffffffffb17c3c50) at
/usr/src/sys/kern/kern_fork.c:821
#17 0xffffffff803a18ee in fork_trampoline () at
/usr/src/sys/amd64/amd64/exception.S:394

(kgdb) fr 7
#7  0xffffffff801e554c in g_io_request (bp=0xffffff006d3ecca8,
cp=0xffffff003ad56280) at /usr/src/sys/geom/geom_io.c:299
299             g_trace(G_T_BIO, "bio_request(%p) from %p(%s) to %p(%s)
cmd %d",

(kgdb) p pp
$5 = (struct g_provider *) 0x0


I think this is a crash that could have been avoided, because it seems
that there are no data corruption, only an unchecked situation.
I see that there is a KASSERT in the code, but I am not sure if this is
a situation that can not be expected to happen and to be handled.

I'll keep the core file around in case somebody has any interest in this.

-- 
Andriy Gapon