help with GPF on 5.4-STABLE

[Sean McNeil]

On Sun, 2005-05-22 at 13:26 -0700, Doug White wrote:
> Answer is inline, but a ways down.
> 
> On Fri, 20 May 2005, Sean McNeil wrote:
> 
> > Doug,
> >
> > Thanks for helping me look into this.
> >
> > On May 20, 2005, at 1:59 PM, Doug White wrote:
> >
> > > Lets prune this down:
> > >
> > > On Thu, 19 May 2005, Sean McNeil wrote:
> > >
> > >
> > >> I'm not sure what information to provide from my crash dump.  I
> > >> tried to
> > >> burn a CD with my
> > >>
> > >> 'TOSHIBA ' 'CD/DVDW SD-R5372' 'TU31' Removable CD-ROM
> > >>
> > >> via. nautilus CD burner and I get a kernel panic:
> > >>
> > >> May 19 19:41:23 server kernel: Fatal trap 9: general protection
> > >> fault while in kernel mode
> > >> May 19 19:41:23 server kernel: instruction pointer      =
> > >> 0x8:0xffffffff801f4d99May 19 19:41:23 server kernel: stack
> > >> pointer            = 0x10:0xffffffffb1d7ab80
> > >> May 19 19:41:23 server kernel: frame pointer            =
> > >> 0x10:0xffffff0000c3b000
> > >> May 19 19:41:23 server kernel: code segment             = base
> > >> 0x0, limit 0xfffff, type 0x1b
> > >> May 19 19:41:23 server kernel: = DPL 0, pres 1, long 1, def32 0,
> > >> gran 1
> > >> May 19 19:41:23 server kernel: processor eflags = interrupt
> > >> enabled, resume, IOPL = 0
> > >> May 19 19:41:23 server kernel: current process          = 5
> > >> (thread taskq)
> > >> May 19 19:41:23 server kernel: trap number              = 9
> > >> May 19 19:41:23 server kernel: panic: general protection fault
> > >>
> > >> What can I do to get the proper info to the developers? using kgdb, I
> > >> checked the threads (pids) and stack.
> > >>
> >
> > There appears to be a missing return on the lines above.  I think it
> > caused you to read the SP for the IP.
> >
> > > kern.timeout.c line 530 is
> > >
> > > 530         mtx_unlock_spin(&callout_lock);
> >
> > I don't think this is the problem.  I think it is happening inside an
> > interrupt handler while the thread was at this point.
> >
> > > I'm not sure what in there would generate a GPF.  Load up a debugging
> > > version of the kernel that generated this error into gdb (add
> > > "makeoptions
> > > DEBUG=-g" to your kernel config & rebuild if you don't have one,
> > > and you
> > > don't need to load in the crashdump), and enter
> > >
> > > disass 0xffffffffb1d7ab80
> >
> > Looking at 0xffffffff801f4d99 (as that is the IP and above is the
> > SP), I see:
> >
> > (gdb) l *0xffffffff801f4d99
> > 0xffffffff801f4d99 is in ata_completed (/usr/src/sys/dev/ata/ata-
> > queue.c:401).
> > 396
> > 397         ATA_DEBUG_RQ(request, "completed callback/wakeup");
> > 398
> > 399         /* get results back to the initiator */
> > 400         if (request->callback)
> > 401             (request->callback)(request);
> > 402         else
> > 403             sema_post(&request->done);
> > 404
> > 405         ata_start(ch);
> >
> > 0xffffffff801f4d87 <ata_completed+103>: mov    0x58(%rbx),%rax
> > 0xffffffff801f4d8b <ata_completed+107>: test   %rax,%rax
> > 0xffffffff801f4d8e <ata_completed+110>: data16
> > 0xffffffff801f4d8f <ata_completed+111>: nop
> > 0xffffffff801f4d90 <ata_completed+112>: je     0xffffffff801f4eb5
> > <ata_completed+405>
> > 0xffffffff801f4d96 <ata_completed+118>: mov    %rbx,%rdi
> > 0xffffffff801f4d99 <ata_completed+121>: callq  *%eax
> >
> > There is an eax register in 64-bit mode?  When I do an info reg in
> > kgdb I don't see one.
> 
> %r?x are the 64 bit versions of %e?x which are the 32 bit versions of %?x
> :)
> 
> I think this is a peculiarity of long vs. normal mode and that the CALL
> instruction prefix is the same for 32 and 64 bit quantities. Its entirely
> possible gdb is just decoding the instruction wrong, assuming its 32 bit
> and not 64.
> 
> Can you print the value of callback in the request there? I wonder if the
> pointer is somehow mangled.

It appears to be exactly what is in the rax register (the callback
value):

(kgdb)  p *(struct ata_request *)0xffffff007abafe18
$1 = {device = 0xffffff0000c3b1b8, driver = 0xffffff00628d6780, u = {ata = {
      command = 3 '\003', feature = 0 '\0', count = 0, lba = 0}, atapi = {
      ccb = "\003\000\000\000\022\000\000\000\000\000\000\000\000\000\000",
      sense_data = {error_code = 0 '\0', valid = 0 '\0', segment = 0 '\0',
        sense_key = 0 '\0', reserved2_4 = 0 '\0', ili = 0 '\0', eom = 0 '\0',
        filemark = 0 '\0', cmd_info = 0, sense_length = 0 '\0',
        cmd_specific_info = 0, asc = 0 '\0', ascq = 0 '\0',
        replaceable_unit_code = 0 '\0', sk_specific = 0 '\0', sksv = 0 '\0',
        sk_specific1 = 0 '\0', sk_specific2 = 0 '\0'}, sense_key = 80 'P',
      sense_cmd = 85 'U'}}, status = 80 'P', error = 0 '\0', dmastat = 0 '\0',
  bytecount = 18, transfersize = 18, donecount = 78,
  data = 0xffffff007abafe38 "", flags = 1650, callback = 0x50070802106a0,
  done = {sema_mtx = {mtx_object = {lo_class = 0xa000000,
        lo_name = 0xc0080000026 <Address 0xc0080000026 out of bounds>,
        lo_type = 0x0, lo_flags = 0, lo_list = {tqe_next = 0x0,
          tqe_prev = 0x0}, lo_witness = 0x0}, mtx_lock = 0, mtx_recurse = 0},
    sema_cv = {cv_description = 0x0, cv_waiters = 0}, sema_waiters = 0,
    sema_value = 0}, retries = 2, timeout = 5, callout = {c_links = {sle = {
        sle_next = 0x0}, tqe = {tqe_next = 0x0,
        tqe_prev = 0xffffffff99bc0570}}, c_time = 538867,
    c_arg = 0xffffff007abafe18, c_func = 0xffffffff801f5bf0 <ata_timeout>,
    c_flags = 8}, result = 5, task = {ta_link = {stqe_next = 0x0},
    ta_pending = 0, ta_priority = 0,
---Type <return> to continue, or q <return> to quit---
    ta_func = 0xffffffff801f4d20 <ata_completed>,
    ta_context = 0xffffff007abafe18}, bio = 0x0, sequence = {tqe_next = 0x0,
    tqe_prev = 0x0}, chain = {tqe_next = 0x0, tqe_prev = 0xffffff0000c3b2c8}}

The device is:

(kgdb)  p *((struct ata_request *)0xffffff007abafe18)->device
$3 = {channel = 0xffffff0000c3b000, unit = 16,
  name = 0xffffff007b0057e0 "acd1", param = 0xffffff000114c400,
  softc = 0xffffff00010c7800, attach = 0xffffffff8020a530 <acd_attach>,
  detach = 0xffffffff8020a000 <acd_detach>, config = 0,
  start = 0xffffffff8020b6e0 <acd_start>, flags = 4, cmd = 0, mode = 12,
  setmode = 0xffffffff80204430 <ata_via_family_setmode>}

Cheers,
Sean