AMD-IOMMU and problem with __init(data)?

AMD-IOMMU and problem with __init(data)?

[Alexander Holler]

Hello,

It looks like I have a problem with the AMD IOMMU and it's handling of 
__init or __initdata.

I'm working on something which stores some structs right after 
INIT_CALLS but before CON_INITCALL (see include/asm-generic/vmlinux.lds.h).

This structures will be accessed right after the initcalls from level fs 
(5, see init/main.c), have been called.

Here is how that structure is defined:
--
struct _annotated_initcall {
	initcall_t initcall;
	unsigned driver_id;
	unsigned *dependencies;
	struct device_driver *driver;
};
extern struct _annotated_initcall __annotated_initcall_start[],
				  __annotated_initcall_end[];
--

The code which uses that is
--
	struct _annotated_initcall *ac;

	ac = __annotated_initcall_start;
	for (; ac < __annotated_initcall_end; ++ac)
		pr_info("AHO: ac %p ic %p ID %u deps %p drv %p\n",
			ac, ac->initcall, ac->driver_id,
			ac->dependencies, ac->driver);
--

What now happens if I've enabled CONFIG_AMD_IOMMU is the following:

--
(...)
[    1.240362] io scheduler noop registered
[    1.395764] iommu: Adding device 0000:00:00.0 to group 0
[    1.401478] iommu: Adding device 0000:00:01.0 to group 1
[    1.406828] iommu: Adding device 0000:00:01.1 to group 1
[    1.412487] iommu: Adding device 0000:00:10.0 to group 2
[    1.417839] iommu: Adding device 0000:00:10.1 to group 2
[    1.423501] iommu: Adding device 0000:00:11.0 to group 3
[    1.429157] iommu: Adding device 0000:00:12.0 to group 4
[    1.434510] iommu: Adding device 0000:00:12.2 to group 4
[    1.440166] iommu: Adding device 0000:00:13.0 to group 5
[    1.445520] iommu: Adding device 0000:00:13.2 to group 5
[    1.451196] iommu: Adding device 0000:00:14.0 to group 6
[    1.456551] iommu: Adding device 0000:00:14.2 to group 6
[    1.461904] iommu: Adding device 0000:00:14.3 to group 6
[    1.467568] iommu: Adding device 0000:00:14.4 to group 7
[    1.473226] iommu: Adding device 0000:00:15.0 to group 8
[    1.480807] iommu: Adding device 0000:00:15.1 to group 8
[    1.486470] iommu: Adding device 0000:00:18.0 to group 9
[    1.491822] iommu: Adding device 0000:00:18.1 to group 9
[    1.497176] iommu: Adding device 0000:00:18.2 to group 9
[    1.502528] iommu: Adding device 0000:00:18.3 to group 9
[    1.507883] iommu: Adding device 0000:00:18.4 to group 9
[    1.513237] iommu: Adding device 0000:00:18.5 to group 9
[    1.518593] iommu: Adding device 0000:03:00.0 to group 8
[    1.523932] AMD-Vi: Found IOMMU at 0000:00:00.2 cap 0x40
[    1.529276] AMD-Vi:  Extended features:  PreF PPR GT IA
[    1.534776] AMD-Vi: Interrupt remapping enabled
[    1.539496] AMD-Vi: Lazy IO/TLB flushing enabled
[    1.545741] AHO: count_annotated 25
[    1.549259] AHO: build inventory
[    1.552517] AHO: ac ffffffff81d400d8 ic           (null) ID 
2177560225 deps 00000000000000b0 drv ffffffff81d25090
[    1.562801] BUG: unable to handle kernel paging request at 
00000000039c2af5
(...)
--

The bug happens because the field driver_id of the structure (and likely 
the other stuff) is wrong.

If I disable CONFIG_AMD_IOMMU it looks like it should and how it works 
on ARM and Intel systems:
--
(...)
[    1.151906] io scheduler noop registered
[    1.307088] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    1.313563] software IO TLB [mem 0x894ca000-0x8d4ca000] (64MB) mapped 
at [ffff8800894ca000-ffff88008d4c9fff]
[    1.323411] AHO: count_annotated 25
[    1.326934] AHO: build inventory
[    1.330189] AHO: ac ffffffff81d3cea0 ic ffffffff81cadcb4 ID 176 deps 
ffffffff81d22090 drv           (null)
(...)
--

Does anyone have an idea what's going on?

Kernel is 4.2.1 (x86_64) and HW is an A10-5800K.

If it's necessary, I could try put together a small patch which kills a 
system (reproducible here).

Thanks in advance,

Alexander Holler

Re: AMD-IOMMU and problem with __init(data)?

[Joerg Roedel]

Hey Alexander,

On Wed, Sep 23, 2015 at 12:22:24PM +0200, Alexander Holler wrote:
> [    1.539496] AMD-Vi: Lazy IO/TLB flushing enabled
> [    1.545741] AHO: count_annotated 25
> [    1.549259] AHO: build inventory
> [    1.552517] AHO: ac ffffffff81d400d8 ic           (null) ID
> 2177560225 deps 00000000000000b0 drv ffffffff81d25090
> [    1.562801] BUG: unable to handle kernel paging request at
> 00000000039c2af5
> (...)

Do you possibly have the full BUG message including the stacktrace?

> If it's necessary, I could try put together a small patch which
> kills a system (reproducible here).

That would help too, please also send me your .config and I'll try to
reproduce the issue here.


	Joerg

Re: AMD-IOMMU and problem with __init(data)?

[Alexander Holler]

Am 23.09.2015 um 13:43 schrieb Joerg Roedel:
> Hey Alexander,
>
> On Wed, Sep 23, 2015 at 12:22:24PM +0200, Alexander Holler wrote:
>> [    1.539496] AMD-Vi: Lazy IO/TLB flushing enabled
>> [    1.545741] AHO: count_annotated 25
>> [    1.549259] AHO: build inventory
>> [    1.552517] AHO: ac ffffffff81d400d8 ic           (null) ID
>> 2177560225 deps 00000000000000b0 drv ffffffff81d25090
>> [    1.562801] BUG: unable to handle kernel paging request at
>> 00000000039c2af5
>> (...)
>
> Do you possibly have the full BUG message including the stacktrace?

The full msg is

---------
[    1.552517] AHO: ac ffffffff81d400d8 ic           (null) ID 
2177560225 deps 00000000000000b0 drv ffffffff81d25090
[    1.562801] BUG: unable to handle kernel paging request at 
00000000039c2af5
[    1.569889] IP: [<ffffffff81c9d7b4>] do_annotated_initcalls+0x6f/0x25b
[    1.576490] PGD 0
[    1.578587] Oops: 0002 [#1] SMP
[    1.581947] Modules linked in:
[    1.585085] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 
4.2.1-deps-00154-gb5f382c-dirty #768
[    1.593374] Hardware name: System manufacturer System Product 
Name/F2A85-M, BIOS 6508 07/11/2014
[    1.602184] task: ffff88042d508000 ti: ffff88042d510000 task.ti: 
ffff88042d510000
[    1.609693] RIP: 0010:[<ffffffff81c9d7b4>]  [<ffffffff81c9d7b4>] 
do_annotated_initcalls+0x6f/0x25b
[    1.618718] RSP: 0018:ffff88042d513f08  EFLAGS: 00010296
[    1.624056] RAX: 0000000081caeea1 RBX: ffffffff81d400d8 RCX: 
0000000000000000
[    1.631210] RDX: 0000000081caeea1 RSI: 0000000000000246 RDI: 
ffffffff81da7ae8
[    1.638365] RBP: 0000000000000001 R08: 0000000000000000 R09: 
0000000000000000
[    1.645519] R10: 00000000000001f9 R11: 0000000000000006 R12: 
0000000000000000
[    1.652676] R13: 0000000000000000 R14: 0000000000000000 R15: 
0000000000000000
[    1.659830] FS:  0000000000000000(0000) GS:ffff88043ec00000(0000) 
knlGS:0000000000000000
[    1.667940] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[    1.673707] CR2: 00000000039c2af5 CR3: 0000000001c0b000 CR4: 
00000000000406f0
[    1.680864] Stack:
[    1.682908]  0000000000000006 0000000000000001 0000000000000000 
ffffffff81c9ced8
[    1.690531]  0000000080000000 ffffffff8164b3d0 0000000000000000 
ffffffff8164b3d9
[    1.698153]  ffffffff81c25380 ffffffff81656f5f 0000000000000000 
0000000000000000
[    1.705777] Call Trace:
[    1.708255]  [<ffffffff81c9ced8>] ? kernel_init_freeable+0xda/0x16a
[    1.714544]  [<ffffffff8164b3d0>] ? rest_init+0x70/0x70
[    1.719793]  [<ffffffff8164b3d9>] ? kernel_init+0x9/0xe0
[    1.725129]  [<ffffffff81656f5f>] ? ret_from_fork+0x3f/0x70
[    1.730724]  [<ffffffff8164b3d0>] ? rest_init+0x70/0x70
[    1.735974] Code: d4 81 73 4d 8b 4b 08 85 c9 74 40 48 8b 13 4c 8b 4b 
18 48 89 de 4c 8b 43 10 48 c7 c7 e0 4e 9d 81 e8 1c fe 9a ff 8b 53 08 48 
89 d0 <c6> 82 54 3c d1 81 01 48 89 1c d5 40 f2 d0 81 8b 15 c7 63 07 00
[    1.758158] RIP  [<ffffffff81c9d7b4>] do_annotated_initcalls+0x6f/0x25b
[    1.764845]  RSP <ffff88042d513f08>
[    1.768361] CR2: 00000000039c2af5
[    1.771710] ---[ end trace 5a4348fb7eabd051 ]---
[    1.776363] ------------[ cut here ]------------
[    1.781010] WARNING: CPU: 0 PID: 1 at kernel/smp.c:292 
smp_call_function_single+0xe7/0x100()
[    1.789472] Modules linked in:
[    1.792610] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G      D 
4.2.1-deps-00154-gb5f382c-dirty #768
[    1.802112] Hardware name: System manufacturer System Product 
Name/F2A85-M, BIOS 6508 07/11/2014
[    1.810921]  0000000000000000 ffffffff819d6fba ffffffff8164f11e 
0000000000000000
[    1.818542]  ffffffff81039647 0000000000000000 ffffffff810c87c0 
ffffffff81c22040
[    1.826166]  0000000000000000 00000000039c2af5 ffffffff8109bc97 
ffff88042d513cf8
[    1.833790] Call Trace:
[    1.836267]  [<ffffffff8164f11e>] ? dump_stack+0x40/0x50
[    1.841603]  [<ffffffff81039647>] ? warn_slowpath_common+0x87/0xd0
[    1.847806]  [<ffffffff810c87c0>] ? cpu_clock_event_start+0x30/0x30
[    1.854095]  [<ffffffff8109bc97>] ? smp_call_function_single+0xe7/0x100
[    1.860729]  [<ffffffff810c7962>] ? task_function_call+0x42/0x50
[    1.866760]  [<ffffffff810cc670>] ? perf_cgroup_switch+0x160/0x160
[    1.872963]  [<ffffffff810ac800>] ? cgroup_exit+0xb0/0x130
[    1.878470]  [<ffffffff8103b987>] ? do_exit+0x347/0x9a0
[    1.883720]  [<ffffffff8100693c>] ? oops_end+0x8c/0xd0
[    1.888882]  [<ffffffff8102cd83>] ? no_context+0x123/0x370
[    1.894392]  [<ffffffff81658132>] ? page_fault+0x22/0x30
[    1.899728]  [<ffffffff81c9d7b4>] ? do_annotated_initcalls+0x6f/0x25b
[    1.906190]  [<ffffffff81c9d7ae>] ? do_annotated_initcalls+0x69/0x25b
[    1.912653]  [<ffffffff81c9ced8>] ? kernel_init_freeable+0xda/0x16a
[    1.918941]  [<ffffffff8164b3d0>] ? rest_init+0x70/0x70
[    1.924190]  [<ffffffff8164b3d9>] ? kernel_init+0x9/0xe0
[    1.929526]  [<ffffffff81656f5f>] ? ret_from_fork+0x3f/0x70
[    1.935123]  [<ffffffff8164b3d0>] ? rest_init+0x70/0x70
[    1.940371] ---[ end trace 5a4348fb7eabd052 ]---
[    1.945023] Kernel panic - not syncing: Attempted to kill init! 
exitcode=0x00000009
[    1.945023]
[    1.954235] ---[ end Kernel panic - not syncing: Attempted to kill 
init! exitcode=0x00000009
---------

The bug happens because the code tried to uses foo[ID] and with an ID of 
2177560225 it wents clearly out of bounds. ;)

>
>> If it's necessary, I could try put together a small patch which
>> kills a system (reproducible here).
>
> That would help too, please also send me your .config and I'll try to
> reproduce the issue here.

Will do. Later.

Thanks,

Regards,

Alexander Holler

Re: AMD-IOMMU and problem with __init(data)?

[Alexander Holler]

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

Am 23.09.2015 um 17:50 schrieb Alexander Holler:
> Am 23.09.2015 um 13:43 schrieb Joerg Roedel:
>>> If it's necessary, I could try put together a small patch which
>>> kills a system (reproducible here).
>>
>> That would help too, please also send me your .config and I'll try to
>> reproduce the issue here.
>
> Will do. Later.

Done. Patch(es) and config attached. Note, while reducing the patch, 
I've noted that when I change


struct _annotated_initcall {
	initcall_t initcall;
	unsigned driver_id;
	unsigned *dependencies;
	struct device_driver *driver;
};

to

struct _annotated_initcall {
	initcall_t initcall;
	unsigned driver_id;
};

it does not crash. That's what the second patch does. So in order to 
crash a system, just use patch 0001.

Regards,

Alexander Holler

[-- Attachment #2: 0001-CRASH-on-AMD-with-CONFIG_AMD_IOMMU.patch --]
[-- Type: text/x-patch, Size: 2313 bytes --]

>From d94e5568925d7cb8a3fc628606e8fcf1374ea177 Mon Sep 17 00:00:00 2001
From: Alexander Holler <holler@ahsoftware.de>
Date: Wed, 23 Sep 2015 19:43:51 +0200
Subject: [PATCH 1/2] CRASH on AMD with CONFIG_AMD_IOMMU

---
 include/asm-generic/vmlinux.lds.h |  6 ++++++
 init/main.c                       | 30 +++++++++++++++++++++++++++++-
 2 files changed, 35 insertions(+), 1 deletion(-)

diff --git a/include/asm-generic/vmlinux.lds.h b/include/asm-generic/vmlinux.lds.h
index 8bd374d..13f9189 100644
--- a/include/asm-generic/vmlinux.lds.h
+++ b/include/asm-generic/vmlinux.lds.h
@@ -660,6 +660,11 @@
 		INIT_CALLS_LEVEL(7)					\
 		VMLINUX_SYMBOL(__initcall_end) = .;
 
+#define ANNOTATED_INITCALLS						\
+		VMLINUX_SYMBOL(__annotated_initcall_start) = .;		\
+		*(.annotated_initcall.init)				\
+		VMLINUX_SYMBOL(__annotated_initcall_end) = .;
+
 #define CON_INITCALL							\
 		VMLINUX_SYMBOL(__con_initcall_start) = .;		\
 		*(.con_initcall.init)					\
@@ -816,6 +821,7 @@
 		INIT_DATA						\
 		INIT_SETUP(initsetup_align)				\
 		INIT_CALLS						\
+		ANNOTATED_INITCALLS					\
 		CON_INITCALL						\
 		SECURITY_INITCALL					\
 		INIT_RAM_FS						\
diff --git a/init/main.c b/init/main.c
index 5650655..1498f9b 100644
--- a/init/main.c
+++ b/init/main.c
@@ -859,12 +859,40 @@ static void __init do_initcall_level(int level)
 		do_one_initcall(*fn);
 }
 
+struct _annotated_initcall {
+	initcall_t initcall;
+	unsigned driver_id;
+	unsigned *dependencies;
+	struct device_driver *driver;
+};
+extern struct _annotated_initcall __annotated_initcall_start[];
+
+#define annotated_initcall(fn, id) \
+	static struct _annotated_initcall __annotated_initcall_##fn __used \
+	__attribute__((__section__(".annotated_initcall.init"))) = \
+							{ .initcall = fn, .driver_id = id }
+
+
+static int __init foo(void)
+{
+	return 0;
+}
+
+annotated_initcall(foo, 23);
+
 static void __init do_initcalls(void)
 {
 	int level;
+	struct _annotated_initcall *ac;
 
-	for (level = 0; level < ARRAY_SIZE(initcall_levels) - 1; level++)
+	for (level = 0; level < ARRAY_SIZE(initcall_levels) - 3; level++)
 		do_initcall_level(level);
+
+	ac = __annotated_initcall_start;
+	pr_info("ac %p ID %u\n", ac, ac->driver_id);
+	BUG_ON(ac->driver_id != 23);
+	do_initcall_level(level++);
+	do_initcall_level(level);
 }
 
 /*
-- 
2.1.0


[-- Attachment #3: 0002-NO-crash.patch --]
[-- Type: text/x-patch, Size: 632 bytes --]

>From 17c9b286710931947c63ef49bba69f679ecdc400 Mon Sep 17 00:00:00 2001
From: Alexander Holler <holler@ahsoftware.de>
Date: Wed, 23 Sep 2015 20:39:28 +0200
Subject: [PATCH 2/2] NO crash

---
 init/main.c | 2 --
 1 file changed, 2 deletions(-)

diff --git a/init/main.c b/init/main.c
index 1498f9b..4c1f041 100644
--- a/init/main.c
+++ b/init/main.c
@@ -862,8 +862,6 @@ static void __init do_initcall_level(int level)
 struct _annotated_initcall {
 	initcall_t initcall;
 	unsigned driver_id;
-	unsigned *dependencies;
-	struct device_driver *driver;
 };
 extern struct _annotated_initcall __annotated_initcall_start[];
 
-- 
2.1.0


[-- Attachment #4: crash_amd_iommu.config.bz2 --]
[-- Type: application/x-bzip, Size: 23799 bytes --]

Re: AMD-IOMMU and problem with __init(data)?

[Alexander Holler]

Am 23.09.2015 um 21:04 schrieb Alexander Holler:
> Am 23.09.2015 um 17:50 schrieb Alexander Holler:
>> Am 23.09.2015 um 13:43 schrieb Joerg Roedel:
>>>> If it's necessary, I could try put together a small patch which
>>>> kills a system (reproducible here).
>>>
>>> That would help too, please also send me your .config and I'll try to
>>> reproduce the issue here.
>>
>> Will do. Later.
>
> Done. Patch(es) and config attached. Note, while reducing the patch,
> I've noted that when I change

Just in case of, the command line I'm using is

ro root=/dev/sdb2 rootfstype=btrfs rootflags=compress=zlib enforcing=0 
selinux=0 cgroup_disable=memory swapaccount=0 
earlycon=uart8250,io,0x3f8,115200n8 console=ttyS0,115200n8 console=tty0 
memtest=3 LANG=de_DE.UTF-8 video=DVI-D-1:1920x1080-32@60

And memtest never failed (I'm always using that). So it's unlikely it's 
a problem with the memory.

But usually I don't have enabled the serial, that means normally I'm 
booting with

root=/dev/sdb2 rootfstype=btrfs rootflags=compress=zlib enforcing=0 
selinux=0 cgroup_disable=memory swapaccount=0 console=tty0 memtest=3 
LANG=de_DE.UTF-8 video=DVI-D-1:1920x1080-32@60

so maybe enabling the serial does something bad. Also I've enabled it 
before and haven't seen something bad. And because I assume the IOMMU is 
the problem, I don't use any cards, just the HW on mb.

Regards,

Alexander Holler

Re: AMD-IOMMU and problem with __init(data)?

[Joerg Roedel]

As expected it is no bug in the AMD IOMMU driver, but in your code.

On Wed, Sep 23, 2015 at 09:04:31PM +0200, Alexander Holler wrote:
> struct _annotated_initcall {
> 	initcall_t initcall;
> 	unsigned driver_id;
> 	unsigned *dependencies;
> 	struct device_driver *driver;
> };

This struct gets aligned on a 32 bytes boundary.

> +#define ANNOTATED_INITCALLS						\
> +		VMLINUX_SYMBOL(__annotated_initcall_start) = .;		\
> +		*(.annotated_initcall.init)				\
> +		VMLINUX_SYMBOL(__annotated_initcall_end) = .;

But this section does not.

> +	ac = __annotated_initcall_start;
> +	pr_info("ac %p ID %u\n", ac, ac->driver_id);
> +	BUG_ON(ac->driver_id != 23);

So when you access __annotated_initcall_start here, you don't access the
first element of your array, but actually the zero padding before your
struct.

On my system the section was aligned on an 8 bytes boundary, which means
there were 24 bytes of padding before the symbol you try to access.



	Joerg

Re: AMD-IOMMU and problem with __init(data)?

[Alexander Holler]

Am 29.09.2015 um 17:06 schrieb Joerg Roedel:
> As expected it is no bug in the AMD IOMMU driver, but in your code.
>
> On Wed, Sep 23, 2015 at 09:04:31PM +0200, Alexander Holler wrote:
>> struct _annotated_initcall {
>> 	initcall_t initcall;
>> 	unsigned driver_id;
>> 	unsigned *dependencies;
>> 	struct device_driver *driver;
>> };
>
> This struct gets aligned on a 32 bytes boundary.
>
>> +#define ANNOTATED_INITCALLS						\
>> +		VMLINUX_SYMBOL(__annotated_initcall_start) = .;		\
>> +		*(.annotated_initcall.init)				\
>> +		VMLINUX_SYMBOL(__annotated_initcall_end) = .;
>
> But this section does not.
>
>> +	ac = __annotated_initcall_start;
>> +	pr_info("ac %p ID %u\n", ac, ac->driver_id);
>> +	BUG_ON(ac->driver_id != 23);
>
> So when you access __annotated_initcall_start here, you don't access the
> first element of your array, but actually the zero padding before your
> struct.
>
> On my system the section was aligned on an 8 bytes boundary, which means
> there were 24 bytes of padding before the symbol you try to access.

Hmm. Thanks a lot. Also I've checked the alignment (at least twice) and 
remember it was 32bit. But maybe I've checked something different or 
looked at some file for ARM or x86(_32) or was confused or similar. But 
now, when I look at ARM the initcall section seems to be aligned to 8 
too. So I wonder why the stuff works on ARM (v5 and v7) and on an Intel 
Atom (32bit). I think at least the armv5 box should have trapped (fatal) 
too, but maybe that changed.

Sorry for not having looked at the alignment at least once more. 
Alignment bugs are always hard to see and I've already assumed such, 
especially because any other kernel seems to work, but I was obviously 
unable to see it.

Again, thanks a lot.

Regards,

Alexander Holler