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
