PANIC: ASSERT FAILED (/usr/home/rene/devel/src/add-ons/kernel/bus_managers/ata/ata_request.c:83): status != 0x01

[anevilyak]

While jamming Haiku within Haiku (after having done an svn up on the copy of the tree stored on the disk), I hit this kdl. Backtrace as follows:

stack trace for thread 37 "scsi scheduler"
    kernel stack: 0xa017b000 to 0xa017f000
frame            caller     <image>:function + offset
 0 a017eb08 (+  48) 800577d5   <kernel>:invoke_debugger_command + 0x00ed
 1 a017eb38 (+  64) 800575cd   <kernel>:invoke_pipe_segment__FP21debugger_command_pipelPc + 0x0079
 2 a017eb78 (+  64) 80057915   <kernel>:invoke_debugger_command_pipe + 0x009d
 3 a017ebb8 (+  48) 800587f0   <kernel>:_ParseCommandPipe__16ExpressionParserRi + 0x0234
 4 a017ebe8 (+  48) 800581a6   <kernel>:EvaluateCommand__16ExpressionParserPCcRi + 0x01de
 5 a017ec18 (+ 224) 80059bbc   <kernel>:evaluate_debug_command + 0x0088
 6 a017ecf8 (+  64) 80055c4a   <kernel>:kernel_debugger_loop__Fv + 0x01ae
 7 a017ed38 (+  48) 800567e3   <kernel>:kernel_debugger + 0x0117
 8 a017ed68 (+ 192) 800566c1   <kernel>:panic + 0x0029
 9 a017ee28 (+  48) 807cdde5   <ide>:ata_request_set_status + 0x003d
10 a017ee58 (+  48) 807d083e   <ide>:ata_exec_io + 0x0402
11 a017ee88 (+  48) 807cec42   <ide>:sim_scsi_io + 0x006a
12 a017eeb8 (+  64) 808cd99b   <scsi>:scsi_async_io + 0x02f3
13 a017eef8 (+  96) 808e0678   <scsi_periph>:periph_io__FP23scsi_periph_device_infoP11IOOperationPUl + 0x025c
14 a017ef58 (+  48) 808dbcfe   <scsi_disk>:do_io__FPvP11IOOperation + 0x0032
15 a017ef88 (+  48) 80068829   <kernel>:_Scheduler__11IOScheduler + 0x0055
16 a017efb8 (+  32) 80068896   <kernel>:_SchedulerThread__11IOSchedulerPv + 0x0012
17 a017efd8 (+  32) 8004d8c3   <kernel>:_create_kernel_thread_kentry__Fv + 0x001b
18 a017eff8 (+1609043976) 8004d860   <kernel>:thread_kthread_exit__Fv + 0x0000

I don't know what else would be useful to look up at this point though, so I'm going to leave the box in KDL so you can let me know if there's anything else you want me to pull out of the kernel debugger.

[axeld]

I had the same problem before hrev26839. AFAICT this is only triggered by the "ata" driver when a zero length request comes in.

If it's reproducible, you might want to print the request, and, more importantly, the io_operation in scsi2ata.c, line 567, right before this: ata_request_set_status(request, SCSI_REQ_CMP);

Something like: dprintf("request %p, ccb %p, io_operation %p\n", request, ccb, ccb->io_operation);

Alternatively, you should also be able to see this io_operation pointer in the second argument of call 14 in this stack trace (you could see this with "call 14 -2").

Then, when in KDL, you can use the "io_operation" command with this pointer, and print your findings here :-)

[anevilyak]

Will see what I can find this evening :) Also I feel dumb for not mentioning the revision number of that build, but it was hrev26872 in any case.

[anevilyak]

call 14 -2
thread 37, scsi scheduler
a017ef58 808dbcfe   <scsi_disk>:do_io__FPvP11IOOperation(0x90d84de8, 0x90dcfbe0)
kdebug> io_operation 0x90dcfbe0
io_operation at 0x90dcfbe0
  parent:           0x90dd78c4
  status:           No Error (1)
  dma buffer:       0x90da8660
  offset:           50769447424 (original: 50769447424)
  length:           0        (original: 0)
  transferred:      0
  block size:       512
  saved vec index:  1
  saved vec length: 512
  r/w:              read
  phase:            do all
  partial begin:    no
  partial end:      no
  bounce buffer:    no

Hope that helps :)

[anevilyak]

A few more things (thanks to mmlr for tips):

DMABuffer at 0x90da8660
  bounce buffer:      0x90ca4000 (physical 0xf768000)
  bounce buffer size: 16384
  vecs:               0

io_request at 0x90dd78c4
  parent:            0xa18977e8
  status:            No Error (1)
  mutex:             0x90dd78e0
  IOBuffer:          0x90d94780
  offset:            50769349120
  length:            131072
  transfer size:     98304
  relative offset:   0
  pending children:  2
  flags:             0x1
  team:              472
  r/w:               read
  partial transfer:  no
  finished cvar:     0x90dd7930
  iteration:
    vec index:       16
    vec offset:      0
    remaining bytes: 32768
  callbacks:
    finished 0x00000000, cookie 0x00000000
    iteration 0x00000000, cookie 0x00000000
  children:
    0x90dcfb40
    0x90dcfbe0

Going off of that, the other child op:
io_operation at 0x90dcfb40
  parent:           0x90dd78c4
  status:           No error
  dma buffer:       0x90da84c8
  offset:           50769349120 (original: 50769349120)
  length:           98304    (original: 98304)
  transferred:      98304
  block size:       512
  saved vec index:  1
  saved vec length: 512
  r/w:              read
  phase:            do all
  partial begin:    no
  partial end:      no
  bounce buffer:    no

And its DMA buffer:
DMABuffer at 0x90da84c8
  bounce buffer:      0x90c9c000 (physical 0xf760000)
  bounce buffer size: 16384
  vecs:               16
    [0] 0x291ee000, 8192
    [1] 0x291f1000, 4096
    [2] 0x291f0000, 4096
    [3] 0x291f2000, 24576
    [4] 0x20d4c000, 8192
    [5] 0x20d5c000, 8192
    [6] 0x2c332000, 4096
    [7] 0x2c331000, 4096
    [8] 0x2c330000, 4096
    [9] 0x2c2b7000, 4096
    [10] 0x2c2b6000, 4096
    [11] 0x2bd6f000, 4096
    [12] 0x2bd5e000, 4096
    [13] 0x2bd5d000, 4096
    [14] 0x2bd5c000, 4096
    [15] 0x2bd16000, 4096

[anevilyak]

And just in case, the io buffer:

IOBuffer at 0x90d94780
  origin:     user
  kind:       physical
  length:     131072
  capacity:   23
  vecs:       23
    [0] 0x291ee000, 8192
    [1] 0x291f1000, 4096
    [2] 0x291f0000, 4096
    [3] 0x291f2000, 24576
    [4] 0x20d4c000, 8192
    [5] 0x20d5c000, 8192
    [6] 0x2c332000, 4096
    [7] 0x2c331000, 4096
    [8] 0x2c330000, 4096
    [9] 0x2c2b7000, 4096
    [10] 0x2c2b6000, 4096
    [11] 0x2bd6f000, 4096
    [12] 0x2bd5e000, 4096
    [13] 0x2bd5d000, 4096
    [14] 0x2bd5c000, 4096
    [15] 0x2bd16000, 4096
    [16] 0x2bd05000, 4096
    [17] 0x2bcec000, 4096
    [18] 0x2bceb000, 4096
    [19] 0x2bce8000, 4096
    [20] 0x2bcd7000, 4096
    [21] 0x293d2000, 8192
    [22] 0x294c0000, 4096

[bonefish]

Thanks, excellent info! The problem should be fixed in hrev26881. Please reopen, if it isn't.

[anevilyak]

Thank Axel for the nice io_* kdebug commands :) And will give it a try in a bit, might need to reinit that partition depending on what happened to it there.

[anevilyak]

Doesn't seem to KDL any more, but the issue mentioned in ticket #2584 still seems to be present after this fix.