On Mon, Feb 07, 2022 at 03:21:58PM +0100, Takashi Iwai wrote: > > In the last functions a circular buffer is used to write commands. The > > problem is that "bus->corb.buf[wp]" and "bus->rirb.res[addr]" are nowhere > > close to the IOMMU-reported address of the offending memory access. It's > > likely that I've missed other communication channels. But is it possible > > that IOMMU-reported address and buffers addresses are of different kinds > > (physical/virtual) or different regions mapped to the same physical pages? > Hm, I'm not sure, either. But let's try to avoid some possible > confusion at first, e.g. a patch like below. No changes with the patch applied. Also, I added logs for dma_type used: snd_hdac_bus_alloc_stream_pages: dma_type = 2 snd_hdac_bus_alloc_stream_pages: dma_type = 2 snd_hdac_bus_alloc_stream_pages: dma_type = 2 Which matches SNDRV_DMA_TYPE_DEV, so the same behavior is expected. I've noticed that the IO_PAGE_FAULT regularly comes shortly after the write position overflows and restarts from 0, while after the driver binding the wp starts from 1 and not 0. Correlation does not mean causation, through. A similar overflow happens during the initial kernel bootup with no error messages. An another way of looking on it -- the fault comes on wp=0x1, which corresponds to the first re-used address in the buffer. bus->corb.buf[wp] = cpu_to_le32(val) // = 0x14ba000, wp=0xfe, &buf[wp]=000000005b92167d snd_hdac_bus_get_response: reading result from 0000000096c36d67 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x14b8000, wp=0xff, &buf[wp]=00000000a91a3679 snd_hdac_bus_get_response: reading result from 0000000096c36d67 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x2ba000, wp=0x0, &buf[wp]=000000002fda9222 snd_hdac_bus_get_response: reading result from 0000000096c36d67 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x2b8000, wp=0x1, &buf[wp]=000000009747a629 snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff800 flags=0x0020] snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff800 flags=0x0020] And I finally got "out of range cmd", but logging is limited to IO addresses. bus->corb.buf[wp] = cpu_to_le32(val) // = 0x14ba000, wp=0xfe, &buf[wp]=0000000036a02eae snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x14b8000, wp=0xff, &buf[wp]=00000000ce140303 snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x2ba000, wp=0x0, &buf[wp]=000000004c6aa283 snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x2b8000, wp=0x1, &buf[wp]=000000002a825cc8 snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff800 flags=0x0020] snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff800 flags=0x0020] snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x239000, wp=0x2, &buf[wp]=0000000078eca2cf snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff800 flags=0x0020] snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x1970724, wp=0x3, &buf[wp]=00000000613071da snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x1270720, wp=0x4, &buf[wp]=000000006db33d93 snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff800 flags=0x0020] snd_hdac_bus_get_response: reading result from 0000000037aa0724 snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff820 flags=0x0020] bus->corb.buf[wp] = cpu_to_le32(val) // = 0x8b2000, wp=0x5, &buf[wp]=000000002a3c7e90 snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff820 flags=0x0020] snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x836080, wp=0x6, &buf[wp]=00000000571d53bf snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x8b0000, wp=0x7, &buf[wp]=000000000a52a2af snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff820 flags=0x0020] snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff820 flags=0x0020] snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x835080, wp=0x8, &buf[wp]=00000000f139c302 snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff840 flags=0x0020] snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x23f000d, wp=0x9, &buf[wp]=000000003c565021 snd_hda_intel 0000:05:00.6: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x0015 address=0x1fffff840 flags=0x0020] snd_hdac_bus_get_response: reading result from 0000000037aa0724 ... bus->corb.buf[wp] = cpu_to_le32(val) // = 0x205000b, wp=0x3e, &buf[wp]=000000002ce016ac snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x20c0000, wp=0x3f, &buf[wp]=000000003ad48d6f snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x8350a7, wp=0x40, &buf[wp]=0000000098c2fb2d snd_hdac_bus_get_response: reading result from 0000000037aa0724 bus->corb.buf[wp] = cpu_to_le32(val) // = 0x205000b, wp=0x41, &buf[wp]=000000006e281f5b snd_hdac_bus_get_response: reading result from 0000000037aa0724 snd_hda_codec_realtek hdaudioC1D0: out of range cmd 0:20:400:40600001
