kern/101752: 6.1-RELEASE kernel panic on usb device insertion
Jim Segrave
jes at jes-2.demon.nl
Thu Aug 10 12:00:38 UTC 2006
>Number: 101752
>Category: kern
>Synopsis: 6.1-RELEASE kernel panic on usb device insertion
>Confidential: no
>Severity: serious
>Priority: medium
>Responsible: freebsd-bugs
>State: open
>Quarter:
>Keywords:
>Date-Required:
>Class: sw-bug
>Submitter-Id: current-users
>Arrival-Date: Thu Aug 10 12:00:34 GMT 2006
>Closed-Date:
>Last-Modified:
>Originator: Jim Segrave
>Release: FreeBSD 6.1-STABLE i386
>Organization:
>Environment:
System: FreeBSD jes-2.demon.nl 6.1-STABLE FreeBSD 6.1-STABLE #1: Wed Aug 9 15:48:15 CEST 2006 root at jes-2.demon.nl:/usr/obj/usr/src/sys/SONY-VAIO-ZX1 i386
Source cvsupped on Aug 9 11:53 UTC
Hardware:
Sony VAIO PCG-Z1SP laptop running 6.1-STABLE FreeBSD, Intel 82801DB uhci USB
controller, Standard Centrino based laptop with IDE hard disc and two
USB ports. 512Mb Ram, running X with fvwm2, using ndis with internal
wireless
The offending USB device:
Casio EX-Z1000 digital camera with 2GB memory card
>Description:
This looks more or less identical to PR usb/84326, although this is a
later version of FreeBSD (that report is for 5.4). I'd upgraded to 6.1 for
exactly this problem.
Enabling the usb connector from the camera causes an immediate kernel
panic. (The camera connects via a small docking station and you have
to press a button on the docking station to enable the USB connection,
simply plugging in the cable does not have any effect and it is not visible
as a USB device).
I first encountered this with my system running FreeBSD 5.4 Release from
Sep 5 2005. Rather than spend a lot of time pursuing it, I decided to
upgrade to 6.1-release. The symptoms remain unchanged. Activating the usb
cable causes the system to panic instantly.
The last log message (*.* is directed to /var/log/messages) was, in its
entirety:
Aug 10 02:18:53 jes-2 kernel: umass1: CASIO COMPUTER CASIO QV DIGITAL, rev 2.00/10.00, addr 2
Examining the core file with kgdb:
Unread portion of the kernel message buffer:
Fatal trap 18: integer divide fault while in kernel mode
instruction pointer = 0x20:0xc06667df
stack pointer = 0x28:0xd445a7b4
frame pointer = 0x28:0xd445a83c
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 = 17 (swi2: cambio)
trap number = 18
panic: integer divide fault
(kgdb) bt
#0 doadump () at pcpu.h:165
#1 0xc0542cac in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:409
#2 0xc0542f57 in panic (fmt=0xc0682eae "%s")
at /usr/src/sys/kern/kern_shutdown.c:565
#3 0xc065dfa6 in trap_fatal (frame=0xd445a774, eva=0)
at /usr/src/sys/i386/i386/trap.c:836
#4 0xc065db0c in trap (frame=
{tf_fs = 8, tf_es = 40, tf_ds = -1066401752, tf_edi = 1, tf_esi = 0, tf_e\
bp = -733632452, tf_isp = -733632608, tf_ebx = -557797921, tf_edx = 0, tf_ecx =\
0, tf_eax = 1, tf_trapno = 18, tf_err = 0, tf_eip = -1067030561, tf_cs = 32, t\
f_eflags = 66118, tf_esp = -1066353280, tf_ss = 0})
at /usr/src/sys/i386/i386/trap.c:631
#5 0xc065021a in calltrap () at /usr/src/sys/i386/i386/exception.s:139
#6 0xc06667df in __qdivrem (uq=Unhandled dwarf expression opcode 0x93
) at /usr/src/sys/libkern/qdivrem.c:97
#7 0xc0666c2a in __udivdi3 (a=3737169375, b=0)
at /usr/src/sys/libkern/udivdi3.c:47
#8 0xc04333a2 in cam_calc_geometry (ccg=0xd445a8e4, extended=1)
at /usr/src/sys/cam/cam.c:376
#9 0xc04eccfa in umass_cam_action (sim=0xc4123980, ccb=0xd445a8e4)
at /usr/src/sys/dev/usb/umass.c:2629
#10 0xc0437602 in xpt_action (start_ccb=0xd445a8e4)
at /usr/src/sys/cam/cam_xpt.c:3137
#11 0xc0442ac5 in dasetgeom (periph=0x0, block_len=1, maxsector=3737169374)
at /usr/src/sys/cam/scsi/scsi_da.c:1868
#12 0xc04423d6 in dadone (periph=0xc4116c00, done_ccb=0xc35ee800)
at /usr/src/sys/cam/scsi/scsi_da.c:1522
#13 0xc043b1f5 in camisr (V_queue=0xc35ee800)
at /usr/src/sys/cam/cam_xpt.c:7277
#14 0xc053057e in ithread_execute_handlers (p=0xc32b8a3c, ie=0xc32b1480)
at /usr/src/sys/kern/kern_intr.c:682
#15 0xc05306a2 in ithread_loop (arg=0xc3322550)
at /usr/src/sys/kern/kern_intr.c:765
#16 0xc052f7ec in fork_exit (callout=0xc053063c <ithread_loop>,
arg=0xc3322550, frame=0xd445ad38) at /usr/src/sys/kern/kern_fork.c:805
#17 0xc065027c in fork_trampoline () at /usr/src/sys/i386/i386/exception.s:208
Going to cam_calc_geometry to have a look, I find:
(kgdb) f 8
#8 0xc04333a2 in cam_calc_geometry (ccg=0xd445a8e4, extended=1)
at /usr/src/sys/cam/cam.c:376
376 size_mb = ccg->volume_size / ((1024L * 1024L) / ccg->block_size\
);
(kgdb) l
371 void
372 cam_calc_geometry(struct ccb_calc_geometry *ccg, int extended)
373 {
374 uint32_t size_mb, secs_per_cylinder;
375
376 size_mb = ccg->volume_size / ((1024L * 1024L) / ccg->block_size\
);
377 if (size_mb > 1024 && extended) {
378 ccg->heads = 255;
379 ccg->secs_per_track = 63;
380 } else {
And examining ccg gives:
(kgdb) p *ccg
$1 = {ccb_h = {pinfo = {priority = 1, generation = 15, index = -1},
xpt_links = {le = {le_next = 0xc4123940, le_prev = 0x246}, sle = {
sle_next = 0xc4123940}, tqe = {tqe_next = 0xc4123940,
tqe_prev = 0x246}, stqe = {stqe_next = 0xc4123940}}, sim_links = {
le = {le_next = 0xc06e3324, le_prev = 0xc104eb48}, sle = {
sle_next = 0xc06e3324}, tqe = {tqe_next = 0xc06e3324,
tqe_prev = 0xc104eb48}, stqe = {stqe_next = 0xc06e3324}},
periph_links = {le = {le_next = 0x8e5, le_prev = 0x4}, sle = {
sle_next = 0x8e5}, tqe = {tqe_next = 0x8e5, tqe_prev = 0x4}, stqe = {
stqe_next = 0x8e5}}, retry_count = 4294967295, cbfcnp = 0xc35ee800,
func_code = XPT_CALC_GEOMETRY, status = 0, path = 0xc4039a20, path_id = 4,
target_id = 0, target_lun = 0, flags = 0, periph_priv = {entries = {{
ptr = 0x0, field = 0, bytes = "\000\000\000"}, {ptr = 0x0,
field = 0, bytes = "\000\000\000"}},
bytes = "\000\000\000\000\000\000\000"}, sim_priv = {entries = {{
ptr = 0xc411e000, field = 3289505792, bytes = "\000021}, {
ptr = 0x3, field = 3, bytes = "\003\000\000"}},
bytes = "\000021003\000\000"}, timeout = 3277776896, timeout_ch = {
callout = 0xc3500c00}}, block_size = 3737169374,
volume_size = 3737169375, cylinders = 0, heads = 0 '\0',
secs_per_track = 0 '\0'}
As noted in the earlier PR, the volume and block size look like they come
from unitialised memory:
(kgdb) printf "%x\n%x\n", ccg->block_size, ccg->volume_size
dec0adde
dec0addf
Interesting that 'deadc0de' has been incremented in ccg->volume_size,
though probably not very useful.
Going back to frame 13, camisr(), I get
(kgdb) f 13
#13 0xc043b1f5 in camisr (V_queue=0xc35ee800)
at /usr/src/sys/cam/cam_xpt.c:7277
7277 (*ccb_h->cbfcnp)(ccb_h->path->periph, (union ccb *)ccb_\
h);
(kgdb) l
7267 if ((ccb_h->flags & CAM_DEV_QFRZDIS)
7268 && (ccb_h->status & CAM_DEV_QFRZN)) {
7269 xpt_release_devq(ccb_h->path, /*count*/1,
7270 /*run_queue*/TRUE);
7271 ccb_h->status &= ~CAM_DEV_QFRZN;
7272 } else if (runq) {
7273 xpt_run_dev_sendq(ccb_h->path->bus);
7274 }
7275
7276 /* Call the peripheral driver's callback */
7277 (*ccb_h->cbfcnp)(ccb_h->path->periph, (union ccb *)ccb_\
h);
7278
7279 /* Raise IPL for while test */
7280 s = splcam();
(kgdb) p *ccb_h
$4 = {pinfo = {priority = 5, generation = 13, index = -1}, xpt_links = {le = {
le_next = 0x0, le_prev = 0xc411e068}, sle = {sle_next = 0x0}, tqe = {
tqe_next = 0x0, tqe_prev = 0xc411e068}, stqe = {stqe_next = 0x0}},
sim_links = {le = {le_next = 0x0, le_prev = 0xd445acc0}, sle = {
sle_next = 0x0}, tqe = {tqe_next = 0x0, tqe_prev = 0xd445acc0}, stqe = {
stqe_next = 0x0}}, periph_links = {le = {le_next = 0x0,
le_prev = 0xdeadc0de}, sle = {sle_next = 0x0}, tqe = {tqe_next = 0x0,
tqe_prev = 0xdeadc0de}, stqe = {stqe_next = 0x0}}, retry_count = 3,
cbfcnp = 0xc0442010 <dadone>, func_code = XPT_SCSI_IO, status = 1,
path = 0xc4039a20, path_id = 4, target_id = 0, target_lun = 0, flags = 64,
periph_priv = {entries = {{ptr = 0x1, field = 1, bytes = "\001\000\000"}, {
ptr = 0x0, field = 0, bytes = "\000\000\000"}},
bytes = "\001\000\000\000\000\000\000"}, sim_priv = {entries = {{
ptr = 0xdeadc0de, field = 3735929054, bytes = "}, {
ptr = 0xdeadc0de, field = 3735929054, bytes = "}},
bytes = "}, timeout = 5000, timeout_ch = {callout = 0x0}}
ccb_h->flags is:
CAM_DIR_IN = 0x00000040,/* Data direction (01:DATA IN) */
I can either provide further details from the core dump if needed or I am
willing to create a kernel with CAMDEBUG and its suboptions set. Assuming
the hard disc doesn't go through the cam subsystem, I can safely simply
enable debugging of all busses and luns, as there are no other active USB
devices on this machine.
I gather that CAMDEBUG writes to the system console rather than logging to
files. The Sony does not have a serial port, so I do not know how
successful I will be at manually transcribing debugging output. I may be
able to capture this output by ssh'ing in from another machine using script
to capture the xterm on the remote machine, but I don't know if the console
output will be visible there.
>How-To-Repeat:
Inserting the usb cable from the camera and making it active is 100% fatal
(10 times out of 10, 6 under FreeBSD 5.4, 4 under FreeBSD 6.1).
Another digital camera (Sony Cybershot DSC100 with a smaller memory card)
works without incident.
>Fix:
>Release-Note:
>Audit-Trail:
>Unformatted:
More information about the freebsd-bugs
mailing list