[Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting

[Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting

[Lennart Sorensen]

So I did some experiments on 3.12 kernel on an omap5726.

Xenomai/ipipe seems to work great (after all it managed to pass the
xenomai test suite).

LPAE+KVM also works great.

However if you enable LPAE (with or without KVM) while ipipe is enabled
(with or without xenomai enabled), then the kernel never boots (no
console messages at all).

Any ideas where to start on debugging this problem?

-- 
Len Sorensen

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting

[Gilles Chanteperdrix]

On 08/28/2014 10:35 PM, Lennart Sorensen wrote:
> So I did some experiments on 3.12 kernel on an omap5726.
> 
> Xenomai/ipipe seems to work great (after all it managed to pass the
> xenomai test suite).
> 
> LPAE+KVM also works great.
> 
> However if you enable LPAE (with or without KVM) while ipipe is enabled
> (with or without xenomai enabled), then the kernel never boots (no
> console messages at all).
> 
> Any ideas where to start on debugging this problem?

Chances are high that the kernel starts booting, but encounters a 
problem before enabling the console. In order to get the traces, see:

http://xenomai.org/2014/06/porting-xenomai-to-a-new-arm-soc/#The_kernel_stops_after_the_message_8220Uncompressing_Linux8230_done_booting_the_kernel8221

-- 
                                                                Gilles.

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting

[Lennart Sorensen]

On Thu, Aug 28, 2014 at 10:40:03PM +0200, Gilles Chanteperdrix wrote:
> Chances are high that the kernel starts booting, but encounters a 
> problem before enabling the console. In order to get the traces, see:
> 
> http://xenomai.org/2014/06/porting-xenomai-to-a-new-arm-soc/#The_kernel_stops_after_the_message_8220Uncompressing_Linux8230_done_booting_the_kernel8221

Unfortunately the serial port is NOT 8250 on the omap5, although it is
a 16750 supposely, just driven by another driver (this is changing in
the future fortunately).

I will give it a try though.

It didn't occur to me to look at the porting docs given "it already
works". :)

-- 
Len Sorensen

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting

[Gilles Chanteperdrix]

On 08/28/2014 10:47 PM, Lennart Sorensen wrote:
> On Thu, Aug 28, 2014 at 10:40:03PM +0200, Gilles Chanteperdrix wrote:
>> Chances are high that the kernel starts booting, but encounters a 
>> problem before enabling the console. In order to get the traces, see:
>>
>> http://xenomai.org/2014/06/porting-xenomai-to-a-new-arm-soc/#The_kernel_stops_after_the_message_8220Uncompressing_Linux8230_done_booting_the_kernel8221
> 
> Unfortunately the serial port is NOT 8250 on the omap5, although it is
> a 16750 supposely, just driven by another driver (this is changing in
> the future fortunately).
> 
> I will give it a try though.
> 
> It didn't occur to me to look at the porting docs given "it already
> works". :)
> 

If you have JTAG with gdb server, then simply connect gdb and dump
printk_buf.

-- 
                                                                Gilles.

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting

[Lennart Sorensen]

On Thu, Aug 28, 2014 at 10:49:18PM +0200, Gilles Chanteperdrix wrote:
> If you have JTAG with gdb server, then simply connect gdb and dump
> printk_buf.

Yeah I guess I could do that, but then I have to use eclipse because it
is ti's debugger.  But I will if I have to.

-- 
Len Sorensen

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting

[Gilles Chanteperdrix]

On 08/28/2014 10:51 PM, Lennart Sorensen wrote:
> On Thu, Aug 28, 2014 at 10:49:18PM +0200, Gilles Chanteperdrix wrote:
>> If you have JTAG with gdb server, then simply connect gdb and dump
>> printk_buf.
> 
> Yeah I guess I could do that, but then I have to use eclipse because it
> is ti's debugger.  But I will if I have to.
> 
I understand the feeling about CCS. Maybe you can try openocd?

-- 
                                                                Gilles.

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting

[Lennart Sorensen]

On Thu, Aug 28, 2014 at 10:53:11PM +0200, Gilles Chanteperdrix wrote:
> I understand the feeling about CCS. Maybe you can try openocd?

I don't think it works with the interface we have.

-- 
Len Sorensen

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting

[Gilles Chanteperdrix]

On 08/28/2014 10:51 PM, Lennart Sorensen wrote:
> On Thu, Aug 28, 2014 at 10:49:18PM +0200, Gilles Chanteperdrix wrote:
>> If you have JTAG with gdb server, then simply connect gdb and dump
>> printk_buf.
> 
> Yeah I guess I could do that, but then I have to use eclipse because it
> is ti's debugger.  But I will if I have to.

Yet another solution is to enable early printk via the "DCC" channel,
which should normally get the early printks to be sent to the JTAG. You
can then ask your JTAG to display the messages.

The openocd command seems to be "target_request debugmsgs charmsg". I
have never tried this on TI processors, but I have tried it on other
processors with other JTAG, which shows that at least, on Linux side, it
works.

-- 
                                                                Gilles.

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting - now with crash message

[Lennart Sorensen]

On Thu, Aug 28, 2014 at 10:40:03PM +0200, Gilles Chanteperdrix wrote:
> On 08/28/2014 10:35 PM, Lennart Sorensen wrote:
> > So I did some experiments on 3.12 kernel on an omap5726.
> > 
> > Xenomai/ipipe seems to work great (after all it managed to pass the
> > xenomai test suite).
> > 
> > LPAE+KVM also works great.
> > 
> > However if you enable LPAE (with or without KVM) while ipipe is enabled
> > (with or without xenomai enabled), then the kernel never boots (no
> > console messages at all).
> > 
> > Any ideas where to start on debugging this problem?
> 
> Chances are high that the kernel starts booting, but encounters a 
> problem before enabling the console. In order to get the traces, see:
> 
> http://xenomai.org/2014/06/porting-xenomai-to-a-new-arm-soc/#The_kernel_stops_after_the_message_8220Uncompressing_Linux8230_done_booting_the_kernel8221

I made the assumption that an OMAP57xx was a lot like an OMAP54xx and
hence got earlyprintk working and we get this:

Starting kernel ...

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 3.12-1-am5726 (debian-kernel@lists.debian.org) (gcc version 4.7.2 (Debian 4.7.2-5) ) #1 SMP Debian 3.12.26-0.1 (2014-07-14)
[    0.000000] CPU: ARMv7 Processor [412fc0f2] revision 2 (ARMv7), cr=30c7387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] Machine: Generic DRA7XX (Flattened Device Tree), model: RCM RX1400
[    0.000000] bootconsole [earlycon0] enabled
[    0.000000] Memory policy: ECC disabled, Data cache writealloc
[    0.000000] PERCPU: Embedded 11 pages/cpu @c0fcd000 s23552 r8192 d13312 u45056
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 256016
[    0.000000] Kernel command line: root=/dev/mmcblk0p5 ro console=ttyO2,57600n8 rootwait 3 earlyprintk bootver=2014.04RR3
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 1012996K/1030144K available (4601K kernel code, 469K rwdata, 1900K rodata, 431K init, 523K bss, 17148K reserved, 251904K highmem)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
[    0.000000]     vmalloc : 0xf0000000 - 0xff000000   ( 240 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xef800000   ( 760 MB)
[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
[    0.000000]       .text : 0xc0008000 - 0xc0661a14   (6503 kB)
[    0.000000]       .init : 0xc0662000 - 0xc06cdc00   ( 431 kB)
[    0.000000]       .data : 0xc06ce000 - 0xc07435d8   ( 470 kB)
[    0.000000]        .bss : 0xc07435d8 - 0xc07c6370   ( 524 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] kmemleak: Kernel memory leak detector disabled
[    0.000000] OMAP clockevent source: timer1 at 32768 Hz
[    0.000000] sched_clock: 32 bits at 32kHz, resolution 30517ns, wraps every 131071999ms
[    0.000000] OMAP clocksource: 32k_counter at 32768 Hz
[    0.000000] Architected cp15 timer(s) running at 6.14MHz (phys).
[    0.000000] I-pipe, 6.144 MHz clocksource
[    0.000000] Switching to timer-based delay loop
[    0.000000] sched_clock: ARM arch timer >56 bits at 6144kHz, resolution 162ns
[    0.000000] Interrupt pipeline (release #1)
[   91.652385] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.28 BogoMIPS (lpj=6144)
[   91.673300] pid_max: default: 32768 minimum: 301
[   91.682962] Security Framework initialized
[   91.691510] Mount-cache hash table entries: 512
[   91.722838] CPU: Testing write buffer coherency: ok
[   91.733166] /cpus/cpu@0 missing clock-frequency property
[   91.744165] /cpus/cpu@1 missing clock-frequency property
[   91.755156] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[   91.766862] Setting up static identity map for 0xc045afd8 - 0xc045b030
[   91.780611] Unable to handle kernel NULL pointer dereference at virtual address 00000000
[   91.797264] pgd = c0003000, hw pgd = c0003000
[   91.806303] [00000000] *pgd=80000080004003, *pmd=00000000
[   91.817483] Internal error: Oops: 206 [#1] SMP ARM
[   91.827398] Modules linked in:
[   91.833781] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 3.12-1-am5726 #1 Debian 3.12.26-0.1
[   91.850599] task: ee8f0000 ti: ee8f4000 task.ti: ee8f4000
[   91.861761] PC is at _raw_spin_lock_irqsave+0x10/0x4c
[   91.872209] LR is at _raw_spin_lock_irqsave+0xc/0x4c
[   91.882479] pc : [<c0455c98>]    lr : [<c0455c94>]    psr: 20000153
[   91.882479] sp : ee8f5dc0  ip : 20000153  fp : c0d97760
[   91.906198] r10: 00000000  r9 : c006a46c  r8 : ee8f5e04
[   91.916997] r7 : 00000000  r6 : ee83ba40  r5 : c0743af4  r4 : 00000000
[   91.930451] r3 : c06c8b88  r2 : 00905000  r1 : 00000001  r0 : 00000000
[   91.943907] Flags: nzCv  IRQs on  FIQs off  Mode SVC_32  ISA ARM  Segment kernel
[   91.959131] Control: 30c5387d  Table: 80003000  DAC: fffffffd
[   91.970992] Process swapper/0 (pid: 1, stack limit = 0xee8f4248)
[   91.983385] Stack: (0xee8f5dc0 to 0xee8f6000)
[   91.992419] 5dc0: c0d97760 c04502ac ee8f5dec c007a32c 0000071f ee83b9c0 ee8d2200 ee83ba00
[   92.009239] 5de0: c0743af4 ee83ba40 00000000 c045051c ee8f5e04 ee8690e0 00000000 c007c52c
[   92.026058] 5e00: c06db5f8 00000002 ee8d2100 ee8d2200 ee8d2258 ee8d2100 ee83ba00 c06db5f8
[   92.042877] 5e20: c06d6aa8 c006a46c ee804400 ee8d2100 ee83b9c0 ee8d2200 ee83ba00 ee8d2110
[   92.059695] 5e40: ee83ba40 00000000 00000000 c006a46c 00000002 ee8d2100 ee8d2110 00000002
[   92.076515] 5e60: ee8d2108 c0746764 c06d6aa8 00000000 c0460ba4 c006a604 00000055 00000001
[   92.093333] 5e80: ee8d2168 00000000 ee8d50c8 00000000 ee8f5ec4 ee8d50c0 ffffffec 00000000
[   92.110151] 5ea0: c06d6534 00000001 c06d6528 c0746898 c06d6aa8 c07468a0 c0460ba4 c0676314
[   92.126970] 5ec0: 00000000 c06d6aa8 ee8f4000 ee8f5ed4 00000000 ffffffec 00000000 c06c7840
[   92.143789] 5ee0: c06c7870 00000000 00000000 c0676044 ee8f4000 00000000 00000000 c0008c78
[   92.160607] 5f00: 00000000 00000000 00000000 c008b2e0 c059bc00 ee8f5f44 00000000 c044f028
[   92.177426] 5f20: c059bc6c ee8f5f44 00905000 c07439a0 80000000 00000002 00000000 c00287f0
[   92.194244] 5f40: c059bc04 00000000 ffffffff 00000000 00000000 c06c7840 c06c7870 00000000
[   92.211062] 5f60: 00000000 00000000 00000000 00000000 00000000 c0662adc 00000026 c00790e0
[   92.227880] 5f80: ee8f0000 c0fd1d40 00000000 c044bea4 00000000 00000000 00000000 00000000
[   92.244698] 5fa0: 00000000 c044beac 00000000 c001db20 00000000 00000000 00000000 00000000
[   92.261515] 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[   92.278334] 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000 646b66f7 f71f7b59
[   92.295163] [<c0455c98>] (_raw_spin_lock_irqsave+0x10/0x4c) from [<c04502ac>] (free_debug_processing+0x28/0x260)
[   92.316057] [<c04502ac>] (free_debug_processing+0x28/0x260) from [<c045051c>] (__slab_free+0x38/0x2a0)
[   92.335184] [<c045051c>] (__slab_free+0x38/0x2a0) from [<c006a46c>] (apply_workqueue_attrs+0x1a0/0x22c)
[   92.354485] [<c006a46c>] (apply_workqueue_attrs+0x1a0/0x22c) from [<c006a604>] (__alloc_workqueue_key+0x10c/0x3a0)
[   92.375733] [<c006a604>] (__alloc_workqueue_key+0x10c/0x3a0) from [<c0676314>] (init_workqueues+0x2d0/0x3d8)
[   92.395917] [<c0676314>] (init_workqueues+0x2d0/0x3d8) from [<c0008c78>] (do_one_initcall+0xe4/0x140)
[   92.414863] [<c0008c78>] (do_one_initcall+0xe4/0x140) from [<c0662adc>] (kernel_init_freeable+0x64/0x1cc)
[   92.434516] [<c0662adc>] (kernel_init_freeable+0x64/0x1cc) from [<c044beac>] (kernel_init+0x8/0xe4)
[   92.453108] [<c044beac>] (kernel_init+0x8/0xe4) from [<c001db20>] (ret_from_fork+0x18/0x38)
[   92.470282] Code: e92d4010 e1a04000 ebef4bd5 e1a00380 (e1943f9f) 
[   92.482882] ---[ end trace 1b75b31a2719ed1c ]---
[   92.492480] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
[   92.492480] 

-- 
MLen Sorensen

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting - now with crash message

[Gilles Chanteperdrix]

On 08/29/2014 12:01 AM, Lennart Sorensen wrote:
> [   91.861761] PC is at _raw_spin_lock_irqsave+0x10/0x4c
> [   91.872209] LR is at _raw_spin_lock_irqsave+0xc/0x4c
> [   91.882479] pc : [<c0455c98>]    lr : [<c0455c94>]    psr: 20000153
> [   91.882479] sp : ee8f5dc0  ip : 20000153  fp : c0d97760
> [   91.906198] r10: 00000000  r9 : c006a46c  r8 : ee8f5e04
> [   91.916997] r7 : 00000000  r6 : ee83ba40  r5 : c0743af4  r4 : 00000000
> [   91.930451] r3 : c06c8b88  r2 : 00905000  r1 : 00000001  r0 : 00000000

You have to disassemble _raw_spin_lock_irqsave to see what is at offset
0x10, and where it can come from.

-- 
                                                                Gilles.

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting - now with crash message

[Lennart Sorensen]

On Fri, Aug 29, 2014 at 12:13:02AM +0200, Gilles Chanteperdrix wrote:
> On 08/29/2014 12:01 AM, Lennart Sorensen wrote:
> > [   91.861761] PC is at _raw_spin_lock_irqsave+0x10/0x4c
> > [   91.872209] LR is at _raw_spin_lock_irqsave+0xc/0x4c
> > [   91.882479] pc : [<c0455c98>]    lr : [<c0455c94>]    psr: 20000153
> > [   91.882479] sp : ee8f5dc0  ip : 20000153  fp : c0d97760
> > [   91.906198] r10: 00000000  r9 : c006a46c  r8 : ee8f5e04
> > [   91.916997] r7 : 00000000  r6 : ee83ba40  r5 : c0743af4  r4 : 00000000
> > [   91.930451] r3 : c06c8b88  r2 : 00905000  r1 : 00000001  r0 : 00000000
> 
> You have to disassemble _raw_spin_lock_irqsave to see what is at offset
> 0x10, and where it can come from.

I will give that a try next week when i am back at work.

-- 
Len Sorensen

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting - now with crash message

[Lennart Sorensen]

On Thu, Aug 28, 2014 at 07:16:25PM -0400, Lennart Sorensen wrote:
> On Fri, Aug 29, 2014 at 12:13:02AM +0200, Gilles Chanteperdrix wrote:
> > On 08/29/2014 12:01 AM, Lennart Sorensen wrote:
> > > [   91.861761] PC is at _raw_spin_lock_irqsave+0x10/0x4c
> > > [   91.872209] LR is at _raw_spin_lock_irqsave+0xc/0x4c
> > > [   91.882479] pc : [<c0455c98>]    lr : [<c0455c94>]    psr: 20000153
> > > [   91.882479] sp : ee8f5dc0  ip : 20000153  fp : c0d97760
> > > [   91.906198] r10: 00000000  r9 : c006a46c  r8 : ee8f5e04
> > > [   91.916997] r7 : 00000000  r6 : ee83ba40  r5 : c0743af4  r4 : 00000000
> > > [   91.930451] r3 : c06c8b88  r2 : 00905000  r1 : 00000001  r0 : 00000000
> > 
> > You have to disassemble _raw_spin_lock_irqsave to see what is at offset
> > 0x10, and where it can come from.
> 
> I will give that a try next week when i am back at work.

OK so far I have:

static noinline struct kmem_cache_node *free_debug_processing(
        struct kmem_cache *s, struct page *page, void *object,
        unsigned long addr, unsigned long *flags)
{
        struct kmem_cache_node *n = get_node(s, page_to_nid(page));

pr_info("n: %p flags: %p\n", n, flags);
        spin_lock_irqsave(&n->list_lock, *flags);
        slab_lock(page);

        if (!check_slab(s, page))
                goto fail;

        if (!check_valid_pointer(s, page, object)) {
                slab_err(s, page, "Invalid object pointer 0x%p", object);
                goto fail;
        }

prints out:

[  176.234145] n:   (null) flags: ee8f5e04

n being NULL is obviously a bad thing.

-- 
Len Sorensen

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting - now with crash message

[Lennart Sorensen]

On Wed, Sep 03, 2014 at 08:54:22AM -0400, Lennart Sorensen wrote:
> OK so far I have:
> 
> static noinline struct kmem_cache_node *free_debug_processing(
>         struct kmem_cache *s, struct page *page, void *object,
>         unsigned long addr, unsigned long *flags)
> {
>         struct kmem_cache_node *n = get_node(s, page_to_nid(page));
> 
> pr_info("n: %p flags: %p\n", n, flags);
>         spin_lock_irqsave(&n->list_lock, *flags);
>         slab_lock(page);
> 
>         if (!check_slab(s, page))
>                 goto fail;
> 
>         if (!check_valid_pointer(s, page, object)) {
>                 slab_err(s, page, "Invalid object pointer 0x%p", object);
>                 goto fail;
>         }
> 
> prints out:
> 
> [  176.234145] n:   (null) flags: ee8f5e04
> 
> n being NULL is obviously a bad thing.

So if I turn of SLUB_DEBUG, then I don't enter that code and it gets
further, but then I get:

[  433.393529] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[  433.405234] Setting up static identity map for 0xc0458758 - 0xc04587b0
[  434.418708] CPU1: failed to come online
[  434.426710] Brought up 1 CPUs
[  434.432918] SP: Total of 1 processors activated.
[  434.442663] CPU: All CPU(s) started in HYP mode.
[  434.452232] CPU: Virtualization extensions available.

which interestingly is right around the same message where it was crashing
with SLUB_DEBUG enabled (where debug functions seemed to be getting
called with an invalid kmem_cache)

Also:

[  434.528377] WARNING: CPU: 0 PID: 1 at /tmp/linux/linux-3.12.26.rr1/arch/arm/mach-omap2/omap_hwmod.c:2574 _init+0x4c0/0x50c()
[  434.551394] omap_hwmod: uart3: doesn't have mpu register target base
[  434.564501] Modules linked in:
[  434.570890] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 3.12-1-am5726 #1 Debian 3.12.26-0.1
[  434.587734] [<c0024fd0>] (unwind_backtrace+0x0/0xf8) from [<c00214ac>] (show_stack+0x10/0x14)
[  434.605277] [<c00214ac>] (show_stack+0x10/0x14) from [<c044f130>] (dump_stack+0x70/0x8c)
[  434.621935] [<c044f130>] (dump_stack+0x70/0x8c) from [<c00504a4>] (warn_slowpath_common+0x68/0x8c)
[  434.640358] [<c00504a4>] (warn_slowpath_common+0x68/0x8c) from [<c005055c>] (warn_slowpath_fmt+0x30/0x40)
[  434.660018] [<c005055c>] (warn_slowpath_fmt+0x30/0x40) from [<c066b220>] (_init+0x4c0/0x50c)
[  434.677383] [<c066b220>] (_init+0x4c0/0x50c) from [<c003aab4>] (omap_hwmod_for_each+0x30/0x5c)
[  434.695100] [<c003aab4>] (omap_hwmod_for_each+0x30/0x5c) from [<c066b728>] (__omap_hwmod_setup_all+0x24/0x40)
[  434.715470] [<c066b728>] (__omap_hwmod_setup_all+0x24/0x40) from [<c0008c78>] (do_one_initcall+0xe4/0x140)
[  434.735309] [<c0008c78>] (do_one_initcall+0xe4/0x140) from [<c065fb78>] (kernel_init_freeable+0x100/0x1cc)
[  434.755148] [<c065fb78>] (kernel_init_freeable+0x100/0x1cc) from [<c0449b2c>] (kernel_init+0x8/0xe4)
[  434.773923] [<c0449b2c>] (kernel_init+0x8/0xe4) from [<c001db20>] (ret_from_fork+0x18/0x38)

and

[  435.976369] NET: Registered protocol family 1
[  435.986006] kvm [1]: interrupt-controller@48214000 IRQ25
[  435.997131] kvm [1]: timer IRQ27
[  436.003886] kvm [1]: Hyp mode initialized successfully
[  436.017503] audit: initializing netlink socket (disabled)
[  436.028800] type=2000 audit(1.478:1): initialized
[  436.128627] bounce pool size: 64 pages
[  436.143714] Unable to handle kernel NULL pointer dereference at virtual address 00000003
[  436.160397] pgd = c0003000, hw pgd = c0003000
[  436.169438] [00000003] *pgd=80000080004003, *pmd=00000000
[  436.180623] Internal error: Oops: a06 [#1] SMP ARM
[  436.190538] Modules linked in:
[  436.196921] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G        W    3.12-1-am5726 #1 Debian 3.12.26-0.1
[  436.215685] task: ee8f0000 ti: ee8f4000 task.ti: ee8f4000
[  436.226845] PC is at _test_and_set_bit+0x4/0x48
[  436.236235] LR is at unfreeze_partials+0xa0/0x188
[  436.245975] pc : [<c0230114>]    lr : [<c0124880>]    psr: 20000153
[  436.245975] sp : ee8f5e88  ip : 00000003  fp : 538df7d0
[  436.269694] r10: c169b760  r9 : c07419f4  r8 : 00000000
[  436.280494] r7 : 00000000  r6 : 54763746  r5 : d38df7d0  r4 : e20bb003
[  436.293948] r3 : 00000053  r2 : 00000000  r1 : e20bb003  r0 : 00000000
[  436.307404] Flags: nzCv  IRQs on  FIQs off  Mode SVC_32  ISA ARM  Segment kernel
[  436.322628] Control: 30c5387d  Table: 80003000  DAC: fffffffd
[  436.334490] Process swapper/0 (pid: 1, stack limit = 0xee8f4248)
[  436.346884] Stack: (0xee8f5e88 to 0xee8f6000)
[  436.355916] 5e80:                   00000000 eeb1a040 eeb21280 538df7d0 8040003f c044df50
[  436.372735] 5ea0: 8040003f 00000000 eeb21280 c0d95760 00000000 c06d95f8 c06d4aa8 00000001
[  436.389554] 5ec0: c07419f4 c065f510 00000000 c044dda0 ee83bd40 c07b4a24 c06aeae8 c0741500
[  436.406373] 5ee0: c067e478 ee8f4000 c065f510 c067e538 00000000 c06c4998 00000006 c0008c78
[  436.423192] 5f00: 00000064 c0fc8bf6 00000000 00000000 00000000 c063326c 00000072 ee8f5f30
[  436.440011] 5f20: c006cd00 c0237744 20000153 ffffffff c0fc8c04 c04906b4 00000064 c006cf24
[  436.456830] 5f40: c05e7ba0 c0632e8c 00000006 00000006 c0707874 c06c4998 00000006 c06aeae8
[  436.473649] 5f60: c0741500 00000064 c06aeaf4 c065f510 00000000 c065fb78 00000006 00000006
[  436.490467] 5f80: c065f510 c0fcfd40 00000000 c0449b24 00000000 00000000 00000000 00000000
[  436.507286] 5fa0: 00000000 c0449b2c 00000000 c001db20 00000000 00000000 00000000 00000000
[  436.524104] 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[  436.540923] 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000 646b66f7 f71f7b59
[  436.557749] [<c0230114>] (_test_and_set_bit+0x4/0x48) from [<c0124880>] (unfreeze_partials+0xa0/0x188)
[  436.576875] [<c0124880>] (unfreeze_partials+0xa0/0x188) from [<c044dda0>] (put_cpu_partial+0x90/0x138)
[  436.596000] [<c044dda0>] (put_cpu_partial+0x90/0x138) from [<c067e538>] (slab_sysfs_init+0xc0/0x10c)
[  436.614769] [<c067e538>] (slab_sysfs_init+0xc0/0x10c) from [<c0008c78>] (do_one_initcall+0xe4/0x140)
[  436.633538] [<c0008c78>] (do_one_initcall+0xe4/0x140) from [<c065fb78>] (kernel_init_freeable+0x100/0x1cc)
[  436.653368] [<c065fb78>] (kernel_init_freeable+0x100/0x1cc) from [<c0449b2c>] (kernel_init+0x8/0xe4)
[  436.672136] [<c0449b2c>] (kernel_init+0x8/0xe4) from [<c001db20>] (ret_from_fork+0x18/0x38)
[  436.689310] Code: e3500000 13a00001 e12fff1e e211c003 (15cc1000) 
[  436.701913] ---[ end trace 1b75b31a2719ed1d ]---
[  436.711532] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b

Given one of the cores didn't come online, it clearly still is far
from happy.

Any idea which parts of memory management IPIPE might mess around with?

-- 
Len Sorensen

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting - now with crash message

[Gilles Chanteperdrix]

On 09/03/2014 03:21 PM, Lennart Sorensen wrote:
> On Wed, Sep 03, 2014 at 08:54:22AM -0400, Lennart Sorensen wrote:
>> OK so far I have:
>>
>> static noinline struct kmem_cache_node *free_debug_processing(
>>         struct kmem_cache *s, struct page *page, void *object,
>>         unsigned long addr, unsigned long *flags)
>> {
>>         struct kmem_cache_node *n = get_node(s, page_to_nid(page));
>>
>> pr_info("n: %p flags: %p\n", n, flags);

The next thing to do is to check the get_node and page_to_nid code to
see how this can result in a NULL pointer. Even before that, is the page
pointer valid?

-- 
                                                                Gilles.

Re: [Xenomai] Xenomai/Ipipe on arm with LPAE enabled not booting - now with crash message

[Lennart Sorensen]

On Wed, Sep 03, 2014 at 03:39:41PM +0200, Gilles Chanteperdrix wrote:
> On 09/03/2014 03:21 PM, Lennart Sorensen wrote:
> > On Wed, Sep 03, 2014 at 08:54:22AM -0400, Lennart Sorensen wrote:
> >> OK so far I have:
> >>
> >> static noinline struct kmem_cache_node *free_debug_processing(
> >>         struct kmem_cache *s, struct page *page, void *object,
> >>         unsigned long addr, unsigned long *flags)
> >> {
> >>         struct kmem_cache_node *n = get_node(s, page_to_nid(page));
> >>
> >> pr_info("n: %p flags: %p\n", n, flags);
> 
> The next thing to do is to check the get_node and page_to_nid code to
> see how this can result in a NULL pointer. Even before that, is the page
> pointer valid?

That's a good question.

Just for curiousity I tried using SLAB instead of SLUB and got this:

[  393.237099] Setting up static identity map for 0xc04584d8 - 0xc0458530
[  393.250644] Unable to handle kernel NULL pointer dereference at virtual address 00000000
[  393.267294] pgd = c0003000, hw pgd = c0003000
[  393.276332] [00000000] *pgd=80000080004003, *pmd=00000000
[  393.287511] Internal error: Oops: 206 [#1] SMP ARM
[  393.297424] Modules linked in:
[  393.303807] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 3.12-1-am5726 #1 Debian 3.12.26-0.1
[  393.320625] task: ee8e59c0 ti: ee8e6000 task.ti: ee8e6000
[  393.331788] PC is at kfree+0x74/0x148
[  393.339405] LR is at kfree+0x10c/0x148
[  393.347197] pc : [<c0125024>]    lr : [<c01250bc>]    psr: 60000153
[  393.347197] sp : ee8e7dd0  ip : a0000153  fp : 00000002
[  393.370915] r10: 00000000  r9 : 0000003c  r8 : c06d45b8
[  393.381715] r7 : 00000000  r6 : c0741934  r5 : ee850900  r4 : 00000000
[  393.395169] r3 : 00000000  r2 : 0000073f  r1 : ee850900  r0 : ee850900
[  393.408624] Flags: nZCv  IRQs on  FIQs off  Mode SVC_32  ISA ARM  Segment kernel
[  393.423847] Control: 30c5387d  Table: 80003000  DAC: fffffffd
[  393.435708] Process swapper/0 (pid: 1, stack limit = 0xee8e6248)
[  393.448101] Stack: (0xee8e7dd0 to 0xee8e8000)
[  393.457133] 7dc0:                                     00000002 ee844740 c06d4520 000000d0
[  393.473952] 7de0: ee850900 c012527c 0000005b 00000008 ee8e5140 ee844740 0000003c 00000078
[  393.490771] 7e00: 000000d0 00000000 00001000 00001000 00000000 c01254a8 000000d0 ee844740
[  393.507590] 7e20: 00040000 ee844740 00040000 00000100 00000100 c0125fbc 00000010 00000000
[  393.524408] 7e40: 00000104 00000100 00000000 00000001 000000d0 00000039 c05a6d64 ee844740
[  393.541227] 7e60: 00000100 00040000 00000100 c05a6d64 ee8e6000 c07aeea4 00000000 c01063e4
[  393.558046] 7e80: 00000100 00000100 c05a6d64 00000000 00000000 c067304c 00000000 c0106500
[  393.574865] 7ea0: 00040000 00000000 00000000 00000000 00000000 ffffffff c06c472c c0673080
[  393.591682] 7ec0: 00000000 c06d4aa8 ee8e6000 00000000 00000000 ffffffec 00000000 c06c46fc
[  393.608501] 7ee0: c06c472c 00000000 00000000 c067304c ee8e6000 00000000 00000000 c0008c78
[  393.625320] 7f00: 00000000 00000000 00000000 c008b2e0 c0599500 ee8e7f44 00000000 c044ce58
[  393.642139] 7f20: c05995cc ee8e7f44 00906000 c07417e0 80000000 00000002 00000000 c00287f0
[  393.658958] 7f40: c0599564 00000000 ffffffff 00000000 00000000 c06c46fc c06c472c 00000000
[  393.675776] 7f60: 00000000 00000000 00000000 00000000 00000000 c065fadc 00000026 c00790e0
[  393.692593] 7f80: ee8e59c0 c0fcfd40 00000000 c0449ac4 00000000 00000000 00000000 00000000
[  393.709412] 7fa0: 00000000 c0449acc 00000000 c001db20 00000000 00000000 00000000 00000000
[  393.726231] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[  393.743049] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000 00000000 00000000
[  393.759875] [<c0125024>] (kfree+0x74/0x148) from [<c012527c>] (__do_tune_cpucache+0x184/0x35c)
[  393.777583] [<c012527c>] (__do_tune_cpucache+0x184/0x35c) from [<c01254a8>] (enable_cpucache+0x54/0xd0)
[  393.796884] [<c01254a8>] (enable_cpucache+0x54/0xd0) from [<c0125fbc>] (__kmem_cache_create+0x21c/0x2c0)
[  393.816360] [<c0125fbc>] (__kmem_cache_create+0x21c/0x2c0) from [<c01063e4>] (kmem_cache_create_memcg+0x94/0x174)
[  393.837426] [<c01063e4>] (kmem_cache_create_memcg+0x94/0x174) from [<c0106500>] (kmem_cache_create+0x3c/0x44)
[  393.857790] [<c0106500>] (kmem_cache_create+0x3c/0x44) from [<c0673080>] (init_workqueues+0x34/0x3d8)
[  393.876736] [<c0673080>] (init_workqueues+0x34/0x3d8) from [<c0008c78>] (do_one_initcall+0xe4/0x140)
[  393.895505] [<c0008c78>] (do_one_initcall+0xe4/0x140) from [<c065fadc>] (kernel_init_freeable+0x64/0x1cc)
[  393.915159] [<c065fadc>] (kernel_init_freeable+0x64/0x1cc) from [<c0449acc>] (kernel_init+0x8/0xe4)
[  393.933751] [<c0449acc>] (kernel_init+0x8/0xe4) from [<c001db20>] (ret_from_fork+0x18/0x38)
[  393.950925] Code: e0863103 e3120502 e5934054 0a000023 (e894000c) 
[  393.963524] ---[ end trace 1b75b31a2719ed1c ]---
[  393.973120] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b

So it too thinks there is something wrong with the init_workqueues startup.

The SLUB stack trace was:

[   92.295163] [<c0455c98>] (_raw_spin_lock_irqsave+0x10/0x4c) from [<c04502ac>] (free_debug_processing+0x28/0x260)                                                                                                                                                            
[   92.316057] [<c04502ac>] (free_debug_processing+0x28/0x260) from [<c045051c>] (__slab_free+0x38/0x2a0)                                                                                                                                                                      
[   92.335184] [<c045051c>] (__slab_free+0x38/0x2a0) from [<c006a46c>] (apply_workqueue_attrs+0x1a0/0x22c)                                                                                                                                                                     
[   92.354485] [<c006a46c>] (apply_workqueue_attrs+0x1a0/0x22c) from [<c006a604>] (__alloc_workqueue_key+0x10c/0x3a0)                                                                                                                                                          
[   92.375733] [<c006a604>] (__alloc_workqueue_key+0x10c/0x3a0) from [<c0676314>] (init_workqueues+0x2d0/0x3d8)                                                                                                                                                                
[   92.395917] [<c0676314>] (init_workqueues+0x2d0/0x3d8) from [<c0008c78>] (do_one_initcall+0xe4/0x140)                                                                                                                                                                       
[   92.414863] [<c0008c78>] (do_one_initcall+0xe4/0x140) from [<c0662adc>] (kernel_init_freeable+0x64/0x1cc)                                                                                                                                                                   
[   92.434516] [<c0662adc>] (kernel_init_freeable+0x64/0x1cc) from [<c044beac>] (kernel_init+0x8/0xe4)                                                                                                                                                                         
[   92.453108] [<c044beac>] (kernel_init+0x8/0xe4) from [<c001db20>] (ret_from_fork+0x18/0x38)                                                                                                                                                                                 

So init_workqueues calls
        pwq_cache = KMEM_CACHE(pool_workqueue, SLAB_PANIC);

which blows up with SLAB, while with SLUB we blow up while doing these
calls slightly later in init_workqueues:

        system_wq = alloc_workqueue("events", 0, 0);
        system_highpri_wq = alloc_workqueue("events_highpri", WQ_HIGHPRI, 0);
        system_long_wq = alloc_workqueue("events_long", 0, 0);
        system_unbound_wq = alloc_workqueue("events_unbound", WQ_UNBOUND,
                                            WQ_UNBOUND_MAX_ACTIVE);
        system_freezable_wq = alloc_workqueue("events_freezable",
                                              WQ_FREEZABLE, 0);
        system_power_efficient_wq = alloc_workqueue("events_power_efficient",
                                              WQ_POWER_EFFICIENT, 0);
        system_freezable_power_efficient_wq = alloc_workqueue("events_freezable_power_efficient",
                                              WQ_FREEZABLE | WQ_POWER_EFFICIENT,
                                              0);

-- 
Len Sorensen