ttm dma allocator issue ?

ttm dma allocator issue ?

[Jerome Glisse]

Hi Konrad i stumble on this after a long period of test :

Dec  9 12:00:37 homer kernel: ------------[ cut here ]------------
Dec  9 12:00:37 homer kernel: WARNING: at lib/dma-debug.c:894
check_unmap+0x262/0x7e0()
Dec  9 12:00:37 homer kernel: Hardware name: GA-A75M-UD2H
Dec  9 12:00:37 homer kernel: radeon 0000:01:00.0: DMA-API: device
driver frees DMA memory with different CPU address [device address=0x00000002093f3000]
                                                   [size=4096 bytes]
                                                   [cpu alloc address=0x0000000213bf2000]
                                                   [cpu free address=0x00000002093f3000]
Dec  9 12:00:37 homer kernel: Modules linked in: radeon ttm
drm_kms_helper drm ip6t_REJECT ipt_REJECT nf_conntrack_ipv6
nf_conntrack_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 xt_state nf_conntrack
ip6table_filter iptable_filter ip6_tables ip_tables dm_mirror
dm_region_hash dm_log dm_mod snd_hda_codec_hdmi snd_hda_codec_realtek
snd_hda_intel snd_hda_codec snd_hwdep snd_seq snd_seq_device r8169
snd_pcm microcode serio_raw xhci_hcd mii hwmon i2c_piix4 i2c_algo_bit
snd_timer snd soundcore snd_page_alloc ipv6 ext4 mbcache jbd2
ata_generic pata_atiixp [last unloaded: drm]
Dec  9 12:00:37 homer kernel: Pid: 1158, comm: Heaven_x64 Not tainted 3.2.0-rc4+ #72
Dec  9 12:00:37 homer kernel: Call Trace:
Dec  9 12:00:37 homer kernel: [<ffffffff81043d0f>] warn_slowpath_common+0x7f/0xc0
Dec  9 12:00:37 homer kernel: [<ffffffff81043e06>] warn_slowpath_fmt+0x46/0x50
Dec  9 12:00:37 homer kernel: [<ffffffff81229382>] check_unmap+0x262/0x7e0
Dec  9 12:00:37 homer kernel: [<ffffffff81113977>] ?vm_unmap_aliases+0x77/0x1d0
Dec  9 12:00:37 homer kernel: [<ffffffff8122996d>] debug_dma_free_coherent+0x6d/0x80
Dec  9 12:00:37 homer kernel: [<ffffffff8104bb60>] ?__request_resource+0x60/0x60
Dec  9 12:00:37 homer kernel: [<ffffffffa03e7597>] __ttm_dma_free_page+0x67/0xd0 [ttm]
Dec  9 12:00:37 homer kernel: [<ffffffffa03e7f45>] ttm_dma_unpopulate+0x2c5/0x340 [ttm]
Dec  9 12:00:37 homer kernel: [<ffffffffa042a81f>] radeon_ttm_tt_unpopulate+0xdf/0xf0 [radeon]
Dec  9 12:00:37 homer kernel: [<ffffffffa03df151>] ttm_tt_destroy+0x31/0x70 [ttm]
Dec  9 12:00:37 homer kernel: [<ffffffffa03df703>] ttm_bo_cleanup_memtype_use+0x43/0xb0 [ttm]
Dec  9 12:00:37 homer kernel: [<ffffffffa03e0988>] ttm_bo_release+0x218/0x240 [ttm]
Dec  9 12:00:37 homer kernel: [<ffffffffa03e0770>] ?ttm_bo_delayed_workqueue+0x40/0x40 [ttm]
Dec  9 12:00:37 homer kernel: [<ffffffff8120df96>] kref_put+0x36/0x70
Dec  9 12:00:37 homer kernel: [<ffffffffa03dfa71>] ttm_bo_unref+0x41/0x60 [ttm]
Dec  9 12:00:37 homer kernel: [<ffffffffa042bb29>] radeon_bo_unref+0x49/0x80 [radeon]
Dec  9 12:00:37 homer kernel: [<ffffffffa038e4d0>] ?drm_gem_object_release_handle+0x90/0x90 [drm]
Dec  9 12:00:37 homer kernel: [<ffffffffa043cd16>] radeon_gem_object_free+0x26/0x30 [radeon]
Dec  9 12:00:37 homer kernel: [<ffffffffa038e4fa>] drm_gem_object_free+0x2a/0x30 [drm]
Dec  9 12:00:37 homer kernel: [<ffffffff8120df96>] kref_put+0x36/0x70
Dec  9 12:00:37 homer kernel: [<ffffffffa038e152>] drm_gem_handle_delete+0xc2/0x110 [drm]
Dec  9 12:00:37 homer kernel: [<ffffffffa038e7e8>] drm_gem_close_ioctl+0x28/0x30 [drm]
Dec  9 12:00:37 homer kernel: [<ffffffffa038c5d4>] drm_ioctl+0x444/0x510 [drm]
Dec  9 12:00:37 homer kernel: [<ffffffffa038e7c0>] ?drm_gem_destroy+0x60/0x60 [drm]
Dec  9 12:00:37 homer kernel: [<ffffffff811c4670>] ?inode_has_perm+0x30/0x40
Dec  9 12:00:37 homer kernel: [<ffffffff811c4d6c>] ?file_has_perm+0xdc/0xf0
Dec  9 12:00:37 homer kernel: [<ffffffff81146198>] do_vfs_ioctl+0x98/0x570
Dec  9 12:00:37 homer kernel: [<ffffffff81146701>] sys_ioctl+0x91/0xa0
Dec  9 12:00:37 homer kernel: [<ffffffff814bf42b>] system_call_fastpath+0x16/0x1b
Dec  9 12:00:37 homer kernel: ---[ end trace 8219ad8f7980f419 ]---
Dec  9 12:00:37 homer kernel: Mapped at:
Dec  9 12:00:37 homer kernel: [<ffffffff812282eb>] debug_dma_alloc_coherent+0x3b/0x90
Dec  9 12:00:37 homer kernel: [<ffffffffa03e84a0>] ttm_dma_populate+0x340/0xa30 [ttm]
Dec  9 12:00:37 homer kernel: [<ffffffffa042ae4f>] radeon_ttm_tt_populate+0x19f/0x280 [radeon]
Dec  9 12:00:37 homer kernel: [<ffffffffa03df0ae>] ttm_tt_bind+0x3e/0x70 [ttm]
Dec  9 12:00:37 homer kernel: [<ffffffffa03e0fcf>] ttm_bo_handle_move_mem+0x36f/0x3e0 [ttm]
Dec  9 12:01:29 homer kernel: DMA-API: debugging out of memory - disabling
Dec  9 19:16:54 homer kernel: [drm:radeon_dvi_detect] *ERROR* DVI-I-1:
probed a monitor but no|invalid EDID

Nothing else in the log. Quite frankly i dont this how this can happen.
Any ideas ?

Cheers,
Jerome

Re: ttm dma allocator issue ?

[Konrad Rzeszutek Wilk]

On Fri, Dec 09, 2011 at 09:25:43PM -0500, Jerome Glisse wrote:
> Hi Konrad i stumble on this after a long period of test :
> 
> Dec  9 12:00:37 homer kernel: ------------[ cut here ]------------
> Dec  9 12:00:37 homer kernel: WARNING: at lib/dma-debug.c:894
> check_unmap+0x262/0x7e0()
> Dec  9 12:00:37 homer kernel: Hardware name: GA-A75M-UD2H
> Dec  9 12:00:37 homer kernel: radeon 0000:01:00.0: DMA-API: device
> driver frees DMA memory with different CPU address [device address=0x00000002093f3000]
>                                                    [size=4096 bytes]
>                                                    [cpu alloc address=0x0000000213bf2000]
>                                                    [cpu free address=0x00000002093f3000]
> Dec  9 12:00:37 homer kernel: Modules linked in: radeon ttm
> drm_kms_helper drm ip6t_REJECT ipt_REJECT nf_conntrack_ipv6
> nf_conntrack_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 xt_state nf_conntrack
> ip6table_filter iptable_filter ip6_tables ip_tables dm_mirror
> dm_region_hash dm_log dm_mod snd_hda_codec_hdmi snd_hda_codec_realtek
> snd_hda_intel snd_hda_codec snd_hwdep snd_seq snd_seq_device r8169
> snd_pcm microcode serio_raw xhci_hcd mii hwmon i2c_piix4 i2c_algo_bit
> snd_timer snd soundcore snd_page_alloc ipv6 ext4 mbcache jbd2
> ata_generic pata_atiixp [last unloaded: drm]
> Dec  9 12:00:37 homer kernel: Pid: 1158, comm: Heaven_x64 Not tainted 3.2.0-rc4+ #72
> Dec  9 12:00:37 homer kernel: Call Trace:
> Dec  9 12:00:37 homer kernel: [<ffffffff81043d0f>] warn_slowpath_common+0x7f/0xc0
> Dec  9 12:00:37 homer kernel: [<ffffffff81043e06>] warn_slowpath_fmt+0x46/0x50
> Dec  9 12:00:37 homer kernel: [<ffffffff81229382>] check_unmap+0x262/0x7e0
> Dec  9 12:00:37 homer kernel: [<ffffffff81113977>] ?vm_unmap_aliases+0x77/0x1d0
> Dec  9 12:00:37 homer kernel: [<ffffffff8122996d>] debug_dma_free_coherent+0x6d/0x80
> Dec  9 12:00:37 homer kernel: [<ffffffff8104bb60>] ?__request_resource+0x60/0x60
> Dec  9 12:00:37 homer kernel: [<ffffffffa03e7597>] __ttm_dma_free_page+0x67/0xd0 [ttm]
> Dec  9 12:00:37 homer kernel: [<ffffffffa03e7f45>] ttm_dma_unpopulate+0x2c5/0x340 [ttm]
> Dec  9 12:00:37 homer kernel: [<ffffffffa042a81f>] radeon_ttm_tt_unpopulate+0xdf/0xf0 [radeon]
.. snip..
> Dec  9 12:00:37 homer kernel: Mapped at:
> Dec  9 12:00:37 homer kernel: [<ffffffff812282eb>] debug_dma_alloc_coherent+0x3b/0x90
> Dec  9 12:00:37 homer kernel: [<ffffffffa03e84a0>] ttm_dma_populate+0x340/0xa30 [ttm]
> Dec  9 12:00:37 homer kernel: [<ffffffffa042ae4f>] radeon_ttm_tt_populate+0x19f/0x280 [radeon]
> Dec  9 12:00:37 homer kernel: [<ffffffffa03df0ae>] ttm_tt_bind+0x3e/0x70 [ttm]
> Dec  9 12:00:37 homer kernel: [<ffffffffa03e0fcf>] ttm_bo_handle_move_mem+0x36f/0x3e0 [ttm]
> Dec  9 12:01:29 homer kernel: DMA-API: debugging out of memory - disabling
> Dec  9 19:16:54 homer kernel: [drm:radeon_dvi_detect] *ERROR* DVI-I-1:
> probed a monitor but no|invalid EDID
> 
> Nothing else in the log. Quite frankly i dont this how this can happen.
> Any ideas ?

The only way to do that would be to modify the 'struct dma_page' vaddr and dma
variables from what they had in __ttm_dma_alloc_page. But I am not seeing any
willfull modifications. We do pass in to dma_free_coherent the _same_ values!


Hm, it might be worth adding in the 'struct dma_page' a 'virt_to_phys' value
(which is what the DMA debug API uses to check), and see we get inconsitent
values _before_ we call the DMA debug API. This is rather to double check
the DMA API debug API. I am going to try something like this (not compile tested at all):

diff --git a/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c b/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c
index 6678abc..2dd7d6c 100644
--- a/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c
+++ b/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c
@@ -127,6 +127,7 @@ struct dma_page {
 	void *vaddr;
 	struct page *p;
 	dma_addr_t dma;
+	void *phys;	/* Based on virt_to_phys so not really bus addr */
 };
 
 /*
@@ -330,6 +331,11 @@ static int ttm_set_pages_caching(struct dma_pool *pool,
 static void __ttm_dma_free_page(struct dma_pool *pool, struct dma_page *d_page)
 {
 	dma_addr_t dma = d_page->dma;
+
+	WARN_ON(virt_to_phys(d_page->vaddr) != d_page->virt,
+		"WTF: saved 0x%lx, but now we get 0x%lx!\n",
+		d_page->virt, virt_to_phys(d_page->vaddr));
+
 	dma_free_coherent(pool->dev, pool->size, d_page->vaddr, dma);
 
 	kfree(d_page);
@@ -348,6 +354,7 @@ static struct dma_page *__ttm_dma_alloc_page(struct dma_pool *pool)
 					   pool->gfp_flags);
 	if (d_page->vaddr)
 		d_page->p = virt_to_page(d_page->vaddr);
+		d_page->virt = virt_to_phys(d_page->vaddr);
 	else {
 		kfree(d_page);
 		d_page = NULL;

Re: ttm dma allocator issue ?

[Konrad Rzeszutek Wilk]

> > Any ideas ?
> 
> The only way to do that would be to modify the 'struct dma_page' vaddr and dma
> variables from what they had in __ttm_dma_alloc_page. But I am not seeing any
> willfull modifications. We do pass in to dma_free_coherent the _same_ values!
> 
> 
> Hm, it might be worth adding in the 'struct dma_page' a 'virt_to_phys' value
> (which is what the DMA debug API uses to check), and see we get inconsitent
> values _before_ we call the DMA debug API. This is rather to double check
> the DMA API debug API. I am going to try something like this (not compile tested at all):

This one is compile tested :-)

diff --git a/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c b/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c
index 6678abc..659b0ee 100644
--- a/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c
+++ b/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c
@@ -32,7 +32,7 @@
  * - Tracks whether the page is UC, WB or cached (and reverts to WB
  *   when freed).
  */
-
+#define DEBUG 1
 #include <linux/dma-mapping.h>
 #include <linux/list.h>
 #include <linux/seq_file.h> /* for seq_printf */
@@ -127,6 +127,7 @@ struct dma_page {
 	void *vaddr;
 	struct page *p;
 	dma_addr_t dma;
+	void *phys;	/* Based on virt_to_phys so not really bus addr */
 };
 
 /*
@@ -330,6 +331,11 @@ static int ttm_set_pages_caching(struct dma_pool *pool,
 static void __ttm_dma_free_page(struct dma_pool *pool, struct dma_page *d_page)
 {
 	dma_addr_t dma = d_page->dma;
+
+	WARN(virt_to_phys(d_page->vaddr) != d_page->phys,
+		"We saved 0x%lx, but now we get 0x%lx!?\n",
+		(unsigned long)d_page->phys, (unsigned long)virt_to_phys(d_page->vaddr));
+
 	dma_free_coherent(pool->dev, pool->size, d_page->vaddr, dma);
 
 	kfree(d_page);
@@ -346,8 +352,10 @@ static struct dma_page *__ttm_dma_alloc_page(struct dma_pool *pool)
 	d_page->vaddr = dma_alloc_coherent(pool->dev, pool->size,
 					   &d_page->dma,
 					   pool->gfp_flags);
-	if (d_page->vaddr)
+	if (d_page->vaddr) {
 		d_page->p = virt_to_page(d_page->vaddr);
+		d_page->phys = virt_to_phys(d_page->vaddr);
+	}
 	else {
 		kfree(d_page);
 		d_page = NULL;

Re: ttm dma allocator issue ?

[Konrad Rzeszutek Wilk]

On Mon, Dec 12, 2011 at 12:37:43PM -0500, Konrad Rzeszutek Wilk wrote:
> > > Any ideas ?
> > 
> > The only way to do that would be to modify the 'struct dma_page' vaddr and dma
> > variables from what they had in __ttm_dma_alloc_page. But I am not seeing any
> > willfull modifications. We do pass in to dma_free_coherent the _same_ values!
> > 
> > 
> > Hm, it might be worth adding in the 'struct dma_page' a 'virt_to_phys' value
> > (which is what the DMA debug API uses to check), and see we get inconsitent
> > values _before_ we call the DMA debug API. This is rather to double check
> > the DMA API debug API. I am going to try something like this (not compile tested at all):
> 
> This one is compile tested :-)
> 
> diff --git a/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c b/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c
> index 6678abc..659b0ee 100644
> --- a/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c
> +++ b/drivers/gpu/drm/ttm/ttm_page_alloc_dma.c
> @@ -32,7 +32,7 @@
>   * - Tracks whether the page is UC, WB or cached (and reverts to WB
>   *   when freed).
>   */
> -

And I think if you cherry-pick git commit 91ec37cc1015220965e39bf342fb846810d19e79

Author: Thomas Jarosch <thomas.jarosch@intra2net.com>
Date:   Thu Nov 17 20:31:02 2011 +0100

    Fix comparison using wrong pointer variable in dma debug code

which fixes the DMA debug API code, the error you are getting will go away.