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

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

[BALATON Zoltan]

On Wed, 7 May 2014, Mark Cave-Ayland wrote:
> On 07/05/14 18:00, BALATON Zoltan wrote:
>> On Wed, 7 May 2014, Mark Cave-Ayland wrote:
>>> I'm not sure if your problem related to s->lba == -1 should be solved
>>> just for macio or higher up in the block layer, but the block people
>>> will be on qemu-devel and not qemu-ppc so you should definitely CC the
>>> main list to get their feedback on this.

Cc'd the devel list now, the original question can be found here:
http://lists.nongnu.org/archive/html/qemu-ppc/2014-05/msg00003.html

>> I think it's handled by the block layer but the translation in macio
>> breaks it and converts it to -4 which causes an error so probably it
>> should only be solved for macio. But I hope Alex can look at it and tell
>> for sure or maybe solve it.
>
> Okay. So in that case it could just be a macio bug.
>
>>> Those ISOs only boot for me with the default -M g3beige, but darwin is
>>> a huge culprit for these unaligned accesses. My point was that if you
>>> are making changes in this area, if you can still boot the darwin
>>> images then that would be a good test that any changes you make are
>>> working correctly :)
>> 
>> Ah, OK. They boot for me without a -M parameter with my changes (to the
>> point saying "available for installation:" and then empty as I did not
>> specify a hard disk image) too, but I was testing with -M mac99 as that
>> was what I changed. I think they still "work" as before.
>
> But... the block patchset link I sent you has the potential to fix this 
> anyway, since if the unaligned accesses can be passed directly up to the 
> block layer then in theory this problem should go away as this whole chunk of 
> code should no longer be required.
>
> A good test for this would be to try reverting this patch: 
> https://github.com/agraf/qemu/commit/063a333911f1bb09fcc1a4925c8ebf5c88fc2b63 
> which is Alex's original alignment fix. If you find with that with this patch 
> reverted darwin boots as before, it means that the block alignment patches in 
> core are working correctly and hopefully you may find that it fixes your 
> MorphOS problem.
>
> But again, you really should get this on qemu-devel to get the definitive 
> answer from the block guys.

That patch would be 80fc95d8bdaf3392106b131a97ca701fd374489a in QEMU 
master. I've tried reverting it and Darwin still boots (without -M mac99) 
up to the point where it asks to install as before but I don't know how 
good a test is this as I'm not sure it does unaligned accesses up to this 
point. I see accesses like this:

pmac_ide_transfer(ATAPI) lba=ffffffff, buffer_index=30, len=930
pmac_ide_transfer(ATAPI) lba=0, buffer_index=0, len=930
pmac_ide_transfer(ATAPI) lba=0, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=1, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=1, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=2, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=2, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=0, buffer_index=0, len=2000
pmac_ide_transfer(ATAPI) lba=f2, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=f3, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=1ac, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=9ae, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=9af, buffer_index=0, len=400
pmac_ide_transfer(ATAPI) lba=9ae, buffer_index=0, len=400
pmac_ide_transfer(ATAPI) lba=9ae, buffer_index=400, len=400
pmac_ide_transfer(ATAPI) lba=9af, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=11ae, buffer_index=0, len=800
pmac_ide_transfer(ATAPI) lba=11af, buffer_index=0, len=1000
[...]
pmac_ide_transfer(ATAPI) lba=3858e, buffer_index=0, len=2000
pmac_ide_transfer(ATAPI) lba=3856e, buffer_index=0, len=2000
pmac_ide_transfer(ATAPI) lba=38572, buffer_index=0, len=4000
pmac_ide_transfer(ATAPI) lba=38590, buffer_index=0, len=4000
pmac_ide_transfer(ATAPI) lba=38584, buffer_index=0, len=1000
pmac_ide_transfer(ATAPI) lba=38586, buffer_index=0, len=3000
pmac_ide_transfer(ATAPI) lba=3857e, buffer_index=0, len=3000
pmac_ide_transfer(ATAPI) lba=38566, buffer_index=0, len=4000
pmac_ide_transfer(ATAPI) lba=38550, buffer_index=0, len=1000
pmac_ide_transfer(ATAPI) lba=38552, buffer_index=0, len=4000
pmac_ide_transfer(ATAPI) lba=38536, buffer_index=0, len=4000
pmac_ide_transfer(ATAPI) lba=3852c, buffer_index=0, len=5000
pmac_ide_transfer(ATAPI) lba=385a6, buffer_index=0, len=4000
pmac_ide_transfer(ATAPI) lba=a724, buffer_index=0, len=2000
pmac_ide_transfer(ATAPI) lba=3854a, buffer_index=0, len=3000
pmac_ide_transfer(ATAPI) lba=1654, buffer_index=0, len=1000
pmac_ide_transfer(ATAPI) lba=3b1cc, buffer_index=0, len=8000
pmac_ide_transfer(ATAPI) lba=3b3a8, buffer_index=0, len=8000
pmac_ide_transfer(ATAPI) lba=3b3a0, buffer_index=0, len=4000
pmac_ide_transfer(ATAPI) lba=3b3a8, buffer_index=0, len=2000
pmac_ide_transfer(ATAPI) lba=38546, buffer_index=0, len=2000
pmac_ide_transfer(ATAPI) lba=3854a, buffer_index=0, len=8000
pmac_ide_transfer(ATAPI) lba=3b3d8, buffer_index=0, len=8000
pmac_ide_transfer(ATAPI) lba=3b3e8, buffer_index=0, len=7000
pmac_ide_transfer(ATAPI) lba=3b3ca, buffer_index=0, len=7000
pmac_ide_transfer(ATAPI) lba=3b3d8, buffer_index=0, len=1000

This however does not fix MorphOS which fails as before. I've tried this 
patch too (on top of the previous revert) but that did not work either:

diff --git a/hw/ide/macio.c b/hw/ide/macio.c
index d3395f4..bce14fc 100644
--- a/hw/ide/macio.c
+++ b/hw/ide/macio.c
@@ -56,6 +56,7 @@ static void pmac_ide_atapi_transfer_cb(void *opaque, int 
ret)
      DBDMA_io *io = opaque;
      MACIOIDEState *m = io->opaque;
      IDEState *s = idebus_active_if(&m->bus);
+    int64_t sector_num;

      if (ret < 0) {
          m->aiocb = NULL;
@@ -107,13 +108,16 @@ static void pmac_ide_atapi_transfer_cb(void *opaque, 
int r
      qemu_sglist_add(&s->sg, io->addr, io->len);
      io->addr += io->len;
      io->len = 0;
-
-    MACIO_DPRINTF("sector_num=%d size=%d, cmd_cmd=%d\n",
-                  (s->lba << 2) + (s->io_buffer_index >> 9),
+    if (s->lba >= 0)
+        sector_num = (s->lba << 2) + (s->io_buffer_index >> 9);
+    else
+        sector_num = s->lba;
+    MACIO_DPRINTF("sector_num=%ld size=%d, cmd_cmd=%d\n",
+                  sector_num,
                    s->packet_transfer_size, s->dma_cmd);

      m->aiocb = dma_bdrv_read(s->bs, &s->sg,
-                             (int64_t)(s->lba << 2) + (s->io_buffer_index >> 9)
+                             sector_num,
                               pmac_ide_atapi_transfer_cb, io);
      return;

This still produces an error in MorphOS as before:

DBDMA: writel 0x0000000000000d0c <= 0x00e5ac80
DBDMA: channel 0x1a reg 0x3
DBDMA: dbdma_cmdptr_load 0x00e5ac80
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 0x7f7dddff5ae0
     req_count 0x0324
     command 0x3000
     phy_addr 0x00e7dddc
     cmd_dep 0x00000000
     res_count 0x0000
     xfer_status 0x0000
DBDMA: start_input
DBDMA: addr 0xe7dddc 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

Interestingly a similar read works for Darwin which does this:

ATAPI limit=0x0 packet: bb 00 ff ff 00 00 00 00 00 00 00 00
ATAPI limit=0xfffe packet: 43 02 00 00 00 00 00 ff fe 80 00 00
reply: tx_size=48 elem_tx_size=0 index=0
byte_count_limit=65534
status=0x58
reply: tx_size=0 elem_tx_size=0 index=48
status=0x50
ATAPI limit=0x30 packet: 43 02 00 00 00 00 00 00 30 80 00 00
reply: tx_size=48 elem_tx_size=0 index=0
byte_count_limit=48
status=0x58
reply: tx_size=0 elem_tx_size=0 index=48
status=0x50
DBDMA: readl 0x0000000000000d04 => 0x00000000
DBDMA: channel 0x1a reg 0x1
DBDMA: writel 0x0000000000000d08 <= 0x00000000
DBDMA: channel 0x1a reg 0x2
DBDMA: writel 0x0000000000000d0c <= 0x011f8010
DBDMA: channel 0x1a reg 0x3
DBDMA: dbdma_cmdptr_load 0x011f8010
DBDMA: writel 0x0000000000000d00 <= 0x90009000
DBDMA: channel 0x1a reg 0x0
DBDMA:     status 0x00009400
DBDMA: DBDMA_run_bh
DBDMA: channel_run
dbdma_cmd 0x7ffa05173c60
     req_count 0x0930
     command 0x2000
     phy_addr 0x017cc000
     cmd_dep 0x00000000
     res_count 0x0000
     xfer_status 0x0000
DBDMA: start_input
DBDMA: addr 0x17cc000 key 0x0
pmac_ide_transfer(ATAPI) lba=ffffffff, buffer_index=30, len=930
waiting for data (0x3 - 0x930 - 50)
ATAPI limit=0x930 packet: be 00 00 00 00 00 00 00 01 f8 00 00
read dma: LBA=0 nb_sectors=1

DBDMA: DBDMA_run_bh
DBDMA: channel_run
dbdma_cmd 0x7ffa05173c60
     req_count 0x0930
     command 0x2000
     phy_addr 0x017cc000
     cmd_dep 0x00000000
     res_count 0x0000
     xfer_status 0x0000
DBDMA: start_input
DBDMA: addr 0x17cc000 key 0x0
pmac_ide_transfer(ATAPI) lba=0, buffer_index=0, len=930
io_buffer_size = 0
io->len = 0x930
sector_num=0 size=2352, cmd_cmd=0
io_buffer_size = 0x930
end of transfer
end of DMA
done DMA
DBDMA: dbdma_end

If these make sense to anyone and can tell what could be the problem 
please share your thoughts.

Regards,
BALATON Zoltan

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

[Mark Cave-Ayland]

On 10/05/14 13:30, BALATON Zoltan wrote:

> That patch would be 80fc95d8bdaf3392106b131a97ca701fd374489a in QEMU
> master. I've tried reverting it and Darwin still boots (without -M
> mac99) up to the point where it asks to install as before but I don't
> know how good a test is this as I'm not sure it does unaligned accesses
> up to this point. I see accesses like this:
>
> pmac_ide_transfer(ATAPI) lba=ffffffff, buffer_index=30, len=930
> pmac_ide_transfer(ATAPI) lba=0, buffer_index=0, len=930

Here is an example of an unaligned access, where the length is not a 
multiple of 0x200 (512 bytes) which was required for the block layer DMA 
APIs at the time it was written. If you can get to the same point with 
the patch reverted, then it means Kevin's patchset for byte-level rather 
than sector-level granularity for block requests is working.

What's important is the sum of the start_input size descriptors now 
matches the size of the ATA request, so the dma_* callbacks can now be 
used directly with byte precision rather than clobbering the memory up 
to the next multiple of 0x200.

> This however does not fix MorphOS which fails as before. I've tried this
> patch too (on top of the previous revert) but that did not work either:
>
> diff --git a/hw/ide/macio.c b/hw/ide/macio.c
> index d3395f4..bce14fc 100644
> --- a/hw/ide/macio.c
> +++ b/hw/ide/macio.c
> @@ -56,6 +56,7 @@ static void pmac_ide_atapi_transfer_cb(void *opaque,
> int ret)
>       DBDMA_io *io = opaque;
>       MACIOIDEState *m = io->opaque;
>       IDEState *s = idebus_active_if(&m->bus);
> +    int64_t sector_num;
>
>       if (ret < 0) {
>           m->aiocb = NULL;
> @@ -107,13 +108,16 @@ static void pmac_ide_atapi_transfer_cb(void
> *opaque, int r
>       qemu_sglist_add(&s->sg, io->addr, io->len);
>       io->addr += io->len;
>       io->len = 0;
> -
> -    MACIO_DPRINTF("sector_num=%d size=%d, cmd_cmd=%d\n",
> -                  (s->lba << 2) + (s->io_buffer_index >> 9),
> +    if (s->lba >= 0)
> +        sector_num = (s->lba << 2) + (s->io_buffer_index >> 9);
> +    else
> +        sector_num = s->lba;
> +    MACIO_DPRINTF("sector_num=%ld size=%d, cmd_cmd=%d\n",
> +                  sector_num,
>                     s->packet_transfer_size, s->dma_cmd);
>
>       m->aiocb = dma_bdrv_read(s->bs, &s->sg,
> -                             (int64_t)(s->lba << 2) +
> (s->io_buffer_index >> 9)
> +                             sector_num,
>                                pmac_ide_atapi_transfer_cb, io);
>       return;
>
> This still produces an error in MorphOS as before:
>
> DBDMA: writel 0x0000000000000d0c <= 0x00e5ac80
> DBDMA: channel 0x1a reg 0x3
> DBDMA: dbdma_cmdptr_load 0x00e5ac80
> 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 0x7f7dddff5ae0
>      req_count 0x0324
>      command 0x3000
>      phy_addr 0x00e7dddc
>      cmd_dep 0x00000000
>      res_count 0x0000
>      xfer_status 0x0000
> DBDMA: start_input
> DBDMA: addr 0xe7dddc 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
>
> Interestingly a similar read works for Darwin which does this:
>
> ATAPI limit=0x0 packet: bb 00 ff ff 00 00 00 00 00 00 00 00
> ATAPI limit=0xfffe packet: 43 02 00 00 00 00 00 ff fe 80 00 00
> reply: tx_size=48 elem_tx_size=0 index=0
> byte_count_limit=65534
> status=0x58
> reply: tx_size=0 elem_tx_size=0 index=48
> status=0x50
> ATAPI limit=0x30 packet: 43 02 00 00 00 00 00 00 30 80 00 00
> reply: tx_size=48 elem_tx_size=0 index=0
> byte_count_limit=48
> status=0x58
> reply: tx_size=0 elem_tx_size=0 index=48
> status=0x50
> DBDMA: readl 0x0000000000000d04 => 0x00000000
> DBDMA: channel 0x1a reg 0x1
> DBDMA: writel 0x0000000000000d08 <= 0x00000000
> DBDMA: channel 0x1a reg 0x2
> DBDMA: writel 0x0000000000000d0c <= 0x011f8010
> DBDMA: channel 0x1a reg 0x3
> DBDMA: dbdma_cmdptr_load 0x011f8010
> DBDMA: writel 0x0000000000000d00 <= 0x90009000
> DBDMA: channel 0x1a reg 0x0
> DBDMA:     status 0x00009400
> DBDMA: DBDMA_run_bh
> DBDMA: channel_run
> dbdma_cmd 0x7ffa05173c60
>      req_count 0x0930
>      command 0x2000
>      phy_addr 0x017cc000
>      cmd_dep 0x00000000
>      res_count 0x0000
>      xfer_status 0x0000
> DBDMA: start_input
> DBDMA: addr 0x17cc000 key 0x0
> pmac_ide_transfer(ATAPI) lba=ffffffff, buffer_index=30, len=930
> waiting for data (0x3 - 0x930 - 50)

^^^^^

> ATAPI limit=0x930 packet: be 00 00 00 00 00 00 00 01 f8 00 00
> read dma: LBA=0 nb_sectors=1
>
> DBDMA: DBDMA_run_bh
> DBDMA: channel_run
> dbdma_cmd 0x7ffa05173c60
>      req_count 0x0930
>      command 0x2000
>      phy_addr 0x017cc000
>      cmd_dep 0x00000000
>      res_count 0x0000
>      xfer_status 0x0000
> DBDMA: start_input
> DBDMA: addr 0x17cc000 key 0x0
> pmac_ide_transfer(ATAPI) lba=0, buffer_index=0, len=930
> io_buffer_size = 0
> io->len = 0x930
> sector_num=0 size=2352, cmd_cmd=0
> io_buffer_size = 0x930
> end of transfer
> end of DMA
> done DMA
> DBDMA: dbdma_end

 From the limited block layer knowledge I have, it seems that lba == -1 
is a default value meaning the ATA request hasn't been submitted.

Take a look at the lines I marked above: it looks to me as if in the 2nd 
request, the DMA controller is running but realises that it is still 
waiting for the ATA request to complete before continuing which is why 
you see "waiting for data" followed by that ATAPI packet. In your first 
case, pmac_ide_transfer() incorrectly believes the ATA request has 
already completed which is why it tries to continue and then chokes on 
the invalid lba value of -1.


HTH,

Mark.

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

[BALATON Zoltan]

On Mon, 12 May 2014, Mark Cave-Ayland wrote:
> On 10/05/14 13:30, BALATON Zoltan wrote:
>> That patch would be 80fc95d8bdaf3392106b131a97ca701fd374489a in QEMU
>> master. I've tried reverting it and Darwin still boots (without -M
>> mac99) up to the point where it asks to install as before but I don't
>> know how good a test is this as I'm not sure it does unaligned accesses
>> up to this point. I see accesses like this:
>> 
>> pmac_ide_transfer(ATAPI) lba=ffffffff, buffer_index=30, len=930
>> pmac_ide_transfer(ATAPI) lba=0, buffer_index=0, len=930
>
> Here is an example of an unaligned access, where the length is not a multiple 
> of 0x200 (512 bytes) which was required for the block layer DMA APIs at the 
> time it was written. If you can get to the same point with the patch 
> reverted, then it means Kevin's patchset for byte-level rather than 
> sector-level granularity for block requests is working.

These logs were with the above commit reverted so it's probably not needed 
any more. I've tried booting Darwin 6.0.2, Darwin 8.0.1 up to the 
installation (did not install it) and Finnix 109 and they seem to work as 
before.

> What's important is the sum of the start_input size descriptors now matches 
> the size of the ATA request, so the dma_* callbacks can now be used directly 
> with byte precision rather than clobbering the memory up to the next multiple 
> of 0x200.
>
>> This however does not fix MorphOS which fails as before. I've tried this
>> patch too (on top of the previous revert) but that did not work either:
>> 
>> diff --git a/hw/ide/macio.c b/hw/ide/macio.c
>> index d3395f4..bce14fc 100644
>> --- a/hw/ide/macio.c
>> +++ b/hw/ide/macio.c
>> @@ -56,6 +56,7 @@ static void pmac_ide_atapi_transfer_cb(void *opaque,
>> int ret)
>>       DBDMA_io *io = opaque;
>>       MACIOIDEState *m = io->opaque;
>>       IDEState *s = idebus_active_if(&m->bus);
>> +    int64_t sector_num;
>>
>>       if (ret < 0) {
>>           m->aiocb = NULL;
>> @@ -107,13 +108,16 @@ static void pmac_ide_atapi_transfer_cb(void
>> *opaque, int r
>>       qemu_sglist_add(&s->sg, io->addr, io->len);
>>       io->addr += io->len;
>>       io->len = 0;
>> -
>> -    MACIO_DPRINTF("sector_num=%d size=%d, cmd_cmd=%d\n",
>> -                  (s->lba << 2) + (s->io_buffer_index >> 9),
>> +    if (s->lba >= 0)
>> +        sector_num = (s->lba << 2) + (s->io_buffer_index >> 9);
>> +    else
>> +        sector_num = s->lba;
>> +    MACIO_DPRINTF("sector_num=%ld size=%d, cmd_cmd=%d\n",
>> +                  sector_num,
>>                     s->packet_transfer_size, s->dma_cmd);
>>
>>       m->aiocb = dma_bdrv_read(s->bs, &s->sg,
>> -                             (int64_t)(s->lba << 2) +
>> (s->io_buffer_index >> 9)
>> +                             sector_num,
>>                                pmac_ide_atapi_transfer_cb, io);
>>       return;
>> 
>> This still produces an error in MorphOS as before:
>> 
>> DBDMA: writel 0x0000000000000d0c <= 0x00e5ac80
>> DBDMA: channel 0x1a reg 0x3
>> DBDMA: dbdma_cmdptr_load 0x00e5ac80
>> 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 0x7f7dddff5ae0
>>      req_count 0x0324
>>      command 0x3000
>>      phy_addr 0x00e7dddc
>>      cmd_dep 0x00000000
>>      res_count 0x0000
>>      xfer_status 0x0000
>> DBDMA: start_input
>> DBDMA: addr 0xe7dddc 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
>> 
>> Interestingly a similar read works for Darwin which does this:
>> 
>> ATAPI limit=0x0 packet: bb 00 ff ff 00 00 00 00 00 00 00 00
>> ATAPI limit=0xfffe packet: 43 02 00 00 00 00 00 ff fe 80 00 00
>> reply: tx_size=48 elem_tx_size=0 index=0
>> byte_count_limit=65534
>> status=0x58
>> reply: tx_size=0 elem_tx_size=0 index=48
>> status=0x50
>> ATAPI limit=0x30 packet: 43 02 00 00 00 00 00 00 30 80 00 00
>> reply: tx_size=48 elem_tx_size=0 index=0
>> byte_count_limit=48
>> status=0x58
>> reply: tx_size=0 elem_tx_size=0 index=48
>> status=0x50
>> DBDMA: readl 0x0000000000000d04 => 0x00000000
>> DBDMA: channel 0x1a reg 0x1
>> DBDMA: writel 0x0000000000000d08 <= 0x00000000
>> DBDMA: channel 0x1a reg 0x2
>> DBDMA: writel 0x0000000000000d0c <= 0x011f8010
>> DBDMA: channel 0x1a reg 0x3
>> DBDMA: dbdma_cmdptr_load 0x011f8010
>> DBDMA: writel 0x0000000000000d00 <= 0x90009000
>> DBDMA: channel 0x1a reg 0x0
>> DBDMA:     status 0x00009400
>> DBDMA: DBDMA_run_bh
>> DBDMA: channel_run
>> dbdma_cmd 0x7ffa05173c60
>>      req_count 0x0930
>>      command 0x2000
>>      phy_addr 0x017cc000
>>      cmd_dep 0x00000000
>>      res_count 0x0000
>>      xfer_status 0x0000
>> DBDMA: start_input
>> DBDMA: addr 0x17cc000 key 0x0
>> pmac_ide_transfer(ATAPI) lba=ffffffff, buffer_index=30, len=930
>> waiting for data (0x3 - 0x930 - 50)
>
> ^^^^^
>
>> ATAPI limit=0x930 packet: be 00 00 00 00 00 00 00 01 f8 00 00
>> read dma: LBA=0 nb_sectors=1
>> 
>> DBDMA: DBDMA_run_bh
>> DBDMA: channel_run
>> dbdma_cmd 0x7ffa05173c60
>>      req_count 0x0930
>>      command 0x2000
>>      phy_addr 0x017cc000
>>      cmd_dep 0x00000000
>>      res_count 0x0000
>>      xfer_status 0x0000
>> DBDMA: start_input
>> DBDMA: addr 0x17cc000 key 0x0
>> pmac_ide_transfer(ATAPI) lba=0, buffer_index=0, len=930
>> io_buffer_size = 0
>> io->len = 0x930
>> sector_num=0 size=2352, cmd_cmd=0
>> io_buffer_size = 0x930
>> end of transfer
>> end of DMA
>> done DMA
>> DBDMA: dbdma_end
>
> From the limited block layer knowledge I have, it seems that lba == -1 is a 
> default value meaning the ATA request hasn't been submitted.

I don't know but according to hw/ide/atapi.c lba=-1 is a special value 
meaning that no sector needs to be read but only the results are 
requested. I don't know if this is only an atapi thing or how the block 
layer handles it but I believe that it is used for reading the TOC from 
the disk.

> Take a look at the lines I marked above: it looks to me as if in the 2nd 
> request, the DMA controller is running but realises that it is still waiting 
> for the ATA request to complete before continuing which is why you see 
> "waiting for data" followed by that ATAPI packet. In your first case, 
> pmac_ide_transfer() incorrectly believes the ATA request has already 
> completed which is why it tries to continue and then chokes on the invalid 
> lba value of -1.

MorphOS and Darwin are definitely doing things differently. I hope someone 
who understands what is happening can explain it why one of them works 
while the other doesn't.

Regards,
BALATON Zoltan

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

[Mark Cave-Ayland]

On 12/05/14 20:32, BALATON Zoltan wrote:

> On Mon, 12 May 2014, Mark Cave-Ayland wrote:
>> On 10/05/14 13:30, BALATON Zoltan wrote:
>>> That patch would be 80fc95d8bdaf3392106b131a97ca701fd374489a in QEMU
>>> master. I've tried reverting it and Darwin still boots (without -M
>>> mac99) up to the point where it asks to install as before but I don't
>>> know how good a test is this as I'm not sure it does unaligned accesses
>>> up to this point. I see accesses like this:
>>>
>>> pmac_ide_transfer(ATAPI) lba=ffffffff, buffer_index=30, len=930
>>> pmac_ide_transfer(ATAPI) lba=0, buffer_index=0, len=930
>>
>> Here is an example of an unaligned access, where the length is not a
>> multiple of 0x200 (512 bytes) which was required for the block layer
>> DMA APIs at the time it was written. If you can get to the same point
>> with the patch reverted, then it means Kevin's patchset for byte-level
>> rather than sector-level granularity for block requests is working.
>
> These logs were with the above commit reverted so it's probably not
> needed any more. I've tried booting Darwin 6.0.2, Darwin 8.0.1 up to the
> installation (did not install it) and Finnix 109 and they seem to work
> as before.

Okay that's definitely an improvement on what's there already :)  When I 
find a moment, I'll try some local testing here and see if it's worth 
submitting a patch.

>>> This still produces an error in MorphOS as before:
>>>
>>> DBDMA: writel 0x0000000000000d0c <= 0x00e5ac80
>>> DBDMA: channel 0x1a reg 0x3
>>> DBDMA: dbdma_cmdptr_load 0x00e5ac80
>>> 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 0x7f7dddff5ae0
>>>      req_count 0x0324
>>>      command 0x3000
>>>      phy_addr 0x00e7dddc
>>>      cmd_dep 0x00000000
>>>      res_count 0x0000
>>>      xfer_status 0x0000
>>> DBDMA: start_input
>>> DBDMA: addr 0xe7dddc 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

(cut)

> MorphOS and Darwin are definitely doing things differently. I hope
> someone who understands what is happening can explain it why one of them
> works while the other doesn't.

Which I hope is what I'm trying to do? From hw/ide/atapi.c you can see 
that command 0x43 is read the TOC which according to atapi_cmd_table 
should call cmd_read_toc_pma_atip(). You can see that in your MorphOS 
case you are getting a line with a "atapi_cmd_error" prefix which 
indicates that something is calling ide_atapi_cmd_error() to return an 
error code instead of ide_atapi_cmd_reply() which would output the 
"reply" prefix as seen in your Darwin case. So you need to step through 
these functions in QEMU in order to see why your ATAPI command is failing.


HTH,

Mark.

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

[BALATON Zoltan]

On Mon, 12 May 2014, Mark Cave-Ayland wrote:
> On 12/05/14 20:32, BALATON Zoltan wrote:
> (cut)
>
>> MorphOS and Darwin are definitely doing things differently. I hope
>> someone who understands what is happening can explain it why one of them
>> works while the other doesn't.
>
> Which I hope is what I'm trying to do? From hw/ide/atapi.c you can see that

Yes, your comments and advise are helping a lot. Thank you.

> command 0x43 is read the TOC which according to atapi_cmd_table should call 
> cmd_read_toc_pma_atip(). You can see that in your MorphOS case you are 
> getting a line with a "atapi_cmd_error" prefix which indicates that something 
> is calling ide_atapi_cmd_error() to return an error code instead of 
> ide_atapi_cmd_reply() which would output the "reply" prefix as seen in your 
> Darwin case. So you need to step through these functions in QEMU in order to 
> see why your ATAPI command is failing.

I've tried doing this and it seems that the cmd_read_toc_pma_atip function 
returns all right (via the case 0 path) with a 20 byte result array and 
calls ide_atapi_cmd_reply which takes the DMA path as s->atapi_dma is set 
to 1 and the error comes from somewhere during trying to DMA the result 
back to the client. I could not follow it so I've only got a backtrace 
from where ide_atapi_cmd_error is called:

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 0x5555563cccb0
     req_count 0x0324
     command 0x3000
     phy_addr 0x00e17e4c
     cmd_dep 0x00000000
     res_count 0x0000
     xfer_status 0x0000
DBDMA: start_input
DBDMA: addr 0xe17e4c 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
[Switching to Thread 0x7ffff7fc5900 (LWP 6462)]

Breakpoint 2, ide_atapi_cmd_error (s=0x5555563cb238, sense_key=5, asc=33)
     at hw/ide/atapi.c:141
141	{
(gdb) bt
#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

Do you have any idea how to debug this further or does this help to tell 
where is the problem? (I think the question is where does the -5 return 
value come from?)

Regards,
BALATON Zoltan

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

[Mark Cave-Ayland]

On 14/05/14 00:02, BALATON Zoltan wrote:

>> command 0x43 is read the TOC which according to atapi_cmd_table should
>> call cmd_read_toc_pma_atip(). You can see that in your MorphOS case
>> you are getting a line with a "atapi_cmd_error" prefix which indicates
>> that something is calling ide_atapi_cmd_error() to return an error
>> code instead of ide_atapi_cmd_reply() which would output the "reply"
>> prefix as seen in your Darwin case. So you need to step through these
>> functions in QEMU in order to see why your ATAPI command is failing.
>
> I've tried doing this and it seems that the cmd_read_toc_pma_atip
> function returns all right (via the case 0 path) with a 20 byte result
> array and calls ide_atapi_cmd_reply which takes the DMA path as
> s->atapi_dma is set to 1 and the error comes from somewhere during
> trying to DMA the result back to the client. I could not follow it so
> I've only got a backtrace from where ide_atapi_cmd_error is called:

So this basically confirms that the DMA errors out because s->lba == -1 
in the macio callback. FWIW you should probably ensure that 
DEBUG_IDE_ATAPI is enabled when posting logs in future as this helps 
show the interaction between the two systems.

> Do you have any idea how to debug this further or does this help to tell
> where is the problem? (I think the question is where does the -5 return
> value come from?)

Well from this the cause is fairly easy to spot: ide_atapi_cmd_reply() 
sets s->lba == -1 when called from cmd_read_toc_pma_atip(). And since as 
you correctly point out this is a DMA request, it invokes the start_dma 
function in macio's dbdma_ops (ide_dbdma_start), which kicks the DBDMA 
engine into life.

I think the issue here is related to the fact that reading a TOC doesn't 
actually involve reading physical blocks from disk (as the TOC is placed 
directly in the buffer) and so the dma_bdrv_* functions shouldn't 
actually be invoked in the first place. And because of the DBDMA setup, 
ide_atapi_cmd_read_dma_cb() can't be used which is why 
pmac_ide_transfer_cb() needs to do a lot of similar work itself. Maybe 
you can find some clues there as to what the logic should be?


HTH,

Mark.

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 00:02, BALATON Zoltan wrote:
>>> command 0x43 is read the TOC which according to atapi_cmd_table should
>>> call cmd_read_toc_pma_atip(). You can see that in your MorphOS case
>>> you are getting a line with a "atapi_cmd_error" prefix which indicates
>>> that something is calling ide_atapi_cmd_error() to return an error
>>> code instead of ide_atapi_cmd_reply() which would output the "reply"
>>> prefix as seen in your Darwin case. So you need to step through these
>>> functions in QEMU in order to see why your ATAPI command is failing.
>> 
>> I've tried doing this and it seems that the cmd_read_toc_pma_atip
>> function returns all right (via the case 0 path) with a 20 byte result
>> array and calls ide_atapi_cmd_reply which takes the DMA path as
>> s->atapi_dma is set to 1 and the error comes from somewhere during
>> trying to DMA the result back to the client. I could not follow it so
>> I've only got a backtrace from where ide_atapi_cmd_error is called:
>
> So this basically confirms that the DMA errors out because s->lba == -1 in 
> the macio callback. FWIW you should probably ensure that DEBUG_IDE_ATAPI is 
> enabled when posting logs in future as this helps show the interaction 
> between the two systems.

The logs I've posted are with DEBUG_IDE_ATAPI, DEBUG_DBDMA and DEBUG_MACIO 
already enabled...

>> Do you have any idea how to debug this further or does this help to tell
>> where is the problem? (I think the question is where does the -5 return
>> value come from?)
>
> Well from this the cause is fairly easy to spot: ide_atapi_cmd_reply() sets 
> s->lba == -1 when called from cmd_read_toc_pma_atip(). And since as you 
> correctly point out this is a DMA request, it invokes the start_dma function 
> in macio's dbdma_ops (ide_dbdma_start), which kicks the DBDMA engine into 
> life.
>
> I think the issue here is related to the fact that reading a TOC doesn't 
> actually involve reading physical blocks from disk (as the TOC is placed 
> directly in the buffer) and so the dma_bdrv_* functions shouldn't actually be 
> invoked in the first place. And because of the DBDMA setup, 
> ide_atapi_cmd_read_dma_cb() can't be used which is why pmac_ide_transfer_cb() 
> needs to do a lot of similar work itself. Maybe you can find some clues there 
> as to what the logic should be?

I'm afraid I still can't understand it. Is there a way to trace the path 
after DBDMA engine is kicked? Where should I break to get some insight on 
what is happening? (Maybe it's a dbdma bug not a macio one.)

Regards,
BALATON Zoltan

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

[Mark Cave-Ayland]

On 14/05/14 12:10, BALATON Zoltan wrote:

>>> I've tried doing this and it seems that the cmd_read_toc_pma_atip
>>> function returns all right (via the case 0 path) with a 20 byte result
>>> array and calls ide_atapi_cmd_reply which takes the DMA path as
>>> s->atapi_dma is set to 1 and the error comes from somewhere during
>>> trying to DMA the result back to the client. I could not follow it so
>>> I've only got a backtrace from where ide_atapi_cmd_error is called:
>>
>> So this basically confirms that the DMA errors out because s->lba ==
>> -1 in the macio callback. FWIW you should probably ensure that
>> DEBUG_IDE_ATAPI is enabled when posting logs in future as this helps
>> show the interaction between the two systems.
>
> 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.

>>> Do you have any idea how to debug this further or does this help to tell
>>> where is the problem? (I think the question is where does the -5 return
>>> value come from?)
>>
>> Well from this the cause is fairly easy to spot: ide_atapi_cmd_reply()
>> sets s->lba == -1 when called from cmd_read_toc_pma_atip(). And since
>> as you correctly point out this is a DMA request, it invokes the
>> start_dma function in macio's dbdma_ops (ide_dbdma_start), which kicks
>> the DBDMA engine into life.
>>
>> I think the issue here is related to the fact that reading a TOC
>> doesn't actually involve reading physical blocks from disk (as the TOC
>> is placed directly in the buffer) and so the dma_bdrv_* functions
>> shouldn't actually be invoked in the first place. And because of the
>> DBDMA setup, ide_atapi_cmd_read_dma_cb() can't be used which is why
>> pmac_ide_transfer_cb() needs to do a lot of similar work itself. Maybe
>> you can find some clues there as to what the logic should be?
>
> I'm afraid I still can't understand it. Is there a way to trace the path
> after DBDMA engine is kicked? Where should I break to get some insight
> on what is happening? (Maybe it's a dbdma bug not a macio one.)

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.


ATB,

Mark.

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:

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

Regards,
BALATON Zoltan

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

[Mark Cave-Ayland]

On 15/05/14 00:21, BALATON Zoltan wrote:

>> 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.

Have you noticed that the dma_bdrv_*() functions use a function pointer 
to pmac_ide_atapi_transfer_cb() as their callback function? The 
dma_bdrv_*() functions operate in a separate thread and then invoke the 
callback function when finished.

The breakpoint you are hitting above is the invocation of 
pmac_ide_atapi_transfer_cb() as a result of the callback *after* the 
command has already failed, and not the invocation of 
pmac_ide_atapi_transfer_cb() which calls dma_bdrv_*() to setup the 
asynchronous transfer. Hence the DMA has already failed and the -5 value 
is being returned from the IDE code. I can only guess the reason this 
works with Darwin is because it is a non-DMA request.

If you place a breakpoint on pmac_ide_transfer() then its invocation of 
pmac_ide_atapi_transfer_cb() should be the first iteration which sets up 
the DMA request, and the second invocation should be the (failing) 
callback from the dma_bdrv_*() functions. But as I mentioned before, I 
think the problem is that these functions shouldn't be called in the 
first place when requesting a TOC.


HTH,

Mark.

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

[BALATON Zoltan]

On Thu, 15 May 2014, Mark Cave-Ayland wrote:
> On 15/05/14 00:21, BALATON Zoltan wrote:
>>> 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.
>
> Have you noticed that the dma_bdrv_*() functions use a function pointer to 
> pmac_ide_atapi_transfer_cb() as their callback function? The dma_bdrv_*() 
> functions operate in a separate thread and then invoke the callback function 
> when finished.
>
> The breakpoint you are hitting above is the invocation of 
> pmac_ide_atapi_transfer_cb() as a result of the callback *after* the command 
> has already failed, and not the invocation of pmac_ide_atapi_transfer_cb() 
> which calls dma_bdrv_*() to setup the asynchronous transfer. Hence the DMA 
> has already failed and the -5 value is being returned from the IDE code. I 
> can only guess the reason this works with Darwin is because it is a non-DMA 
> request.
>
> If you place a breakpoint on pmac_ide_transfer() then its invocation of 
> pmac_ide_atapi_transfer_cb() should be the first iteration which sets up the 
> DMA request, and the second invocation should be the (failing) callback from 
> the dma_bdrv_*() functions. But as I mentioned before, I think the problem is 
> that these functions shouldn't be called in the first place when requesting a 
> TOC.

OK, I've done that and stopped at the first invocation of 
pmac_ide_atapi_transfer_cb. Here is a backtrace and the contents of some 
data structures:

#0  pmac_ide_atapi_transfer_cb (opaque=0x5555563ccc68, ret=0)
     at hw/ide/macio.c:55
#1  0x00005555556da6d0 in pmac_ide_transfer (io=0x5555563ccc68)
     at hw/ide/macio.c:225
#2  0x00005555556eeee2 in start_input (ch=0x5555563ccc18, key=0, addr=
     14777932, req_count=804, is_last=1) at hw/misc/macio/mac_dbdma.c:334
#3  0x00005555556ef444 in channel_run (ch=0x5555563ccc18)
     at hw/misc/macio/mac_dbdma.c:489
#4  0x00005555556ef599 in DBDMA_run (s=0x5555563cba40)
     at hw/misc/macio/mac_dbdma.c:531
#5  0x00005555556ef5f4 in DBDMA_run_bh (opaque=0x5555563cba40)
     at hw/misc/macio/mac_dbdma.c:542
#6  0x00005555555f8200 in aio_bh_poll (ctx=0x55555637fc00) at async.c:81
#7  0x00005555555f7e59 in aio_poll (ctx=0x55555637fc00, blocking=false)
     at aio-posix.c:188
#8  0x00005555555f8617 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 0x00005555557a0fde in glib_pollfds_poll () at main-loop.c:190
#11 0x00005555557a10de in os_host_main_loop_wait (timeout=15883632)
     at main-loop.c:235
#12 0x00005555557a11b1 in main_loop_wait (nonblocking=0) at main-loop.c:484
#13 0x000055555584422c in main_loop () at vl.c:2075
#14 0x000055555584bcbf in main (argc=32, argv=0x7fffffffdc48, envp=
     0x7fffffffdd50) at vl.c:4556

(gdb) p *io
$5 = {opaque = 0x5555563c8db0, channel = 0x5555563ccc18, addr = 14777932,
   len = 804, is_last = 1, is_dma_out = 0, dma_end =
     0x5555556eebf7 <dbdma_end>, processing = true}

(gdb) p *m
$4 = {parent_obj = {parent_obj = {parent_obj = {class = 0x555556357c20, free =
     0x0, properties = {tqh_first = 0x5555563924c0, tqh_last = 0x5555563cd1d0},
         ref = 6, parent = 0x5555563c3290}, id = 0x0, realized = true, opts =
     0x0, hotplugged = 0, parent_bus = 0x555556384d30, num_gpio_out = 0,
       gpio_out = 0x0, num_gpio_in = 0, gpio_in = 0x0, child_bus = {lh_first =
     0x5555563cb1b0}, num_child_bus = 1, instance_id_alias = -1,
       alias_required_for_version = 0}, num_irq = 2, irqs = {
     0x0 <repeats 512 times>}, irqp = {0x5555563cb0d8, 0x5555563cb0e0,
     0x0 <repeats 510 times>}, num_mmio = 1, mmio = {{addr =
     18446744073709551615, memory = 0x5555563cb0e8}, {addr = 0, memory =
     0x0} <repeats 31 times>}, num_pio = 0, pio = {0 <repeats 32 times>}},
   irq = 0x5555563a2eb0, dma_irq = 0x5555563a2da8, mem = {ops =
     0x555555dc6480 <pmac_ide_ops>, iommu_ops = 0x0, opaque = 0x5555563c8db0,
     owner = 0x5555563c8db0, parent = 0x5555563c3a28, size = {lo = 4096, hi =
     0}, addr = 135168, destructor =
     0x5555558ce04e <memory_region_destructor_none>, ram_addr =
     18446744073709551615, subpage = false, terminates = true, romd_mode =
     true, ram = false, readonly = false, enabled = true, rom_device = false,
     warning_printed = false, flush_coalesced_mmio = false, alias = 0x0,
     alias_offset = 0, priority = 0, may_overlap = false, subregions = {
       tqh_first = 0x0, tqh_last = 0x5555563cb160}, subregions_link = {
       tqe_next = 0x5555563c8468, tqe_prev = 0x5555563c5ea0}, coalesced = {
       tqh_first = 0x0, tqh_last = 0x5555563cb180}, name =
     0x5555563cd180 "pmac-ide", dirty_log_mask = 0 '\000', ioeventfd_nb = 0,
     ioeventfds = 0x0, iommu_notify = {notifiers = {lh_first = 0x0}}}, bus = {
     qbus = {obj = {class = 0x555556368cd0, free = 0x0, properties = {
           tqh_first = 0x555556392760, tqh_last = 0x555556392930}, ref = 2,
         parent = 0x5555563c8db0}, parent = 0x5555563c8db0, name =
     0x5555563cd140 "ide.1", allow_hotplug = 0, hotplug_handler = 0x0,
       max_index = 1, realized = true, children = {tqh_first = 0x555556392890,
         tqh_last = 0x5555563928a0}, sibling = {le_next = 0x0, le_prev =
     0x5555563c8e28}}, master = 0x5555563d6980, slave = 0x0, ifs = {{bus =
     0x5555563cb1b0, unit = 0 '\000', drive_kind = IDE_CD, cylinders = 0,
         heads = 0, sectors = 0, chs_trans = 0, nb_sectors = 451360,
         mult_sectors = 16, identify_set = 1, identify_data =
     "\300\205", '\000' <repeats 18 times>, "MQ0000 3", ' ' <repeats 12 
times>, "\003\000\000\002\004\000.2.005  EQUMD DVR-MO", ' ' <repeats 28 
times>, "\000\000\001\000\000\003\000\000\000\000\000\000\a", '\000' 
<repeats 17 times>, 
"\a\000\a\000\003\000\264\000\264\000,\001\264\000\000\000\000\000\036\000\036", 
'\000' <repeats 15 times>, "\036", '\000' <repeats 15 times>, "?\001", 
'\000' <repeats 333 times>, drive_serial = 3, drive_serial_str =
     "QM00003", '\000' <repeats 13 times>, drive_model_str =
     "QEMU DVD-ROM", '\000' <repeats 28 times>, wwn = 0, feature = 1 '\001',
         error = 0 '\000', nsector = 1, sector = 0 '\000', lcyl = 0 '\000',
         hcyl = 128 '\200', hob_feature = 0 '\000', hob_nsector = 3 '\003',
         hob_sector = 0 '\000', hob_lcyl = 34 '"', hob_hcyl = 0 '\000',
         select = 160 '\240', status = 88 'X', lba48 = 0 '\000', bs =
     0x555556393c40, version = "2.0.50\000\000", events = {eject_request =
     false, new_media = false}, sense_key = 5 '\005', asc = 36 '$', tray_open =
     false, tray_locked = false, cdrom_changed = 0 '\000',
         packet_transfer_size = 20, elementary_transfer_size = 0,
         io_buffer_index = 0, lba = -1, cd_sector_size = 2048, atapi_dma = 1,
         acct = {bytes = 804, start_time_ns = 26904886035916, type =
     BDRV_ACCT_READ}, pio_aiocb = 0x0, iov = {iov_base = 0x0, iov_len = 0},
         qiov = {iov = 0x0, niov = 0, nalloc = 0, size = 0}, io_buffer_offset =
     0, io_buffer_size = 0, sg = {sg = 0x0, nsg = 0, nalloc = 0, size = 0,
           dev = 0x0, as = 0x0}, req_nb_sectors = 0, end_transfer_func =
     0x5555556d0ee3 <ide_atapi_cmd>, data_ptr = 0x7ffff7e4e80c "", data_end =
     0x7ffff7e4e80c "", io_buffer = 0x7ffff7e4e800 "", io_buffer_total_len =
     131076, cur_io_buffer_offset = 0, cur_io_buffer_len = 0,
         end_transfer_fn_idx = 0 '\000', sector_write_timer = 0x5555563b5fa0,
         irq_count = 0, ext_error = 0 '\000', mdata_size = 0, mdata_storage =
     0x0, media_changed = 0, dma_cmd = IDE_DMA_READ, smart_enabled = 1 '\001',
         smart_autosave = 1 '\001', smart_errors = 0, smart_selftest_count =
     0 '\000', smart_selftest_data = 0x5555563b8000 "", ncq_queues = 0}, {bus =
     0x5555563cb1b0, unit = 1 '\001', drive_kind = IDE_HD, cylinders = 0,
         heads = 0, sectors = 0, chs_trans = 0, nb_sectors = 0, mult_sectors =
     16, identify_set = 0, identify_data = '\000' <repeats 511 times>,
         drive_serial = 4, drive_serial_str = '\000' <repeats 20 times>,
         drive_model_str = '\000' <repeats 40 times>, wwn = 0, feature =
     1 '\001', error = 1 '\001', nsector = 0, sector = 0 '\000', lcyl =
     0 '\000', hcyl = 128 '\200', hob_feature = 0 '\000', hob_nsector =
     0 '\000', hob_sector = 0 '\000', hob_lcyl = 0 '\000', hob_hcyl =
     128 '\200', select = 176 '\260', status = 80 'P', lba48 = 0 '\000', bs =
     0x0, version = "\000\000\000\000\000\000\000\000", events = {
           eject_request = false, new_media = false}, sense_key = 0 '\000',
         asc = 0 '\000', tray_open = false, tray_locked = false,
         cdrom_changed = 0 '\000', packet_transfer_size = 0,
         elementary_transfer_size = 0, io_buffer_index = 0, lba = 0,
         cd_sector_size = 0, atapi_dma = 0, acct = {bytes = 0, start_time_ns =
     0, type = BDRV_ACCT_READ}, pio_aiocb = 0x0, iov = {iov_base = 0x0,
           iov_len = 0}, qiov = {iov = 0x0, niov = 0, nalloc = 0, size = 0},
         io_buffer_offset = 0, io_buffer_size = 0, sg = {sg = 0x0, nsg = 0,
           nalloc = 0, size = 0, dev = 0x0, as = 0x0}, req_nb_sectors = 0,
         end_transfer_func = 0x5555556d7f17 <ide_dummy_transfer_stop>,
         data_ptr = 0x7ffff7e2d800 "\377\377\377\377", data_end =
     0x7ffff7e2d800 "\377\377\377\377", io_buffer =
     0x7ffff7e2d800 "\377\377\377\377", io_buffer_total_len = 131076,
         cur_io_buffer_offset = 0, cur_io_buffer_len = 0, end_transfer_fn_idx =
     0 '\000', sector_write_timer = 0x5555563d6c50, irq_count = 0, ext_error =
     0 '\000', mdata_size = 0, mdata_storage = 0x0, media_changed = 0,
         dma_cmd = IDE_DMA_READ, smart_enabled = 0 '\000', smart_autosave =
     0 '\000', smart_errors = 0, smart_selftest_count = 0 '\000',
         smart_selftest_data = 0x5555563d7000 "", ncq_queues = 0}}, bus_id = 0,
     max_units = 2, dma = 0x5555563cb9e8, unit = 0 '\000', cmd = 8 '\b', irq =
     0x5555563a2eb0, error_status = 0}, aiocb = 0x0, dma = {ops =
     0x555555dc6560 <dbdma_ops>, iov = {iov_base = 0x0, iov_len = 0}, qiov = {
       iov = 0x0, niov = 0, nalloc = 0, size = 0}, aiocb = 0x0}, dbdma =
     0x5555563cba40, dma_active = true}

(gdb) p *s
$6 = {bus = 0x5555563cb1b0, unit = 0 '\000', drive_kind = IDE_CD, cylinders =
     0, heads = 0, sectors = 0, chs_trans = 0, nb_sectors = 451360,
   mult_sectors = 16, identify_set = 1, identify_data =
     "\300\205", '\000' <repeats 18 times>, "MQ0000 3", ' ' <repeats 12 
times>, "\003\000\000\002\004\000.2.005  EQUMD DVR-MO", ' ' <repeats 28 
times>, "\000\000\001\000\000\003\000\000\000\000\000\000\a", '\000' 
<repeats 17 times>, 
"\a\000\a\000\003\000\264\000\264\000,\001\264\000\000\000\000\000\036\000\036", 
'\000' <repeats 15 times>, "\036", '\000' <repeats 15 times>, "?\001", 
'\000' <repeats 333 times>, drive_serial = 3, drive_serial_str =
     "QM00003", '\000' <repeats 13 times>, drive_model_str =
     "QEMU DVD-ROM", '\000' <repeats 28 times>, wwn = 0, feature = 1 '\001',
   error = 0 '\000', nsector = 1, sector = 0 '\000', lcyl = 0 '\000', hcyl =
     128 '\200', hob_feature = 0 '\000', hob_nsector = 3 '\003', hob_sector =
     0 '\000', hob_lcyl = 34 '"', hob_hcyl = 0 '\000', select = 160 '\240',
   status = 88 'X', lba48 = 0 '\000', bs = 0x555556393c40, version =
     "2.0.50\000\000", events = {eject_request = false, new_media = false},
   sense_key = 5 '\005', asc = 36 '$', tray_open = false, tray_locked = false,
   cdrom_changed = 0 '\000', packet_transfer_size = 20,
   elementary_transfer_size = 0, io_buffer_index = 0, lba = -1,
   cd_sector_size = 2048, atapi_dma = 1, acct = {bytes = 804, start_time_ns =
     26904886035916, type = BDRV_ACCT_READ}, pio_aiocb = 0x0, iov = {iov_base =
     0x0, iov_len = 0}, qiov = {iov = 0x0, niov = 0, nalloc = 0, size = 0},
   io_buffer_offset = 0, io_buffer_size = 0, sg = {sg = 0x0, nsg = 0, nalloc =
     0, size = 0, dev = 0x0, as = 0x0}, req_nb_sectors = 0, end_transfer_func =
     0x5555556d0ee3 <ide_atapi_cmd>, data_ptr = 0x7ffff7e4e80c "", data_end =
     0x7ffff7e4e80c "", io_buffer = 0x7ffff7e4e800 "", io_buffer_total_len =
     131076, cur_io_buffer_offset = 0, cur_io_buffer_len = 0,
   end_transfer_fn_idx = 0 '\000', sector_write_timer = 0x5555563b5fa0,
   irq_count = 0, ext_error = 0 '\000', mdata_size = 0, mdata_storage = 0x0,
   media_changed = 0, dma_cmd = IDE_DMA_READ, smart_enabled = 1 '\001',
   smart_autosave = 1 '\001', smart_errors = 0, smart_selftest_count =
     0 '\000', smart_selftest_data = 0x5555563b8000 "", ncq_queues = 0}

My testing was done with commit 80fc95d8bdaf3392106b131a97ca701fd374489a 
already reverted as that was established before that it is not needed any 
more which simplifies pmac_ide_atapi_transfer_cb() quite a bit but I still 
can't understand the flow of this function and don't see where should I 
add a condition to handle this lba=-1 case that happens with READ_TOC 
using DMA. The reason I don't understand it is that the different fields 
(sizes and indexes) in these structures that are used in this callback 
don't make sense to me and I don't know how to use 
cpu_physical_memory_write() to copy data from the ide buffer to the guest 
memory as was suggested by Mark. Now that the problem is fairly well 
understood, wouldn't it be easier to one of you who understands what's 
happening to create a patch, instead of trying to explain all this to me?

This part was last touched by Alexander Graf so I assume he knows how it 
works and it would not be too hard for him to fix it. I'm happy to help 
testing and providing more debugging info as needed but I'm not sure I 
want to detangle it and figure out the whole block layer and DBDMA without 
any documentation to be able to fix it myself. Would it be possible to 
find some time for it in the foreseeable future? (That might still be 
sooner than me wrapping my head around it.)

Regards,
BALATON Zoltan

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

[Mark Cave-Ayland]

[-- Attachment #1: Type: text/plain, Size: 4891 bytes --]

On 15/05/14 18:28, BALATON Zoltan wrote:

>> If you place a breakpoint on pmac_ide_transfer() then its invocation
>> of pmac_ide_atapi_transfer_cb() should be the first iteration which
>> sets up the DMA request, and the second invocation should be the
>> (failing) callback from the dma_bdrv_*() functions. But as I mentioned
>> before, I think the problem is that these functions shouldn't be
>> called in the first place when requesting a TOC.
>
> OK, I've done that and stopped at the first invocation of
> pmac_ide_atapi_transfer_cb. Here is a backtrace and the contents of some
> data structures:
>
> #0  pmac_ide_atapi_transfer_cb (opaque=0x5555563ccc68, ret=0)
>      at hw/ide/macio.c:55
> #1  0x00005555556da6d0 in pmac_ide_transfer (io=0x5555563ccc68)
>      at hw/ide/macio.c:225
> #2  0x00005555556eeee2 in start_input (ch=0x5555563ccc18, key=0, addr=
>      14777932, req_count=804, is_last=1) at hw/misc/macio/mac_dbdma.c:334
> #3  0x00005555556ef444 in channel_run (ch=0x5555563ccc18)
>      at hw/misc/macio/mac_dbdma.c:489
> #4  0x00005555556ef599 in DBDMA_run (s=0x5555563cba40)
>      at hw/misc/macio/mac_dbdma.c:531
> #5  0x00005555556ef5f4 in DBDMA_run_bh (opaque=0x5555563cba40)
>      at hw/misc/macio/mac_dbdma.c:542
> #6  0x00005555555f8200 in aio_bh_poll (ctx=0x55555637fc00) at async.c:81
> #7  0x00005555555f7e59 in aio_poll (ctx=0x55555637fc00, blocking=false)
>      at aio-posix.c:188
> #8  0x00005555555f8617 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 0x00005555557a0fde in glib_pollfds_poll () at main-loop.c:190
> #11 0x00005555557a10de in os_host_main_loop_wait (timeout=15883632)
>      at main-loop.c:235
> #12 0x00005555557a11b1 in main_loop_wait (nonblocking=0) at main-loop.c:484
> #13 0x000055555584422c in main_loop () at vl.c:2075
> #14 0x000055555584bcbf in main (argc=32, argv=0x7fffffffdc48, envp=
>      0x7fffffffdd50) at vl.c:4556

(lots cut)

So that looks like the correct request based upon it's size so what 
happened when you stepped into pmac_ide_atapi_transfer_cb()...?

> My testing was done with commit 80fc95d8bdaf3392106b131a97ca701fd374489a
> already reverted as that was established before that it is not needed
> any more which simplifies pmac_ide_atapi_transfer_cb() quite a bit

Sadly I've now found that this isn't the case (email to the qemu-devel 
list to follow, but I've run out of time today) :(

> but I
> still can't understand the flow of this function and don't see where
> should I add a condition to handle this lba=-1 case that happens with
> READ_TOC using DMA. The reason I don't understand it is that the
> different fields (sizes and indexes) in these structures that are used
> in this callback don't make sense to me and I don't know how to use
> cpu_physical_memory_write() to copy data from the ide buffer to the
> guest memory as was suggested by Mark. Now that the problem is fairly
> well understood, wouldn't it be easier to one of you who understands
> what's happening to create a patch, instead of trying to explain all
> this to me?

Well my understanding is that it's impossible to boot a MorphOS image 
directly and requires all sorts of tricks with debuggers etc. Unless you 
can provide a "run this and it breaks" test case, then the time barrier 
for trying to fix bugs like this is exceptionally high.

You mention that you don't understand the fields and sizes, so explain 
which ones you don't understand and ask. Search around for guides to how 
ATAPI/IDE works, and compare with gdb output to find the correlation 
with the IDEState variables. Have you tried looking at the header file 
for cpu_physical_memory_write()? Even to someone who had never seen this 
function before Alex's patches, it seems fairly obvious how the API 
should work.

I'm afraid that there really is no alternative to spending the time 
getting stuck into the code, experimenting, adding printf()'s in 
exciting places, and then asking specific questions to the mailing list.

> This part was last touched by Alexander Graf so I assume he knows how it
> works and it would not be too hard for him to fix it. I'm happy to help
> testing and providing more debugging info as needed but I'm not sure I
> want to detangle it and figure out the whole block layer and DBDMA
> without any documentation to be able to fix it myself. Would it be
> possible to find some time for it in the foreseeable future? (That might
> still be sooner than me wrapping my head around it.)

Please see above. FWIW based upon the your gdb output I've put together 
the following patch which compiles, but that's all I can vouch for it. 
Further testing and debugging will have to be done by you, although I 
will try and respond to specific questions where possible.


ATB,

Mark.


[-- Attachment #2: qemu-macio-atapi.patch --]
[-- Type: text/x-diff, Size: 716 bytes --]

diff --git a/hw/ide/macio.c b/hw/ide/macio.c
index da94580..96c2556 100644
--- a/hw/ide/macio.c
+++ b/hw/ide/macio.c
@@ -111,6 +111,14 @@ static void pmac_ide_atapi_transfer_cb(void *opaque, int ret)
         return;
     }
 
+    if (s->packet_transfer_size && s->lba == -1) {
+        MACIO_DPRINTF("non-IO ATAPI DMA transfer size: %d\n", io->len);
+        /* Copy ATAPI buffer directly to RAM and finish */
+        cpu_physical_memory_write(io->addr, s->io_buffer, io->len);
+        s->packet_transfer_size -= io->len;
+        MACIO_DPRINTF("end of non-IO ATAPI DMA transfer\n");    
+    }
+    
     if (!s->packet_transfer_size) {
         MACIO_DPRINTF("end of transfer\n");
         ide_atapi_cmd_ok(s);

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

[BALATON Zoltan]

On Thu, 15 May 2014, Mark Cave-Ayland wrote:
> On 15/05/14 18:28, BALATON Zoltan wrote:
>> #0  pmac_ide_atapi_transfer_cb (opaque=0x5555563ccc68, ret=0)
>>      at hw/ide/macio.c:55
>> #1  0x00005555556da6d0 in pmac_ide_transfer (io=0x5555563ccc68)
>>      at hw/ide/macio.c:225
>> #2  0x00005555556eeee2 in start_input (ch=0x5555563ccc18, key=0, addr=
>>      14777932, req_count=804, is_last=1) at hw/misc/macio/mac_dbdma.c:334
>> #3  0x00005555556ef444 in channel_run (ch=0x5555563ccc18)
>>      at hw/misc/macio/mac_dbdma.c:489
>> #4  0x00005555556ef599 in DBDMA_run (s=0x5555563cba40)
>>      at hw/misc/macio/mac_dbdma.c:531
>> #5  0x00005555556ef5f4 in DBDMA_run_bh (opaque=0x5555563cba40)
>>      at hw/misc/macio/mac_dbdma.c:542
>> #6  0x00005555555f8200 in aio_bh_poll (ctx=0x55555637fc00) at async.c:81
>> #7  0x00005555555f7e59 in aio_poll (ctx=0x55555637fc00, blocking=false)
>>      at aio-posix.c:188
>> #8  0x00005555555f8617 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 0x00005555557a0fde in glib_pollfds_poll () at main-loop.c:190
>> #11 0x00005555557a10de in os_host_main_loop_wait (timeout=15883632)
>>      at main-loop.c:235
>> #12 0x00005555557a11b1 in main_loop_wait (nonblocking=0) at main-loop.c:484
>> #13 0x000055555584422c in main_loop () at vl.c:2075
>> #14 0x000055555584bcbf in main (argc=32, argv=0x7fffffffdc48, envp=
>>      0x7fffffffdd50) at vl.c:4556
>
> (lots cut)
>
> So that looks like the correct request based upon it's size so what happened 
> when you stepped into pmac_ide_atapi_transfer_cb()...?

Did not follow it to the end because we know it would fail and the sense 
value returned seems to be just a remnant of previous failures as can be 
seen from the structures I've printed.

>> My testing was done with commit 80fc95d8bdaf3392106b131a97ca701fd374489a
>> already reverted as that was established before that it is not needed
>> any more which simplifies pmac_ide_atapi_transfer_cb() quite a bit
>
> Sadly I've now found that this isn't the case (email to the qemu-devel list 
> to follow, but I've run out of time today) :(

OK, I'm back to the HEAD version and testing with that with your patch 
applied.

> Well my understanding is that it's impossible to boot a MorphOS image 
> directly and requires all sorts of tricks with debuggers etc. Unless you can 
> provide a "run this and it breaks" test case, then the time barrier for 
> trying to fix bugs like this is exceptionally high.

Unfortunately it is not straightforward to test with MorphOS but I think 
it could be reproduced with other OS-es if they can be made to do a read 
TOC with DMA. I can try to find a way to reproduce it with Linux but 
hopefully we can get to the end of it now. (I think we are close.)

> You mention that you don't understand the fields and sizes, so explain which 
> ones you don't understand and ask. Search around for guides to how ATAPI/IDE

The ones used in pmac_ide_atapi_transfer_cb(). It's not clear to me where 
is the source buffer where is the destination and what is the correct 
lenght to use. Your patch helps but it's not correct yet. See below.

> Please see above. FWIW based upon the your gdb output I've put together the 
> following patch which compiles, but that's all I can vouch for it. Further 
> testing and debugging will have to be done by you, although I will try and 
> respond to specific questions where possible.

Thanks a lot. I've tested your patch and it comes closer but not quite 
there yet. Running it in a debugger I've seen this:

Breakpoint 1, pmac_ide_transfer (io=0x5555563d1068) at hw/ide/macio.c:340
340	{
(gdb) n
341	    MACIOIDEState *m = io->opaque;
342	    IDEState *s = idebus_active_if(&m->bus);
344	    MACIO_DPRINTF("pmac_ide_transfer%s lba=%x, buffer_index=%x, len=%x\n",
pmac_ide_transfer(ATAPI) lba=ffffffff, buffer_index=0, len=324
348	    s->io_buffer_size = 0;
349	    if (s->drive_kind == IDE_CD) {
350	        bdrv_acct_start(s->bs, &s->acct, io->len, BDRV_ACCT_READ);
351	        pmac_ide_atapi_transfer_cb(io, 0);
(gdb) s
pmac_ide_atapi_transfer_cb (opaque=0x5555563d1068, ret=0) at hw/ide/macio.c:55
55	{
56	    DBDMA_io *io = opaque;
57	    MACIOIDEState *m = io->opaque;
58	    IDEState *s = idebus_active_if(&m->bus);
61	    if (ret < 0) {
69	    if (!m->dma_active) {
77	    MACIO_DPRINTF("io_buffer_size = %#x\n", s->io_buffer_size);
io_buffer_size = 0
79	    if (s->io_buffer_size > 0) {
90	    s->io_buffer_size = MIN(io->len, s->packet_transfer_size);
92	    MACIO_DPRINTF("remainder: %d io->len: %d size: %d\n", io->remainder_len,
remainder: 0 io->len: 804 size: 20
94	    if (io->remainder_len && io->len) {
114	    if (s->packet_transfer_size && s->lba == -1) {
115	        MACIO_DPRINTF("non-IO ATAPI DMA transfer size: %d\n", io->len);
non-IO ATAPI DMA transfer size: 804
117	        cpu_physical_memory_write(io->addr, s->io_buffer, io->len);
(gdb) x/40x s->io_buffer
0x7ffff7e4e800:	0x01011200	0x00011400	0x00000000	0x00aa1600
0x7ffff7e4e810:	0xc8b80100	0x00000000	0x00000000	0x00000000
0x7ffff7e4e820:	0x2e300000	0x20202020	0x02000003	0x322e0004
0x7ffff7e4e830:	0x3530302e	0x51452020	0x20444d55	0x2d525644
0x7ffff7e4e840:	0x20204f4d	0x20202020	0x20202020	0x20202020
0x7ffff7e4e850:	0x20202020	0x20202020	0x20202020	0x00002020
0x7ffff7e4e860:	0x03000001	0x00000000	0x00070000	0x00000000
0x7ffff7e4e870:	0x00000000	0x00000000	0x00000000	0x00070007
0x7ffff7e4e880:	0x00b40003	0x012c00b4	0x000000b4	0x001e0000
0x7ffff7e4e890:	0x0000001e	0x00000000	0x00000000	0x00000000
(gdb) n
118	        s->packet_transfer_size -= io->len;
(gdb) p s->packet_transfer_size
$2 = 20
(gdb) n
119	        MACIO_DPRINTF("end of non-IO ATAPI DMA transfer\n");
end of non-IO ATAPI DMA transfer
122	    if (!s->packet_transfer_size) {
(gdb) p s->io_buffer_size
$3 = 20
(gdb) l
117	        cpu_physical_memory_write(io->addr, s->io_buffer, io->len);
118	        s->packet_transfer_size -= io->len;
119	        MACIO_DPRINTF("end of non-IO ATAPI DMA transfer\n");
120	    }
121
122	    if (!s->packet_transfer_size) {
123	        MACIO_DPRINTF("end of transfer\n");
124	        ide_atapi_cmd_ok(s);
125	        m->dma_active = false;
126	    }
127
128	    if (io->len == 0) {
129	        MACIO_DPRINTF("end of DMA\n");
130	        goto done;
131	    }
132
133	    /* launch next transfer */
134
135	    /* handle unaligned accesses first, get them over with and only do the
136	       remaining bulk transfer using our async DMA helpers */
(gdb) c
Continuing.
precopying unaligned 292 bytes to 0xe4f064
io->len = 0x200
set remainder to: -804
sector_num=-4 size=-784, cmd_cmd=0
atapi_cmd_error: sense=0x5 asc=0x21
done DMA
DBDMA: dbdma_end
DBDMA: conditional_wait
DBDMA: dbdma_cmdptr_save 0x00e51bb0
DBDMA: xfer_status 0x00008400 res_count 0x0000
DBDMA: conditional_interrupt
DBDMA: conditional_branch
DBDMA: dbdma_cmdptr_load 0x00e51bc0
DBDMA: channel_run
dbdma_cmd 0x5555563d12b0
     req_count 0x0000
     command 0x7000
     phy_addr 0x00000000
     cmd_dep 0x00000000
     res_count 0x0000
     xfer_status 0x0000
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

So it still fails but maybe only because the wrong size is used (io->len). 
(That's what I meant when I said these values are not clear to me and very 
confusing.) Do you think that replacing io->len in your patch with 
s->io_buffer_size would be the correct thing to do?

Regards,
BALATON Zoltan

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

[BALATON Zoltan]

On Thu, 15 May 2014, BALATON Zoltan wrote:
> confusing.) Do you think that replacing io->len in your patch with 
> s->io_buffer_size would be the correct thing to do?

Probably that's not enough. I've tried it and then it gets to here:

end of non-IO ATAPI DMA transfer
122	    if (!s->packet_transfer_size) {
(gdb) p s->packet_transfer_size
$1 = 0
(gdb) n
123	        MACIO_DPRINTF("end of transfer\n");
end of transfer
124	        ide_atapi_cmd_ok(s);
125	        m->dma_active = false;
128	    if (io->len == 0) {
(gdb) p io->len
$2 = 804
(gdb) l
123	        MACIO_DPRINTF("end of transfer\n");
124	        ide_atapi_cmd_ok(s);
125	        m->dma_active = false;
126	    }
127
128	    if (io->len == 0) {
129	        MACIO_DPRINTF("end of DMA\n");
130	        goto done;
131	    }
132
133	    /* launch next transfer */
134
135	    /* handle unaligned accesses first, get them over with and only do the
136	       remaining bulk transfer using our async DMA helpers */
137	    unaligned = io->len & 0x1ff;
138	    if (unaligned) {
139	        int sector_num = (s->lba << 2) + (s->io_buffer_index >> 9);
140	        int nsector = io->len >> 9;
141
142	        MACIO_DPRINTF("precopying unaligned %d bytes to %#" HWADDR_PRIx "\n",
(gdb) c
Continuing.
precopying unaligned 292 bytes to 0xe4f50c
io->len = 0x200
set remainder to: -20
sector_num=-4 size=0, cmd_cmd=0
atapi_cmd_error: sense=0x5 asc=0x21
done DMA
DBDMA: dbdma_end

Regards,
BALATON Zoltan

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

[BALATON Zoltan]

On Thu, 15 May 2014, BALATON Zoltan wrote:
> On Thu, 15 May 2014, BALATON Zoltan wrote:
>> confusing.) Do you think that replacing io->len in your patch with 
>> s->io_buffer_size would be the correct thing to do?
>
> Probably that's not enough. I've tried it and then it gets to here:

I should've also included these lines too to make it more clear what did I 
change:

114	    if (s->packet_transfer_size && s->lba == -1) {
115	        MACIO_DPRINTF("non-IO ATAPI DMA transfer size: %d\n", io->len);
non-IO ATAPI DMA transfer size: 804
117	        cpu_physical_memory_write(io->addr, s->io_buffer, s->io_buffer_size);
118	        s->packet_transfer_size -= s->io_buffer_size;
119	        MACIO_DPRINTF("end of non-IO ATAPI DMA transfer\n");

> end of non-IO ATAPI DMA transfer
> 122	    if (!s->packet_transfer_size) {
> (gdb) p s->packet_transfer_size
> $1 = 0
> (gdb) n
> 123	        MACIO_DPRINTF("end of transfer\n");
> end of transfer
> 124	        ide_atapi_cmd_ok(s);
> 125	        m->dma_active = false;
> 128	    if (io->len == 0) {
> (gdb) p io->len
> $2 = 804
> (gdb) l
> 123	        MACIO_DPRINTF("end of transfer\n");
> 124	        ide_atapi_cmd_ok(s);
> 125	        m->dma_active = false;
> 126	    }
> 127
> 128	    if (io->len == 0) {
> 129	        MACIO_DPRINTF("end of DMA\n");
> 130	        goto done;
> 131	    }
> 132
> 133	    /* launch next transfer */
> 134
> 135	    /* handle unaligned accesses first, get them over with and only 
> do the
> 136	       remaining bulk transfer using our async DMA helpers */
> 137	    unaligned = io->len & 0x1ff;
> 138	    if (unaligned) {
> 139	        int sector_num = (s->lba << 2) + (s->io_buffer_index >> 9);
> 140	        int nsector = io->len >> 9;
> 141
> 142	        MACIO_DPRINTF("precopying unaligned %d bytes to %#" 
> HWADDR_PRIx "\n",
> (gdb) c
> Continuing.
> precopying unaligned 292 bytes to 0xe4f50c
> io->len = 0x200
> set remainder to: -20
> sector_num=-4 size=0, cmd_cmd=0
> atapi_cmd_error: sense=0x5 asc=0x21
> done DMA
> DBDMA: dbdma_end
>
> Regards,
> BALATON Zoltan
>

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

[Mark Cave-Ayland]

[-- Attachment #1: Type: text/plain, Size: 1283 bytes --]

On 15/05/14 21:28, BALATON Zoltan wrote:

> On Thu, 15 May 2014, BALATON Zoltan wrote:
>> On Thu, 15 May 2014, BALATON Zoltan wrote:
>>> confusing.) Do you think that replacing io->len in your patch with
>>> s->io_buffer_size would be the correct thing to do?

That looks reasonable, as the MIN() will help prevent excessive memory 
clobber.

>> Probably that's not enough. I've tried it and then it gets to here:
>
> I should've also included these lines too to make it more clear what did
> I change:

Yes, this is definitely helpful. It appears that cmd_read_toc_pma_atip() 
returns 0x20 bytes of data (can you confirm this?), while the DMA engine 
is configured to transfer 0x324 bytes of data - perhaps this is the 
maximum possible size of a TOC?. So the existing code determines there 
are still 0x324 - 0x20 = 0x304 bytes remaining for the DMA request and 
falls into the unaligned code which is definitely not what we want.

Perhaps we need to assume for a non-IO DMA request that the result will 
only be a single ATAPI reply packet? Attached is another version of the 
patch for you to experiment with which makes your s->io_buffer_size 
change but also moves the logic into pmac_ide_transfer() so that we 
don't inadvertently drop into the unaligned code.


ATB,

Mark.


[-- Attachment #2: qemu-macio-atapi-v2.patch --]
[-- Type: text/x-diff, Size: 1115 bytes --]

diff --git a/hw/ide/macio.c b/hw/ide/macio.c
index da94580..0f68124 100644
--- a/hw/ide/macio.c
+++ b/hw/ide/macio.c
@@ -337,6 +337,24 @@ static void pmac_ide_transfer(DBDMA_io *io)
 
     s->io_buffer_size = 0;
     if (s->drive_kind == IDE_CD) {
+        
+        /* Handle non-IO DMA ATAPI transfers */
+        if (s->lba == -1) {
+            s->io_buffer_size = MIN(io->len, s->packet_transfer_size);
+            bdrv_acct_start(s->bs, &s->acct, s->io_buffer_size, BDRV_ACCT_READ);
+            MACIO_DPRINTF("non-IO ATAPI DMA transfer size: %d\n", s->io_buffer_size);
+
+            /* Copy ATAPI buffer directly to RAM and finish */
+            cpu_physical_memory_write(io->addr, s->io_buffer, s->io_buffer_size);
+            ide_atapi_cmd_ok(s);
+            m->dma_active = false;
+            
+            MACIO_DPRINTF("end of non-IO ATAPI DMA transfer\n");
+            bdrv_acct_done(s->bs, &s->acct);
+            io->dma_end(io);
+            return;
+        }
+
         bdrv_acct_start(s->bs, &s->acct, io->len, BDRV_ACCT_READ);
         pmac_ide_atapi_transfer_cb(io, 0);
         return;

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

[BALATON Zoltan]

On Fri, 16 May 2014, Mark Cave-Ayland wrote:
> Perhaps we need to assume for a non-IO DMA request that the result will only 
> be a single ATAPI reply packet? Attached is another version of the patch for 
> you to experiment with which makes your s->io_buffer_size change but also 
> moves the logic into pmac_ide_transfer() so that we don't inadvertently drop 
> into the unaligned code.

This seems to have worked and now it mounts its boot cd and seems to boot 
afterwards. At least it generated a lot of logs that I'm currently looking 
at which end with an error about failing to open the display so it looks 
good so far. (I'm sure there are more problems ahead but hopefully I can 
now look at the display problem which is the next big thing.)

Thank you very much for helping with this. You have saved me a lot of time 
by providing this patch so I did not have to dig up all the pieces that 
are scattered in the qemu sources that are involved in this DMA transfer. 
Understanding it conceptually is one thing but finding all the details in 
the several files involved to get the details is more difficult.

Regards,
BALATON Zoltan