Re: [Qemu-devel] [Qemu-ppc] macio ide question/bug report

[BALATON Zoltan]

On Wed, 14 May 2014, Mark Cave-Ayland wrote:
> On 14/05/14 12:10, BALATON Zoltan wrote:
> > The logs I've posted are with DEBUG_IDE_ATAPI, DEBUG_DBDMA and
> > DEBUG_MACIO already enabled...
>
> Well sure, but not the ones in your last email - I had to go back several 
> mails back into the thread to pull them out. Bear in mind the high volume of 
> these lists means that a lot of people who could help won't have the time to 
> do this.

All the logs I posted in this thread were with these debug options 
enabled. Maybe the beginning was missing as I only included the logs from 
the failing dma reply because before that I was tracing to see that the 
TOC was read and about to be returned so I did not include those logs 
again. (They were in the previous mail though.) I'm including them again 
below this time.

> Which part is it that's still confusing you? Putting breakpoints on 
> pmac_ide_transfer() and pmac_ide_atapi_transfer_cb() will show you the 
> iterations on each DMA request (be sure to compare against a "known good" 
> example to understand how it should work first). If you can give more detail 
> as to which bits are confusing, I will try my best to explain them.

Looking at the backtrace:

#0  ide_atapi_cmd_error (s=0x5555563cb238, sense_key=5, asc=33)
    at hw/ide/atapi.c:141
#1  0x00005555556cecf5 in ide_atapi_io_error (s=0x5555563cb238, ret=-5)
    at hw/ide/atapi.c:160
#2  0x00005555556d9d01 in pmac_ide_atapi_transfer_cb (opaque=0x5555563ccc68,
    ret=-5) at hw/ide/macio.c:64
#3  0x00005555556780d2 in dma_complete (dbs=0x5555563ab840, ret=-5)
    at dma-helpers.c:121
#4  0x00005555556781db in dma_bdrv_cb (opaque=0x5555563ab840, ret=-5)
    at dma-helpers.c:149
#5  0x0000555555614dd1 in bdrv_co_em_bh (opaque=0x5555563b5000) at block.c:4602
#6  0x00005555555f8170 in aio_bh_poll (ctx=0x55555637fc00) at async.c:81
#7  0x00005555555f7dc9 in aio_poll (ctx=0x55555637fc00, blocking=false)
    at aio-posix.c:188
#8  0x00005555555f8587 in aio_ctx_dispatch (source=0x55555637fc00, callback=
    0x0, user_data=0x0) at async.c:205
#9  0x00007ffff78ca6d5 in g_main_context_dispatch ()
   from /lib64/libglib-2.0.so.0
#10 0x00005555557a0f42 in glib_pollfds_poll () at main-loop.c:190
#11 0x00005555557a1042 in os_host_main_loop_wait (timeout=0) at main-loop.c:235
#12 0x00005555557a1115 in main_loop_wait (nonblocking=1) at main-loop.c:484
#13 0x0000555555844190 in main_loop () at vl.c:2075
#14 0x000055555584bc23 in main (argc=30, argv=0x7fffffffdc88, envp=
    0x7fffffffdd80) at vl.c:4556

shows that pmac_ide_atapi_transfer_cb is called with ret=-5 which is why 
it fails, so putting a breakpoint there is too late. What I don't 
understand is where this -5 value comes from. I don't have a known good 
example because Darwin reads the TOC differently (probably before enabling 
DMA, I did not trace it more than the logs I've included earlier though) 
and MorphOS always fails.

Here are the logs of all requests MorphOS does up to the failing ReadTOC 
again:

ATAPI limit=0x8000 packet: 00 00 00 00 00 00 00 00 00 00 00 00
ATAPI limit=0x8000 packet: 12 00 00 00 24 00 00 00 00 00 00 00
reply: tx_size=36 elem_tx_size=0 index=0
byte_count_limit=32768
status=0x58
reply: tx_size=0 elem_tx_size=0 index=36
status=0x50
ATAPI limit=0x8000 packet: 1b 00 00 00 01 00 00 00 00 00 00 00
ATAPI limit=0x8000 packet: 00 00 00 00 00 00 00 00 00 00 00 00
ATAPI limit=0x8000 packet: 25 00 00 00 00 00 00 00 00 00 00 00
reply: tx_size=8 elem_tx_size=0 index=0
byte_count_limit=32768
status=0x58
reply: tx_size=0 elem_tx_size=0 index=8
status=0x50
ATAPI limit=0x8000 packet: 5a 00 05 00 00 00 00 00 30 00 00 00
atapi_cmd_error: sense=0x5 asc=0x24
ATAPI limit=0x8000 packet: 5a 00 04 00 00 00 00 00 28 00 00 00
atapi_cmd_error: sense=0x5 asc=0x24
ATAPI limit=0x8000 packet: 5a 00 03 00 00 00 00 00 28 00 00 00
atapi_cmd_error: sense=0x5 asc=0x24
ATAPI limit=0x8000 packet: 5a 00 3f 00 00 00 00 01 02 00 00 00
atapi_cmd_error: sense=0x5 asc=0x24
ATAPI limit=0x8000 packet: 51 00 00 00 00 00 00 00 22 00 00 00
reply: tx_size=34 elem_tx_size=0 index=0
byte_count_limit=32768
status=0x58
reply: tx_size=0 elem_tx_size=0 index=34
status=0x50
DBDMA: writel 0x0000000000000d0c <= 0x00e4e960
DBDMA: channel 0x1a reg 0x3
DBDMA: dbdma_cmdptr_load 0x00e4e960
ATAPI limit=0x8000 packet: 43 00 00 00 00 00 00 03 24 00 00 00

DBDMA: DBDMA_run_bh
DBDMA: writel 0x0000000000000d00 <= 0x80008000
DBDMA: channel 0x1a reg 0x0
DBDMA:     status 0x00008400
DBDMA: readl 0x0000000000000d00 => 0x80008000
DBDMA: channel 0x1a reg 0x0
DBDMA: DBDMA_run_bh
DBDMA: channel_run
dbdma_cmd 0x7f8f93662ee0
    req_count 0x0324
    command 0x3000
    phy_addr 0x00e4f30c
    cmd_dep 0x00000000
    res_count 0x0000
    xfer_status 0x0000
DBDMA: start_input
DBDMA: addr 0xe4f30c key 0x0
pmac_ide_transfer(ATAPI) lba=ffffffff, buffer_index=0, len=324
io_buffer_size = 0
io->len = 0x324
sector_num=-1 size=20, cmd_cmd=0
atapi_cmd_error: sense=0x5 asc=0x21
done DMA
DBDMA: dbdma_end
DBDMA: conditional_wait
DBDMA: dbdma_cmdptr_save 0x00e4e960
DBDMA: xfer_status 0x00008400 res_count 0x0000
DBDMA: conditional_interrupt
DBDMA: conditional_branch
DBDMA: dbdma_cmdptr_load 0x00e4e970
DBDMA: channel_run
dbdma_cmd 0x7f8f93662ee0
    req_count 0x0000
    command 0x7000
    phy_addr 0x00000000
    cmd_dep 0x00000000
    res_count 0x0000
    xfer_status 0x0000
DBDMA: readl 0x0000000000000d04 => 0x00008000
DBDMA: channel 0x1a reg 0x1
DBDMA: writel 0x0000000000000d00 <= 0x98000000
DBDMA: channel 0x1a reg 0x0
DBDMA:     status 0x00000000
ATAPI limit=0x8000 packet: 00 00 00 00 00 00 00 00 00 00 00 00
ATAPI limit=0x8000 packet: 00 00 00 00 00 00 00 00 00 00 00 00

and here are the corresponding debug logs from MorphOS that shows what is 
it trying to do:

address@hidden: DiskPort 0x200a9310
address@hidden: ATAPI
address@hidden:
address@hidden: Send TestDrive
address@hidden: 1st TestDrive Status 0
address@hidden: Send Inquiry
address@hidden: No IOError
address@hidden: Unit is there physically
address@hidden: DriveGeometry
address@hidden: SectorSize 2048
address@hidden: SectorSize 2048 SectorShift 11 SectorShiftHighMask 0xffe00000
address@hidden: Set Removable
address@hidden: Send StartUnit
address@hidden: StartMotor IOError 0 SCSIError 0x0
address@hidden: Sense [0] 0x00000000000000000000000000000000
address@hidden: TestUnitReady IOError 0 SCSIError 0x0
address@hidden: Sense[0] 0x00000000000000000000000000000000
address@hidden: StartUnit done
address@hidden: TstDrive IOError 0 SCSIError 0x0
address@hidden:
address@hidden: DeviceType 5 needs Capacity
address@hidden:
address@hidden: Send Capacity16
address@hidden: IOError -4 SCSIError 0x0
address@hidden:
address@hidden: Send Capacity
address@hidden: Status ok
address@hidden: SectorCount 112839 (0x1b8c7)
address@hidden: SectorSize 2048
address@hidden: ignore for CDROM..too dangerous with Atapi returning random crap
address@hidden: TotalSectors 112839
address@hidden: SectorSize 2048
address@hidden: Capacity10 ok
address@hidden: Send ModeSense(Flex Disk Page)
address@hidden: Page 5 Length 32 Flags 0x0 PageOffset 0x200cae98
address@hidden: Use ModeSense10
address@hidden: Final Length 48 Offset 16
address@hidden: ModeSense error 45
address@hidden: Send ModeSense(Rigid Disk Geometry Page)
address@hidden: Page 4 Length 24 Flags 0x0 PageOffset 0x200cae98
address@hidden: Use ModeSense10
address@hidden: Final Length 40 Offset 16
address@hidden: ModeSense error 45
address@hidden: Send ModeSense(Format Page)
address@hidden: Page 3 Length 24 Flags 0x0 PageOffset 0x200cae98
address@hidden: Use ModeSense10
address@hidden: Final Length 40 Offset 16
address@hidden: ModeSense error 45
address@hidden: No ModeHeader yet
address@hidden: Send ModeSense(Parameter Header)
address@hidden: Page 63 Length 242 Flags 0x0 PageOffset 0x200cae98
address@hidden: Use ModeSense10
address@hidden: Final Length 258 Offset 16
address@hidden: ModeSense error 45
address@hidden: Mark Unit is ready
address@hidden: scan/mount partitions
address@hidden: DeviceType 5 MountMode 0
address@hidden: mountable devicetype
address@hidden: Mount CD
address@hidden: DiskPort 0x2004bf60
address@hidden: Device 0x200a7f64 <idemacio2.device> Unit 0x20078654 UnitNum 0
address@hidden: Check for bootable disc...
address@hidden:
address@hidden: MyDiscInfoData 0x200abe84
address@hidden: GetDiscInfo io_Error(0)
address@hidden: Flags 0xe FirstTrack 1
address@hidden: Sessions 1
address@hidden: FirstTrackLastSession 1
address@hidden: Flags1 0x20 DiscType 0
address@hidden: DiscID <> DiscBarCode <>
address@hidden: ok
address@hidden: MyDiscInfoData 0x200abe84 Length 32
address@hidden: Locate ISO descriptor
address@hidden: READ_TOC io_Error(45)
address@hidden: failed
address@hidden: no toc data

Regards,
BALATON Zoltan