[Xenomai] kernel NULL pointer dereference

[Xenomai] kernel NULL pointer dereference

[Henri Roosen]

Hi,

I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
(d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
I reserved one cpu (kernel param isolcpus=1).

Our application triggers the following NULL pointer dereference when I
set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
The application does not trigger this when all tasks have the same
affinity (set via /proc/xenomai/affinity).

I was able to reproduce this also under QEMU and will do some
debugging, but maybe someone knows what is wrong already by seeing the
stacktrace below:

[  108.013023] BUG: unable to handle kernel NULL pointer dereference at 00000294
[  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
[  108.013901] *pde = 36fa6067 *pte = 00000000
[  108.013901] Oops: 0000 [#1] PREEMPT SMP
[  108.013901] Modules linked in: platform_edge(O) sigmatek_lrt(O) usbhid
[  108.013901]
[  108.013901] Pid: 248, comm: cyclic:217:248 Tainted: G           O
3.4.6+ #62 Bochs Bochs
[  108.013901] EIP: 0060:[<c0126a91>] EFLAGS: 00213002 CPU: 1
[  108.013901] EIP is at __lock_task_sighand+0x53/0xc3
[  108.013901] EAX: 00000294 EBX: 00000000 ECX: 00000000 EDX: 00000000
[  108.013901] ESI: fffffffd EDI: f4b83d44 EBP: f4b83d34 ESP: f4b83d20
[  108.013901]  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[  108.013901] CR0: 8005003b CR2: 00000294 CR3: 36f9c000 CR4: 00000690
[  108.013901] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[  108.013901] DR6: ffff0ff0 DR7: 00000400
[  108.013901] Process cyclic:217:248 (pid: 248, ti=f4b82000
task=f4b48c80 task.ti=f4b82000)
[  108.013901] I-pipe domain Linux
[  108.013901] Stack:
[  108.013901]  00000000 00000294 00000000 fffffffd 00000000 f4b83d54
c0127971 f4b83d7c
[  108.013901]  0000001c 00000000 0000001c 00000000 f4b83dfc f4b83d64
c0127b9b 00000000
[  108.013901]  00001e02 f4b83e08 c0169674 0000001c c05e3e78 f4b83d7c
c056f538 0000001c
[  108.013901] Call Trace:
[  108.013901]  [<c0127971>] do_send_sig_info+0x23/0x5d
[  108.013901]  [<c0127b9b>] send_sig_info+0x19/0x1f
[  108.013901]  [<c0169674>] lostage_handler+0xf6/0x13a
[  108.013901]  [<c015f47a>] rthal_apc_handler+0x65/0x9c
[  108.013901]  [<c0155fbf>] __ipipe_do_sync_stage+0x108/0x15c
[  108.013901]  [<c0156049>] __ipipe_do_sync_pipeline+0x36/0x74
[  108.013901]  [<c0156288>] __ipipe_dispatch_irq+0x152/0x19d
[  108.013901]  [<c01124b5>] __ipipe_handle_irq+0x50/0x106
[  108.013901]  [<c011258a>] ipipe_raise_irq+0x1f/0x27
[  108.013901]  [<c01603a9>] ? xnheap_test_and_free+0x27e/0x288
[  108.013901]  [<c01603a9>] ? xnheap_test_and_free+0x27e/0x288
[  108.013901]  [<c0162669>] __xnpod_schedule+0x36/0x508
[  108.013901]  [<c016858a>] ? xnshadow_ppd_get+0x57/0x64
[  108.013901]  [<c016944a>] xnpod_schedule+0x32/0x34
[  108.013901]  [<c01699af>] taskexit_event+0xe4/0x149
[  108.013901]  [<c0157079>] ipipe_kevent_hook+0x17/0x1a
[  108.013901]  [<c0155ba5>] __ipipe_notify_kevent+0x3d/0x4e
[  108.013901]  [<c011f900>] do_exit+0x1d1/0x66b
[  108.013901]  [<c015703f>] ? ipipe_syscall_hook+0x2e/0x32
[  108.013901]  [<c011fe49>] sys_exit+0x13/0x13
[  108.013901]  [<c03d718a>] syscall_call+0x7/0xb
[  108.013901] Code: 19 d2 9d 83 fa 01 19 d2 81 e2 00 02 00 00 9c fa
64 a1 d8 b3 54 c0 8d 80 fc bc 54 c0 0f ba 28 00 9d 89 17 e8 04 cc 02
00 8b 45 f0 <8b> 30 85 f6 75 1c e8 0d da 02 00 8b 07 f6 c4 02 75 07 b8
01 00
[  108.013901] EIP: [<c0126a91>] __lock_task_sighand+0x53/0xc3 SS:ESP
0068:f4b83d20
[  108.013901] CR2: 0000000000000294
[  108.013901] ---[ end trace e6b28d16f226c997 ]---
[  108.013901] Kernel panic - not syncing: Fatal exception in interrupt

Thanks,
Henri

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/04/2012 03:42 PM, Henri Roosen wrote:
> Hi,
> 
> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
> I reserved one cpu (kernel param isolcpus=1).
> 
> Our application triggers the following NULL pointer dereference when I
> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
> The application does not trigger this when all tasks have the same
> affinity (set via /proc/xenomai/affinity).
> 
> I was able to reproduce this also under QEMU and will do some
> debugging, but maybe someone knows what is wrong already by seeing the
> stacktrace below:

Could you try to reduce the bug to a simple testcase which we would try
and run to reproduce?

> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
at 00000294
> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3

Or send us a disassembly of the function __lock_task_sighand?

-- 
					    Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Henri Roosen]

On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
<gilles.chanteperdrix@xenomai.org> wrote:
> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>> Hi,
>>
>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>> I reserved one cpu (kernel param isolcpus=1).
>>
>> Our application triggers the following NULL pointer dereference when I
>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>> The application does not trigger this when all tasks have the same
>> affinity (set via /proc/xenomai/affinity).
>>
>> I was able to reproduce this also under QEMU and will do some
>> debugging, but maybe someone knows what is wrong already by seeing the
>> stacktrace below:
>
> Could you try to reduce the bug to a simple testcase which we would try
> and run to reproduce?
>
>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
> at 00000294
>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>
> Or send us a disassembly of the function __lock_task_sighand?

Please find the disassembly of the __lock_task_sighand below:

00000e3a <__lock_task_sighand>:
     e3a:       55                      push   %ebp
     e3b:       89 e5                   mov    %esp,%ebp
     e3d:       57                      push   %edi
     e3e:       89 d7                   mov    %edx,%edi
     e40:       56                      push   %esi
     e41:       53                      push   %ebx
     e42:       83 ec 08                sub    $0x8,%esp
     e45:       89 45 ec                mov    %eax,-0x14(%ebp)
     e48:       05 94 02 00 00          add    $0x294,%eax
     e4d:       89 45 f0                mov    %eax,-0x10(%ebp)
     e50:       9c                      pushf
     e51:       fa                      cli
     e52:       64 a1 00 00 00 00       mov    %fs:0x0,%eax
     e58:       8d 80 00 00 00 00       lea    0x0(%eax),%eax
     e5e:       0f ba 20 00             btl    $0x0,(%eax)
     e62:       19 d2                   sbb    %edx,%edx
     e64:       9d                      popf
     e65:       83 fa 01                cmp    $0x1,%edx
     e68:       19 d2                   sbb    %edx,%edx
     e6a:       81 e2 00 02 00 00       and    $0x200,%edx
     e70:       9c                      pushf
     e71:       fa                      cli
     e72:       64 a1 00 00 00 00       mov    %fs:0x0,%eax
     e78:       8d 80 00 00 00 00       lea    0x0(%eax),%eax
     e7e:       0f ba 28 00             btsl   $0x0,(%eax)
     e82:       9d                      popf
     e83:       89 17                   mov    %edx,(%edi)
     e85:       e8 fc ff ff ff          call   e86 <__lock_task_sighand+0x4c>
     e8a:       8b 45 f0                mov    -0x10(%ebp),%eax
     e8d:       8b 30                   mov    (%eax),%esi
     e8f:       85 f6                   test   %esi,%esi
     e91:       75 1c                   jne    eaf <__lock_task_sighand+0x75>
     e93:       e8 fc ff ff ff          call   e94 <__lock_task_sighand+0x5a>
     e98:       8b 07                   mov    (%edi),%eax
     e9a:       f6 c4 02                test   $0x2,%ah
     e9d:       75 07                   jne    ea6 <__lock_task_sighand+0x6c>
     e9f:       b8 01 00 00 00          mov    $0x1,%eax
     ea4:       eb 02                   jmp    ea8 <__lock_task_sighand+0x6e>
     ea6:       31 c0                   xor    %eax,%eax
     ea8:       e8 fc ff ff ff          call   ea9 <__lock_task_sighand+0x6f>
     ead:       eb 45                   jmp    ef4 <__lock_task_sighand+0xba>
     eaf:       8d 9e 04 05 00 00       lea    0x504(%esi),%ebx
     eb5:       89 d8                   mov    %ebx,%eax
     eb7:       e8 fc ff ff ff          call   eb8 <__lock_task_sighand+0x7e>
     ebc:       8b 45 ec                mov    -0x14(%ebp),%eax
     ebf:       3b b0 94 02 00 00       cmp    0x294(%eax),%esi
     ec5:       75 07                   jne    ece <__lock_task_sighand+0x94>
     ec7:       e8 fc ff ff ff          call   ec8 <__lock_task_sighand+0x8e>
     ecc:       eb 26                   jmp    ef4 <__lock_task_sighand+0xba>
     ece:       89 d8                   mov    %ebx,%eax
     ed0:       e8 fc ff ff ff          call   ed1 <__lock_task_sighand+0x97>
     ed5:       e8 fc ff ff ff          call   ed6 <__lock_task_sighand+0x9c>
     eda:       8b 07                   mov    (%edi),%eax
     edc:       f6 c4 02                test   $0x2,%ah
     edf:       75 07                   jne    ee8 <__lock_task_sighand+0xae>
     ee1:       b8 01 00 00 00          mov    $0x1,%eax
     ee6:       eb 02                   jmp    eea <__lock_task_sighand+0xb0>
     ee8:       31 c0                   xor    %eax,%eax
     eea:       e8 fc ff ff ff          call   eeb <__lock_task_sighand+0xb1>
     eef:       e9 5c ff ff ff          jmp    e50 <__lock_task_sighand+0x16>
     ef4:       59                      pop    %ecx
     ef5:       89 f0                   mov    %esi,%eax
     ef7:       5b                      pop    %ebx
     ef8:       5b                      pop    %ebx
     ef9:       5e                      pop    %esi
     efa:       5f                      pop    %edi
     efb:       5d                      pop    %ebp
     efc:       c3                      ret


>
> --
>                                             Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/04/2012 04:28 PM, Henri Roosen wrote:

> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
> <gilles.chanteperdrix@xenomai.org> wrote:
>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>> Hi,
>>>
>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>> I reserved one cpu (kernel param isolcpus=1).
>>>
>>> Our application triggers the following NULL pointer dereference when I
>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>> The application does not trigger this when all tasks have the same
>>> affinity (set via /proc/xenomai/affinity).
>>>
>>> I was able to reproduce this also under QEMU and will do some
>>> debugging, but maybe someone knows what is wrong already by seeing the
>>> stacktrace below:
>>
>> Could you try to reduce the bug to a simple testcase which we would try
>> and run to reproduce?
>>
>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>> at 00000294
>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>
>> Or send us a disassembly of the function __lock_task_sighand?


Looks like someone is calling send_sig_info with an invalid pointer. 
There is something seriously wrong.

On the other hand, now that I think about it, you need at least the 
following patch:

diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
index c75fcac..0f37bb2 100644
--- a/ksrc/nucleus/intr.c
+++ b/ksrc/nucleus/intr.c
@@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
 
 void xnintr_clock_handler(void)
 {
-	struct xnsched *sched = xnpod_current_sched();
 	xnstat_exectime_t *prev;
+	struct xnsched *sched;
+	unsigned cpu;
+
+	cpu = xnarch_current_cpu();
+
+	if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
+		xnarch_relay_tick();
+		return;
+	}
+
+	sched = xnpod_sched_slot(cpu);
 
 	prev = xnstat_exectime_switch(sched,
 		&nkclock.stat[xnsched_cpu(sched)].account);



-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:

> On 09/04/2012 04:28 PM, Henri Roosen wrote:
> 
>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>> <gilles.chanteperdrix@xenomai.org> wrote:
>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>> Hi,
>>>>
>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>
>>>> Our application triggers the following NULL pointer dereference when I
>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>> The application does not trigger this when all tasks have the same
>>>> affinity (set via /proc/xenomai/affinity).
>>>>
>>>> I was able to reproduce this also under QEMU and will do some
>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>> stacktrace below:
>>>
>>> Could you try to reduce the bug to a simple testcase which we would try
>>> and run to reproduce?
>>>
>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>> at 00000294
>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>
>>> Or send us a disassembly of the function __lock_task_sighand?
> 
> 
> Looks like someone is calling send_sig_info with an invalid pointer. 
> There is something seriously wrong.
> 
> On the other hand, now that I think about it, you need at least the 
> following patch:
> 
> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
> index c75fcac..0f37bb2 100644
> --- a/ksrc/nucleus/intr.c
> +++ b/ksrc/nucleus/intr.c
> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>  
>  void xnintr_clock_handler(void)
>  {
> -	struct xnsched *sched = xnpod_current_sched();
>  	xnstat_exectime_t *prev;
> +	struct xnsched *sched;
> +	unsigned cpu;
> +
> +	cpu = xnarch_current_cpu();
> +
> +	if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
> +		xnarch_relay_tick();
> +		return;
> +	}
> +
> +	sched = xnpod_sched_slot(cpu);
>  
>  	prev = xnstat_exectime_switch(sched,
>  		&nkclock.stat[xnsched_cpu(sched)].account);


No, it will not work. I do not understand how it supposed to work, actually.

When the local timer interrupt happens for a non supported cpus, how
does it get propagated to the root domain?

-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/04/2012 08:43 PM, Gilles Chanteperdrix wrote:

> When the local timer interrupt happens for a non supported cpus, how
> does it get propagated to the root domain?


Ok. Got it now. Before the I-pipe core, Xenomai was reprogramming the
APIC of the cpus in rthal_supported_cpu to use a different vector for
the local timer irq. So, no propagaction was needed. We simply need the
I-pipe core APIC timer initialization function to do the same thing.

-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:

> On 09/04/2012 04:28 PM, Henri Roosen wrote:
> 
>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>> <gilles.chanteperdrix@xenomai.org> wrote:
>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>> Hi,
>>>>
>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>
>>>> Our application triggers the following NULL pointer dereference when I
>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>> The application does not trigger this when all tasks have the same
>>>> affinity (set via /proc/xenomai/affinity).
>>>>
>>>> I was able to reproduce this also under QEMU and will do some
>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>> stacktrace below:
>>>
>>> Could you try to reduce the bug to a simple testcase which we would try
>>> and run to reproduce?
>>>
>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>> at 00000294
>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>
>>> Or send us a disassembly of the function __lock_task_sighand?
> 
> 
> Looks like someone is calling send_sig_info with an invalid pointer. 
> There is something seriously wrong.
> 
> On the other hand, now that I think about it, you need at least the 
> following patch:
> 
> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
> index c75fcac..0f37bb2 100644
> --- a/ksrc/nucleus/intr.c
> +++ b/ksrc/nucleus/intr.c
> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>  
>  void xnintr_clock_handler(void)
>  {
> -	struct xnsched *sched = xnpod_current_sched();
>  	xnstat_exectime_t *prev;
> +	struct xnsched *sched;
> +	unsigned cpu;
> +
> +	cpu = xnarch_current_cpu();
> +
> +	if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
> +		xnarch_relay_tick();
> +		return;
> +	}
> +
> +	sched = xnpod_sched_slot(cpu);
>  
>  	prev = xnstat_exectime_switch(sched,
>  		&nkclock.stat[xnsched_cpu(sched)].account);


It should work (I did not test it), with the following patch on the 
I-pipe:

diff --git a/kernel/ipipe/timer.c b/kernel/ipipe/timer.c
index d51fa62..301cdc0 100644
--- a/kernel/ipipe/timer.c
+++ b/kernel/ipipe/timer.c
@@ -176,11 +176,17 @@ int ipipe_select_timers(const struct cpumask *mask)
 		hrclock_freq = __ipipe_hrclock_freq;
 
 	spin_lock_irqsave(&lock, flags);
-	for_each_cpu(cpu, mask) {
+	for_each_cpu(cpu, cpu_online_mask) {
 		list_for_each_entry(t, &timers, link) {
 			if (!cpumask_test_cpu(cpu, t->cpumask))
 				continue;
 
+			if (!cpumask_test_cpu(cpu, mask)
+			    && t->irq == per_cpu(ipipe_percpu.hrtimer_irq, 0)) {
+				per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
+				goto found;
+			}
+
 			evtdev = t->host_timer;
 #ifdef CONFIG_GENERIC_CLOCKEVENTS
 			if (!evtdev
@@ -188,10 +194,16 @@ int ipipe_select_timers(const struct cpumask *mask)
 #endif /* CONFIG_GENERIC_CLOCKEVENTS */
 				goto found;
 		}
+		if (!cpumask_test_cpu(cpu, mask))
+			continue;
+
 		printk("I-pipe: could not find timer for cpu #%d\n", cpu);
 		goto err_remove_all;
 
 	  found:
+		if (!cpumask_test_cpu(cpu, mask))
+			continue;
+
 		if (__ipipe_hrtimer_freq == 0)
 			__ipipe_hrtimer_freq = t->freq;
 		per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;


-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Henri Roosen]

On Tue, Sep 4, 2012 at 9:21 PM, Gilles Chanteperdrix
<gilles.chanteperdrix@xenomai.org> wrote:
> On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:
>
>> On 09/04/2012 04:28 PM, Henri Roosen wrote:
>>
>>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>>> Hi,
>>>>>
>>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>>
>>>>> Our application triggers the following NULL pointer dereference when I
>>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>>> The application does not trigger this when all tasks have the same
>>>>> affinity (set via /proc/xenomai/affinity).
>>>>>
>>>>> I was able to reproduce this also under QEMU and will do some
>>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>>> stacktrace below:
>>>>
>>>> Could you try to reduce the bug to a simple testcase which we would try
>>>> and run to reproduce?
>>>>
>>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>>> at 00000294
>>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>>
>>>> Or send us a disassembly of the function __lock_task_sighand?
>>
>>
>> Looks like someone is calling send_sig_info with an invalid pointer.
>> There is something seriously wrong.
>>
>> On the other hand, now that I think about it, you need at least the
>> following patch:
>>
>> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
>> index c75fcac..0f37bb2 100644
>> --- a/ksrc/nucleus/intr.c
>> +++ b/ksrc/nucleus/intr.c
>> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>>
>>  void xnintr_clock_handler(void)
>>  {
>> -     struct xnsched *sched = xnpod_current_sched();
>>       xnstat_exectime_t *prev;
>> +     struct xnsched *sched;
>> +     unsigned cpu;
>> +
>> +     cpu = xnarch_current_cpu();
>> +
>> +     if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
>> +             xnarch_relay_tick();
>> +             return;
>> +     }
>> +
>> +     sched = xnpod_sched_slot(cpu);
>>
>>       prev = xnstat_exectime_switch(sched,
>>               &nkclock.stat[xnsched_cpu(sched)].account);
>
>
> It should work (I did not test it), with the following patch on the
> I-pipe:
>
> diff --git a/kernel/ipipe/timer.c b/kernel/ipipe/timer.c
> index d51fa62..301cdc0 100644
> --- a/kernel/ipipe/timer.c
> +++ b/kernel/ipipe/timer.c
> @@ -176,11 +176,17 @@ int ipipe_select_timers(const struct cpumask *mask)
>                 hrclock_freq = __ipipe_hrclock_freq;
>
>         spin_lock_irqsave(&lock, flags);
> -       for_each_cpu(cpu, mask) {
> +       for_each_cpu(cpu, cpu_online_mask) {
>                 list_for_each_entry(t, &timers, link) {
>                         if (!cpumask_test_cpu(cpu, t->cpumask))
>                                 continue;
>
> +                       if (!cpumask_test_cpu(cpu, mask)
> +                           && t->irq == per_cpu(ipipe_percpu.hrtimer_irq, 0)) {
> +                               per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
> +                               goto found;
> +                       }
> +
>                         evtdev = t->host_timer;
>  #ifdef CONFIG_GENERIC_CLOCKEVENTS
>                         if (!evtdev
> @@ -188,10 +194,16 @@ int ipipe_select_timers(const struct cpumask *mask)
>  #endif /* CONFIG_GENERIC_CLOCKEVENTS */
>                                 goto found;
>                 }
> +               if (!cpumask_test_cpu(cpu, mask))
> +                       continue;
> +
>                 printk("I-pipe: could not find timer for cpu #%d\n", cpu);
>                 goto err_remove_all;
>
>           found:
> +               if (!cpumask_test_cpu(cpu, mask))
> +                       continue;
> +
>                 if (__ipipe_hrtimer_freq == 0)
>                         __ipipe_hrtimer_freq = t->freq;
>                 per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>
Thanks for looking into this Gilles!
I tried your second patch only and unfortunately I was still able to
reproduce the same kernel NULL pointer dereference.
>
> --
>                                                                 Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/05/2012 09:26 AM, Henri Roosen wrote:

> On Tue, Sep 4, 2012 at 9:21 PM, Gilles Chanteperdrix
> <gilles.chanteperdrix@xenomai.org> wrote:
>> On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:
>>
>>> On 09/04/2012 04:28 PM, Henri Roosen wrote:
>>>
>>>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>>>> Hi,
>>>>>>
>>>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>>>
>>>>>> Our application triggers the following NULL pointer dereference when I
>>>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>>>> The application does not trigger this when all tasks have the same
>>>>>> affinity (set via /proc/xenomai/affinity).
>>>>>>
>>>>>> I was able to reproduce this also under QEMU and will do some
>>>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>>>> stacktrace below:
>>>>>
>>>>> Could you try to reduce the bug to a simple testcase which we would try
>>>>> and run to reproduce?
>>>>>
>>>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>>>> at 00000294
>>>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>>>
>>>>> Or send us a disassembly of the function __lock_task_sighand?
>>>
>>>
>>> Looks like someone is calling send_sig_info with an invalid pointer.
>>> There is something seriously wrong.
>>>
>>> On the other hand, now that I think about it, you need at least the
>>> following patch:
>>>
>>> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
>>> index c75fcac..0f37bb2 100644
>>> --- a/ksrc/nucleus/intr.c
>>> +++ b/ksrc/nucleus/intr.c
>>> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>>>
>>>  void xnintr_clock_handler(void)
>>>  {
>>> -     struct xnsched *sched = xnpod_current_sched();
>>>       xnstat_exectime_t *prev;
>>> +     struct xnsched *sched;
>>> +     unsigned cpu;
>>> +
>>> +     cpu = xnarch_current_cpu();
>>> +
>>> +     if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
>>> +             xnarch_relay_tick();
>>> +             return;
>>> +     }
>>> +
>>> +     sched = xnpod_sched_slot(cpu);
>>>
>>>       prev = xnstat_exectime_switch(sched,
>>>               &nkclock.stat[xnsched_cpu(sched)].account);
>>
>>
>> It should work (I did not test it), with the following patch on the
>> I-pipe:
>>
>> diff --git a/kernel/ipipe/timer.c b/kernel/ipipe/timer.c
>> index d51fa62..301cdc0 100644
>> --- a/kernel/ipipe/timer.c
>> +++ b/kernel/ipipe/timer.c
>> @@ -176,11 +176,17 @@ int ipipe_select_timers(const struct cpumask *mask)
>>                 hrclock_freq = __ipipe_hrclock_freq;
>>
>>         spin_lock_irqsave(&lock, flags);
>> -       for_each_cpu(cpu, mask) {
>> +       for_each_cpu(cpu, cpu_online_mask) {
>>                 list_for_each_entry(t, &timers, link) {
>>                         if (!cpumask_test_cpu(cpu, t->cpumask))
>>                                 continue;
>>
>> +                       if (!cpumask_test_cpu(cpu, mask)
>> +                           && t->irq == per_cpu(ipipe_percpu.hrtimer_irq, 0)) {
>> +                               per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>> +                               goto found;
>> +                       }
>> +
>>                         evtdev = t->host_timer;
>>  #ifdef CONFIG_GENERIC_CLOCKEVENTS
>>                         if (!evtdev
>> @@ -188,10 +194,16 @@ int ipipe_select_timers(const struct cpumask *mask)
>>  #endif /* CONFIG_GENERIC_CLOCKEVENTS */
>>                                 goto found;
>>                 }
>> +               if (!cpumask_test_cpu(cpu, mask))
>> +                       continue;
>> +
>>                 printk("I-pipe: could not find timer for cpu #%d\n", cpu);
>>                 goto err_remove_all;
>>
>>           found:
>> +               if (!cpumask_test_cpu(cpu, mask))
>> +                       continue;
>> +
>>                 if (__ipipe_hrtimer_freq == 0)
>>                         __ipipe_hrtimer_freq = t->freq;
>>                 per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>
> Thanks for looking into this Gilles!
> I tried your second patch only and unfortunately I was still able to
> reproduce the same kernel NULL pointer dereference.


Sorry, I meant the first xenomai patch needs the second I-pipe patch to
work.

-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Henri Roosen]

On Wed, Sep 5, 2012 at 9:28 AM, Gilles Chanteperdrix
<gilles.chanteperdrix@xenomai.org> wrote:
> On 09/05/2012 09:26 AM, Henri Roosen wrote:
>
>> On Tue, Sep 4, 2012 at 9:21 PM, Gilles Chanteperdrix
>> <gilles.chanteperdrix@xenomai.org> wrote:
>>> On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:
>>>
>>>> On 09/04/2012 04:28 PM, Henri Roosen wrote:
>>>>
>>>>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>>>>> Hi,
>>>>>>>
>>>>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>>>>
>>>>>>> Our application triggers the following NULL pointer dereference when I
>>>>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>>>>> The application does not trigger this when all tasks have the same
>>>>>>> affinity (set via /proc/xenomai/affinity).
>>>>>>>
>>>>>>> I was able to reproduce this also under QEMU and will do some
>>>>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>>>>> stacktrace below:
>>>>>>
>>>>>> Could you try to reduce the bug to a simple testcase which we would try
>>>>>> and run to reproduce?
>>>>>>
>>>>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>>>>> at 00000294
>>>>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>>>>
>>>>>> Or send us a disassembly of the function __lock_task_sighand?
>>>>
>>>>
>>>> Looks like someone is calling send_sig_info with an invalid pointer.
>>>> There is something seriously wrong.
>>>>
>>>> On the other hand, now that I think about it, you need at least the
>>>> following patch:
>>>>
>>>> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
>>>> index c75fcac..0f37bb2 100644
>>>> --- a/ksrc/nucleus/intr.c
>>>> +++ b/ksrc/nucleus/intr.c
>>>> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>>>>
>>>>  void xnintr_clock_handler(void)
>>>>  {
>>>> -     struct xnsched *sched = xnpod_current_sched();
>>>>       xnstat_exectime_t *prev;
>>>> +     struct xnsched *sched;
>>>> +     unsigned cpu;
>>>> +
>>>> +     cpu = xnarch_current_cpu();
>>>> +
>>>> +     if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
>>>> +             xnarch_relay_tick();
>>>> +             return;
>>>> +     }
>>>> +
>>>> +     sched = xnpod_sched_slot(cpu);
>>>>
>>>>       prev = xnstat_exectime_switch(sched,
>>>>               &nkclock.stat[xnsched_cpu(sched)].account);
>>>
>>>
>>> It should work (I did not test it), with the following patch on the
>>> I-pipe:
>>>
>>> diff --git a/kernel/ipipe/timer.c b/kernel/ipipe/timer.c
>>> index d51fa62..301cdc0 100644
>>> --- a/kernel/ipipe/timer.c
>>> +++ b/kernel/ipipe/timer.c
>>> @@ -176,11 +176,17 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>                 hrclock_freq = __ipipe_hrclock_freq;
>>>
>>>         spin_lock_irqsave(&lock, flags);
>>> -       for_each_cpu(cpu, mask) {
>>> +       for_each_cpu(cpu, cpu_online_mask) {
>>>                 list_for_each_entry(t, &timers, link) {
>>>                         if (!cpumask_test_cpu(cpu, t->cpumask))
>>>                                 continue;
>>>
>>> +                       if (!cpumask_test_cpu(cpu, mask)
>>> +                           && t->irq == per_cpu(ipipe_percpu.hrtimer_irq, 0)) {
>>> +                               per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>> +                               goto found;
>>> +                       }
>>> +
>>>                         evtdev = t->host_timer;
>>>  #ifdef CONFIG_GENERIC_CLOCKEVENTS
>>>                         if (!evtdev
>>> @@ -188,10 +194,16 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>  #endif /* CONFIG_GENERIC_CLOCKEVENTS */
>>>                                 goto found;
>>>                 }
>>> +               if (!cpumask_test_cpu(cpu, mask))
>>> +                       continue;
>>> +
>>>                 printk("I-pipe: could not find timer for cpu #%d\n", cpu);
>>>                 goto err_remove_all;
>>>
>>>           found:
>>> +               if (!cpumask_test_cpu(cpu, mask))
>>> +                       continue;
>>> +
>>>                 if (__ipipe_hrtimer_freq == 0)
>>>                         __ipipe_hrtimer_freq = t->freq;
>>>                 per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>
>> Thanks for looking into this Gilles!
>> I tried your second patch only and unfortunately I was still able to
>> reproduce the same kernel NULL pointer dereference.
>
>
> Sorry, I meant the first xenomai patch needs the second I-pipe patch to
> work.

I applied both patches now, but still able to reproduce the same problem.
>
> --
>                                                                 Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/05/2012 09:42 AM, Henri Roosen wrote:
> On Wed, Sep 5, 2012 at 9:28 AM, Gilles Chanteperdrix
> <gilles.chanteperdrix@xenomai.org> wrote:
>> On 09/05/2012 09:26 AM, Henri Roosen wrote:
>>
>>> On Tue, Sep 4, 2012 at 9:21 PM, Gilles Chanteperdrix
>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>> On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:
>>>>
>>>>> On 09/04/2012 04:28 PM, Henri Roosen wrote:
>>>>>
>>>>>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>>>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>>>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>>>>>
>>>>>>>> Our application triggers the following NULL pointer dereference when I
>>>>>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>>>>>> The application does not trigger this when all tasks have the same
>>>>>>>> affinity (set via /proc/xenomai/affinity).
>>>>>>>>
>>>>>>>> I was able to reproduce this also under QEMU and will do some
>>>>>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>>>>>> stacktrace below:
>>>>>>>
>>>>>>> Could you try to reduce the bug to a simple testcase which we would try
>>>>>>> and run to reproduce?
>>>>>>>
>>>>>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>>>>>> at 00000294
>>>>>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>>>>>
>>>>>>> Or send us a disassembly of the function __lock_task_sighand?
>>>>>
>>>>>
>>>>> Looks like someone is calling send_sig_info with an invalid pointer.
>>>>> There is something seriously wrong.
>>>>>
>>>>> On the other hand, now that I think about it, you need at least the
>>>>> following patch:
>>>>>
>>>>> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
>>>>> index c75fcac..0f37bb2 100644
>>>>> --- a/ksrc/nucleus/intr.c
>>>>> +++ b/ksrc/nucleus/intr.c
>>>>> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>>>>>
>>>>>  void xnintr_clock_handler(void)
>>>>>  {
>>>>> -     struct xnsched *sched = xnpod_current_sched();
>>>>>       xnstat_exectime_t *prev;
>>>>> +     struct xnsched *sched;
>>>>> +     unsigned cpu;
>>>>> +
>>>>> +     cpu = xnarch_current_cpu();
>>>>> +
>>>>> +     if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
>>>>> +             xnarch_relay_tick();
>>>>> +             return;
>>>>> +     }
>>>>> +
>>>>> +     sched = xnpod_sched_slot(cpu);
>>>>>
>>>>>       prev = xnstat_exectime_switch(sched,
>>>>>               &nkclock.stat[xnsched_cpu(sched)].account);
>>>>
>>>>
>>>> It should work (I did not test it), with the following patch on the
>>>> I-pipe:
>>>>
>>>> diff --git a/kernel/ipipe/timer.c b/kernel/ipipe/timer.c
>>>> index d51fa62..301cdc0 100644
>>>> --- a/kernel/ipipe/timer.c
>>>> +++ b/kernel/ipipe/timer.c
>>>> @@ -176,11 +176,17 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>                 hrclock_freq = __ipipe_hrclock_freq;
>>>>
>>>>         spin_lock_irqsave(&lock, flags);
>>>> -       for_each_cpu(cpu, mask) {
>>>> +       for_each_cpu(cpu, cpu_online_mask) {
>>>>                 list_for_each_entry(t, &timers, link) {
>>>>                         if (!cpumask_test_cpu(cpu, t->cpumask))
>>>>                                 continue;
>>>>
>>>> +                       if (!cpumask_test_cpu(cpu, mask)
>>>> +                           && t->irq == per_cpu(ipipe_percpu.hrtimer_irq, 0)) {
>>>> +                               per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>> +                               goto found;
>>>> +                       }
>>>> +
>>>>                         evtdev = t->host_timer;
>>>>  #ifdef CONFIG_GENERIC_CLOCKEVENTS
>>>>                         if (!evtdev
>>>> @@ -188,10 +194,16 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>  #endif /* CONFIG_GENERIC_CLOCKEVENTS */
>>>>                                 goto found;
>>>>                 }
>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>> +                       continue;
>>>> +
>>>>                 printk("I-pipe: could not find timer for cpu #%d\n", cpu);
>>>>                 goto err_remove_all;
>>>>
>>>>           found:
>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>> +                       continue;
>>>> +
>>>>                 if (__ipipe_hrtimer_freq == 0)
>>>>                         __ipipe_hrtimer_freq = t->freq;
>>>>                 per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>
>>> Thanks for looking into this Gilles!
>>> I tried your second patch only and unfortunately I was still able to
>>> reproduce the same kernel NULL pointer dereference.
>>
>>
>> Sorry, I meant the first xenomai patch needs the second I-pipe patch to
>> work.
> 
> I applied both patches now, but still able to reproduce the same problem.

Ok, to debug this, you can add:
BUG_ON((unsigned long)xnthread_user_task(thread) < 0xc0000000);
in xnshadow_send_sig. Add:
BUG_ON((unsigned long)p < 0xc0000000)
in lostage_handler, in the LO_SIGTHR_REQ case.

Enable the I-pipe tracer, panic back traces, then set the number of
points to a reasonably high value before running your test.

-- 
					    Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Henri Roosen]

On Wed, Sep 5, 2012 at 10:28 AM, Gilles Chanteperdrix
<gilles.chanteperdrix@xenomai.org> wrote:
> On 09/05/2012 09:42 AM, Henri Roosen wrote:
>> On Wed, Sep 5, 2012 at 9:28 AM, Gilles Chanteperdrix
>> <gilles.chanteperdrix@xenomai.org> wrote:
>>> On 09/05/2012 09:26 AM, Henri Roosen wrote:
>>>
>>>> On Tue, Sep 4, 2012 at 9:21 PM, Gilles Chanteperdrix
>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>> On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:
>>>>>
>>>>>> On 09/04/2012 04:28 PM, Henri Roosen wrote:
>>>>>>
>>>>>>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>>>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>>>>>>> Hi,
>>>>>>>>>
>>>>>>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>>>>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>>>>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>>>>>>
>>>>>>>>> Our application triggers the following NULL pointer dereference when I
>>>>>>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>>>>>>> The application does not trigger this when all tasks have the same
>>>>>>>>> affinity (set via /proc/xenomai/affinity).
>>>>>>>>>
>>>>>>>>> I was able to reproduce this also under QEMU and will do some
>>>>>>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>>>>>>> stacktrace below:
>>>>>>>>
>>>>>>>> Could you try to reduce the bug to a simple testcase which we would try
>>>>>>>> and run to reproduce?
>>>>>>>>
>>>>>>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>>>>>>> at 00000294
>>>>>>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>>>>>>
>>>>>>>> Or send us a disassembly of the function __lock_task_sighand?
>>>>>>
>>>>>>
>>>>>> Looks like someone is calling send_sig_info with an invalid pointer.
>>>>>> There is something seriously wrong.
>>>>>>
>>>>>> On the other hand, now that I think about it, you need at least the
>>>>>> following patch:
>>>>>>
>>>>>> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
>>>>>> index c75fcac..0f37bb2 100644
>>>>>> --- a/ksrc/nucleus/intr.c
>>>>>> +++ b/ksrc/nucleus/intr.c
>>>>>> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>>>>>>
>>>>>>  void xnintr_clock_handler(void)
>>>>>>  {
>>>>>> -     struct xnsched *sched = xnpod_current_sched();
>>>>>>       xnstat_exectime_t *prev;
>>>>>> +     struct xnsched *sched;
>>>>>> +     unsigned cpu;
>>>>>> +
>>>>>> +     cpu = xnarch_current_cpu();
>>>>>> +
>>>>>> +     if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
>>>>>> +             xnarch_relay_tick();
>>>>>> +             return;
>>>>>> +     }
>>>>>> +
>>>>>> +     sched = xnpod_sched_slot(cpu);
>>>>>>
>>>>>>       prev = xnstat_exectime_switch(sched,
>>>>>>               &nkclock.stat[xnsched_cpu(sched)].account);
>>>>>
>>>>>
>>>>> It should work (I did not test it), with the following patch on the
>>>>> I-pipe:
>>>>>
>>>>> diff --git a/kernel/ipipe/timer.c b/kernel/ipipe/timer.c
>>>>> index d51fa62..301cdc0 100644
>>>>> --- a/kernel/ipipe/timer.c
>>>>> +++ b/kernel/ipipe/timer.c
>>>>> @@ -176,11 +176,17 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>>                 hrclock_freq = __ipipe_hrclock_freq;
>>>>>
>>>>>         spin_lock_irqsave(&lock, flags);
>>>>> -       for_each_cpu(cpu, mask) {
>>>>> +       for_each_cpu(cpu, cpu_online_mask) {
>>>>>                 list_for_each_entry(t, &timers, link) {
>>>>>                         if (!cpumask_test_cpu(cpu, t->cpumask))
>>>>>                                 continue;
>>>>>
>>>>> +                       if (!cpumask_test_cpu(cpu, mask)
>>>>> +                           && t->irq == per_cpu(ipipe_percpu.hrtimer_irq, 0)) {
>>>>> +                               per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>> +                               goto found;
>>>>> +                       }
>>>>> +
>>>>>                         evtdev = t->host_timer;
>>>>>  #ifdef CONFIG_GENERIC_CLOCKEVENTS
>>>>>                         if (!evtdev
>>>>> @@ -188,10 +194,16 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>>  #endif /* CONFIG_GENERIC_CLOCKEVENTS */
>>>>>                                 goto found;
>>>>>                 }
>>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>>> +                       continue;
>>>>> +
>>>>>                 printk("I-pipe: could not find timer for cpu #%d\n", cpu);
>>>>>                 goto err_remove_all;
>>>>>
>>>>>           found:
>>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>>> +                       continue;
>>>>> +
>>>>>                 if (__ipipe_hrtimer_freq == 0)
>>>>>                         __ipipe_hrtimer_freq = t->freq;
>>>>>                 per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>>
>>>> Thanks for looking into this Gilles!
>>>> I tried your second patch only and unfortunately I was still able to
>>>> reproduce the same kernel NULL pointer dereference.
>>>
>>>
>>> Sorry, I meant the first xenomai patch needs the second I-pipe patch to
>>> work.
>>
>> I applied both patches now, but still able to reproduce the same problem.
>
> Ok, to debug this, you can add:
> BUG_ON((unsigned long)xnthread_user_task(thread) < 0xc0000000);
> in xnshadow_send_sig. Add:
> BUG_ON((unsigned long)p < 0xc0000000)
> in lostage_handler, in the LO_SIGTHR_REQ case.
>
> Enable the I-pipe tracer, panic back traces, then set the number of
> points to a reasonably high value before running your test.

Please find attached the trace ipipe_trace.txt

Note that in order to compile the ipipe-tracer for x86 I had to remove
the call to hard_irqs_disabled_flags. I changed that to 0.. hope that
doesn't affect the trace log.

>
> --
>                                             Gilles.
-------------- next part --------------
[   60.026336] I-pipe: Detected stalled head domain, probably caused by a bug.
[   60.026339]         A critical section may have been left unterminated.
[   60.026774] Pid: 244, comm: cyclic:213:244 Tainted: G           O 3.4.6+ #70
[   60.026774] Call Trace:
[   60.026774]  [<c0161420>] ipipe_root_only+0x7f/0x8b
[   60.026774]  [<c0161f7a>] ipipe_unstall_root+0x12/0x2d
[   60.026774]  [<c0102695>] conditional_sti+0xe/0x10
[   60.026774]  [<c01029e6>] do_invalid_op+0x59/0x80
[   60.026774]  [<c018836b>] ? xnshadow_send_sig+0x19/0x3e
[   60.026774]  [<c01614f0>] ? __ipipe_notify_trap+0x9/0x82
[   60.026774]  [<c0113d3f>] ? __ipipe_handle_exception+0x9/0x1f4
[   60.026774]  [<c01645c5>] ? ipipe_trace_function+0x19/0x1c
[   60.026774]  [<c0113922>] ? __ipipe_get_current_domain+0xe/0x43
[   60.026774]  [<c0113f11>] __ipipe_handle_exception+0x1db/0x1f4
[   60.026774]  [<c041e5a7>] error_code+0x5f/0x6c
[   60.026774]  [<c016007b>] ? __rcu_process_callbacks+0x2b7/0x355
[   60.026774]  [<c018836b>] ? xnshadow_send_sig+0x19/0x3e
[   60.026774]  [<c018841b>] xnshadow_renice+0x2d/0x30
[   60.026774]  [<c0182d7f>] xnsynch_renice_thread+0x32/0x48
[   60.026774]  [<c0182e0b>] xnsynch_clear_boost+0x76/0x79
[   60.026774]  [<c01831a6>] xnsynch_release_thread+0xe1/0x12b
[   60.026774]  [<c018322e>] xnsynch_release_all_ownerships+0x3e/0x55
[   60.026774]  [<c01811bc>] xnpod_delete_thread+0x18e/0x254
[   60.026774]  [<c0187d69>] taskexit_event+0xce/0x14e
[   60.026774]  [<c0164885>] ipipe_kevent_hook+0x1c/0x1f
[   60.026774]  [<c01614c7>] __ipipe_notify_kevent+0x4e/0x6e
[   60.026774]  [<c01225c0>] do_exit+0x207/0x6a1
[   60.026774]  [<c01645c5>] ? ipipe_trace_function+0x19/0x1c
[   60.026774]  [<c0122b18>] sys_exit+0x18/0x18
[   60.026774]  [<c041dd6a>] syscall_call+0x7/0xb
[   60.026774] I-pipe tracer log (100 points):
[   60.026774]     *#func                    0 ipipe_trace_panic_freeze+0x4 (ipipe_root_only+0x53)
[   60.026774]     *#func                    0 ipipe_prepare_panic+0x4 (ipipe_root_only+0x4e)
[   60.026774]     *#func                    0 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   60.026774]     *#func                    0 ipipe_unstall_root+0x3 (conditional_sti+0xe)
[   60.026774]     *#func                   -1 __rcu_read_unlock+0x4 (__atomic_notifier_call_chain+0x31)
[   60.026774]     *#func                   -9 hw_breakpoint_exceptions_notify+0x9 (notifier_call_chain+0x30)
[   60.026774]     *#func                   -9 notifier_call_chain+0x9 (__atomic_notifier_call_chain+0x2a)
[   60.026774]     *#func                   -9 __rcu_read_lock+0x3 (__atomic_notifier_call_chain+0x19)
[   60.026774]     *#func                   -9 __atomic_notifier_call_chain+0x6 (atomic_notifier_call_chain+0x11)
[   60.026774]     *#func                  -10 atomic_notifier_call_chain+0x3 (notify_die+0x2d)
[   60.026774]     *#func                  -10 do_invalid_op+0x8 (__ipipe_handle_exception+0x1db)
[   60.026774]     *#func                  -10 __ipipe_notify_trap+0x9 (__ipipe_handle_exception+0x89)
[   60.026774]     *+func                  -11 __ipipe_handle_exception+0x9 (error_code+0x5f)
[   60.026774]     *+func                  -16 xnshadow_send_sig+0x4 (xnshadow_renice+0x2d)
[   60.026774]     *+func                  -17 xnshadow_renice+0x3 (xnsynch_renice_thread+0x32)
[   60.026774]     *+func                  -17 xnsched_track_policy+0x5 (xnsynch_renice_thread+0x10)
[   60.026774]     *+func                  -17 xnsynch_renice_thread+0x4 (xnsynch_clear_boost+0x76)
[   60.026774]     *+func                  -17 xnsynch_clear_boost+0x4 (xnsynch_release_thread+0xe1)
[   60.026774]     *+[  228] Watchdo 96    -17 xnpod_resume_thread+0x40 (xnsynch_release_thread+0xd1)
[   60.026774]     *+func                  -18 xnpod_resume_thread+0x9 (xnsynch_release_thread+0xd1)
[   60.026774]     *+func                  -18 xnsynch_release_thread+0x9 (xnsynch_release_all_ownerships+0x3e)
[   60.026774]     *+func                  -18 xnsynch_release_all_ownerships+0x9 (xnpod_delete_thread+0x18e)
[   60.026774]     *+func                  -19 xntimer_destroy+0x5 (xnpod_delete_thread+0x15e)
[   60.026774]     *+func                  -19 xntimer_destroy+0x5 (xnpod_delete_thread+0x153)
[   60.026774]     *+func                  -19 xnpod_delete_thread+0x6 (taskexit_event+0xce)
[   60.026774]      +begin   0x80000000    -20 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   60.026774]      +func                  -20 __task_get_magic+0x3 (taskexit_event+0x5b)
[   60.026774]      +func                  -20 taskexit_event+0x9 (ipipe_kevent_hook+0x1c)
[   60.026774]      +func                  -20 ipipe_kevent_hook+0x4 (__ipipe_notify_kevent+0x4e)
[   60.026774]      +end     0x80000001    -20 hard_local_irq_restore+0x15 (__ipipe_notify_kevent+0x43)
[   60.026774]      +begin   0x80000001    -21 hard_local_irq_save+0x16 (__ipipe_notify_kevent+0x20)
[   60.026774]      +end     0x80000001    -21 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   60.026774]      +begin   0x80000001    -21 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   60.026774]      +func                  -21 ipipe_root_only+0x5 (__ipipe_notify_kevent+0x1b)
[   60.026774]      +func                  -21 __ipipe_notify_kevent+0x9 (do_exit+0x207)
[   60.026774]      +end     0x80000001    -21 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   60.026774]      +begin   0x80000001    -21 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   60.026774]      +func                  -21 ipipe_root_only+0x5 (mmput+0x10)
[   60.026774]      +func                  -22 mmput+0x4 (exit_mm+0xe5)
[   60.026774]      +func                  -22 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   60.026774]      +func                  -22 _raw_spin_unlock+0x3 (exit_mm+0xde)
[   60.026774]      +func                  -22 up_read+0x3 (exit_mm+0xc3)
[   60.026774]      +end     0x80000001    -22 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   60.026774]      +begin   0x80000001    -22 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   60.026774]      +func                  -22 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   60.026774]      +func                  -23 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   60.026774]      +func                  -23 _raw_spin_lock+0x4 (exit_mm+0xb1)
[   60.026774]      +end     0x80000001    -23 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   60.026774]      +begin   0x80000001    -23 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   60.026774]      +func                  -23 ipipe_root_only+0x5 (down_read+0x10)
[   60.026774]      +func                  -23 down_read+0x4 (exit_mm+0x37)
[   60.026774]      +func                  -23 sync_mm_rss+0x5 (exit_mm+0x2c)
[   60.026774]      +func                  -24 drop_futex_key_refs+0x3 (futex_wake+0xd0)
[   60.026774]      +func                  -24 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   60.026774]      +func                  -24 _raw_spin_unlock+0x3 (futex_wake+0xc8)
[   60.026774]      +end     0x80000001    -24 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   60.026774]      +begin   0x80000001    -24 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   60.026774]      +func                  -25 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   60.026774]      +func                  -25 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   60.026774]      +func                  -25 _raw_spin_lock+0x4 (futex_wake+0x58)
[   60.026774]      +func                  -25 hash_futex+0x4 (futex_wake+0x51)
[   60.026774]      +func                  -25 put_page+0x3 (get_futex_key+0x17e)
[   60.026774]      +func                  -25 __wake_up_bit+0x7 (unlock_page+0x45)
[   60.026774]      +func                  -26 unlock_page+0x4 (get_futex_key+0x177)
[   60.026774]      +func                  -26 get_futex_key_refs+0x3 (get_futex_key+0x170)
[   60.026774]      +end     0x80000001    -26 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   60.026774]      +begin   0x80000001    -26 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   60.026774]      +func                  -26 ipipe_root_only+0x5 (get_futex_key+0x108)
[   60.026774]      +end     0x80000000    -26 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   60.026774]      #func                  -26 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   60.026774]      #begin   0x80000000    -27 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   60.026774]      #func                  -27 ipipe_unstall_root+0x3 (get_user_pages_fast+0xb7)
[   60.026774]      #func                  -27 gup_pte_range+0x9 (gup_pud_range+0x4a)
[   60.026774]      #func                  -27 gup_pud_range+0x9 (get_user_pages_fast+0x9e)
[   60.026774]      +func                  -28 get_user_pages_fast+0x9 (get_futex_key+0x94)
[   60.026774]      +func                  -28 get_futex_key+0x9 (futex_wake+0x3f)
[   60.026774]      +func                  -28 futex_wake+0x9 (do_futex+0xce)
[   60.026774]      +func                  -28 do_futex+0xc (sys_futex+0xee)
[   60.026774]      +func                  -29 sys_futex+0x9 (mm_release+0xb4)
[   60.026774]      +end     0x80000001    -29 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   60.026774]      +begin   0x80000001    -29 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   60.026774]      +func                  -29 ipipe_root_only+0x5 (mm_release+0x97)
[   60.026774]      +end     0x80000001    -30 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   60.026774]      +begin   0x80000001    -30 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   60.026774]      +func                  -30 ipipe_root_only+0x5 (exit_robust_list+0x5e)
[   60.026774]      +end     0x80000001    -30 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   60.026774]      +begin   0x80000001    -30 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   60.026774]      +func                  -30 ipipe_root_only+0x5 (exit_robust_list+0x43)
[   60.026774]      +end     0x80000001    -30 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   60.026774]      +begin   0x80000001    -30 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   60.026774]      +func                  -31 ipipe_root_only+0x5 (exit_robust_list+0x2c)
[   60.026774]      +func                  -31 exit_robust_list+0x9 (mm_release+0x1d)
[   60.026774]      +func                  -31 mm_release+0x6 (exit_mm+0x1d)
[   60.026774]      +func                  -31 exit_mm+0x9 (do_exit+0x1c1)
[   60.026774]      +func                  -31 sync_mm_rss+0x5 (do_exit+0x13d)
[   60.026774]      +func                  -32 exit_irq_thread+0x5 (do_exit+0xfc)
[   60.026774]      +func                  -32 sub_preempt_count+0x4 (_raw_spin_unlock_irq+0x1a)
[   60.026774]      +end     0x80000000    -32 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   60.026774]      #func                  -33 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   60.026774]      #begin   0x80000000    -33 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   60.026774] ------------[ cut here ]------------
[   60.026774] kernel BUG at kernel/xenomai/nucleus/shadow.c:2233!
[   60.026774] invalid opcode: 0000 [#1] PREEMPT SMP
[   60.026774] Modules linked in: platform_edge(O) sigmatek_lrt(O) usbhid
[   60.026774]
[   60.026774] Pid: 244, comm: cyclic:213:244 Tainted: G           O 3.4.6+ #70 Bochs Bochs
[   60.026774] EIP: 0060:[<c018836b>] EFLAGS: 00213213 CPU: 1
[   60.026774] EIP is at xnshadow_send_sig+0x19/0x3e
[   60.026774] EAX: f8d32040 EBX: 0000001c ECX: 00001e02 EDX: 00000000
[   60.026774] ESI: f8d2cd04 EDI: f8d2cd14 EBP: f6053eac ESP: f6053ea8
[   60.026774]  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[   60.026774] CR0: 8005003b CR2: 00000000 CR3: 35c60000 CR4: 00000690
[   60.026774] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[   60.026774] DR6: ffff0ff0 DR7: 00000400
[   60.026774] Process cyclic:213:244 (pid: 244, ti=f6052000 task=f6a1f1d0 task.ti=f6052000)
[   60.026774] I-pipe domain Linux
[   60.026774] Stack:
[   60.026774]  f8d32040 f6053eb8 c018841b 00000001 f6053ec4 c0182d7f f8d32040 f6053ed0
[   60.026774]  c0182e0b f8d29a40 f6053ef0 c01831a6 f8d32040 00000001 00000003 f8d2cd04
[   60.026774]  00000000 f8d32040 f6053f08 c018322e f8d32408 f8d32040 c0675880 00000003
[   60.026774] Call Trace:
[   60.026774]  [<c018841b>] xnshadow_renice+0x2d/0x30
[   60.026774]  [<c0182d7f>] xnsynch_renice_thread+0x32/0x48
[   60.026774]  [<c0182e0b>] xnsynch_clear_boost+0x76/0x79
[   60.026774]  [<c01831a6>] xnsynch_release_thread+0xe1/0x12b
[   60.026774]  [<c018322e>] xnsynch_release_all_ownerships+0x3e/0x55
[   60.026774]  [<c01811bc>] xnpod_delete_thread+0x18e/0x254
[   60.026774]  [<c0187d69>] taskexit_event+0xce/0x14e
[   60.026774]  [<c0164885>] ipipe_kevent_hook+0x1c/0x1f
[   60.026774]  [<c01614c7>] __ipipe_notify_kevent+0x4e/0x6e
[   60.026774]  [<c01225c0>] do_exit+0x207/0x6a1
[   60.026774]  [<c01645c5>] ? ipipe_trace_function+0x19/0x1c
[   60.026774]  [<c0122b18>] sys_exit+0x18/0x18
[   60.026774]  [<c041dd6a>] syscall_call+0x7/0xb
[   60.026774] Code: ff 83 e7 01 89 f8 e8 ed e9 ff ff 5e 5f 5b 5e 5f 5d c3 55 89 e5 53 e8 45 6a 29 00 89 d3 8b 90 5c 03 00 00 81 fa ff ff ff bf 77 04 <0f> 0b eb fe 83 7d 08 00 75 09 b8 02 00 00 00 31 c9 eb 08 c1 e1
[   60.026774] EIP: [<c018836b>] xnshadow_send_sig+0x19/0x3e SS:ESP 0068:f6053ea8
[   60.026774] ---[ end trace 72017e0ee9364459 ]---
[   60.026774] Fixing recursive fault but reboot is needed!

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/05/2012 11:29 AM, Henri Roosen wrote:

> On Wed, Sep 5, 2012 at 10:28 AM, Gilles Chanteperdrix
> <gilles.chanteperdrix@xenomai.org> wrote:
>> On 09/05/2012 09:42 AM, Henri Roosen wrote:
>>> On Wed, Sep 5, 2012 at 9:28 AM, Gilles Chanteperdrix
>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>> On 09/05/2012 09:26 AM, Henri Roosen wrote:
>>>>
>>>>> On Tue, Sep 4, 2012 at 9:21 PM, Gilles Chanteperdrix
>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>> On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:
>>>>>>
>>>>>>> On 09/04/2012 04:28 PM, Henri Roosen wrote:
>>>>>>>
>>>>>>>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>>>>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>>>>>>>> Hi,
>>>>>>>>>>
>>>>>>>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>>>>>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>>>>>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>>>>>>>
>>>>>>>>>> Our application triggers the following NULL pointer dereference when I
>>>>>>>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>>>>>>>> The application does not trigger this when all tasks have the same
>>>>>>>>>> affinity (set via /proc/xenomai/affinity).
>>>>>>>>>>
>>>>>>>>>> I was able to reproduce this also under QEMU and will do some
>>>>>>>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>>>>>>>> stacktrace below:
>>>>>>>>>
>>>>>>>>> Could you try to reduce the bug to a simple testcase which we would try
>>>>>>>>> and run to reproduce?
>>>>>>>>>
>>>>>>>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>>>>>>>> at 00000294
>>>>>>>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>>>>>>>
>>>>>>>>> Or send us a disassembly of the function __lock_task_sighand?
>>>>>>>
>>>>>>>
>>>>>>> Looks like someone is calling send_sig_info with an invalid pointer.
>>>>>>> There is something seriously wrong.
>>>>>>>
>>>>>>> On the other hand, now that I think about it, you need at least the
>>>>>>> following patch:
>>>>>>>
>>>>>>> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
>>>>>>> index c75fcac..0f37bb2 100644
>>>>>>> --- a/ksrc/nucleus/intr.c
>>>>>>> +++ b/ksrc/nucleus/intr.c
>>>>>>> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>>>>>>>
>>>>>>>  void xnintr_clock_handler(void)
>>>>>>>  {
>>>>>>> -     struct xnsched *sched = xnpod_current_sched();
>>>>>>>       xnstat_exectime_t *prev;
>>>>>>> +     struct xnsched *sched;
>>>>>>> +     unsigned cpu;
>>>>>>> +
>>>>>>> +     cpu = xnarch_current_cpu();
>>>>>>> +
>>>>>>> +     if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
>>>>>>> +             xnarch_relay_tick();
>>>>>>> +             return;
>>>>>>> +     }
>>>>>>> +
>>>>>>> +     sched = xnpod_sched_slot(cpu);
>>>>>>>
>>>>>>>       prev = xnstat_exectime_switch(sched,
>>>>>>>               &nkclock.stat[xnsched_cpu(sched)].account);
>>>>>>
>>>>>>
>>>>>> It should work (I did not test it), with the following patch on the
>>>>>> I-pipe:
>>>>>>
>>>>>> diff --git a/kernel/ipipe/timer.c b/kernel/ipipe/timer.c
>>>>>> index d51fa62..301cdc0 100644
>>>>>> --- a/kernel/ipipe/timer.c
>>>>>> +++ b/kernel/ipipe/timer.c
>>>>>> @@ -176,11 +176,17 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>>>                 hrclock_freq = __ipipe_hrclock_freq;
>>>>>>
>>>>>>         spin_lock_irqsave(&lock, flags);
>>>>>> -       for_each_cpu(cpu, mask) {
>>>>>> +       for_each_cpu(cpu, cpu_online_mask) {
>>>>>>                 list_for_each_entry(t, &timers, link) {
>>>>>>                         if (!cpumask_test_cpu(cpu, t->cpumask))
>>>>>>                                 continue;
>>>>>>
>>>>>> +                       if (!cpumask_test_cpu(cpu, mask)
>>>>>> +                           && t->irq == per_cpu(ipipe_percpu.hrtimer_irq, 0)) {
>>>>>> +                               per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>>> +                               goto found;
>>>>>> +                       }
>>>>>> +
>>>>>>                         evtdev = t->host_timer;
>>>>>>  #ifdef CONFIG_GENERIC_CLOCKEVENTS
>>>>>>                         if (!evtdev
>>>>>> @@ -188,10 +194,16 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>>>  #endif /* CONFIG_GENERIC_CLOCKEVENTS */
>>>>>>                                 goto found;
>>>>>>                 }
>>>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>>>> +                       continue;
>>>>>> +
>>>>>>                 printk("I-pipe: could not find timer for cpu #%d\n", cpu);
>>>>>>                 goto err_remove_all;
>>>>>>
>>>>>>           found:
>>>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>>>> +                       continue;
>>>>>> +
>>>>>>                 if (__ipipe_hrtimer_freq == 0)
>>>>>>                         __ipipe_hrtimer_freq = t->freq;
>>>>>>                 per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>>>
>>>>> Thanks for looking into this Gilles!
>>>>> I tried your second patch only and unfortunately I was still able to
>>>>> reproduce the same kernel NULL pointer dereference.
>>>>
>>>>
>>>> Sorry, I meant the first xenomai patch needs the second I-pipe patch to
>>>> work.
>>>
>>> I applied both patches now, but still able to reproduce the same problem.
>>
>> Ok, to debug this, you can add:
>> BUG_ON((unsigned long)xnthread_user_task(thread) < 0xc0000000);
>> in xnshadow_send_sig. Add:
>> BUG_ON((unsigned long)p < 0xc0000000)
>> in lostage_handler, in the LO_SIGTHR_REQ case.
>>
>> Enable the I-pipe tracer, panic back traces, then set the number of
>> points to a reasonably high value before running your test.
> 
> Please find attached the trace ipipe_trace.txt
> 
> Note that in order to compile the ipipe-tracer for x86 I had to remove
> the call to hard_irqs_disabled_flags. I changed that to 0.. hope that
> doesn't affect the trace log.


It does affect the trace, we do not see whether the irqs are off, but it
is not very important for the issue you have. You can replace with
arch_irqs_disable_flags, I have a fix for this in my tree, not pushed
yet, but should be in the I-pipe repository soon.

Anyway, what seems to happen is that your application calls exit, while
some thread was waiting for a a PI mutex, the nucleus tries to send a
signal to the mutex holder. However, something gets wrong, and the mutex
holder task pointer is invalid.

What is strange, also, is how a task can be waiting for a mutex and
calling exit at the same time. Could you try to increase the number of
trace points to say 1000 points?

-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/05/2012 01:03 PM, Gilles Chanteperdrix wrote:

> On 09/05/2012 11:29 AM, Henri Roosen wrote:
> 
>> On Wed, Sep 5, 2012 at 10:28 AM, Gilles Chanteperdrix
>> <gilles.chanteperdrix@xenomai.org> wrote:
>>> On 09/05/2012 09:42 AM, Henri Roosen wrote:
>>>> On Wed, Sep 5, 2012 at 9:28 AM, Gilles Chanteperdrix
>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>> On 09/05/2012 09:26 AM, Henri Roosen wrote:
>>>>>
>>>>>> On Tue, Sep 4, 2012 at 9:21 PM, Gilles Chanteperdrix
>>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>> On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:
>>>>>>>
>>>>>>>> On 09/04/2012 04:28 PM, Henri Roosen wrote:
>>>>>>>>
>>>>>>>>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>>>>>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>>>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>>>>>>>>> Hi,
>>>>>>>>>>>
>>>>>>>>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>>>>>>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>>>>>>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>>>>>>>>
>>>>>>>>>>> Our application triggers the following NULL pointer dereference when I
>>>>>>>>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>>>>>>>>> The application does not trigger this when all tasks have the same
>>>>>>>>>>> affinity (set via /proc/xenomai/affinity).
>>>>>>>>>>>
>>>>>>>>>>> I was able to reproduce this also under QEMU and will do some
>>>>>>>>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>>>>>>>>> stacktrace below:
>>>>>>>>>>
>>>>>>>>>> Could you try to reduce the bug to a simple testcase which we would try
>>>>>>>>>> and run to reproduce?
>>>>>>>>>>
>>>>>>>>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>>>>>>>>> at 00000294
>>>>>>>>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>>>>>>>>
>>>>>>>>>> Or send us a disassembly of the function __lock_task_sighand?
>>>>>>>>
>>>>>>>>
>>>>>>>> Looks like someone is calling send_sig_info with an invalid pointer.
>>>>>>>> There is something seriously wrong.
>>>>>>>>
>>>>>>>> On the other hand, now that I think about it, you need at least the
>>>>>>>> following patch:
>>>>>>>>
>>>>>>>> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
>>>>>>>> index c75fcac..0f37bb2 100644
>>>>>>>> --- a/ksrc/nucleus/intr.c
>>>>>>>> +++ b/ksrc/nucleus/intr.c
>>>>>>>> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>>>>>>>>
>>>>>>>>  void xnintr_clock_handler(void)
>>>>>>>>  {
>>>>>>>> -     struct xnsched *sched = xnpod_current_sched();
>>>>>>>>       xnstat_exectime_t *prev;
>>>>>>>> +     struct xnsched *sched;
>>>>>>>> +     unsigned cpu;
>>>>>>>> +
>>>>>>>> +     cpu = xnarch_current_cpu();
>>>>>>>> +
>>>>>>>> +     if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
>>>>>>>> +             xnarch_relay_tick();
>>>>>>>> +             return;
>>>>>>>> +     }
>>>>>>>> +
>>>>>>>> +     sched = xnpod_sched_slot(cpu);
>>>>>>>>
>>>>>>>>       prev = xnstat_exectime_switch(sched,
>>>>>>>>               &nkclock.stat[xnsched_cpu(sched)].account);
>>>>>>>
>>>>>>>
>>>>>>> It should work (I did not test it), with the following patch on the
>>>>>>> I-pipe:
>>>>>>>
>>>>>>> diff --git a/kernel/ipipe/timer.c b/kernel/ipipe/timer.c
>>>>>>> index d51fa62..301cdc0 100644
>>>>>>> --- a/kernel/ipipe/timer.c
>>>>>>> +++ b/kernel/ipipe/timer.c
>>>>>>> @@ -176,11 +176,17 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>>>>                 hrclock_freq = __ipipe_hrclock_freq;
>>>>>>>
>>>>>>>         spin_lock_irqsave(&lock, flags);
>>>>>>> -       for_each_cpu(cpu, mask) {
>>>>>>> +       for_each_cpu(cpu, cpu_online_mask) {
>>>>>>>                 list_for_each_entry(t, &timers, link) {
>>>>>>>                         if (!cpumask_test_cpu(cpu, t->cpumask))
>>>>>>>                                 continue;
>>>>>>>
>>>>>>> +                       if (!cpumask_test_cpu(cpu, mask)
>>>>>>> +                           && t->irq == per_cpu(ipipe_percpu.hrtimer_irq, 0)) {
>>>>>>> +                               per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>>>> +                               goto found;
>>>>>>> +                       }
>>>>>>> +
>>>>>>>                         evtdev = t->host_timer;
>>>>>>>  #ifdef CONFIG_GENERIC_CLOCKEVENTS
>>>>>>>                         if (!evtdev
>>>>>>> @@ -188,10 +194,16 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>>>>  #endif /* CONFIG_GENERIC_CLOCKEVENTS */
>>>>>>>                                 goto found;
>>>>>>>                 }
>>>>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>>>>> +                       continue;
>>>>>>> +
>>>>>>>                 printk("I-pipe: could not find timer for cpu #%d\n", cpu);
>>>>>>>                 goto err_remove_all;
>>>>>>>
>>>>>>>           found:
>>>>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>>>>> +                       continue;
>>>>>>> +
>>>>>>>                 if (__ipipe_hrtimer_freq == 0)
>>>>>>>                         __ipipe_hrtimer_freq = t->freq;
>>>>>>>                 per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>>>>
>>>>>> Thanks for looking into this Gilles!
>>>>>> I tried your second patch only and unfortunately I was still able to
>>>>>> reproduce the same kernel NULL pointer dereference.
>>>>>
>>>>>
>>>>> Sorry, I meant the first xenomai patch needs the second I-pipe patch to
>>>>> work.
>>>>
>>>> I applied both patches now, but still able to reproduce the same problem.
>>>
>>> Ok, to debug this, you can add:
>>> BUG_ON((unsigned long)xnthread_user_task(thread) < 0xc0000000);
>>> in xnshadow_send_sig. Add:
>>> BUG_ON((unsigned long)p < 0xc0000000)
>>> in lostage_handler, in the LO_SIGTHR_REQ case.
>>>
>>> Enable the I-pipe tracer, panic back traces, then set the number of
>>> points to a reasonably high value before running your test.
>>
>> Please find attached the trace ipipe_trace.txt
>>
>> Note that in order to compile the ipipe-tracer for x86 I had to remove
>> the call to hard_irqs_disabled_flags. I changed that to 0.. hope that
>> doesn't affect the trace log.
> 
> 
> It does affect the trace, we do not see whether the irqs are off, but it
> is not very important for the issue you have. You can replace with
> arch_irqs_disable_flags, I have a fix for this in my tree, not pushed
> yet, but should be in the I-pipe repository soon.
> 
> Anyway, what seems to happen is that your application calls exit, while
> some thread was waiting for a a PI mutex, the nucleus tries to send a
> signal to the mutex holder. However, something gets wrong, and the mutex
> holder task pointer is invalid.
> 
> What is strange, also, is how a task can be waiting for a mutex and
> calling exit at the same time. Could you try to increase the number of
> trace points to say 1000 points?


Answering myself. The thread killed is the one holding the mutex. The
signal is sent to this precise thread, so this may fail because the
thread is in the process of being destroyed, and its user_task pointer
is no longer valid.

-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Henri Roosen]

On Wed, Sep 5, 2012 at 1:21 PM, Gilles Chanteperdrix
<gilles.chanteperdrix@xenomai.org> wrote:
> On 09/05/2012 01:03 PM, Gilles Chanteperdrix wrote:
>
>> On 09/05/2012 11:29 AM, Henri Roosen wrote:
>>
>>> On Wed, Sep 5, 2012 at 10:28 AM, Gilles Chanteperdrix
>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>> On 09/05/2012 09:42 AM, Henri Roosen wrote:
>>>>> On Wed, Sep 5, 2012 at 9:28 AM, Gilles Chanteperdrix
>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>> On 09/05/2012 09:26 AM, Henri Roosen wrote:
>>>>>>
>>>>>>> On Tue, Sep 4, 2012 at 9:21 PM, Gilles Chanteperdrix
>>>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>>> On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:
>>>>>>>>
>>>>>>>>> On 09/04/2012 04:28 PM, Henri Roosen wrote:
>>>>>>>>>
>>>>>>>>>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>>>>>>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>>>>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>>>>>>>>>> Hi,
>>>>>>>>>>>>
>>>>>>>>>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>>>>>>>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>>>>>>>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>>>>>>>>>
>>>>>>>>>>>> Our application triggers the following NULL pointer dereference when I
>>>>>>>>>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>>>>>>>>>> The application does not trigger this when all tasks have the same
>>>>>>>>>>>> affinity (set via /proc/xenomai/affinity).
>>>>>>>>>>>>
>>>>>>>>>>>> I was able to reproduce this also under QEMU and will do some
>>>>>>>>>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>>>>>>>>>> stacktrace below:
>>>>>>>>>>>
>>>>>>>>>>> Could you try to reduce the bug to a simple testcase which we would try
>>>>>>>>>>> and run to reproduce?
>>>>>>>>>>>
>>>>>>>>>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>>>>>>>>>> at 00000294
>>>>>>>>>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>>>>>>>>>
>>>>>>>>>>> Or send us a disassembly of the function __lock_task_sighand?
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Looks like someone is calling send_sig_info with an invalid pointer.
>>>>>>>>> There is something seriously wrong.
>>>>>>>>>
>>>>>>>>> On the other hand, now that I think about it, you need at least the
>>>>>>>>> following patch:
>>>>>>>>>
>>>>>>>>> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
>>>>>>>>> index c75fcac..0f37bb2 100644
>>>>>>>>> --- a/ksrc/nucleus/intr.c
>>>>>>>>> +++ b/ksrc/nucleus/intr.c
>>>>>>>>> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>>>>>>>>>
>>>>>>>>>  void xnintr_clock_handler(void)
>>>>>>>>>  {
>>>>>>>>> -     struct xnsched *sched = xnpod_current_sched();
>>>>>>>>>       xnstat_exectime_t *prev;
>>>>>>>>> +     struct xnsched *sched;
>>>>>>>>> +     unsigned cpu;
>>>>>>>>> +
>>>>>>>>> +     cpu = xnarch_current_cpu();
>>>>>>>>> +
>>>>>>>>> +     if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
>>>>>>>>> +             xnarch_relay_tick();
>>>>>>>>> +             return;
>>>>>>>>> +     }
>>>>>>>>> +
>>>>>>>>> +     sched = xnpod_sched_slot(cpu);
>>>>>>>>>
>>>>>>>>>       prev = xnstat_exectime_switch(sched,
>>>>>>>>>               &nkclock.stat[xnsched_cpu(sched)].account);
>>>>>>>>
>>>>>>>>
>>>>>>>> It should work (I did not test it), with the following patch on the
>>>>>>>> I-pipe:
>>>>>>>>
>>>>>>>> diff --git a/kernel/ipipe/timer.c b/kernel/ipipe/timer.c
>>>>>>>> index d51fa62..301cdc0 100644
>>>>>>>> --- a/kernel/ipipe/timer.c
>>>>>>>> +++ b/kernel/ipipe/timer.c
>>>>>>>> @@ -176,11 +176,17 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>>>>>                 hrclock_freq = __ipipe_hrclock_freq;
>>>>>>>>
>>>>>>>>         spin_lock_irqsave(&lock, flags);
>>>>>>>> -       for_each_cpu(cpu, mask) {
>>>>>>>> +       for_each_cpu(cpu, cpu_online_mask) {
>>>>>>>>                 list_for_each_entry(t, &timers, link) {
>>>>>>>>                         if (!cpumask_test_cpu(cpu, t->cpumask))
>>>>>>>>                                 continue;
>>>>>>>>
>>>>>>>> +                       if (!cpumask_test_cpu(cpu, mask)
>>>>>>>> +                           && t->irq == per_cpu(ipipe_percpu.hrtimer_irq, 0)) {
>>>>>>>> +                               per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>>>>> +                               goto found;
>>>>>>>> +                       }
>>>>>>>> +
>>>>>>>>                         evtdev = t->host_timer;
>>>>>>>>  #ifdef CONFIG_GENERIC_CLOCKEVENTS
>>>>>>>>                         if (!evtdev
>>>>>>>> @@ -188,10 +194,16 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>>>>>  #endif /* CONFIG_GENERIC_CLOCKEVENTS */
>>>>>>>>                                 goto found;
>>>>>>>>                 }
>>>>>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>>>>>> +                       continue;
>>>>>>>> +
>>>>>>>>                 printk("I-pipe: could not find timer for cpu #%d\n", cpu);
>>>>>>>>                 goto err_remove_all;
>>>>>>>>
>>>>>>>>           found:
>>>>>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>>>>>> +                       continue;
>>>>>>>> +
>>>>>>>>                 if (__ipipe_hrtimer_freq == 0)
>>>>>>>>                         __ipipe_hrtimer_freq = t->freq;
>>>>>>>>                 per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>>>>>
>>>>>>> Thanks for looking into this Gilles!
>>>>>>> I tried your second patch only and unfortunately I was still able to
>>>>>>> reproduce the same kernel NULL pointer dereference.
>>>>>>
>>>>>>
>>>>>> Sorry, I meant the first xenomai patch needs the second I-pipe patch to
>>>>>> work.
>>>>>
>>>>> I applied both patches now, but still able to reproduce the same problem.
>>>>
>>>> Ok, to debug this, you can add:
>>>> BUG_ON((unsigned long)xnthread_user_task(thread) < 0xc0000000);
>>>> in xnshadow_send_sig. Add:
>>>> BUG_ON((unsigned long)p < 0xc0000000)
>>>> in lostage_handler, in the LO_SIGTHR_REQ case.
>>>>
>>>> Enable the I-pipe tracer, panic back traces, then set the number of
>>>> points to a reasonably high value before running your test.
>>>
>>> Please find attached the trace ipipe_trace.txt
>>>
>>> Note that in order to compile the ipipe-tracer for x86 I had to remove
>>> the call to hard_irqs_disabled_flags. I changed that to 0.. hope that
>>> doesn't affect the trace log.
>>
>>
>> It does affect the trace, we do not see whether the irqs are off, but it
>> is not very important for the issue you have. You can replace with
>> arch_irqs_disable_flags, I have a fix for this in my tree, not pushed
>> yet, but should be in the I-pipe repository soon.
>>
>> Anyway, what seems to happen is that your application calls exit, while
>> some thread was waiting for a a PI mutex, the nucleus tries to send a
>> signal to the mutex holder. However, something gets wrong, and the mutex
>> holder task pointer is invalid.
>>
>> What is strange, also, is how a task can be waiting for a mutex and
>> calling exit at the same time. Could you try to increase the number of
>> trace points to say 1000 points?
>
>
> Answering myself. The thread killed is the one holding the mutex. The
> signal is sent to this precise thread, so this may fail because the
> thread is in the process of being destroyed, and its user_task pointer
> is no longer valid.

Please find attached ipipe_trace_2.txt that has the number of
tracepoints to 1000. Note that this log also doesn't trace whether
irqs are off (arch_irqs_disable_flags is not in the current ipipe tree
yet either).

I will find out why the application is doing a sys_exit. However I'm
not sure how this is related to the thread affinity; when not setting
the affinity, the problem is not reproducable.
>
> --
>                                                                 Gilles.
-------------- next part --------------
[   35.951371] [sched_delayed] sched: RT throttling activated
[   40.191027] I-pipe: Detected stalled head domain, probably caused by a bug.
[   40.191030]         A critical section may have been left unterminated.
[   40.191621] Pid: 246, comm: cyclic:214:246 Tainted: G           O 3.4.6+ #72
[   40.191621] Call Trace:
[   40.191621]  [<c0161420>] ipipe_root_only+0x7f/0x8b
[   40.191621]  [<c0161f7a>] ipipe_unstall_root+0x12/0x2d
[   40.191621]  [<c0102695>] conditional_sti+0xe/0x10
[   40.191621]  [<c01029e6>] do_invalid_op+0x59/0x80
[   40.191621]  [<c0188347>] ? xnshadow_send_sig+0x19/0x3e
[   40.191621]  [<c01614f0>] ? __ipipe_notify_trap+0x9/0x82
[   40.191621]  [<c0113d3f>] ? __ipipe_handle_exception+0x9/0x1f4
[   40.191621]  [<c01645a2>] ? ipipe_trace_function+0x19/0x1c
[   40.191621]  [<c0113922>] ? __ipipe_get_current_domain+0xe/0x43
[   40.191621]  [<c0113f11>] __ipipe_handle_exception+0x1db/0x1f4
[   40.191621]  [<c041e577>] error_code+0x5f/0x6c
[   40.191621]  [<c016007b>] ? __rcu_process_callbacks+0x2b7/0x355
[   40.191621]  [<c0188347>] ? xnshadow_send_sig+0x19/0x3e
[   40.191621]  [<c01883f7>] xnshadow_renice+0x2d/0x30
[   40.191621]  [<c0182d5b>] xnsynch_renice_thread+0x32/0x48
[   40.191621]  [<c0182de7>] xnsynch_clear_boost+0x76/0x79
[   40.191621]  [<c0183182>] xnsynch_release_thread+0xe1/0x12b
[   40.191621]  [<c018320a>] xnsynch_release_all_ownerships+0x3e/0x55
[   40.191621]  [<c0181198>] xnpod_delete_thread+0x18e/0x254
[   40.191621]  [<c0187d45>] taskexit_event+0xce/0x14e
[   40.191621]  [<c0164861>] ipipe_kevent_hook+0x1c/0x1f
[   40.191621]  [<c01614c7>] __ipipe_notify_kevent+0x4e/0x6e
[   40.191621]  [<c01225c0>] do_exit+0x207/0x6a1
[   40.191621]  [<c01645a2>] ? ipipe_trace_function+0x19/0x1c
[   40.191621]  [<c0122b18>] sys_exit+0x18/0x18
[   40.191621]  [<c041dd3a>] syscall_call+0x7/0xb
[   40.191621] I-pipe tracer log (1000 points):
[   40.191621]     *#func                    0 ipipe_trace_panic_freeze+0x4 (ipipe_root_only+0x53)
[   40.191621]     *#func                    0 ipipe_prepare_panic+0x4 (ipipe_root_only+0x4e)
[   40.191621]     *#func                    0 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]     *#func                    0 ipipe_unstall_root+0x3 (conditional_sti+0xe)
[   40.191621]     *#func                    0 __rcu_read_unlock+0x4 (__atomic_notifier_call_chain+0x31)
[   40.191621]     *#func                   -6 hw_breakpoint_exceptions_notify+0x9 (notifier_call_chain+0x30)
[   40.191621]     *#func                   -7 notifier_call_chain+0x9 (__atomic_notifier_call_chain+0x2a)
[   40.191621]     *#func                   -7 __rcu_read_lock+0x3 (__atomic_notifier_call_chain+0x19)
[   40.191621]     *#func                   -7 __atomic_notifier_call_chain+0x6 (atomic_notifier_call_chain+0x11)
[   40.191621]     *#func                   -7 atomic_notifier_call_chain+0x3 (notify_die+0x2d)
[   40.191621]     *#func                   -7 do_invalid_op+0x8 (__ipipe_handle_exception+0x1db)
[   40.191621]     *#func                   -8 __ipipe_notify_trap+0x9 (__ipipe_handle_exception+0x89)
[   40.191621]     *+func                   -8 __ipipe_handle_exception+0x9 (error_code+0x5f)
[   40.191621]     *+func                  -11 xnshadow_send_sig+0x4 (xnshadow_renice+0x2d)
[   40.191621]     *+func                  -12 xnshadow_renice+0x3 (xnsynch_renice_thread+0x32)
[   40.191621]     *+func                  -12 xnsched_track_policy+0x5 (xnsynch_renice_thread+0x10)
[   40.191621]     *+func                  -12 xnsynch_renice_thread+0x4 (xnsynch_clear_boost+0x76)
[   40.191621]     *+func                  -12 xnsynch_clear_boost+0x4 (xnsynch_release_thread+0xe1)
[   40.191621]     *+[  229] Watchdo 96    -12 xnpod_resume_thread+0x40 (xnsynch_release_thread+0xd1)
[   40.191621]     *+func                  -13 xnpod_resume_thread+0x9 (xnsynch_release_thread+0xd1)
[   40.191621]     *+func                  -13 xnsynch_release_thread+0x9 (xnsynch_release_all_ownerships+0x3e)
[   40.191621]     *+func                  -13 xnsynch_release_all_ownerships+0x9 (xnpod_delete_thread+0x18e)
[   40.191621]     *+func                  -14 xntimer_destroy+0x5 (xnpod_delete_thread+0x15e)
[   40.191621]     *+func                  -14 xntimer_destroy+0x5 (xnpod_delete_thread+0x153)
[   40.191621]     *+func                  -14 xnpod_delete_thread+0x6 (taskexit_event+0xce)
[   40.191621]      +begin   0x80000000    -14 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]      +func                  -15 __task_get_magic+0x3 (taskexit_event+0x5b)
[   40.191621]      +func                  -15 taskexit_event+0x9 (ipipe_kevent_hook+0x1c)
[   40.191621]      +func                  -15 ipipe_kevent_hook+0x4 (__ipipe_notify_kevent+0x4e)
[   40.191621]      +end     0x80000001    -15 hard_local_irq_restore+0x15 (__ipipe_notify_kevent+0x43)
[   40.191621]      +begin   0x80000001    -15 hard_local_irq_save+0x16 (__ipipe_notify_kevent+0x20)
[   40.191621]      +end     0x80000001    -15 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -15 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -15 ipipe_root_only+0x5 (__ipipe_notify_kevent+0x1b)
[   40.191621]      +func                  -16 __ipipe_notify_kevent+0x9 (do_exit+0x207)
[   40.191621]      +end     0x80000001    -16 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -16 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -16 ipipe_root_only+0x5 (mmput+0x10)
[   40.191621]      +func                  -16 mmput+0x4 (exit_mm+0xe5)
[   40.191621]      +func                  -16 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      +func                  -16 _raw_spin_unlock+0x3 (exit_mm+0xde)
[   40.191621]      +func                  -17 up_read+0x3 (exit_mm+0xc3)
[   40.191621]      +end     0x80000001    -17 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -17 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -17 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                  -17 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      +func                  -17 _raw_spin_lock+0x4 (exit_mm+0xb1)
[   40.191621]      +end     0x80000001    -17 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -17 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -18 ipipe_root_only+0x5 (down_read+0x10)
[   40.191621]      +func                  -18 down_read+0x4 (exit_mm+0x37)
[   40.191621]      +func                  -18 sync_mm_rss+0x5 (exit_mm+0x2c)
[   40.191621]      +func                  -18 drop_futex_key_refs+0x3 (futex_wake+0xd0)
[   40.191621]      +func                  -18 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      +func                  -18 _raw_spin_unlock+0x3 (futex_wake+0xc8)
[   40.191621]      +end     0x80000001    -18 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -19 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -19 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                  -19 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      +func                  -19 _raw_spin_lock+0x4 (futex_wake+0x58)
[   40.191621]      +func                  -19 hash_futex+0x4 (futex_wake+0x51)
[   40.191621]      +func                  -19 put_page+0x3 (get_futex_key+0x17e)
[   40.191621]      +func                  -19 __wake_up_bit+0x7 (unlock_page+0x45)
[   40.191621]      +func                  -20 unlock_page+0x4 (get_futex_key+0x177)
[   40.191621]      +func                  -20 get_futex_key_refs+0x3 (get_futex_key+0x170)
[   40.191621]      +end     0x80000001    -20 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -20 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -20 ipipe_root_only+0x5 (get_futex_key+0x108)
[   40.191621]      +end     0x80000000    -20 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                  -20 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000    -21 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                  -21 ipipe_unstall_root+0x3 (get_user_pages_fast+0xb7)
[   40.191621]      #func                  -21 gup_pte_range+0x9 (gup_pud_range+0x4a)
[   40.191621]      #func                  -21 gup_pud_range+0x9 (get_user_pages_fast+0x9e)
[   40.191621]      +func                  -22 get_user_pages_fast+0x9 (get_futex_key+0x94)
[   40.191621]      +func                  -22 get_futex_key+0x9 (futex_wake+0x3f)
[   40.191621]      +func                  -22 futex_wake+0x9 (do_futex+0xce)
[   40.191621]      +func                  -22 do_futex+0xc (sys_futex+0xee)
[   40.191621]      +func                  -23 sys_futex+0x9 (mm_release+0xb4)
[   40.191621]      +end     0x80000001    -23 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -23 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -23 ipipe_root_only+0x5 (mm_release+0x97)
[   40.191621]      +end     0x80000001    -24 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -24 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -24 ipipe_root_only+0x5 (exit_robust_list+0x5e)
[   40.191621]      +end     0x80000001    -24 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -24 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -24 ipipe_root_only+0x5 (exit_robust_list+0x43)
[   40.191621]      +end     0x80000001    -24 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -24 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -24 ipipe_root_only+0x5 (exit_robust_list+0x2c)
[   40.191621]      +func                  -25 exit_robust_list+0x9 (mm_release+0x1d)
[   40.191621]      +func                  -25 mm_release+0x6 (exit_mm+0x1d)
[   40.191621]      +func                  -25 exit_mm+0x9 (do_exit+0x1c1)
[   40.191621]      +func                  -25 sync_mm_rss+0x5 (do_exit+0x13d)
[   40.191621]      +func                  -26 exit_irq_thread+0x5 (do_exit+0xfc)
[   40.191621]      +func                  -26 sub_preempt_count+0x4 (_raw_spin_unlock_irq+0x1a)
[   40.191621]      +end     0x80000000    -26 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                  -26 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000    -26 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                  -27 ipipe_unstall_root+0x3 (_raw_spin_unlock_irq+0x10)
[   40.191621]      #func                  -27 _raw_spin_unlock_irq+0x3 (exit_signals+0x83)
[   40.191621]      #end     0x80000001    -27 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -27 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -27 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                  -27 add_preempt_count+0x4 (_raw_spin_lock_irq+0x28)
[   40.191621]      +func                  -27 _raw_spin_lock_irq+0x4 (exit_signals+0xb8)
[   40.191621]      +func                  -28 exit_signals+0x8 (do_exit+0xd9)
[   40.191621]      +func                  -28 do_exit+0x9 (complete_and_exit+0x0)
[   40.191621]      +func                  -28 sys_exit+0x3 (syscall_call+0x7)
[   40.191621]      +end     0x80000001    -28 __ipipe_syscall_root+0x90 (system_call+0x2d)
[   40.191621]      +begin   0x80000001    -29 hard_local_irq_save+0x16 (__ipipe_syscall_root+0x35)
[   40.191621]      +end     0x80000001    -29 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0xc5)
[   40.191621]      +begin   0x80000001    -29 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]      +func                  -29 losyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]      +end     0x80000001    -29 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]      +begin   0x80000001    -29 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]      +func                  -29 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]      +end     0x80000001    -29 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]      +begin   0x80000001    -30 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]      +func                  -30 sub_preempt_count+0x4 (__ipipe_reenter_root+0x39)
[   40.191621]      +func                  -30 sub_preempt_count+0x4 (_raw_spin_unlock_irq+0x1a)
[   40.191621]      +end     0x80000000    -30 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                  -30 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000    -30 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                  -30 ipipe_unstall_root+0x3 (_raw_spin_unlock_irq+0x10)
[   40.191621]      #func                  -31 _raw_spin_unlock_irq+0x3 (finish_task_switch+0x4c)
[   40.191621]      #func                  -31 finish_task_switch+0x9 (__ipipe_reenter_root+0x28)
[   40.191621]      #end     0x80000001    -31 debug_smp_processor_id+0x82 (__ipipe_reenter_root+0x13)
[   40.191621]      #begin   0x80000001    -31 debug_smp_processor_id+0x36 (__ipipe_reenter_root+0x13)
[   40.191621]      #func                  -31 __ipipe_reenter_root+0x4 (xnshadow_relax+0xc5)
[   40.191621]      #end     0x80000000    -31 hard_local_irq_enable+0x14 (ipipe_unstall_head+0x2e)
[   40.191621]     *#func                  -31 ipipe_unstall_head+0x4 (xnshadow_relax+0xb4)
[   40.191621]      #begin   0x80000000    -31 xnpod_suspend_thread+0x1b5 (xnshadow_relax+0xaf)
[   40.191621]      #end     0xffffff0f    -32 ipipe_reschedule_interrupt+0x41 (hard_local_irq_enable+0x16)
[   40.191621]      #func                  -32 __ipipe_do_sync_pipeline+0x4 (__ipipe_dispatch_irq+0x170)
[   40.191621]      #func                  -32 __switch_to+0x9 (__xnpod_schedule+0x407)
[   40.191621]      #begin   0x80000000    -32 __schedule+0x32d (schedule+0x5b)
[   40.191621]      #end     0x80000001    -32 hard_local_irq_restore+0x15 (__ipipe_notify_kevent+0x65)
[   40.191621]      #begin   0x80000001    -32 hard_local_irq_save+0x16 (__ipipe_notify_kevent+0x55)
[   40.191621]      #func                  -33 schedule_event+0x5 (ipipe_kevent_hook+0x1c)
[   40.191621]      #func                  -33 ipipe_kevent_hook+0x4 (__ipipe_notify_kevent+0x4e)
[   40.191621]      #end     0x80000001    -33 hard_local_irq_restore+0x15 (__ipipe_notify_kevent+0x43)
[   40.191621]      #begin   0x80000001    -33 hard_local_irq_save+0x16 (__ipipe_notify_kevent+0x20)
[   40.191621]      #end     0x80000001    -33 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -33 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -33 ipipe_root_only+0x5 (__ipipe_notify_kevent+0x1b)
[   40.191621]      #func                  -33 __ipipe_notify_kevent+0x9 (__schedule+0x31b)
[   40.191621]      #func                  -34 pick_next_task_rt+0x6 (__schedule+0x25f)
[   40.191621]      #func                  -34 pick_next_task_stop+0x3 (__schedule+0x25f)
[   40.191621]      #func                  -34 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      #func                  -34 _raw_spin_unlock+0x3 (update_curr_rt+0x1eb)
[   40.191621]      #end     0x80000001    -34 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -34 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -34 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                  -34 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      #func                  -34 _raw_spin_lock+0x4 (update_curr_rt+0x113)
[   40.191621]      #func                  -35 sched_avg_update+0x9 (update_curr_rt+0xcc)
[   40.191621]      #func                  -35 update_curr_rt+0x9 (put_prev_task_rt+0x13)
[   40.191621]      #func                  -35 put_prev_task_rt+0x5 (__schedule+0x235)
[   40.191621]      #func                  -35 pull_rt_task+0x9 (pre_schedule_rt+0x1c)
[   40.191621]      #func                  -35 pre_schedule_rt+0x3 (__schedule+0x1fc)
[   40.191621]      #func                  -35 update_rt_migration+0x5 (__dequeue_rt_entity+0x13c)
[   40.191621]      #func                  -35 cpupri_set+0x6 (__dequeue_rt_entity+0x11f)
[   40.191621]      #func                  -35 __dequeue_rt_entity+0x9 (dequeue_task_rt+0x39)
[   40.191621]      #func                  -36 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      #func                  -36 _raw_spin_unlock+0x3 (update_curr_rt+0x1eb)
[   40.191621]      #end     0x80000001    -36 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -36 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -36 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                  -36 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      #func                  -36 _raw_spin_lock+0x4 (update_curr_rt+0x113)
[   40.191621]      #func                  -36 sched_avg_update+0x9 (update_curr_rt+0xcc)
[   40.191621]      #func                  -36 update_curr_rt+0x9 (dequeue_task_rt+0x1f)
[   40.191621]      #func                  -37 dequeue_task_rt+0x9 (dequeue_task+0x27)
[   40.191621]      #end     0x80000001    -37 debug_smp_processor_id+0x82 (__cycles_2_ns+0x17)
[   40.191621]      #begin   0x80000001    -37 debug_smp_processor_id+0x36 (__cycles_2_ns+0x17)
[   40.191621]      #end     0x80000001    -37 debug_smp_processor_id+0x82 (sched_clock_cpu+0x95)
[   40.191621]      #begin   0x80000001    -37 debug_smp_processor_id+0x36 (sched_clock_cpu+0x95)
[   40.191621]      #func                  -37 update_rq_clock+0x5 (dequeue_task+0x1a)
[   40.191621]      #func                  -37 dequeue_task+0x9 (deactivate_task+0x24)
[   40.191621]      #func                  -37 deactivate_task+0x4 (__schedule+0x12d)
[   40.191621]      #end     0x80000001    -37 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -38 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -38 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                  -38 add_preempt_count+0x4 (_raw_spin_lock_irq+0x28)
[   40.191621]      +func                  -38 _raw_spin_lock_irq+0x4 (__schedule+0xc5)
[   40.191621]      +end     0x80000001    -38 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -38 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -38 ipipe_root_only+0x5 (__schedule+0x79)
[   40.191621]      +end     0x80000000    -38 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                  -39 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000    -39 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                  -39 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001    -39 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -39 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -39 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                  -39 ipipe_restore_root+0x4 (arch_local_irq_restore+0x11)
[   40.191621]      +func                  -39 rcu_note_context_switch+0x9 (__schedule+0x3d)
[   40.191621]      +end     0x80000001    -40 debug_smp_processor_id+0x82 (__schedule+0x28)
[   40.191621]      +begin   0x80000001    -40 debug_smp_processor_id+0x36 (__schedule+0x28)
[   40.191621]      +end     0x80000001    -40 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001    -40 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                  -40 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                  -40 add_preempt_count+0x4 (__schedule+0x23)
[   40.191621]      +func                  -40 __schedule+0x9 (schedule+0x5b)
[   40.191621]      +func                  -40 schedule+0x3 (gatekeeper_thread+0xbf)
[   40.191621]      +func                  -41 sub_preempt_count+0x4 (_raw_spin_unlock_irqrestore+0x28)
[   40.191621]      +end     0x80000000    -41 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                  -41 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000    -41 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                  -41 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001    -41 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -41 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -41 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                  -41 ipipe_restore_root+0x4 (_raw_spin_unlock_irqrestore+0x1e)
[   40.191621]      #func                  -42 _raw_spin_unlock_irqrestore+0x3 (up+0x37)
[   40.191621]      #func                  -42 __ipipe_spin_unlock_debug+0x3 (up+0x2e)
[   40.191621]      #end     0x80000001    -42 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -42 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -42 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                  -42 add_preempt_count+0x4 (_raw_spin_lock_irqsave+0x49)
[   40.191621]      +func                  -42 _raw_spin_lock_irqsave+0x5 (up+0x11)
[   40.191621]      +func                  -42 up+0x5 (gatekeeper_thread+0xba)
[   40.191621]      +end     0x80000001    -43 ipipe_raise_irq+0x3d (__xnpod_schedule+0x26)
[   40.191621]      #begin   0x80000000    -43 hard_local_irq_disable+0x15 (__ipipe_do_sync_stage+0x111)
[   40.191621]      #func                  -43 sub_preempt_count+0x4 (irq_exit+0xa8)
[   40.191621]      #end     0x80000001    -43 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -43 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -43 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                  -43 ipipe_restore_root+0x4 (arch_local_irq_restore+0x11)
[   40.191621]      #end     0x80000001    -43 debug_smp_processor_id+0x82 (rcu_irq_exit+0x48)
[   40.191621]      #begin   0x80000001    -44 debug_smp_processor_id+0x36 (rcu_irq_exit+0x48)
[   40.191621]      #func                  -44 rcu_irq_exit+0x9 (irq_exit+0x9e)
[   40.191621]      #func                  -44 idle_cpu+0x3 (irq_exit+0x72)
[   40.191621]      #end     0x80000001    -44 debug_smp_processor_id+0x82 (irq_exit+0x6d)
[   40.191621]      #begin   0x80000001    -44 debug_smp_processor_id+0x36 (irq_exit+0x6d)
[   40.191621]      #func                  -44 sub_preempt_count+0x4 (irq_exit+0x12)
[   40.191621]      #func                  -44 irq_exit+0x3 (__ipipe_do_sync_stage+0x10c)
[   40.191621]      #func                  -44 sub_preempt_count+0x4 (_raw_spin_unlock_irqrestore+0x28)
[   40.191621]      #end     0x80000001    -45 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -45 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -45 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                  -45 ipipe_restore_root+0x4 (_raw_spin_unlock_irqrestore+0x1e)
[   40.191621]      #func                  -45 _raw_spin_unlock_irqrestore+0x3 (try_to_wake_up+0x189)
[   40.191621]      #func                  -45 __ipipe_spin_unlock_debug+0x3 (try_to_wake_up+0x17e)
[   40.191621]      #func                  -45 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      #func                  -45 _raw_spin_unlock+0x3 (try_to_wake_up+0x16b)
[   40.191621]      #func                  -45 task_woken_rt+0x4 (ttwu_do_wakeup+0x6d)
[   40.191621]      #func                  -46 check_preempt_curr_rt+0x9 (check_preempt_curr+0x31)
[   40.191621]      #func                  -46 check_preempt_curr+0x9 (ttwu_do_wakeup+0x57)
[   40.191621]      #func                  -46 ttwu_do_wakeup+0x9 (ttwu_do_activate+0x39)
[   40.191621]      #func                  -46 update_rt_migration+0x5 (enqueue_task_rt+0x11f)
[   40.191621]      #func                  -46 enqueue_task_rt+0x9 (enqueue_task+0x27)
[   40.191621]      #end     0x80000001    -46 debug_smp_processor_id+0x82 (__cycles_2_ns+0x17)
[   40.191621]      #begin   0x80000001    -47 debug_smp_processor_id+0x36 (__cycles_2_ns+0x17)
[   40.191621]      #end     0x80000001    -47 debug_smp_processor_id+0x82 (sched_clock_cpu+0x95)
[   40.191621]      #begin   0x80000001    -47 debug_smp_processor_id+0x36 (sched_clock_cpu+0x95)
[   40.191621]      #func                  -47 update_rq_clock+0x5 (enqueue_task+0x1a)
[   40.191621]      #func                  -47 enqueue_task+0x9 (activate_task+0x24)
[   40.191621]      #func                  -47 activate_task+0x4 (ttwu_activate+0x13)
[   40.191621]      #func                  -47 ttwu_activate+0x5 (ttwu_do_activate+0x2e)
[   40.191621]      #func                  -47 ttwu_do_activate+0x6 (try_to_wake_up+0x164)
[   40.191621]      #end     0x80000001    -48 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -48 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -48 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                  -48 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      #func                  -48 _raw_spin_lock+0x4 (try_to_wake_up+0x159)
[   40.191621]      #end     0x80000001    -48 debug_smp_processor_id+0x82 (try_to_wake_up+0xf3)
[   40.191621]      #begin   0x80000001    -48 debug_smp_processor_id+0x36 (try_to_wake_up+0xf3)
[   40.191621]      #func                  -48 select_task_rq_rt+0x6 (select_task_rq+0x17)
[   40.191621]      #end     0x80000001    -49 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -49 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -49 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                  -49 add_preempt_count+0x4 (_raw_spin_lock_irqsave+0x49)
[   40.191621]      #func                  -49 _raw_spin_lock_irqsave+0x5 (try_to_wake_up+0x23)
[   40.191621]      #func                  -49 try_to_wake_up+0x9 (wake_up_process+0x14)
[   40.191621]      #func                  -49 wake_up_process+0x3 (lostage_handler+0xae)
[   40.191621]      #end     0x80000001    -49 debug_smp_processor_id+0x82 (lostage_handler+0x16)
[   40.191621]      #begin   0x80000001    -50 debug_smp_processor_id+0x36 (lostage_handler+0x16)
[   40.191621]      #func                  -50 lostage_handler+0xc (rthal_apc_handler+0x6a)
[   40.191621]      #func                  -50 rthal_apc_handler+0x6 (__ipipe_do_sync_stage+0x107)
[   40.191621]      #end     0x80000001    -50 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -50 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -50 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                  -50 add_preempt_count+0x4 (irq_enter+0x4f)
[   40.191621]      #end     0x80000001    -51 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001    -51 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                  -51 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                  -51 ipipe_restore_root+0x4 (arch_local_irq_restore+0x11)
[   40.191621]      #end     0x80000001    -51 debug_smp_processor_id+0x82 (rcu_irq_enter+0x48)
[   40.191621]      #begin   0x80000001    -51 debug_smp_processor_id+0x36 (rcu_irq_enter+0x48)
[   40.191621]      #func                  -51 rcu_irq_enter+0x9 (irq_enter+0x15)
[   40.191621]      #end     0x80000001    -51 debug_smp_processor_id+0x82 (irq_enter+0xe)
[   40.191621]      #begin   0x80000001    -52 debug_smp_processor_id+0x36 (irq_enter+0xe)
[   40.191621]      #func                  -52 irq_enter+0x4 (__ipipe_do_sync_stage+0xf4)
[   40.191621]      #end     0x80000000    -52 hard_local_irq_enable+0x14 (__ipipe_do_sync_stage+0xc0)
[   40.191621]      +func                  -52 __ipipe_do_sync_stage+0x9 (__ipipe_do_sync_pipeline+0x64)
[   40.191621]      +func                  -52 __ipipe_do_sync_pipeline+0x4 (__ipipe_dispatch_irq+0x170)
[   40.191621]     # func                  -52 taskSwitchXenomai+0x5 [sigmatek_lrt] (xnpod_fire_callouts+0x4b)
[   40.191621]     # func                  -52 xnpod_fire_callouts+0x9 (__xnpod_schedule+0x503)
[   40.191621]     # [   19] gatekee -1    -53 __xnpod_schedule+0x47e (xnpod_schedule+0x32)
[   40.191621]     # func                  -53 __switch_to+0x9 (__xnpod_schedule+0x407)
[   40.191621]     # func                  -53 xnsched_pick_next+0x6 (__xnpod_schedule+0xae)
[   40.191621]     # [  244] Loader: 29    -53 __xnpod_schedule+0x5f (xnpod_schedule+0x32)
[   40.191621]     # func                  -54 __xnpod_schedule+0x9 (xnpod_schedule+0x32)
[   40.191621]     # func                  -54 xnpod_suspend_thread+0x9 (xnsynch_sleep_on+0xb9)
[   40.191621]     # func                  -54 xnsynch_sleep_on+0x9 (rtdm_event_timedwait+0x87)
[   40.191621]     + begin   0x80000000    -54 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]     + func                  -54 rtdm_event_timedwait+0x9 (rtdm_event_wait+0x13)
[   40.191621]     + func                  -54 rtdm_event_wait+0x3 (lrtdrv_timing_wait+0xcf [sigmatek_lrt])
[   40.191621]     + end     0x80000001    -54 lrtdrv_timing_wait+0x78 [sigmatek_lrt] (lrt_ioctl_work+0x3ad [sigmatek_lrt])
[   40.191621]     + begin   0x80000001    -54 lrtdrv_timing_wait+0x2c [sigmatek_lrt] (lrt_ioctl_work+0x3ad [sigmatek_lrt])
[   40.191621]     + func                  -54 lrtdrv_timing_wait+0x9 [sigmatek_lrt] (lrt_ioctl_work+0x3ad [sigmatek_lrt])
[   40.191621]     + func                  -55 lrt_ioctl_work+0x9 [sigmatek_lrt] (lrt_ioctl+0x10 [sigmatek_lrt])
[   40.191621]     + func                  -55 lrt_ioctl+0x3 [sigmatek_lrt] (__rt_dev_ioctl+0x40)
[   40.191621]     + end     0x80000001    -55 rtdm_in_rt_context+0x67 (__rt_dev_ioctl+0x30)
[   40.191621]     + begin   0x80000001    -55 rtdm_in_rt_context+0x1d (__rt_dev_ioctl+0x30)
[   40.191621]     + end     0x80000000    -55 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                  -55 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x4d)
[   40.191621]     + begin   0x80000000    -55 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]     + func                  -55 rtdm_context_get+0x5 (__rt_dev_ioctl+0x1e)
[   40.191621]     + func                  -55 __rt_dev_ioctl+0x9 (sys_rtdm_ioctl+0x1d)
[   40.191621]     + func                  -56 sys_rtdm_ioctl+0x3 (hisyscall_event+0x124)
[   40.191621]     + func                  -56 hisyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]     + end     0x80000001    -56 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]     + begin   0x80000001    -56 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]     + func                  -56 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]     + end     0x80000001    -56 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]     + begin   0x80000001    -56 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x16)
[   40.191621]     + func                  -56 __ipipe_notify_syscall+0x9 (__ipipe_syscall_root+0x2e)
[   40.191621]     + func                  -56 __ipipe_syscall_root+0x6 (system_call+0x2d)
[   40.191621]     + begin   0x80000001    -57 hard_local_irq_save+0x16 (__ipipe_syscall_root+0x35)
[   40.191621]     + end     0x80000001    -57 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0xc5)
[   40.191621]     + begin   0x80000001    -57 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]     + func                  -58 __copy_to_user_ll+0x6 (rtdm_safe_copy_to_user+0x2b [platform_edge])
[   40.191621]     + func                  -58 xnarch_tsc_to_ns+0x5 (xnarch_get_cpu_time+0xf)
[   40.191621]     + func                  -58 xnarch_get_cpu_time+0x3 (platform_get_xenomai_time+0x17 [platform_edge])
[   40.191621]     + func                  -58 platform_get_xenomai_time+0x5 [platform_edge] (plc_platform_ioctl_rt+0x46a [platform_edge])
[   40.191621]     + func                  -58 plc_platform_ioctl_rt+0x9 [platform_edge] (__rt_dev_ioctl+0x40)
[   40.191621]     + end     0x80000001    -58 rtdm_in_rt_context+0x67 (__rt_dev_ioctl+0x30)
[   40.191621]     + begin   0x80000001    -58 rtdm_in_rt_context+0x1d (__rt_dev_ioctl+0x30)
[   40.191621]     + end     0x80000000    -58 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                  -58 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x4d)
[   40.191621]     + begin   0x80000000    -59 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]     + func                  -59 rtdm_context_get+0x5 (__rt_dev_ioctl+0x1e)
[   40.191621]     + func                  -59 __rt_dev_ioctl+0x9 (sys_rtdm_ioctl+0x1d)
[   40.191621]     + func                  -59 sys_rtdm_ioctl+0x3 (hisyscall_event+0x124)
[   40.191621]     + func                  -59 hisyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]     + end     0x80000001    -59 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]     + begin   0x80000001    -59 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]     + func                  -59 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]     + end     0x80000001    -59 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]     + begin   0x80000001    -60 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x16)
[   40.191621]     + func                  -60 __ipipe_notify_syscall+0x9 (__ipipe_syscall_root+0x2e)
[   40.191621]     + func                  -60 __ipipe_syscall_root+0x6 (system_call+0x2d)
[   40.191621]     + begin   0x80000001    -60 hard_local_irq_save+0x16 (__ipipe_syscall_root+0x35)
[   40.191621]     + end     0x80000001    -60 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0xc5)
[   40.191621]     + begin   0x80000001    -60 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]     + func                  -61 __copy_to_user_ll+0x6 (rtdm_safe_copy_to_user+0x2b [sigmatek_lrt])
[   40.191621]     + end     0x80000000    -61 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                  -61 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x4d)
[   40.191621]     # func                  -61 taskSwitchXenomai+0x5 [sigmatek_lrt] (xnpod_fire_callouts+0x4b)
[   40.191621]     # func                  -61 xnpod_fire_callouts+0x9 (__xnpod_schedule+0x503)
[   40.191621]     # [  244] Loader: 29    -61 __xnpod_schedule+0x47e (xnpod_schedule+0x32)
[   40.191621]     # func                  -62 __switch_to+0x9 (__xnpod_schedule+0x407)
[   40.191621]     # func                  -62 xnsched_pick_next+0x6 (__xnpod_schedule+0xae)
[   40.191621]     # [  248] realtim 95    -62 __xnpod_schedule+0x5f (xnpod_schedule+0x32)
[   40.191621]     # func                  -62 __xnpod_schedule+0x9 (xnpod_schedule+0x32)
[   40.191621]     # func                  -63 xnpod_suspend_thread+0x9 (xnsynch_sleep_on+0xb9)
[   40.191621]     # func                  -63 xnsynch_sleep_on+0x9 (rtdm_event_timedwait+0x87)
[   40.191621]     + begin   0x80000000    -63 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]     + func                  -63 rtdm_event_timedwait+0x9 (rtdm_event_wait+0x13)
[   40.191621]     + func                  -63 rtdm_event_wait+0x3 (lrtdrv_timing_wait+0xcf [sigmatek_lrt])
[   40.191621]     + end     0x80000001    -63 lrtdrv_timing_wait+0x78 [sigmatek_lrt] (lrt_ioctl_work+0x43d [sigmatek_lrt])
[   40.191621]     + begin   0x80000001    -63 lrtdrv_timing_wait+0x2c [sigmatek_lrt] (lrt_ioctl_work+0x43d [sigmatek_lrt])
[   40.191621]     + func                  -63 lrtdrv_timing_wait+0x9 [sigmatek_lrt] (lrt_ioctl_work+0x43d [sigmatek_lrt])
[   40.191621]     + func                  -64 rt_task_self+0x3 (setup_watchdog+0x44 [sigmatek_lrt])
[   40.191621]     + func                  -64 setup_watchdog+0x6 [sigmatek_lrt] (lrtdrv_timing_watchdog+0x48 [sigmatek_lrt])
[   40.191621]     + func                  -64 lrtdrv_timing_watchdog+0x6 [sigmatek_lrt] (lrt_ioctl_work+0x425 [sigmatek_lrt])
[   40.191621]     + func                  -64 __copy_from_user_ll_nozero+0x6 (rtdm_safe_copy_from_user+0x2d [sigmatek_lrt])
[   40.191621]     + func                  -64 lrt_ioctl_work+0x9 [sigmatek_lrt] (lrt_ioctl+0x10 [sigmatek_lrt])
[   40.191621]     + func                  -64 lrt_ioctl+0x3 [sigmatek_lrt] (__rt_dev_ioctl+0x40)
[   40.191621]     + end     0x80000001    -64 rtdm_in_rt_context+0x67 (__rt_dev_ioctl+0x30)
[   40.191621]     + begin   0x80000001    -65 rtdm_in_rt_context+0x1d (__rt_dev_ioctl+0x30)
[   40.191621]     + end     0x80000000    -65 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                  -65 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x4d)
[   40.191621]     + begin   0x80000000    -65 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]     + func                  -65 rtdm_context_get+0x5 (__rt_dev_ioctl+0x1e)
[   40.191621]     + func                  -65 __rt_dev_ioctl+0x9 (sys_rtdm_ioctl+0x1d)
[   40.191621]     + func                  -65 sys_rtdm_ioctl+0x3 (hisyscall_event+0x124)
[   40.191621]     + func                  -65 hisyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]     + end     0x80000001    -65 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]     + begin   0x80000001    -66 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]     + func                  -66 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]     + end     0x80000001    -66 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]     + begin   0x80000001    -66 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x16)
[   40.191621]     + func                  -66 __ipipe_notify_syscall+0x9 (__ipipe_syscall_root+0x2e)
[   40.191621]     + func                  -66 __ipipe_syscall_root+0x6 (system_call+0x2d)
[   40.191621]     + begin   0x80000001    -67 hard_local_irq_save+0x16 (__ipipe_syscall_root+0x35)
[   40.191621]     + end     0x80000001    -67 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0xc5)
[   40.191621]     + begin   0x80000001    -67 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]     + end     0x80000000    -68 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                  -68 __ipipe_restore_head+0x4 (xnlock_put_irqrestore+0x61)
[   40.191621]     + begin   0x80000000    -68 __xnlock_get_irqsave+0x19 (rt_queue_receive_inner+0x29)
[   40.191621]     + func                  -68 rt_queue_receive_inner+0x9 (__rt_queue_read+0x6b)
[   40.191621]     + func                  -68 __copy_from_user_ll_nozero+0x6 (__xn_safe_copy_from_user+0x28)
[   40.191621]     + func                  -68 xnregistry_fetch+0x3 (__rt_queue_read+0x30)
[   40.191621]     + func                  -68 __copy_from_user_ll_nozero+0x6 (__xn_safe_copy_from_user+0x28)
[   40.191621]     + func                  -69 __rt_queue_read+0x9 (hisyscall_event+0x124)
[   40.191621]     + func                  -69 hisyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]     + end     0x80000001    -69 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]     + begin   0x80000001    -69 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]     + func                  -69 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]     + end     0x80000001    -69 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]     + begin   0x80000001    -69 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x16)
[   40.191621]     + func                  -69 __ipipe_notify_syscall+0x9 (__ipipe_syscall_root+0x2e)
[   40.191621]     + func                  -70 __ipipe_syscall_root+0x6 (system_call+0x2d)
[   40.191621]     + begin   0x80000001    -71 hard_local_irq_save+0x16 (__ipipe_syscall_root+0x35)
[   40.191621]     + end     0x80000001    -72 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0xc5)
[   40.191621]     + begin   0x80000001    -72 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]     + func                  -72 __copy_to_user_ll+0x6 (rtdm_safe_copy_to_user+0x2b [platform_edge])
[   40.191621]     + func                  -72 xnarch_tsc_to_ns+0x5 (xnarch_get_cpu_time+0xf)
[   40.191621]     + func                  -72 xnarch_get_cpu_time+0x3 (platform_get_xenomai_time+0x17 [platform_edge])
[   40.191621]     + func                  -72 platform_get_xenomai_time+0x5 [platform_edge] (plc_platform_ioctl_rt+0x46a [platform_edge])
[   40.191621]     + func                  -72 plc_platform_ioctl_rt+0x9 [platform_edge] (__rt_dev_ioctl+0x40)
[   40.191621]     + end     0x80000001    -72 rtdm_in_rt_context+0x67 (__rt_dev_ioctl+0x30)
[   40.191621]     + begin   0x80000001    -73 rtdm_in_rt_context+0x1d (__rt_dev_ioctl+0x30)
[   40.191621]     + end     0x80000000    -73 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                  -73 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x4d)
[   40.191621]     + begin   0x80000000    -73 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]     + func                  -73 rtdm_context_get+0x5 (__rt_dev_ioctl+0x1e)
[   40.191621]     + func                  -73 __rt_dev_ioctl+0x9 (sys_rtdm_ioctl+0x1d)
[   40.191621]     + func                  -73 sys_rtdm_ioctl+0x3 (hisyscall_event+0x124)
[   40.191621]     + func                  -73 hisyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]     + end     0x80000001    -74 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]     + begin   0x80000001    -74 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]     + func                  -74 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]     + end     0x80000001    -74 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]     + begin   0x80000001    -74 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x16)
[   40.191621]     + func                  -74 __ipipe_notify_syscall+0x9 (__ipipe_syscall_root+0x2e)
[   40.191621]     + func                  -74 __ipipe_syscall_root+0x6 (system_call+0x2d)
[   40.191621]     + begin   0x80000001    -75 hard_local_irq_save+0x16 (__ipipe_syscall_root+0x35)
[   40.191621]     + end     0x80000001    -75 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0xc5)
[   40.191621]     + begin   0x80000001    -75 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]     + func                  -76 __copy_to_user_ll+0x6 (rtdm_safe_copy_to_user+0x2b [sigmatek_lrt])
[   40.191621]     + end     0x80000000    -77 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                  -77 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x4d)
[   40.191621]     # func                  -77 taskSwitchXenomai+0x5 [sigmatek_lrt] (xnpod_fire_callouts+0x4b)
[   40.191621]     # func                  -77 xnpod_fire_callouts+0x9 (__xnpod_schedule+0x503)
[   40.191621]     # [  248] realtim 95    -79 __xnpod_schedule+0x47e (xnpod_schedule+0x32)
[   40.191621]     # func                  -80 __switch_to+0x9 (__xnpod_schedule+0x407)
[   40.191621]     # func                  -80 xnsched_pick_next+0x6 (__xnpod_schedule+0xae)
[   40.191621]     # [  246] cyclic: 96    -81 __xnpod_schedule+0x5f (xnpod_schedule+0x32)
[   40.191621]     # func                  -81 __xnpod_schedule+0x9 (xnpod_schedule+0x32)
[   40.191621]     # func                  -81 xnpod_schedule_handler+0x3 (__ipipe_dispatch_irq+0x13e)
[   40.191621]     + func                  -87 __ipipe_ack_apic+0x3 (__ipipe_dispatch_irq+0x94)
[   40.191621]     + func                  -88 __ipipe_dispatch_irq+0x9 (__ipipe_handle_irq+0x7e)
[   40.191621]     + func                  -88 __ipipe_handle_irq+0x6 (ipipe_reschedule_interrupt+0x37)
[   40.191621]     + begin   0xffffff0f    -88 ipipe_reschedule_interrupt+0x30 (hard_local_irq_enable+0x16)
[   40.191621]     + end     0x80000000    -91 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                  -91 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x4d)
[   40.191621]     # func                  -92 xnpod_suspend_thread+0x9 (xnshadow_relax+0xaf)
[   40.191621]     # func                 -118 __xnlock_spin+0x4 (xnshadow_relax+0x81)
[   40.191621]     # func                 -119 __ipipe_set_irq_pending+0x6 (schedule_linux_call+0x81)
[   40.191621]     # func                 -119 schedule_linux_call+0x9 (xnshadow_relax+0x59)
[   40.191621]     + begin   0x80000000   -119 xnshadow_relax+0x3d (hisyscall_event+0x243)
[   40.191621]     + func                 -119 xnshadow_relax+0xc (hisyscall_event+0x243)
[   40.191621]     + func                 -119 hisyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]     + end     0x80000001   -119 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]     + begin   0x80000001   -120 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]     + func                 -120 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]     + end     0x80000001   -120 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]     + begin   0x80000001   -120 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x16)
[   40.191621]     + func                 -120 __ipipe_notify_syscall+0x9 (__ipipe_syscall_root+0x2e)
[   40.191621]     + func                 -120 __ipipe_syscall_root+0x6 (system_call+0x2d)
[   40.191621]     + begin   0x80000001   -137 hard_local_irq_save+0x16 (__ipipe_syscall_root+0x35)
[   40.191621]     + end     0x80000001   -137 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0xc5)
[   40.191621]     + begin   0x80000001   -137 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]     + func                 -137 __copy_to_user_ll+0x6 (rtdm_safe_copy_to_user+0x2b [platform_edge])
[   40.191621]     + func                 -137 xnarch_tsc_to_ns+0x5 (xnarch_get_cpu_time+0xf)
[   40.191621]     + func                 -137 xnarch_get_cpu_time+0x3 (platform_get_xenomai_time+0x17 [platform_edge])
[   40.191621]     + func                 -137 platform_get_xenomai_time+0x5 [platform_edge] (plc_platform_ioctl_rt+0x46a [platform_edge])
[   40.191621]     + func                 -137 plc_platform_ioctl_rt+0x9 [platform_edge] (__rt_dev_ioctl+0x40)
[   40.191621]     + end     0x80000001   -137 rtdm_in_rt_context+0x67 (__rt_dev_ioctl+0x30)
[   40.191621]     + begin   0x80000001   -138 rtdm_in_rt_context+0x1d (__rt_dev_ioctl+0x30)
[   40.191621]     + end     0x80000000   -138 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                 -138 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x4d)
[   40.191621]     + begin   0x80000000   -138 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]     + func                 -138 rtdm_context_get+0x5 (__rt_dev_ioctl+0x1e)
[   40.191621]     + func                 -138 __rt_dev_ioctl+0x9 (sys_rtdm_ioctl+0x1d)
[   40.191621]     + func                 -138 sys_rtdm_ioctl+0x3 (hisyscall_event+0x124)
[   40.191621]     + func                 -138 hisyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]     + end     0x80000001   -138 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]     + begin   0x80000001   -139 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]     + func                 -139 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]     + end     0x80000001   -139 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]     + begin   0x80000001   -139 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x16)
[   40.191621]     + func                 -139 __ipipe_notify_syscall+0x9 (__ipipe_syscall_root+0x2e)
[   40.191621]     + func                 -139 __ipipe_syscall_root+0x6 (system_call+0x2d)
[   40.191621]     + begin   0x80000001   -141 hard_local_irq_save+0x16 (__ipipe_syscall_root+0x35)
[   40.191621]     + end     0x80000001   -141 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0xc5)
[   40.191621]     + begin   0x80000001   -141 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]     + func                 -141 __copy_to_user_ll+0x6 (rtdm_safe_copy_to_user+0x2b [platform_edge])
[   40.191621]     + func                 -142 xnarch_tsc_to_ns+0x5 (xnarch_get_cpu_time+0xf)
[   40.191621]     + func                 -142 xnarch_get_cpu_time+0x3 (platform_get_xenomai_time+0x17 [platform_edge])
[   40.191621]     + func                 -142 platform_get_xenomai_time+0x5 [platform_edge] (plc_platform_ioctl_rt+0x46a [platform_edge])
[   40.191621]     + func                 -142 plc_platform_ioctl_rt+0x9 [platform_edge] (__rt_dev_ioctl+0x40)
[   40.191621]     + end     0x80000001   -142 rtdm_in_rt_context+0x67 (__rt_dev_ioctl+0x30)
[   40.191621]     + begin   0x80000001   -142 rtdm_in_rt_context+0x1d (__rt_dev_ioctl+0x30)
[   40.191621]     + end     0x80000000   -142 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                 -142 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x4d)
[   40.191621]     + begin   0x80000000   -142 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]     + func                 -143 rtdm_context_get+0x5 (__rt_dev_ioctl+0x1e)
[   40.191621]     + func                 -143 __rt_dev_ioctl+0x9 (sys_rtdm_ioctl+0x1d)
[   40.191621]     + func                 -143 sys_rtdm_ioctl+0x3 (hisyscall_event+0x124)
[   40.191621]     + func                 -143 hisyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]     + end     0x80000001   -143 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]     + begin   0x80000001   -143 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]     + func                 -143 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]     + end     0x80000001   -143 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]     + begin   0x80000001   -144 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x16)
[   40.191621]     + func                 -144 __ipipe_notify_syscall+0x9 (__ipipe_syscall_root+0x2e)
[   40.191621]     + func                 -144 __ipipe_syscall_root+0x6 (system_call+0x2d)
[   40.191621]     + begin   0x80000001   -149 hard_local_irq_save+0x16 (__ipipe_syscall_root+0x35)
[   40.191621]     + end     0x80000001   -149 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0xc5)
[   40.191621]     + begin   0x80000001   -149 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]     + func                 -149 __copy_to_user_ll+0x6 (rtdm_safe_copy_to_user+0x2b [platform_edge])
[   40.191621]     + func                 -150 xnarch_tsc_to_ns+0x5 (xnarch_get_cpu_time+0xf)
[   40.191621]     + func                 -150 xnarch_get_cpu_time+0x3 (platform_get_xenomai_time+0x17 [platform_edge])
[   40.191621]     + func                 -150 platform_get_xenomai_time+0x5 [platform_edge] (plc_platform_ioctl_rt+0x46a [platform_edge])
[   40.191621]     + func                 -150 plc_platform_ioctl_rt+0x9 [platform_edge] (__rt_dev_ioctl+0x40)
[   40.191621]     + end     0x80000001   -150 rtdm_in_rt_context+0x67 (__rt_dev_ioctl+0x30)
[   40.191621]     + begin   0x80000001   -150 rtdm_in_rt_context+0x1d (__rt_dev_ioctl+0x30)
[   40.191621]     + end     0x80000000   -150 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                 -150 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x4d)
[   40.191621]     + begin   0x80000000   -151 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]     + func                 -151 rtdm_context_get+0x5 (__rt_dev_ioctl+0x1e)
[   40.191621]     + func                 -151 __rt_dev_ioctl+0x9 (sys_rtdm_ioctl+0x1d)
[   40.191621]     + func                 -151 sys_rtdm_ioctl+0x3 (hisyscall_event+0x124)
[   40.191621]     + func                 -151 hisyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]     + end     0x80000001   -151 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]     + begin   0x80000001   -152 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]     + func                 -152 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]     + end     0x80000001   -152 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]     + begin   0x80000001   -152 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x16)
[   40.191621]     + func                 -152 __ipipe_notify_syscall+0x9 (__ipipe_syscall_root+0x2e)
[   40.191621]     + func                 -152 __ipipe_syscall_root+0x6 (system_call+0x2d)
[   40.191621]     + begin   0x80000001   -184 hard_local_irq_save+0x16 (__ipipe_syscall_root+0x35)
[   40.191621]     + end     0x80000001   -184 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0xc5)
[   40.191621]     + begin   0x80000001   -184 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]     + func                 -184 xnsynch_acquire+0x9 (rt_mutex_acquire_inner+0x8a)
[   40.191621]     + func                 -185 rt_mutex_acquire_inner+0x9 (__rt_mutex_acquire+0x5a)
[   40.191621]     + func                 -185 xnregistry_fetch+0x3 (__rt_mutex_acquire+0x41)
[   40.191621]     + func                 -185 __copy_from_user_ll_nozero+0x6 (__xn_safe_copy_from_user+0x28)
[   40.191621]     + func                 -185 __copy_from_user_ll_nozero+0x6 (__xn_safe_copy_from_user+0x28)
[   40.191621]     + func                 -185 __rt_mutex_acquire+0x8 (losyscall_event+0xa7)
[   40.191621]     + end     0x80000000   -185 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     # func                 -185 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x1f)
[   40.191621]     # func                 -186 xnpod_switch_fpu+0x3 (xnshadow_harden+0x137)
[   40.191621]     # func                 -186 __ipipe_switch_tail+0x4 (__schedule+0x4e8)
[   40.191621]     # func                 -186 __switch_to+0x9 (__schedule+0x4de)
[   40.191621]     # func                 -186 xnsched_pick_next+0x6 (__xnpod_schedule+0xae)
[   40.191621]     # [   19] gatekee -1   -187 __xnpod_schedule+0x5f (xnpod_schedule+0x32)
[   40.191621]     # func                 -187 __xnpod_schedule+0x9 (xnpod_schedule+0x32)
[   40.191621]     # func                 -187 xnpod_schedule_handler+0x3 (__ipipe_dispatch_irq+0x13e)
[   40.191621]      +func                 -187 __ipipe_dispatch_irq+0x9 (__ipipe_handle_irq+0x7e)
[   40.191621]      +func                 -187 __ipipe_handle_irq+0x6 (ipipe_raise_irq+0x2b)
[   40.191621]      +begin   0x80000001   -187 hard_local_irq_save+0x16 (ipipe_raise_irq+0x14)
[   40.191621]      +func                 -188 ipipe_raise_irq+0x8 (__xnpod_schedule+0x26)
[   40.191621]      +end     0x80000001   -188 ipipe_get_current_domain+0x67 (__xnpod_schedule+0x15)
[   40.191621]      +begin   0x80000001   -188 ipipe_get_current_domain+0x1d (__xnpod_schedule+0x15)
[   40.191621]      +func                 -188 __xnpod_schedule+0x9 (xnpod_schedule+0x32)
[   40.191621]      +end     0x80000000   -188 hard_local_irq_enable+0x14 (__ipipe_restore_head+0x66)
[   40.191621]     *+func                 -188 __ipipe_restore_head+0x4 (ipipe_restore_pipeline_head+0x1f)
[   40.191621]     *+[  246] cyclic: 96   -188 xnpod_resume_thread+0x40 (gatekeeper_thread+0x105)
[   40.191621]     *+func                 -189 xnpod_resume_thread+0x9 (gatekeeper_thread+0x105)
[   40.191621]      +begin   0x80000000   -189 ipipe_test_and_stall_pipeline_head+0x15 (__xnlock_get_irqsave+0xc)
[   40.191621]      +func                 -189 kthread_should_stop+0x3 (gatekeeper_thread+0xc4)
[   40.191621]      +func                 -189 sub_preempt_count+0x4 (__schedule+0x544)
[   40.191621]      +end     0x80000001   -189 debug_smp_processor_id+0x82 (__schedule+0x514)
[   40.191621]      +begin   0x80000001   -189 debug_smp_processor_id+0x36 (__schedule+0x514)
[   40.191621]      +func                 -190 sub_preempt_count+0x4 (_raw_spin_unlock_irq+0x1a)
[   40.191621]      +end     0x80000000   -190 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -190 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -190 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -190 ipipe_unstall_root+0x3 (_raw_spin_unlock_irq+0x10)
[   40.191621]      #func                 -190 _raw_spin_unlock_irq+0x3 (finish_task_switch+0x4c)
[   40.191621]      #func                 -190 finish_task_switch+0x9 (__schedule+0x50f)
[   40.191621]      #end     0x80000001   -190 debug_smp_processor_id+0x82 (__schedule+0x4f8)
[   40.191621]      #begin   0x80000001   -191 debug_smp_processor_id+0x36 (__schedule+0x4f8)
[   40.191621]      #end     0x80000000   -191 hard_local_irq_enable+0x14 (__ipipe_switch_tail+0x34)
[   40.191621]      #func                 -191 __ipipe_switch_tail+0x4 (__schedule+0x4e8)
[   40.191621]      #func                 -191 __switch_to+0x9 (__schedule+0x4de)
[   40.191621]      #begin   0x80000000   -191 __schedule+0x32d (schedule+0x5b)
[   40.191621]      #end     0x80000001   -191 hard_local_irq_restore+0x15 (__ipipe_notify_kevent+0x65)
[   40.191621]      #begin   0x80000001   -191 hard_local_irq_save+0x16 (__ipipe_notify_kevent+0x55)
[   40.191621]      #func                 -192 schedule_event+0x5 (ipipe_kevent_hook+0x1c)
[   40.191621]      #func                 -192 ipipe_kevent_hook+0x4 (__ipipe_notify_kevent+0x4e)
[   40.191621]      #end     0x80000001   -192 hard_local_irq_restore+0x15 (__ipipe_notify_kevent+0x43)
[   40.191621]      #begin   0x80000001   -192 hard_local_irq_save+0x16 (__ipipe_notify_kevent+0x20)
[   40.191621]      #end     0x80000001   -192 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -192 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -192 ipipe_root_only+0x5 (__ipipe_notify_kevent+0x1b)
[   40.191621]      #func                 -192 __ipipe_notify_kevent+0x9 (__schedule+0x31b)
[   40.191621]      #func                 -192 pick_next_task_rt+0x6 (__schedule+0x25f)
[   40.191621]      #func                 -192 pick_next_task_stop+0x3 (__schedule+0x25f)
[   40.191621]      #func                 -193 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      #func                 -193 _raw_spin_unlock+0x3 (update_curr_rt+0x1eb)
[   40.191621]      #end     0x80000001   -193 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -193 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -193 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                 -193 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      #func                 -193 _raw_spin_lock+0x4 (update_curr_rt+0x113)
[   40.191621]      #func                 -193 sched_avg_update+0x9 (update_curr_rt+0xcc)
[   40.191621]      #func                 -193 update_curr_rt+0x9 (put_prev_task_rt+0x13)
[   40.191621]      #func                 -194 put_prev_task_rt+0x5 (__schedule+0x235)
[   40.191621]      #func                 -194 pre_schedule_rt+0x3 (__schedule+0x1fc)
[   40.191621]      #func                 -194 update_rt_migration+0x5 (__dequeue_rt_entity+0x13c)
[   40.191621]      #func                 -194 __dequeue_rt_entity+0x9 (dequeue_task_rt+0x39)
[   40.191621]      #func                 -194 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      #func                 -194 _raw_spin_unlock+0x3 (update_curr_rt+0x1eb)
[   40.191621]      #end     0x80000001   -194 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -194 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -194 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                 -194 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      #func                 -195 _raw_spin_lock+0x4 (update_curr_rt+0x113)
[   40.191621]      #func                 -195 sched_avg_update+0x9 (update_curr_rt+0xcc)
[   40.191621]      #func                 -195 update_curr_rt+0x9 (dequeue_task_rt+0x1f)
[   40.191621]      #func                 -195 dequeue_task_rt+0x9 (dequeue_task+0x27)
[   40.191621]      #func                 -195 update_rq_clock+0x5 (dequeue_task+0x1a)
[   40.191621]      #func                 -195 dequeue_task+0x9 (deactivate_task+0x24)
[   40.191621]      #func                 -195 deactivate_task+0x4 (__schedule+0x12d)
[   40.191621]      #end     0x80000001   -195 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -195 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -196 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                 -196 add_preempt_count+0x4 (_raw_spin_lock_irq+0x28)
[   40.191621]      +func                 -196 _raw_spin_lock_irq+0x4 (__schedule+0xc5)
[   40.191621]      +end     0x80000001   -196 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -196 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -196 ipipe_root_only+0x5 (__schedule+0x79)
[   40.191621]      +func                 -196 sub_preempt_count+0x4 (__schedule+0x5a)
[   40.191621]      +end     0x80000000   -196 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -196 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -197 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -197 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001   -197 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -197 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -197 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                 -197 ipipe_restore_root+0x4 (arch_local_irq_restore+0x11)
[   40.191621]      +func                 -197 rcu_note_context_switch+0x9 (__schedule+0x3d)
[   40.191621]      +end     0x80000001   -197 debug_smp_processor_id+0x82 (__schedule+0x28)
[   40.191621]      +begin   0x80000001   -198 debug_smp_processor_id+0x36 (__schedule+0x28)
[   40.191621]      +end     0x80000001   -198 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -198 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -198 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -198 add_preempt_count+0x4 (__schedule+0x23)
[   40.191621]      +func                 -198 __schedule+0x9 (schedule+0x5b)
[   40.191621]      +func                 -198 schedule+0x3 (xnshadow_harden+0xeb)
[   40.191621]      +func                 -198 sub_preempt_count+0x4 (_raw_spin_unlock_irqrestore+0x28)
[   40.191621]      +end     0x80000000   -198 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -199 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -199 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -199 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001   -199 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -199 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -199 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                 -199 ipipe_restore_root+0x4 (_raw_spin_unlock_irqrestore+0x1e)
[   40.191621]      #func                 -199 _raw_spin_unlock_irqrestore+0x3 (try_to_wake_up+0x189)
[   40.191621]      #func                 -199 __ipipe_spin_unlock_debug+0x3 (try_to_wake_up+0x17e)
[   40.191621]      #func                 -199 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      #func                 -200 _raw_spin_unlock+0x3 (try_to_wake_up+0x16b)
[   40.191621]      #func                 -200 task_woken_rt+0x4 (ttwu_do_wakeup+0x6d)
[   40.191621]      #end     0x80000001   -200 debug_smp_processor_id+0x82 (resched_task+0x51)
[   40.191621]      #begin   0x80000001   -200 debug_smp_processor_id+0x36 (resched_task+0x51)
[   40.191621]      #func                 -200 resched_task+0x5 (check_preempt_curr_rt+0xe2)
[   40.191621]      #func                 -200 check_preempt_curr_rt+0x9 (check_preempt_curr+0x31)
[   40.191621]      #func                 -200 check_preempt_curr+0x9 (ttwu_do_wakeup+0x57)
[   40.191621]      #func                 -200 ttwu_do_wakeup+0x9 (ttwu_do_activate+0x39)
[   40.191621]      #func                 -200 update_rt_migration+0x5 (enqueue_task_rt+0x11f)
[   40.191621]      #func                 -201 cpupri_set+0x6 (enqueue_task_rt+0xff)
[   40.191621]      #func                 -201 enqueue_task_rt+0x9 (enqueue_task+0x27)
[   40.191621]      #end     0x80000001   -201 debug_smp_processor_id+0x82 (__cycles_2_ns+0x17)
[   40.191621]      #begin   0x80000001   -201 debug_smp_processor_id+0x36 (__cycles_2_ns+0x17)
[   40.191621]      #end     0x80000001   -201 debug_smp_processor_id+0x82 (sched_clock_cpu+0x95)
[   40.191621]      #begin   0x80000001   -201 debug_smp_processor_id+0x36 (sched_clock_cpu+0x95)
[   40.191621]      #func                 -201 update_rq_clock+0x5 (enqueue_task+0x1a)
[   40.191621]      #func                 -201 enqueue_task+0x9 (activate_task+0x24)
[   40.191621]      #func                 -202 activate_task+0x4 (ttwu_activate+0x13)
[   40.191621]      #func                 -202 ttwu_activate+0x5 (ttwu_do_activate+0x2e)
[   40.191621]      #func                 -202 ttwu_do_activate+0x6 (try_to_wake_up+0x164)
[   40.191621]      #end     0x80000001   -202 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -202 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -202 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                 -202 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      #func                 -202 _raw_spin_lock+0x4 (try_to_wake_up+0x159)
[   40.191621]      #end     0x80000001   -202 debug_smp_processor_id+0x82 (try_to_wake_up+0xf3)
[   40.191621]      #begin   0x80000001   -202 debug_smp_processor_id+0x36 (try_to_wake_up+0xf3)
[   40.191621]      #func                 -203 select_task_rq_rt+0x6 (select_task_rq+0x17)
[   40.191621]      #end     0x80000001   -203 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -203 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -203 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                 -203 add_preempt_count+0x4 (_raw_spin_lock_irqsave+0x49)
[   40.191621]      +func                 -203 _raw_spin_lock_irqsave+0x5 (try_to_wake_up+0x23)
[   40.191621]      +func                 -203 try_to_wake_up+0x9 (wake_up_process+0x14)
[   40.191621]      +func                 -203 wake_up_process+0x3 (xnshadow_harden+0xe6)
[   40.191621]      +end     0x80000001   -204 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -204 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -204 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -204 add_preempt_count+0x4 (xnshadow_harden+0x7e)
[   40.191621]      +func                 -204 sub_preempt_count+0x4 (_raw_spin_unlock_irqrestore+0x28)
[   40.191621]      +end     0x80000000   -204 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -204 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -204 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -205 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001   -205 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -205 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -205 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                 -205 ipipe_restore_root+0x4 (_raw_spin_unlock_irqrestore+0x1e)
[   40.191621]      #func                 -205 _raw_spin_unlock_irqrestore+0x3 (down_interruptible+0x3c)
[   40.191621]      #func                 -205 __ipipe_spin_unlock_debug+0x3 (down_interruptible+0x33)
[   40.191621]      #end     0x80000001   -205 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -205 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -205 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                 -206 add_preempt_count+0x4 (_raw_spin_lock_irqsave+0x49)
[   40.191621]      +func                 -206 _raw_spin_lock_irqsave+0x5 (down_interruptible+0x12)
[   40.191621]      +func                 -206 down_interruptible+0x6 (xnshadow_harden+0x57)
[   40.191621]      +func                 -206 xnshadow_harden+0x9 (losyscall_event+0x7d)
[   40.191621]      +func                 -206 losyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]      +end     0x80000001   -206 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]      +begin   0x80000001   -206 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]      +func                 -206 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]      +end     0x80000001   -206 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]     + begin   0x80000001   -207 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x6a)
[   40.191621]     + func                 -207 hisyscall_event+0x9 (ipipe_syscall_hook+0x88)
[   40.191621]     + end     0x80000001   -207 ipipe_syscall_hook+0x75 (__ipipe_notify_syscall+0x63)
[   40.191621]     + begin   0x80000001   -207 ipipe_syscall_hook+0x2b (__ipipe_notify_syscall+0x63)
[   40.191621]     + func                 -207 ipipe_syscall_hook+0x9 (__ipipe_notify_syscall+0x63)
[   40.191621]     + end     0x80000001   -207 hard_local_irq_restore+0x15 (__ipipe_notify_syscall+0x58)
[   40.191621]      +begin   0x80000001   -207 hard_local_irq_save+0x16 (__ipipe_notify_syscall+0x16)
[   40.191621]      +func                 -208 __ipipe_notify_syscall+0x9 (__ipipe_syscall_root+0x2e)
[   40.191621]      +func                 -208 __ipipe_syscall_root+0x6 (system_call+0x2d)
[   40.191621]      +func                 -208 sub_preempt_count+0x4 (vfsmount_lock_local_unlock+0x27)
[   40.191621]      +end     0x80000001   -208 debug_smp_processor_id+0x82 (vfsmount_lock_local_unlock+0x13)
[   40.191621]      +begin   0x80000001   -208 debug_smp_processor_id+0x36 (vfsmount_lock_local_unlock+0x13)
[   40.191621]      +func                 -209 vfsmount_lock_local_unlock+0x4 (mntput_no_expire+0x26)
[   40.191621]      +end     0x80000001   -209 debug_smp_processor_id+0x82 (vfsmount_lock_local_lock+0x18)
[   40.191621]      +begin   0x80000001   -209 debug_smp_processor_id+0x36 (vfsmount_lock_local_lock+0x18)
[   40.191621]      +end     0x80000001   -209 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -209 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -209 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -209 add_preempt_count+0x4 (vfsmount_lock_local_lock+0x13)
[   40.191621]      +func                 -209 vfsmount_lock_local_lock+0x4 (mntput_no_expire+0x15)
[   40.191621]      +func                 -209 mntput_no_expire+0x6 (mntput+0x27)
[   40.191621]      +func                 -210 mntput+0x3 (fput+0x18e)
[   40.191621]      +func                 -210 sub_preempt_count+0x4 (_raw_spin_unlock_irqrestore+0x28)
[   40.191621]      +end     0x80000000   -210 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -210 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -210 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -210 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001   -210 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -210 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -211 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                 -211 ipipe_restore_root+0x4 (_raw_spin_unlock_irqrestore+0x1e)
[   40.191621]      #func                 -211 _raw_spin_unlock_irqrestore+0x3 (slob_free+0x2ac)
[   40.191621]      #func                 -211 __ipipe_spin_unlock_debug+0x3 (slob_free+0x29f)
[   40.191621]      #func                 -211 set_slob+0x4 (slob_free+0x297)
[   40.191621]      #func                 -211 set_slob+0x4 (slob_free+0x23c)
[   40.191621]      #end     0x80000001   -212 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -212 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -212 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                 -212 add_preempt_count+0x4 (_raw_spin_lock_irqsave+0x49)
[   40.191621]      +func                 -212 _raw_spin_lock_irqsave+0x5 (slob_free+0x4a)
[   40.191621]      +func                 -213 slob_free+0x9 (__kmem_cache_free+0x18)
[   40.191621]      +func                 -213 __kmem_cache_free+0x4 (kmem_cache_free+0x31)
[   40.191621]      +func                 -213 kmem_cache_free+0x6 (__d_free+0x40)
[   40.191621]      +func                 -213 __d_free+0x4 (d_free+0x3b)
[   40.191621]      +func                 -213 d_free+0x4 (dentry_kill+0x122)
[   40.191621]      +func                 -213 sub_preempt_count+0x4 (_raw_spin_unlock_irqrestore+0x28)
[   40.191621]      +end     0x80000000   -213 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -213 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -213 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -214 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001   -214 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -214 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -214 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                 -214 ipipe_restore_root+0x4 (_raw_spin_unlock_irqrestore+0x1e)
[   40.191621]      #func                 -214 _raw_spin_unlock_irqrestore+0x3 (slob_free+0x2ac)
[   40.191621]      #func                 -214 __ipipe_spin_unlock_debug+0x3 (slob_free+0x29f)
[   40.191621]      #func                 -214 set_slob+0x4 (slob_free+0x297)
[   40.191621]      #func                 -214 set_slob+0x4 (slob_free+0x23c)
[   40.191621]      #end     0x80000001   -215 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -215 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -215 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                 -215 add_preempt_count+0x4 (_raw_spin_lock_irqsave+0x49)
[   40.191621]      +func                 -215 _raw_spin_lock_irqsave+0x5 (slob_free+0x4a)
[   40.191621]      +func                 -215 slob_free+0x9 (__kmem_cache_free+0x18)
[   40.191621]      +func                 -215 __kmem_cache_free+0x4 (kmem_cache_free+0x31)
[   40.191621]      +func                 -216 kmem_cache_free+0x6 (sock_destroy_inode+0x28)
[   40.191621]      +end     0x80000000   -216 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -216 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -216 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -216 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001   -216 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -216 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -216 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                 -216 ipipe_restore_root+0x4 (arch_local_irq_restore+0x11)
[   40.191621]      #end     0x80000001   -217 debug_smp_processor_id+0x82 (__call_rcu+0x8f)
[   40.191621]      #begin   0x80000001   -217 debug_smp_processor_id+0x36 (__call_rcu+0x8f)
[   40.191621]      +func                 -217 __call_rcu+0x9 (kfree_call_rcu+0x14)
[   40.191621]      +func                 -217 kfree_call_rcu+0x3 (sock_destroy_inode+0x1c)
[   40.191621]      +func                 -217 sock_destroy_inode+0x4 (destroy_inode+0x35)
[   40.191621]      +func                 -217 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      +func                 -217 _raw_spin_unlock+0x3 (fsnotify_clear_marks_by_inode+0x72)
[   40.191621]      +end     0x80000001   -217 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -218 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -218 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -218 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      +func                 -218 _raw_spin_lock+0x4 (fsnotify_clear_marks_by_inode+0x23)
[   40.191621]      +func                 -218 fsnotify_clear_marks_by_inode+0x9 (__fsnotify_inode_delete+0xd)
[   40.191621]      +func                 -218 __fsnotify_inode_delete+0x3 (__destroy_inode+0x1f)
[   40.191621]      +func                 -218 inode_has_buffers+0x3 (__destroy_inode+0x10)
[   40.191621]      +func                 -218 __destroy_inode+0x4 (destroy_inode+0x24)
[   40.191621]      +func                 -218 destroy_inode+0x4 (evict+0x129)
[   40.191621]      +func                 -218 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      +func                 -219 _raw_spin_unlock+0x3 (evict+0x122)
[   40.191621]      +func                 -219 __wake_up_bit+0x7 (wake_up_bit+0x61)
[   40.191621]      +func                 -219 wake_up_bit+0x6 (evict+0x111)
[   40.191621]      +end     0x80000001   -219 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -219 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -219 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -219 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      +func                 -219 _raw_spin_lock+0x4 (evict+0x104)
[   40.191621]      +end     0x80000001   -220 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -220 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -220 ipipe_root_only+0x5 (end_writeback+0x5c)
[   40.191621]      +func                 -220 sub_preempt_count+0x4 (_raw_spin_unlock_irq+0x1a)
[   40.191621]      +end     0x80000000   -220 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -220 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -220 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -220 ipipe_unstall_root+0x3 (_raw_spin_unlock_irq+0x10)
[   40.191621]      #func                 -221 _raw_spin_unlock_irq+0x3 (end_writeback+0x32)
[   40.191621]      #end     0x80000001   -221 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -221 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -221 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                 -221 add_preempt_count+0x4 (_raw_spin_lock_irq+0x28)
[   40.191621]      +func                 -221 _raw_spin_lock_irq+0x4 (end_writeback+0x1e)
[   40.191621]      +end     0x80000001   -221 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -221 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -221 ipipe_root_only+0x5 (end_writeback+0x11)
[   40.191621]      +func                 -222 end_writeback+0x5 (evict+0xaf)
[   40.191621]      +func                 -222 evict+0x6 (iput+0x155)
[   40.191621]      +func                 -222 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      +func                 -222 _raw_spin_unlock+0x3 (iput+0x14e)
[   40.191621]      +end     0x80000001   -222 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -222 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -222 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -222 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      +func                 -223 _raw_spin_lock+0x4 (_atomic_dec_and_lock+0x29)
[   40.191621]      +func                 -223 iput+0x6 (dentry_kill+0x10f)
[   40.191621]      +func                 -223 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      +func                 -223 _raw_spin_unlock+0x3 (dentry_kill+0xce)
[   40.191621]      +func                 -223 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      +func                 -223 _raw_spin_unlock+0x3 (dentry_kill+0xc6)
[   40.191621]      +func                 -223 __d_drop+0x4 (dentry_kill+0x6e)
[   40.191621]      +func                 -223 dentry_lru_prune+0x5 (dentry_kill+0x67)
[   40.191621]      +end     0x80000001   -224 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -224 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -224 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -224 add_preempt_count+0x4 (_raw_spin_trylock+0x15)
[   40.191621]      +func                 -224 _raw_spin_trylock+0x4 (dentry_kill+0x1d)
[   40.191621]      +end     0x80000001   -224 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -224 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -224 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -225 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      +func                 -225 _raw_spin_lock+0x4 (dput+0x2a)
[   40.191621]      +end     0x80000001   -225 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -225 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -225 ipipe_root_only+0x5 (dput+0x20)
[   40.191621]      +func                 -225 dput+0x6 (fput+0x186)
[   40.191621]      +end     0x80000000   -225 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -225 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -226 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -226 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001   -226 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -226 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -226 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                 -226 ipipe_restore_root+0x4 (arch_local_irq_restore+0x11)
[   40.191621]      #end     0x80000001   -226 debug_smp_processor_id+0x82 (__call_rcu+0x8f)
[   40.191621]      #begin   0x80000001   -226 debug_smp_processor_id+0x36 (__call_rcu+0x8f)
[   40.191621]      +func                 -226 __call_rcu+0x9 (call_rcu+0x14)
[   40.191621]      +func                 -227 call_rcu+0x3 (file_free+0x27)
[   40.191621]      +func                 -227 sub_preempt_count+0x4 (__percpu_counter_add+0x8c)
[   40.191621]      +end     0x80000001   -227 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -227 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -227 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -227 add_preempt_count+0x4 (__percpu_counter_add+0x1d)
[   40.191621]      +func                 -227 file_sb_list_del+0x4 (fput+0x128)
[   40.191621]      +func                 -227 put_pid+0x3 (fput+0x121)
[   40.191621]      +func                 -227 module_put+0x6 (fput+0x119)
[   40.191621]      +func                 -228 module_put+0x6 (sock_release+0x27)
[   40.191621]      +func                 -228 module_put+0x6 (__sk_free+0xd8)
[   40.191621]      +end     0x80000000   -228 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -228 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -228 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -228 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001   -228 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -229 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -229 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                 -229 ipipe_restore_root+0x4 (arch_local_irq_restore+0x11)
[   40.191621]      #end     0x80000001   -229 debug_smp_processor_id+0x82 (__call_rcu+0x8f)
[   40.191621]      #begin   0x80000001   -229 debug_smp_processor_id+0x36 (__call_rcu+0x8f)
[   40.191621]      +func                 -229 __call_rcu+0x9 (call_rcu+0x14)
[   40.191621]      +func                 -229 call_rcu+0x3 (kmem_cache_free+0x26)
[   40.191621]      +func                 -229 kmem_cache_free+0x6 (__sk_free+0xc8)
[   40.191621]      +func                 -229 put_pid+0x3 (__sk_free+0xae)
[   40.191621]      +func                 -230 dst_release+0x5 (inet_sock_destruct+0x13e)
[   40.191621]      +func                 -230 kfree+0x6 (inet_sock_destruct+0x133)
[   40.191621]      +func                 -230 inet_sock_destruct+0x5 (__sk_free+0x18)
[   40.191621]      +func                 -230 __sk_free+0x5 (sk_free+0x1f)
[   40.191621]      +func                 -230 sk_free+0x3 (tcp_close+0x2c3)
[   40.191621]      +func                 -230 sub_preempt_count+0x4 (_local_bh_enable_ip+0x88)
[   40.191621]      +func                 -230 sub_preempt_count+0x4 (_local_bh_enable_ip+0x5f)
[   40.191621]      +func                 -230 local_bh_enable+0x3 (tcp_close+0x2b2)
[   40.191621]      +func                 -231 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      +func                 -231 _raw_spin_unlock+0x3 (tcp_close+0x2ad)
[   40.191621]      +func                 -231 sub_preempt_count+0x4 (__percpu_counter_add+0x8c)
[   40.191621]      +end     0x80000001   -231 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -231 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -231 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -231 add_preempt_count+0x4 (__percpu_counter_add+0x1d)
[   40.191621]      +func                 -231 sk_stream_kill_queues+0x5 (inet_csk_destroy_sock+0x7d)
[   40.191621]      +func                 -231 sub_preempt_count+0x4 (__percpu_counter_add+0x8c)
[   40.191621]      +end     0x80000001   -232 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -232 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -232 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -232 add_preempt_count+0x4 (__percpu_counter_add+0x1d)
[   40.191621]      +func                 -232 sub_preempt_count+0x4 (_local_bh_enable_ip+0x88)
[   40.191621]      +func                 -232 sub_preempt_count+0x4 (_local_bh_enable_ip+0x5f)
[   40.191621]      +func                 -232 local_bh_enable+0x3 (inet_put_port+0x7f)
[   40.191621]      +func                 -232 sub_preempt_count+0x4 (_raw_spin_unlock+0x15)
[   40.191621]      +func                 -232 _raw_spin_unlock+0x3 (inet_put_port+0x7a)
[   40.191621]      +func                 -233 sub_preempt_count+0x4 (_raw_spin_unlock_irqrestore+0x28)
[   40.191621]      +end     0x80000000   -233 hard_local_irq_enable+0x14 (ipipe_unstall_root+0x2b)
[   40.191621]      #func                 -233 ipipe_root_only+0x5 (ipipe_unstall_root+0x12)
[   40.191621]      #begin   0x80000000   -233 hard_local_irq_disable+0x15 (ipipe_unstall_root+0xd)
[   40.191621]      #func                 -233 ipipe_unstall_root+0x3 (ipipe_restore_root+0x2e)
[   40.191621]      #end     0x80000001   -233 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -233 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -233 ipipe_root_only+0x5 (ipipe_restore_root+0x10)
[   40.191621]      #func                 -233 ipipe_restore_root+0x4 (_raw_spin_unlock_irqrestore+0x1e)
[   40.191621]      #func                 -234 _raw_spin_unlock_irqrestore+0x3 (slob_free+0x2ac)
[   40.191621]      #func                 -234 __ipipe_spin_unlock_debug+0x3 (slob_free+0x29f)
[   40.191621]      #func                 -234 set_slob+0x4 (slob_free+0x297)
[   40.191621]      #func                 -234 set_slob+0x4 (slob_free+0x23c)
[   40.191621]      #end     0x80000001   -235 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      #begin   0x80000001   -235 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      #func                 -235 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      #func                 -235 add_preempt_count+0x4 (_raw_spin_lock_irqsave+0x49)
[   40.191621]      +func                 -235 _raw_spin_lock_irqsave+0x5 (slob_free+0x4a)
[   40.191621]      +func                 -235 slob_free+0x9 (__kmem_cache_free+0x18)
[   40.191621]      +func                 -236 __kmem_cache_free+0x4 (kmem_cache_free+0x31)
[   40.191621]      +func                 -236 kmem_cache_free+0x6 (inet_bind_bucket_destroy+0x27)
[   40.191621]      +func                 -236 inet_bind_bucket_destroy+0x4 (inet_put_port+0x73)
[   40.191621]      +end     0x80000001   -236 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -236 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -236 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -236 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      +func                 -237 _raw_spin_lock+0x4 (inet_put_port+0x40)
[   40.191621]      +end     0x80000001   -237 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -237 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -237 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -237 add_preempt_count+0x4 (local_bh_disable+0x12)
[   40.191621]      +func                 -237 local_bh_disable+0x3 (inet_put_port+0x12)
[   40.191621]      +func                 -237 inet_put_port+0x6 (tcp_v4_destroy_sock+0x129)
[   40.191621]      +func                 -237 module_put+0x6 (tcp_cleanup_congestion_control+0x2a)
[   40.191621]      +func                 -237 tcp_cleanup_congestion_control+0x4 (tcp_v4_destroy_sock+0x22)
[   40.191621]      +func                 -238 sk_stop_timer+0x4 (inet_csk_clear_xmit_timers+0x45)
[   40.191621]      +func                 -238 sk_stop_timer+0x4 (inet_csk_clear_xmit_timers+0x38)
[   40.191621]      +func                 -238 sk_stop_timer+0x4 (inet_csk_clear_xmit_timers+0x2b)
[   40.191621]      +func                 -238 inet_csk_clear_xmit_timers+0x4 (tcp_v4_destroy_sock+0x12)
[   40.191621]      +func                 -238 tcp_v4_destroy_sock+0x6 (inet_csk_destroy_sock+0x76)
[   40.191621]      +func                 -238 inet_csk_destroy_sock+0x4 (tcp_close+0x2a6)
[   40.191621]      +func                 -238 sub_preempt_count+0x4 (__percpu_counter_add+0x8c)
[   40.191621]      +end     0x80000001   -238 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -239 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -239 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -239 add_preempt_count+0x4 (__percpu_counter_add+0x1d)
[   40.191621]      +end     0x80000001   -239 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -239 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -239 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -239 add_preempt_count+0x4 (_raw_spin_lock+0x15)
[   40.191621]      +func                 -239 _raw_spin_lock+0x4 (tcp_close+0x18b)
[   40.191621]      +end     0x80000001   -239 hard_local_irq_restore+0x15 (ipipe_root_only+0x40)
[   40.191621]      +begin   0x80000001   -240 hard_local_irq_save+0x16 (ipipe_root_only+0xf)
[   40.191621]      +func                 -240 ipipe_root_only+0x5 (add_preempt_count+0x10)
[   40.191621]      +func                 -240 add_preempt_count+0x4 (local_bh_disable+0x12)
[   40.191621]      +func                 -240 local_bh_disable+0x3 (tcp_close+0x184)
[   40.191621]      +func                 -240 sub_preempt_count+0x4 (_local_bh_enable_ip+0x88)
[   40.191621]      +func                 -240 sub_preempt_count+0x4 (_local_bh_enable_ip+0x5f)
[   40.191621] ------------[ cut here ]------------
[   40.191621] kernel BUG at kernel/xenomai/nucleus/shadow.c:2233!
[   40.191621] invalid opcode: 0000 [#1] PREEMPT SMP
[   40.191621] Modules linked in: platform_edge(O) sigmatek_lrt(O) usbhid
[   40.191621]
[   40.191621] Pid: 246, comm: cyclic:214:246 Tainted: G           O 3.4.6+ #72 Bochs Bochs
[   40.191621] EIP: 0060:[<c0188347>] EFLAGS: 00213213 CPU: 1
[   40.191621] EIP is at xnshadow_send_sig+0x19/0x3e
[   40.191621] EAX: f9338040 EBX: 0000001c ECX: 00001e02 EDX: 00000000
[   40.191621] ESI: f9332d04 EDI: f9332d14 EBP: f581deac ESP: f581dea8
[   40.191621]  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[   40.191621] CR0: 8005003b CR2: 00000000 CR3: 3635d000 CR4: 00000690
[   40.191621] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[   40.191621] DR6: ffff0ff0 DR7: 00000400
[   40.191621] Process cyclic:214:246 (pid: 246, ti=f581c000 task=f53e02d0 task.ti=f581c000)
[   40.191621] I-pipe domain Linux
[   40.191621] Stack:
[   40.191621]  f9338040 f581deb8 c01883f7 00000001 f581dec4 c0182d5b f9338040 f581ded0
[   40.191621]  c0182de7 f932fa40 f581def0 c0183182 f9338040 00000001 00000003 f9332d04
[   40.191621]  00000000 f9338040 f581df08 c018320a f9338408 f9338040 c06ed880 00000003
[   40.191621] Call Trace:
[   40.191621]  [<c01883f7>] xnshadow_renice+0x2d/0x30
[   40.191621]  [<c0182d5b>] xnsynch_renice_thread+0x32/0x48
[   40.191621]  [<c0182de7>] xnsynch_clear_boost+0x76/0x79
[   40.191621]  [<c0183182>] xnsynch_release_thread+0xe1/0x12b
[   40.191621]  [<c018320a>] xnsynch_release_all_ownerships+0x3e/0x55
[   40.191621]  [<c0181198>] xnpod_delete_thread+0x18e/0x254
[   40.191621]  [<c0187d45>] taskexit_event+0xce/0x14e
[   40.191621]  [<c0164861>] ipipe_kevent_hook+0x1c/0x1f
[   40.191621]  [<c01614c7>] __ipipe_notify_kevent+0x4e/0x6e
[   40.191621]  [<c01225c0>] do_exit+0x207/0x6a1
[   40.191621]  [<c01645a2>] ? ipipe_trace_function+0x19/0x1c
[   40.191621]  [<c0122b18>] sys_exit+0x18/0x18
[   40.191621]  [<c041dd3a>] syscall_call+0x7/0xb
[   40.191621] Code: ff 83 e7 01 89 f8 e8 ed e9 ff ff 5e 5f 5b 5e 5f 5d c3 55 89 e5 53 e8 29 6a 29 00 89 d3 8b 90 5c 03 00 00 81 fa ff ff ff bf 77 04 <0f> 0b eb fe 83 7d 08 00 75 09 b8 02 00 00 00 31 c9 eb 08 c1 e1
[   40.191621] EIP: [<c0188347>] xnshadow_send_sig+0x19/0x3e SS:ESP 0068:f581dea8
[   40.191621] ---[ end trace 8f9c98ef4c873e8e ]---
[   40.191621] Fixing recursive fault but reboot is needed!

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/05/2012 02:10 PM, Henri Roosen wrote:
> On Wed, Sep 5, 2012 at 1:21 PM, Gilles Chanteperdrix
> <gilles.chanteperdrix@xenomai.org> wrote:
>> On 09/05/2012 01:03 PM, Gilles Chanteperdrix wrote:
>>
>>> On 09/05/2012 11:29 AM, Henri Roosen wrote:
>>>
>>>> On Wed, Sep 5, 2012 at 10:28 AM, Gilles Chanteperdrix
>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>> On 09/05/2012 09:42 AM, Henri Roosen wrote:
>>>>>> On Wed, Sep 5, 2012 at 9:28 AM, Gilles Chanteperdrix
>>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>> On 09/05/2012 09:26 AM, Henri Roosen wrote:
>>>>>>>
>>>>>>>> On Tue, Sep 4, 2012 at 9:21 PM, Gilles Chanteperdrix
>>>>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>>>> On 09/04/2012 08:33 PM, Gilles Chanteperdrix wrote:
>>>>>>>>>
>>>>>>>>>> On 09/04/2012 04:28 PM, Henri Roosen wrote:
>>>>>>>>>>
>>>>>>>>>>> On Tue, Sep 4, 2012 at 4:10 PM, Gilles Chanteperdrix
>>>>>>>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>>>>>>> On 09/04/2012 03:42 PM, Henri Roosen wrote:
>>>>>>>>>>>>> Hi,
>>>>>>>>>>>>>
>>>>>>>>>>>>> I'm using the bleeding edge of Xenomai (0590cb45adce468f619) and Ipipe
>>>>>>>>>>>>> (d21e8cdbdcf21ade) on a x86 multicore system and kernel 3.4.6.
>>>>>>>>>>>>> I reserved one cpu (kernel param isolcpus=1).
>>>>>>>>>>>>>
>>>>>>>>>>>>> Our application triggers the following NULL pointer dereference when I
>>>>>>>>>>>>> set the affinity of some tasks to cpu 0 and other tasks to cpu 1.
>>>>>>>>>>>>> The application does not trigger this when all tasks have the same
>>>>>>>>>>>>> affinity (set via /proc/xenomai/affinity).
>>>>>>>>>>>>>
>>>>>>>>>>>>> I was able to reproduce this also under QEMU and will do some
>>>>>>>>>>>>> debugging, but maybe someone knows what is wrong already by seeing the
>>>>>>>>>>>>> stacktrace below:
>>>>>>>>>>>>
>>>>>>>>>>>> Could you try to reduce the bug to a simple testcase which we would try
>>>>>>>>>>>> and run to reproduce?
>>>>>>>>>>>>
>>>>>>>>>>>>> [  108.013023] BUG: unable to handle kernel NULL pointer dereference
>>>>>>>>>>>> at 00000294
>>>>>>>>>>>>> [  108.013550] IP: [<c0126a91>] __lock_task_sighand+0x53/0xc3
>>>>>>>>>>>>
>>>>>>>>>>>> Or send us a disassembly of the function __lock_task_sighand?
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> Looks like someone is calling send_sig_info with an invalid pointer.
>>>>>>>>>> There is something seriously wrong.
>>>>>>>>>>
>>>>>>>>>> On the other hand, now that I think about it, you need at least the
>>>>>>>>>> following patch:
>>>>>>>>>>
>>>>>>>>>> diff --git a/ksrc/nucleus/intr.c b/ksrc/nucleus/intr.c
>>>>>>>>>> index c75fcac..0f37bb2 100644
>>>>>>>>>> --- a/ksrc/nucleus/intr.c
>>>>>>>>>> +++ b/ksrc/nucleus/intr.c
>>>>>>>>>> @@ -93,8 +93,18 @@ void xnintr_host_tick(struct xnsched *sched) /* Interrupts off. */
>>>>>>>>>>
>>>>>>>>>>  void xnintr_clock_handler(void)
>>>>>>>>>>  {
>>>>>>>>>> -     struct xnsched *sched = xnpod_current_sched();
>>>>>>>>>>       xnstat_exectime_t *prev;
>>>>>>>>>> +     struct xnsched *sched;
>>>>>>>>>> +     unsigned cpu;
>>>>>>>>>> +
>>>>>>>>>> +     cpu = xnarch_current_cpu();
>>>>>>>>>> +
>>>>>>>>>> +     if (!cpumask_test_cpu(cpu, &xnarch_supported_cpus)) {
>>>>>>>>>> +             xnarch_relay_tick();
>>>>>>>>>> +             return;
>>>>>>>>>> +     }
>>>>>>>>>> +
>>>>>>>>>> +     sched = xnpod_sched_slot(cpu);
>>>>>>>>>>
>>>>>>>>>>       prev = xnstat_exectime_switch(sched,
>>>>>>>>>>               &nkclock.stat[xnsched_cpu(sched)].account);
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> It should work (I did not test it), with the following patch on the
>>>>>>>>> I-pipe:
>>>>>>>>>
>>>>>>>>> diff --git a/kernel/ipipe/timer.c b/kernel/ipipe/timer.c
>>>>>>>>> index d51fa62..301cdc0 100644
>>>>>>>>> --- a/kernel/ipipe/timer.c
>>>>>>>>> +++ b/kernel/ipipe/timer.c
>>>>>>>>> @@ -176,11 +176,17 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>>>>>>                 hrclock_freq = __ipipe_hrclock_freq;
>>>>>>>>>
>>>>>>>>>         spin_lock_irqsave(&lock, flags);
>>>>>>>>> -       for_each_cpu(cpu, mask) {
>>>>>>>>> +       for_each_cpu(cpu, cpu_online_mask) {
>>>>>>>>>                 list_for_each_entry(t, &timers, link) {
>>>>>>>>>                         if (!cpumask_test_cpu(cpu, t->cpumask))
>>>>>>>>>                                 continue;
>>>>>>>>>
>>>>>>>>> +                       if (!cpumask_test_cpu(cpu, mask)
>>>>>>>>> +                           && t->irq == per_cpu(ipipe_percpu.hrtimer_irq, 0)) {
>>>>>>>>> +                               per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>>>>>> +                               goto found;
>>>>>>>>> +                       }
>>>>>>>>> +
>>>>>>>>>                         evtdev = t->host_timer;
>>>>>>>>>  #ifdef CONFIG_GENERIC_CLOCKEVENTS
>>>>>>>>>                         if (!evtdev
>>>>>>>>> @@ -188,10 +194,16 @@ int ipipe_select_timers(const struct cpumask *mask)
>>>>>>>>>  #endif /* CONFIG_GENERIC_CLOCKEVENTS */
>>>>>>>>>                                 goto found;
>>>>>>>>>                 }
>>>>>>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>>>>>>> +                       continue;
>>>>>>>>> +
>>>>>>>>>                 printk("I-pipe: could not find timer for cpu #%d\n", cpu);
>>>>>>>>>                 goto err_remove_all;
>>>>>>>>>
>>>>>>>>>           found:
>>>>>>>>> +               if (!cpumask_test_cpu(cpu, mask))
>>>>>>>>> +                       continue;
>>>>>>>>> +
>>>>>>>>>                 if (__ipipe_hrtimer_freq == 0)
>>>>>>>>>                         __ipipe_hrtimer_freq = t->freq;
>>>>>>>>>                 per_cpu(ipipe_percpu.hrtimer_irq, cpu) = t->irq;
>>>>>>>>>
>>>>>>>> Thanks for looking into this Gilles!
>>>>>>>> I tried your second patch only and unfortunately I was still able to
>>>>>>>> reproduce the same kernel NULL pointer dereference.
>>>>>>>
>>>>>>>
>>>>>>> Sorry, I meant the first xenomai patch needs the second I-pipe patch to
>>>>>>> work.
>>>>>>
>>>>>> I applied both patches now, but still able to reproduce the same problem.
>>>>>
>>>>> Ok, to debug this, you can add:
>>>>> BUG_ON((unsigned long)xnthread_user_task(thread) < 0xc0000000);
>>>>> in xnshadow_send_sig. Add:
>>>>> BUG_ON((unsigned long)p < 0xc0000000)
>>>>> in lostage_handler, in the LO_SIGTHR_REQ case.
>>>>>
>>>>> Enable the I-pipe tracer, panic back traces, then set the number of
>>>>> points to a reasonably high value before running your test.
>>>>
>>>> Please find attached the trace ipipe_trace.txt
>>>>
>>>> Note that in order to compile the ipipe-tracer for x86 I had to remove
>>>> the call to hard_irqs_disabled_flags. I changed that to 0.. hope that
>>>> doesn't affect the trace log.
>>>
>>>
>>> It does affect the trace, we do not see whether the irqs are off, but it
>>> is not very important for the issue you have. You can replace with
>>> arch_irqs_disable_flags, I have a fix for this in my tree, not pushed
>>> yet, but should be in the I-pipe repository soon.
>>>
>>> Anyway, what seems to happen is that your application calls exit, while
>>> some thread was waiting for a a PI mutex, the nucleus tries to send a
>>> signal to the mutex holder. However, something gets wrong, and the mutex
>>> holder task pointer is invalid.
>>>
>>> What is strange, also, is how a task can be waiting for a mutex and
>>> calling exit at the same time. Could you try to increase the number of
>>> trace points to say 1000 points?
>>
>>
>> Answering myself. The thread killed is the one holding the mutex. The
>> signal is sent to this precise thread, so this may fail because the
>> thread is in the process of being destroyed, and its user_task pointer
>> is no longer valid.
> 
> Please find attached ipipe_trace_2.txt that has the number of
> tracepoints to 1000. Note that this log also doesn't trace whether
> irqs are off (arch_irqs_disable_flags is not in the current ipipe tree
> yet either).

it is arch_irqs_disableD_flags()... But no problem the trace is
sufficient. I am trying to reproduce the bug.

> 
> I will find out why the application is doing a sys_exit. However I'm
> not sure how this is related to the thread affinity; when not setting
> the affinity, the problem is not reproducable.

Thanks for the trace. When we find the bug we will say, of course, that
is the reason! Anyway, at first sight, the bug does not seem related to
multi-processor, I would say the difference with affinity is a
difference in how the cleanup happens in your application (namely the
case where a mutex holder is destroyed while another thread which is
waiting for the mutex is still alive).

-- 
					    Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/05/2012 02:25 PM, Gilles Chanteperdrix wrote:

> On 09/05/2012 02:10 PM, Henri Roosen wrote:
>> I will find out why the application is doing a sys_exit. However I'm
>> not sure how this is related to the thread affinity; when not setting
>> the affinity, the problem is not reproducable.
> 
> Thanks for the trace. When we find the bug we will say, of course, that
> is the reason! Anyway, at first sight, the bug does not seem related to
> multi-processor, I would say the difference with affinity is a
> difference in how the cleanup happens in your application (namely the
> case where a mutex holder is destroyed while another thread which is
> waiting for the mutex is still alive).


Indeed, the bug is reproducible on any UP board with the following 
test case. With RPI enabled, the NULL user_task pointer is a problem in
RPI handling functions, but with RPI disabled, I get the same backtrace
as you.

#include <stdio.h>
#include <string.h>

#include <unistd.h>
#include <sys/mman.h>
#include <pthread.h>
#include <semaphore.h>

pthread_mutex_t mutex;
sem_t ready;

void locker(void)
{
	pthread_set_name_np(pthread_self(), "locker");
	pthread_mutex_lock(&mutex);
	sem_post(&ready);
}

void waiter(void)
{
	pthread_set_name_np(pthread_self(), "waiter");
	sem_wait(&ready);
	pthread_mutex_lock(&mutex);
}

void *thread(void *cookie)
{
	locker();
	sleep(1);
}

int main(void)
{
	pthread_mutexattr_t mattr;
	struct sched_param sp;
	pthread_t tid;
	pid_t p;
	int rc;

	mlockall(MCL_CURRENT | MCL_FUTURE);

	pthread_mutexattr_init(&mattr);
	pthread_mutexattr_setprotocol(&mattr, PTHREAD_PRIO_INHERIT);

	rc = pthread_mutex_init(&mutex, &mattr);
	pthread_mutexattr_destroy(&mattr);
	if (rc) {
		fprintf(stderr, "pthread_mutex_init: %s\n", strerror(rc));
		return 1;
	}

	rc = sem_init(&ready, 0, 0);
	if (rc) {
		perror("sem_init");
		return 1;
	}

	sp.sched_priority = 99;
	pthread_setschedparam(pthread_self(), SCHED_FIFO, &sp);

	rc = pthread_create(&tid, NULL, thread, NULL);
	pthread_attr_destroy(&tattr);
	if (rc) {
		fprintf(stderr, "pthread_create: %s\n", strerror(rc));
		return 1;
	}

	waiter();

	return 0;
}

Regards.

-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/05/2012 09:22 PM, Gilles Chanteperdrix wrote:

> On 09/05/2012 02:25 PM, Gilles Chanteperdrix wrote:
> 
>> On 09/05/2012 02:10 PM, Henri Roosen wrote:
>>> I will find out why the application is doing a sys_exit. However I'm
>>> not sure how this is related to the thread affinity; when not setting
>>> the affinity, the problem is not reproducable.
>>
>> Thanks for the trace. When we find the bug we will say, of course, that
>> is the reason! Anyway, at first sight, the bug does not seem related to
>> multi-processor, I would say the difference with affinity is a
>> difference in how the cleanup happens in your application (namely the
>> case where a mutex holder is destroyed while another thread which is
>> waiting for the mutex is still alive).
> 
> 
> Indeed, the bug is reproducible on any UP board with the following 
> test case. With RPI enabled, the NULL user_task pointer is a problem in
> RPI handling functions, but with RPI disabled, I get the same backtrace
> as you.


The real test code, which really triggers the bug

#include <stdio.h>
#include <string.h>

#include <unistd.h>
#include <sys/mman.h>
#include <pthread.h>
#include <semaphore.h>

pthread_mutex_t mutex;
sem_t ready;

void locker(void)
{
	pthread_set_name_np(pthread_self(), "locker");
	pthread_mutex_lock(&mutex);
	sem_post(&ready);
}

void waiter(void)
{
	pthread_set_name_np(pthread_self(), "waiter");
	sem_wait(&ready);
	pthread_mutex_lock(&mutex);
}

void *thread(void *cookie)
{
	locker();
	sleep(1);
	return cookie;
}

int main(void)
{
	pthread_mutexattr_t mattr;
	struct sched_param sp;
	pthread_t tid;
	int rc;

	mlockall(MCL_CURRENT | MCL_FUTURE);

	pthread_mutexattr_init(&mattr);
	pthread_mutexattr_setprotocol(&mattr, PTHREAD_PRIO_INHERIT);

	rc = pthread_mutex_init(&mutex, &mattr);
	pthread_mutexattr_destroy(&mattr);
	if (rc) {
		fprintf(stderr, "pthread_mutex_init: %s\n", strerror(rc));
		return 1;
	}

	rc = sem_init(&ready, 0, 0);
	if (rc) {
		perror("sem_init");
		return 1;
	}

	rc = pthread_create(&tid, NULL, thread, NULL);
	if (rc) {
		fprintf(stderr, "pthread_create: %s\n", strerror(rc));
		return 1;
	}

	sp.sched_priority = 99;
	pthread_setschedparam(pthread_self(), SCHED_FIFO, &sp);

	waiter();

	return 0;
}


-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Henri Roosen]

On Wed, Sep 5, 2012 at 10:38 PM, Gilles Chanteperdrix
<gilles.chanteperdrix@xenomai.org> wrote:
> On 09/05/2012 09:22 PM, Gilles Chanteperdrix wrote:
>
>> On 09/05/2012 02:25 PM, Gilles Chanteperdrix wrote:
>>
>>> On 09/05/2012 02:10 PM, Henri Roosen wrote:
>>>> I will find out why the application is doing a sys_exit. However I'm
>>>> not sure how this is related to the thread affinity; when not setting
>>>> the affinity, the problem is not reproducable.
>>>
>>> Thanks for the trace. When we find the bug we will say, of course, that
>>> is the reason! Anyway, at first sight, the bug does not seem related to
>>> multi-processor, I would say the difference with affinity is a
>>> difference in how the cleanup happens in your application (namely the
>>> case where a mutex holder is destroyed while another thread which is
>>> waiting for the mutex is still alive).
>>
>>
>> Indeed, the bug is reproducible on any UP board with the following
>> test case. With RPI enabled, the NULL user_task pointer is a problem in
>> RPI handling functions, but with RPI disabled, I get the same backtrace
>> as you.
>
>
> The real test code, which really triggers the bug
>
> #include <stdio.h>
> #include <string.h>
>
> #include <unistd.h>
> #include <sys/mman.h>
> #include <pthread.h>
> #include <semaphore.h>
>
> pthread_mutex_t mutex;
> sem_t ready;
>
> void locker(void)
> {
>         pthread_set_name_np(pthread_self(), "locker");
>         pthread_mutex_lock(&mutex);
>         sem_post(&ready);
> }
>
> void waiter(void)
> {
>         pthread_set_name_np(pthread_self(), "waiter");
>         sem_wait(&ready);
>         pthread_mutex_lock(&mutex);
> }
>
> void *thread(void *cookie)
> {
>         locker();
>         sleep(1);
>         return cookie;
> }
>
> int main(void)
> {
>         pthread_mutexattr_t mattr;
>         struct sched_param sp;
>         pthread_t tid;
>         int rc;
>
>         mlockall(MCL_CURRENT | MCL_FUTURE);
>
>         pthread_mutexattr_init(&mattr);
>         pthread_mutexattr_setprotocol(&mattr, PTHREAD_PRIO_INHERIT);
>
>         rc = pthread_mutex_init(&mutex, &mattr);
>         pthread_mutexattr_destroy(&mattr);
>         if (rc) {
>                 fprintf(stderr, "pthread_mutex_init: %s\n", strerror(rc));
>                 return 1;
>         }
>
>         rc = sem_init(&ready, 0, 0);
>         if (rc) {
>                 perror("sem_init");
>                 return 1;
>         }
>
>         rc = pthread_create(&tid, NULL, thread, NULL);
>         if (rc) {
>                 fprintf(stderr, "pthread_create: %s\n", strerror(rc));
>                 return 1;
>         }
>
>         sp.sched_priority = 99;
>         pthread_setschedparam(pthread_self(), SCHED_FIFO, &sp);
>
>         waiter();
>
>         return 0;
> }
>

Thanks for the patch and test application!!

I tried the patch (with the two previous applied patches still applied
too) and cannot reproduce the kernel NULL pointer dereference anymore
in the QEMU environment. I did a quick test on the hardware and it
seems also there this problem doesn't occur anymore. However, our
application does not run yet; the thread that caused the problem when
moved to another core now dies when moved. That is probably the
sys_exit call.. however, when keeping all threads on the same core,
this thread just starts without a problem. I will try and find out
what is going on there and will get back with more detailed info.

>
> --
>                                                                 Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/06/2012 10:40 AM, Henri Roosen wrote:
> On Wed, Sep 5, 2012 at 10:38 PM, Gilles Chanteperdrix
> <gilles.chanteperdrix@xenomai.org> wrote:
>> On 09/05/2012 09:22 PM, Gilles Chanteperdrix wrote:
>>
>>> On 09/05/2012 02:25 PM, Gilles Chanteperdrix wrote:
>>>
>>>> On 09/05/2012 02:10 PM, Henri Roosen wrote:
>>>>> I will find out why the application is doing a sys_exit. However I'm
>>>>> not sure how this is related to the thread affinity; when not setting
>>>>> the affinity, the problem is not reproducable.
>>>>
>>>> Thanks for the trace. When we find the bug we will say, of course, that
>>>> is the reason! Anyway, at first sight, the bug does not seem related to
>>>> multi-processor, I would say the difference with affinity is a
>>>> difference in how the cleanup happens in your application (namely the
>>>> case where a mutex holder is destroyed while another thread which is
>>>> waiting for the mutex is still alive).
>>>
>>>
>>> Indeed, the bug is reproducible on any UP board with the following
>>> test case. With RPI enabled, the NULL user_task pointer is a problem in
>>> RPI handling functions, but with RPI disabled, I get the same backtrace
>>> as you.
>>
>>
>> The real test code, which really triggers the bug
>>
>> #include <stdio.h>
>> #include <string.h>
>>
>> #include <unistd.h>
>> #include <sys/mman.h>
>> #include <pthread.h>
>> #include <semaphore.h>
>>
>> pthread_mutex_t mutex;
>> sem_t ready;
>>
>> void locker(void)
>> {
>>         pthread_set_name_np(pthread_self(), "locker");
>>         pthread_mutex_lock(&mutex);
>>         sem_post(&ready);
>> }
>>
>> void waiter(void)
>> {
>>         pthread_set_name_np(pthread_self(), "waiter");
>>         sem_wait(&ready);
>>         pthread_mutex_lock(&mutex);
>> }
>>
>> void *thread(void *cookie)
>> {
>>         locker();
>>         sleep(1);
>>         return cookie;
>> }
>>
>> int main(void)
>> {
>>         pthread_mutexattr_t mattr;
>>         struct sched_param sp;
>>         pthread_t tid;
>>         int rc;
>>
>>         mlockall(MCL_CURRENT | MCL_FUTURE);
>>
>>         pthread_mutexattr_init(&mattr);
>>         pthread_mutexattr_setprotocol(&mattr, PTHREAD_PRIO_INHERIT);
>>
>>         rc = pthread_mutex_init(&mutex, &mattr);
>>         pthread_mutexattr_destroy(&mattr);
>>         if (rc) {
>>                 fprintf(stderr, "pthread_mutex_init: %s\n", strerror(rc));
>>                 return 1;
>>         }
>>
>>         rc = sem_init(&ready, 0, 0);
>>         if (rc) {
>>                 perror("sem_init");
>>                 return 1;
>>         }
>>
>>         rc = pthread_create(&tid, NULL, thread, NULL);
>>         if (rc) {
>>                 fprintf(stderr, "pthread_create: %s\n", strerror(rc));
>>                 return 1;
>>         }
>>
>>         sp.sched_priority = 99;
>>         pthread_setschedparam(pthread_self(), SCHED_FIFO, &sp);
>>
>>         waiter();
>>
>>         return 0;
>> }
>>
> 
> Thanks for the patch and test application!!
> 
> I tried the patch (with the two previous applied patches still applied
> too) and cannot reproduce the kernel NULL pointer dereference anymore
> in the QEMU environment. I did a quick test on the hardware and it
> seems also there this problem doesn't occur anymore. However, our
> application does not run yet; the thread that caused the problem when
> moved to another core now dies when moved. That is probably the
> sys_exit call.. however, when keeping all threads on the same core,
> this thread just starts without a problem. I will try and find out
> what is going on there and will get back with more detailed info.

So, you are calling sched_setaffinity while holding a PI mutex and under
priority boost? That is a priority inversion, if you have
CONFIG_XENO_OPT_DEBUG_SYNCH_RELAX, you probably die because you receive
a SIGDEBUG and do not have a handler installed. See
examples/native/sigdebug.c.

-- 
					    Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Henri Roosen]

On Thu, Sep 6, 2012 at 10:57 AM, Gilles Chanteperdrix
<gilles.chanteperdrix@xenomai.org> wrote:
> On 09/06/2012 10:40 AM, Henri Roosen wrote:
>> On Wed, Sep 5, 2012 at 10:38 PM, Gilles Chanteperdrix
>> <gilles.chanteperdrix@xenomai.org> wrote:
>>> On 09/05/2012 09:22 PM, Gilles Chanteperdrix wrote:
>>>
>>>> On 09/05/2012 02:25 PM, Gilles Chanteperdrix wrote:
>>>>
>>>>> On 09/05/2012 02:10 PM, Henri Roosen wrote:
>>>>>> I will find out why the application is doing a sys_exit. However I'm
>>>>>> not sure how this is related to the thread affinity; when not setting
>>>>>> the affinity, the problem is not reproducable.
>>>>>
>>>>> Thanks for the trace. When we find the bug we will say, of course, that
>>>>> is the reason! Anyway, at first sight, the bug does not seem related to
>>>>> multi-processor, I would say the difference with affinity is a
>>>>> difference in how the cleanup happens in your application (namely the
>>>>> case where a mutex holder is destroyed while another thread which is
>>>>> waiting for the mutex is still alive).
>>>>
>>>>
>>>> Indeed, the bug is reproducible on any UP board with the following
>>>> test case. With RPI enabled, the NULL user_task pointer is a problem in
>>>> RPI handling functions, but with RPI disabled, I get the same backtrace
>>>> as you.
>>>
>>>
>>> The real test code, which really triggers the bug
>>>
>>> #include <stdio.h>
>>> #include <string.h>
>>>
>>> #include <unistd.h>
>>> #include <sys/mman.h>
>>> #include <pthread.h>
>>> #include <semaphore.h>
>>>
>>> pthread_mutex_t mutex;
>>> sem_t ready;
>>>
>>> void locker(void)
>>> {
>>>         pthread_set_name_np(pthread_self(), "locker");
>>>         pthread_mutex_lock(&mutex);
>>>         sem_post(&ready);
>>> }
>>>
>>> void waiter(void)
>>> {
>>>         pthread_set_name_np(pthread_self(), "waiter");
>>>         sem_wait(&ready);
>>>         pthread_mutex_lock(&mutex);
>>> }
>>>
>>> void *thread(void *cookie)
>>> {
>>>         locker();
>>>         sleep(1);
>>>         return cookie;
>>> }
>>>
>>> int main(void)
>>> {
>>>         pthread_mutexattr_t mattr;
>>>         struct sched_param sp;
>>>         pthread_t tid;
>>>         int rc;
>>>
>>>         mlockall(MCL_CURRENT | MCL_FUTURE);
>>>
>>>         pthread_mutexattr_init(&mattr);
>>>         pthread_mutexattr_setprotocol(&mattr, PTHREAD_PRIO_INHERIT);
>>>
>>>         rc = pthread_mutex_init(&mutex, &mattr);
>>>         pthread_mutexattr_destroy(&mattr);
>>>         if (rc) {
>>>                 fprintf(stderr, "pthread_mutex_init: %s\n", strerror(rc));
>>>                 return 1;
>>>         }
>>>
>>>         rc = sem_init(&ready, 0, 0);
>>>         if (rc) {
>>>                 perror("sem_init");
>>>                 return 1;
>>>         }
>>>
>>>         rc = pthread_create(&tid, NULL, thread, NULL);
>>>         if (rc) {
>>>                 fprintf(stderr, "pthread_create: %s\n", strerror(rc));
>>>                 return 1;
>>>         }
>>>
>>>         sp.sched_priority = 99;
>>>         pthread_setschedparam(pthread_self(), SCHED_FIFO, &sp);
>>>
>>>         waiter();
>>>
>>>         return 0;
>>> }
>>>
>>
>> Thanks for the patch and test application!!
>>
>> I tried the patch (with the two previous applied patches still applied
>> too) and cannot reproduce the kernel NULL pointer dereference anymore
>> in the QEMU environment. I did a quick test on the hardware and it
>> seems also there this problem doesn't occur anymore. However, our
>> application does not run yet; the thread that caused the problem when
>> moved to another core now dies when moved. That is probably the
>> sys_exit call.. however, when keeping all threads on the same core,
>> this thread just starts without a problem. I will try and find out
>> what is going on there and will get back with more detailed info.
>
> So, you are calling sched_setaffinity while holding a PI mutex and under
> priority boost? That is a priority inversion, if you have
> CONFIG_XENO_OPT_DEBUG_SYNCH_RELAX, you probably die because you receive
> a SIGDEBUG and do not have a handler installed. See
> examples/native/sigdebug.c.
>

Found out our application has some mechanism in place that suspends
certain threads, which was causing Xenomai functions to return -EINTR
and that we handle as fatal exception and stop the thread... I
disabled that mechanism for now and the application starts and seems
to run normal.

So the latter is an issue in our application.
Thanks Gilles for your excellent support!

> --
>                                             Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/06/2012 04:33 PM, Henri Roosen wrote:

> On Thu, Sep 6, 2012 at 10:57 AM, Gilles Chanteperdrix
> <gilles.chanteperdrix@xenomai.org> wrote:
>> On 09/06/2012 10:40 AM, Henri Roosen wrote:
>>> On Wed, Sep 5, 2012 at 10:38 PM, Gilles Chanteperdrix
>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>> On 09/05/2012 09:22 PM, Gilles Chanteperdrix wrote:
>>>>
>>>>> On 09/05/2012 02:25 PM, Gilles Chanteperdrix wrote:
>>>>>
>>>>>> On 09/05/2012 02:10 PM, Henri Roosen wrote:
>>>>>>> I will find out why the application is doing a sys_exit. However I'm
>>>>>>> not sure how this is related to the thread affinity; when not setting
>>>>>>> the affinity, the problem is not reproducable.
>>>>>>
>>>>>> Thanks for the trace. When we find the bug we will say, of course, that
>>>>>> is the reason! Anyway, at first sight, the bug does not seem related to
>>>>>> multi-processor, I would say the difference with affinity is a
>>>>>> difference in how the cleanup happens in your application (namely the
>>>>>> case where a mutex holder is destroyed while another thread which is
>>>>>> waiting for the mutex is still alive).
>>>>>
>>>>>
>>>>> Indeed, the bug is reproducible on any UP board with the following
>>>>> test case. With RPI enabled, the NULL user_task pointer is a problem in
>>>>> RPI handling functions, but with RPI disabled, I get the same backtrace
>>>>> as you.
>>>>
>>>>
>>>> The real test code, which really triggers the bug
>>>>
>>>> #include <stdio.h>
>>>> #include <string.h>
>>>>
>>>> #include <unistd.h>
>>>> #include <sys/mman.h>
>>>> #include <pthread.h>
>>>> #include <semaphore.h>
>>>>
>>>> pthread_mutex_t mutex;
>>>> sem_t ready;
>>>>
>>>> void locker(void)
>>>> {
>>>>         pthread_set_name_np(pthread_self(), "locker");
>>>>         pthread_mutex_lock(&mutex);
>>>>         sem_post(&ready);
>>>> }
>>>>
>>>> void waiter(void)
>>>> {
>>>>         pthread_set_name_np(pthread_self(), "waiter");
>>>>         sem_wait(&ready);
>>>>         pthread_mutex_lock(&mutex);
>>>> }
>>>>
>>>> void *thread(void *cookie)
>>>> {
>>>>         locker();
>>>>         sleep(1);
>>>>         return cookie;
>>>> }
>>>>
>>>> int main(void)
>>>> {
>>>>         pthread_mutexattr_t mattr;
>>>>         struct sched_param sp;
>>>>         pthread_t tid;
>>>>         int rc;
>>>>
>>>>         mlockall(MCL_CURRENT | MCL_FUTURE);
>>>>
>>>>         pthread_mutexattr_init(&mattr);
>>>>         pthread_mutexattr_setprotocol(&mattr, PTHREAD_PRIO_INHERIT);
>>>>
>>>>         rc = pthread_mutex_init(&mutex, &mattr);
>>>>         pthread_mutexattr_destroy(&mattr);
>>>>         if (rc) {
>>>>                 fprintf(stderr, "pthread_mutex_init: %s\n", strerror(rc));
>>>>                 return 1;
>>>>         }
>>>>
>>>>         rc = sem_init(&ready, 0, 0);
>>>>         if (rc) {
>>>>                 perror("sem_init");
>>>>                 return 1;
>>>>         }
>>>>
>>>>         rc = pthread_create(&tid, NULL, thread, NULL);
>>>>         if (rc) {
>>>>                 fprintf(stderr, "pthread_create: %s\n", strerror(rc));
>>>>                 return 1;
>>>>         }
>>>>
>>>>         sp.sched_priority = 99;
>>>>         pthread_setschedparam(pthread_self(), SCHED_FIFO, &sp);
>>>>
>>>>         waiter();
>>>>
>>>>         return 0;
>>>> }
>>>>
>>>
>>> Thanks for the patch and test application!!
>>>
>>> I tried the patch (with the two previous applied patches still applied
>>> too) and cannot reproduce the kernel NULL pointer dereference anymore
>>> in the QEMU environment. I did a quick test on the hardware and it
>>> seems also there this problem doesn't occur anymore. However, our
>>> application does not run yet; the thread that caused the problem when
>>> moved to another core now dies when moved. That is probably the
>>> sys_exit call.. however, when keeping all threads on the same core,
>>> this thread just starts without a problem. I will try and find out
>>> what is going on there and will get back with more detailed info.
>>
>> So, you are calling sched_setaffinity while holding a PI mutex and under
>> priority boost? That is a priority inversion, if you have
>> CONFIG_XENO_OPT_DEBUG_SYNCH_RELAX, you probably die because you receive
>> a SIGDEBUG and do not have a handler installed. See
>> examples/native/sigdebug.c.
>>
> 
> Found out our application has some mechanism in place that suspends
> certain threads, which was causing Xenomai functions to return -EINTR
> and that we handle as fatal exception and stop the thread... I
> disabled that mechanism for now and the application starts and seems
> to run normal.
> 
> So the latter is an issue in our application.
> Thanks Gilles for your excellent support!


You are welcome.

-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/05/2012 02:10 PM, Henri Roosen wrote:

> On Wed, Sep 5, 2012 at 1:21 PM, Gilles Chanteperdrix
> <gilles.chanteperdrix@xenomai.org> wrote:
>>> Anyway, what seems to happen is that your application calls exit, while
>>> some thread was waiting for a a PI mutex, the nucleus tries to send a
>>> signal to the mutex holder. However, something gets wrong, and the mutex
>>> holder task pointer is invalid.
>>>
>>> What is strange, also, is how a task can be waiting for a mutex and
>>> calling exit at the same time. Could you try to increase the number of
>>> trace points to say 1000 points?
>>
>>
>> Answering myself. The thread killed is the one holding the mutex. The
>> signal is sent to this precise thread, so this may fail because the
>> thread is in the process of being destroyed, and its user_task pointer
>> is no longer valid.
> 
> Please find attached ipipe_trace_2.txt that has the number of
> tracepoints to 1000. Note that this log also doesn't trace whether
> irqs are off (arch_irqs_disable_flags is not in the current ipipe tree
> yet either).
> 
> I will find out why the application is doing a sys_exit. However I'm
> not sure how this is related to the thread affinity; when not setting
> the affinity, the problem is not reproducable.


Please try the following patch, it should avoid the bug, but I will 
wait for Philippe's ack before pushing it:

diff --git a/ksrc/nucleus/shadow.c b/ksrc/nucleus/shadow.c
index 260fdef..1f1a737 100644
--- a/ksrc/nucleus/shadow.c
+++ b/ksrc/nucleus/shadow.c
@@ -274,7 +274,9 @@ static void rpi_update(struct xnthread *thread)
 	if (rpi_p(thread)) {
 		xnsched_pop_rpi(thread);
 		thread->rpi = NULL;
-		rpi_push(sched, thread);
+
+		if (xnthread_user_task(thread))
+			rpi_push(sched, thread);
 	}
 
 	xnlock_put_irqrestore(&sched->rpilock, s);
@@ -1516,15 +1518,18 @@ EXPORT_SYMBOL_GPL(xnshadow_start);
 /* Called with nklock locked, Xenomai interrupts off. */
 void xnshadow_renice(struct xnthread *thread)
 {
-	/*
-	 * We need to bound the priority values in the
-	 * [1..MAX_RT_PRIO-1] range, since the Xenomai priority scale
-	 * is a superset of the Linux priority scale.
-	 */
-	int prio = normalize_priority(thread->cprio);
+	if (xnthread_user_task(thread)) {
+		/*
+		 * We need to bound the priority values in the
+		 * [1..MAX_RT_PRIO-1] range, since the Xenomai priority scale
+		 * is a superset of the Linux priority scale.
+		 */
+		int prio = normalize_priority(thread->cprio);
 
-	xnshadow_send_sig(thread, SIGSHADOW,
-			  sigshadow_int(SIGSHADOW_ACTION_RENICE, prio), 1);
+		xnshadow_send_sig
+			(thread, SIGSHADOW,
+			 sigshadow_int(SIGSHADOW_ACTION_RENICE, prio), 1);
+	}
 
 	if (!xnthread_test_state(thread, XNDORMANT) &&
 	    xnthread_sched(thread) == xnpod_current_sched())


-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Philippe Gerum]

On 09/05/2012 10:14 PM, Gilles Chanteperdrix wrote:
> On 09/05/2012 02:10 PM, Henri Roosen wrote:
> 
>> On Wed, Sep 5, 2012 at 1:21 PM, Gilles Chanteperdrix
>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>> Anyway, what seems to happen is that your application calls exit, while
>>>> some thread was waiting for a a PI mutex, the nucleus tries to send a
>>>> signal to the mutex holder. However, something gets wrong, and the mutex
>>>> holder task pointer is invalid.
>>>>
>>>> What is strange, also, is how a task can be waiting for a mutex and
>>>> calling exit at the same time. Could you try to increase the number of
>>>> trace points to say 1000 points?
>>>
>>>
>>> Answering myself. The thread killed is the one holding the mutex. The
>>> signal is sent to this precise thread, so this may fail because the
>>> thread is in the process of being destroyed, and its user_task pointer
>>> is no longer valid.
>>
>> Please find attached ipipe_trace_2.txt that has the number of
>> tracepoints to 1000. Note that this log also doesn't trace whether
>> irqs are off (arch_irqs_disable_flags is not in the current ipipe tree
>> yet either).
>>
>> I will find out why the application is doing a sys_exit. However I'm
>> not sure how this is related to the thread affinity; when not setting
>> the affinity, the problem is not reproducable.
> 
> 
> Please try the following patch, it should avoid the bug, but I will 
> wait for Philippe's ack before pushing it:
> 
> diff --git a/ksrc/nucleus/shadow.c b/ksrc/nucleus/shadow.c
> index 260fdef..1f1a737 100644
> --- a/ksrc/nucleus/shadow.c
> +++ b/ksrc/nucleus/shadow.c
> @@ -274,7 +274,9 @@ static void rpi_update(struct xnthread *thread)
>  	if (rpi_p(thread)) {
>  		xnsched_pop_rpi(thread);
>  		thread->rpi = NULL;
> -		rpi_push(sched, thread);
> +
> +		if (xnthread_user_task(thread))
> +			rpi_push(sched, thread);
>  	}
>  
>  	xnlock_put_irqrestore(&sched->rpilock, s);
> @@ -1516,15 +1518,18 @@ EXPORT_SYMBOL_GPL(xnshadow_start);
>  /* Called with nklock locked, Xenomai interrupts off. */
>  void xnshadow_renice(struct xnthread *thread)
>  {
> -	/*
> -	 * We need to bound the priority values in the
> -	 * [1..MAX_RT_PRIO-1] range, since the Xenomai priority scale
> -	 * is a superset of the Linux priority scale.
> -	 */
> -	int prio = normalize_priority(thread->cprio);
> +	if (xnthread_user_task(thread)) {
> +		/*
> +		 * We need to bound the priority values in the
> +		 * [1..MAX_RT_PRIO-1] range, since the Xenomai priority scale
> +		 * is a superset of the Linux priority scale.
> +		 */
> +		int prio = normalize_priority(thread->cprio);
>  
> -	xnshadow_send_sig(thread, SIGSHADOW,
> -			  sigshadow_int(SIGSHADOW_ACTION_RENICE, prio), 1);
> +		xnshadow_send_sig
> +			(thread, SIGSHADOW,
> +			 sigshadow_int(SIGSHADOW_ACTION_RENICE, prio), 1);
> +	}
>  
>  	if (!xnthread_test_state(thread, XNDORMANT) &&
>  	    xnthread_sched(thread) == xnpod_current_sched())
> 
> 

This patch is correct, but it does not fix the root cause. RPI seems to
be a victim here, not the culprit. As you already noticed, the main
issue is with a thread holding a contented mutex, which exits. This
causes the PIP boost to be cleared for it over its own taskexit handler,
after its task_struct backlink has been cleared. This leads to
schedule_linux_call() being called for a NULL task; enabling
CONFIG_XENO_OPT_DEBUG_NUCLEUS triggers the assertion properly in this
routine.

The source of all issues in this case is xnsynch_clear_boost() not
handling the particular case of a thread exiting with a contended mutex
held. We can reuse the thread zombie bit to flag this, and avoid any
useless renice.

Normally, there should not be any SMP-specific triggers of this bug,
the nucleus lock is held all through the deletion and synch de-boost paths.

If I'm right, the patch below should fix the original issue the same
way:

diff --git a/ksrc/nucleus/pod.c b/ksrc/nucleus/pod.c
index 5f53002..1f4a749 100644
--- a/ksrc/nucleus/pod.c
+++ b/ksrc/nucleus/pod.c
@@ -1187,12 +1187,12 @@ void xnpod_delete_thread(xnthread_t *thread)
 	if (xnthread_test_state(thread, XNPEND))
 		xnsynch_forget_sleeper(thread);

+	xnthread_set_state(thread, XNZOMBIE);
+
 	xnsynch_release_all_ownerships(thread);

 	__xnpod_giveup_fpu(sched, thread);

-	xnthread_set_state(thread, XNZOMBIE);
-
 	if (sched->curr == thread) {
 		/*
 		 * We first need to pick a new curr before
diff --git a/ksrc/nucleus/synch.c b/ksrc/nucleus/synch.c
index 695824e..e10be47 100644
--- a/ksrc/nucleus/synch.c
+++ b/ksrc/nucleus/synch.c
@@ -608,7 +608,8 @@ static void xnsynch_clear_boost(struct xnsynch *synch,
 			target = owner;
 	}

-	if (w_cprio(owner) != wprio)
+	if (w_cprio(owner) != wprio &&
+	    !xnthread_test_state(owner, XNZOMBIE))
 		xnsynch_renice_thread(owner, target);
 }


-- 
Philippe.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/08/2012 12:41 PM, Philippe Gerum wrote:

> On 09/05/2012 10:14 PM, Gilles Chanteperdrix wrote:
>> On 09/05/2012 02:10 PM, Henri Roosen wrote:
>>
>>> On Wed, Sep 5, 2012 at 1:21 PM, Gilles Chanteperdrix
>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>> Anyway, what seems to happen is that your application calls exit, while
>>>>> some thread was waiting for a a PI mutex, the nucleus tries to send a
>>>>> signal to the mutex holder. However, something gets wrong, and the mutex
>>>>> holder task pointer is invalid.
>>>>>
>>>>> What is strange, also, is how a task can be waiting for a mutex and
>>>>> calling exit at the same time. Could you try to increase the number of
>>>>> trace points to say 1000 points?
>>>>
>>>>
>>>> Answering myself. The thread killed is the one holding the mutex. The
>>>> signal is sent to this precise thread, so this may fail because the
>>>> thread is in the process of being destroyed, and its user_task pointer
>>>> is no longer valid.
>>>
>>> Please find attached ipipe_trace_2.txt that has the number of
>>> tracepoints to 1000. Note that this log also doesn't trace whether
>>> irqs are off (arch_irqs_disable_flags is not in the current ipipe tree
>>> yet either).
>>>
>>> I will find out why the application is doing a sys_exit. However I'm
>>> not sure how this is related to the thread affinity; when not setting
>>> the affinity, the problem is not reproducable.
>>
>>
>> Please try the following patch, it should avoid the bug, but I will 
>> wait for Philippe's ack before pushing it:
>>
>> diff --git a/ksrc/nucleus/shadow.c b/ksrc/nucleus/shadow.c
>> index 260fdef..1f1a737 100644
>> --- a/ksrc/nucleus/shadow.c
>> +++ b/ksrc/nucleus/shadow.c
>> @@ -274,7 +274,9 @@ static void rpi_update(struct xnthread *thread)
>>  	if (rpi_p(thread)) {
>>  		xnsched_pop_rpi(thread);
>>  		thread->rpi = NULL;
>> -		rpi_push(sched, thread);
>> +
>> +		if (xnthread_user_task(thread))
>> +			rpi_push(sched, thread);
>>  	}
>>  
>>  	xnlock_put_irqrestore(&sched->rpilock, s);
>> @@ -1516,15 +1518,18 @@ EXPORT_SYMBOL_GPL(xnshadow_start);
>>  /* Called with nklock locked, Xenomai interrupts off. */
>>  void xnshadow_renice(struct xnthread *thread)
>>  {
>> -	/*
>> -	 * We need to bound the priority values in the
>> -	 * [1..MAX_RT_PRIO-1] range, since the Xenomai priority scale
>> -	 * is a superset of the Linux priority scale.
>> -	 */
>> -	int prio = normalize_priority(thread->cprio);
>> +	if (xnthread_user_task(thread)) {
>> +		/*
>> +		 * We need to bound the priority values in the
>> +		 * [1..MAX_RT_PRIO-1] range, since the Xenomai priority scale
>> +		 * is a superset of the Linux priority scale.
>> +		 */
>> +		int prio = normalize_priority(thread->cprio);
>>  
>> -	xnshadow_send_sig(thread, SIGSHADOW,
>> -			  sigshadow_int(SIGSHADOW_ACTION_RENICE, prio), 1);
>> +		xnshadow_send_sig
>> +			(thread, SIGSHADOW,
>> +			 sigshadow_int(SIGSHADOW_ACTION_RENICE, prio), 1);
>> +	}
>>  
>>  	if (!xnthread_test_state(thread, XNDORMANT) &&
>>  	    xnthread_sched(thread) == xnpod_current_sched())
>>
>>
> 
> This patch is correct, but it does not fix the root cause. RPI seems to
> be a victim here, not the culprit. As you already noticed, the main
> issue is with a thread holding a contented mutex, which exits. This
> causes the PIP boost to be cleared for it over its own taskexit handler,
> after its task_struct backlink has been cleared. This leads to
> schedule_linux_call() being called for a NULL task; enabling
> CONFIG_XENO_OPT_DEBUG_NUCLEUS triggers the assertion properly in this
> routine.
> 
> The source of all issues in this case is xnsynch_clear_boost() not
> handling the particular case of a thread exiting with a contended mutex
> held. We can reuse the thread zombie bit to flag this, and avoid any
> useless renice.
> 
> Normally, there should not be any SMP-specific triggers of this bug,
> the nucleus lock is held all through the deletion and synch de-boost paths.


Are we not missing an rpi_pop ?

-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Gilles Chanteperdrix]

On 09/08/2012 12:43 PM, Gilles Chanteperdrix wrote:

> On 09/08/2012 12:41 PM, Philippe Gerum wrote:
> 
>> On 09/05/2012 10:14 PM, Gilles Chanteperdrix wrote:
>>> On 09/05/2012 02:10 PM, Henri Roosen wrote:
>>>
>>>> On Wed, Sep 5, 2012 at 1:21 PM, Gilles Chanteperdrix
>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>> Anyway, what seems to happen is that your application calls exit, while
>>>>>> some thread was waiting for a a PI mutex, the nucleus tries to send a
>>>>>> signal to the mutex holder. However, something gets wrong, and the mutex
>>>>>> holder task pointer is invalid.
>>>>>>
>>>>>> What is strange, also, is how a task can be waiting for a mutex and
>>>>>> calling exit at the same time. Could you try to increase the number of
>>>>>> trace points to say 1000 points?
>>>>>
>>>>>
>>>>> Answering myself. The thread killed is the one holding the mutex. The
>>>>> signal is sent to this precise thread, so this may fail because the
>>>>> thread is in the process of being destroyed, and its user_task pointer
>>>>> is no longer valid.
>>>>
>>>> Please find attached ipipe_trace_2.txt that has the number of
>>>> tracepoints to 1000. Note that this log also doesn't trace whether
>>>> irqs are off (arch_irqs_disable_flags is not in the current ipipe tree
>>>> yet either).
>>>>
>>>> I will find out why the application is doing a sys_exit. However I'm
>>>> not sure how this is related to the thread affinity; when not setting
>>>> the affinity, the problem is not reproducable.
>>>
>>>
>>> Please try the following patch, it should avoid the bug, but I will 
>>> wait for Philippe's ack before pushing it:
>>>
>>> diff --git a/ksrc/nucleus/shadow.c b/ksrc/nucleus/shadow.c
>>> index 260fdef..1f1a737 100644
>>> --- a/ksrc/nucleus/shadow.c
>>> +++ b/ksrc/nucleus/shadow.c
>>> @@ -274,7 +274,9 @@ static void rpi_update(struct xnthread *thread)
>>>  	if (rpi_p(thread)) {
>>>  		xnsched_pop_rpi(thread);
>>>  		thread->rpi = NULL;
>>> -		rpi_push(sched, thread);
>>> +
>>> +		if (xnthread_user_task(thread))
>>> +			rpi_push(sched, thread);
>>>  	}
>>>  
>>>  	xnlock_put_irqrestore(&sched->rpilock, s);
>>> @@ -1516,15 +1518,18 @@ EXPORT_SYMBOL_GPL(xnshadow_start);
>>>  /* Called with nklock locked, Xenomai interrupts off. */
>>>  void xnshadow_renice(struct xnthread *thread)
>>>  {
>>> -	/*
>>> -	 * We need to bound the priority values in the
>>> -	 * [1..MAX_RT_PRIO-1] range, since the Xenomai priority scale
>>> -	 * is a superset of the Linux priority scale.
>>> -	 */
>>> -	int prio = normalize_priority(thread->cprio);
>>> +	if (xnthread_user_task(thread)) {
>>> +		/*
>>> +		 * We need to bound the priority values in the
>>> +		 * [1..MAX_RT_PRIO-1] range, since the Xenomai priority scale
>>> +		 * is a superset of the Linux priority scale.
>>> +		 */
>>> +		int prio = normalize_priority(thread->cprio);
>>>  
>>> -	xnshadow_send_sig(thread, SIGSHADOW,
>>> -			  sigshadow_int(SIGSHADOW_ACTION_RENICE, prio), 1);
>>> +		xnshadow_send_sig
>>> +			(thread, SIGSHADOW,
>>> +			 sigshadow_int(SIGSHADOW_ACTION_RENICE, prio), 1);
>>> +	}
>>>  
>>>  	if (!xnthread_test_state(thread, XNDORMANT) &&
>>>  	    xnthread_sched(thread) == xnpod_current_sched())
>>>
>>>
>>
>> This patch is correct, but it does not fix the root cause. RPI seems to
>> be a victim here, not the culprit. As you already noticed, the main
>> issue is with a thread holding a contented mutex, which exits. This
>> causes the PIP boost to be cleared for it over its own taskexit handler,
>> after its task_struct backlink has been cleared. This leads to
>> schedule_linux_call() being called for a NULL task; enabling
>> CONFIG_XENO_OPT_DEBUG_NUCLEUS triggers the assertion properly in this
>> routine.
>>
>> The source of all issues in this case is xnsynch_clear_boost() not
>> handling the particular case of a thread exiting with a contended mutex
>> held. We can reuse the thread zombie bit to flag this, and avoid any
>> useless renice.
>>
>> Normally, there should not be any SMP-specific triggers of this bug,
>> the nucleus lock is held all through the deletion and synch de-boost paths.
> 
> 
> Are we not missing an rpi_pop ?
> 

Ok. It happens in xnshadow_unmap anyway.

-- 
                                                                Gilles.

Re: [Xenomai] kernel NULL pointer dereference

[Philippe Gerum]

On 09/08/2012 01:57 PM, Gilles Chanteperdrix wrote:
> On 09/08/2012 12:43 PM, Gilles Chanteperdrix wrote:
> 
>> On 09/08/2012 12:41 PM, Philippe Gerum wrote:
>>
>>> On 09/05/2012 10:14 PM, Gilles Chanteperdrix wrote:
>>>> On 09/05/2012 02:10 PM, Henri Roosen wrote:
>>>>
>>>>> On Wed, Sep 5, 2012 at 1:21 PM, Gilles Chanteperdrix
>>>>> <gilles.chanteperdrix@xenomai.org> wrote:
>>>>>>> Anyway, what seems to happen is that your application calls exit, while
>>>>>>> some thread was waiting for a a PI mutex, the nucleus tries to send a
>>>>>>> signal to the mutex holder. However, something gets wrong, and the mutex
>>>>>>> holder task pointer is invalid.
>>>>>>>
>>>>>>> What is strange, also, is how a task can be waiting for a mutex and
>>>>>>> calling exit at the same time. Could you try to increase the number of
>>>>>>> trace points to say 1000 points?
>>>>>>
>>>>>>
>>>>>> Answering myself. The thread killed is the one holding the mutex. The
>>>>>> signal is sent to this precise thread, so this may fail because the
>>>>>> thread is in the process of being destroyed, and its user_task pointer
>>>>>> is no longer valid.
>>>>>
>>>>> Please find attached ipipe_trace_2.txt that has the number of
>>>>> tracepoints to 1000. Note that this log also doesn't trace whether
>>>>> irqs are off (arch_irqs_disable_flags is not in the current ipipe tree
>>>>> yet either).
>>>>>
>>>>> I will find out why the application is doing a sys_exit. However I'm
>>>>> not sure how this is related to the thread affinity; when not setting
>>>>> the affinity, the problem is not reproducable.
>>>>
>>>>
>>>> Please try the following patch, it should avoid the bug, but I will 
>>>> wait for Philippe's ack before pushing it:
>>>>
>>>> diff --git a/ksrc/nucleus/shadow.c b/ksrc/nucleus/shadow.c
>>>> index 260fdef..1f1a737 100644
>>>> --- a/ksrc/nucleus/shadow.c
>>>> +++ b/ksrc/nucleus/shadow.c
>>>> @@ -274,7 +274,9 @@ static void rpi_update(struct xnthread *thread)
>>>>  	if (rpi_p(thread)) {
>>>>  		xnsched_pop_rpi(thread);
>>>>  		thread->rpi = NULL;
>>>> -		rpi_push(sched, thread);
>>>> +
>>>> +		if (xnthread_user_task(thread))
>>>> +			rpi_push(sched, thread);
>>>>  	}
>>>>  
>>>>  	xnlock_put_irqrestore(&sched->rpilock, s);
>>>> @@ -1516,15 +1518,18 @@ EXPORT_SYMBOL_GPL(xnshadow_start);
>>>>  /* Called with nklock locked, Xenomai interrupts off. */
>>>>  void xnshadow_renice(struct xnthread *thread)
>>>>  {
>>>> -	/*
>>>> -	 * We need to bound the priority values in the
>>>> -	 * [1..MAX_RT_PRIO-1] range, since the Xenomai priority scale
>>>> -	 * is a superset of the Linux priority scale.
>>>> -	 */
>>>> -	int prio = normalize_priority(thread->cprio);
>>>> +	if (xnthread_user_task(thread)) {
>>>> +		/*
>>>> +		 * We need to bound the priority values in the
>>>> +		 * [1..MAX_RT_PRIO-1] range, since the Xenomai priority scale
>>>> +		 * is a superset of the Linux priority scale.
>>>> +		 */
>>>> +		int prio = normalize_priority(thread->cprio);
>>>>  
>>>> -	xnshadow_send_sig(thread, SIGSHADOW,
>>>> -			  sigshadow_int(SIGSHADOW_ACTION_RENICE, prio), 1);
>>>> +		xnshadow_send_sig
>>>> +			(thread, SIGSHADOW,
>>>> +			 sigshadow_int(SIGSHADOW_ACTION_RENICE, prio), 1);
>>>> +	}
>>>>  
>>>>  	if (!xnthread_test_state(thread, XNDORMANT) &&
>>>>  	    xnthread_sched(thread) == xnpod_current_sched())
>>>>
>>>>
>>>
>>> This patch is correct, but it does not fix the root cause. RPI seems to
>>> be a victim here, not the culprit. As you already noticed, the main
>>> issue is with a thread holding a contented mutex, which exits. This
>>> causes the PIP boost to be cleared for it over its own taskexit handler,
>>> after its task_struct backlink has been cleared. This leads to
>>> schedule_linux_call() being called for a NULL task; enabling
>>> CONFIG_XENO_OPT_DEBUG_NUCLEUS triggers the assertion properly in this
>>> routine.
>>>
>>> The source of all issues in this case is xnsynch_clear_boost() not
>>> handling the particular case of a thread exiting with a contended mutex
>>> held. We can reuse the thread zombie bit to flag this, and avoid any
>>> useless renice.
>>>
>>> Normally, there should not be any SMP-specific triggers of this bug,
>>> the nucleus lock is held all through the deletion and synch de-boost paths.
>>
>>
>> Are we not missing an rpi_pop ?
>>
> 
> Ok. It happens in xnshadow_unmap anyway.
> 

Yes, RPI is actually uncorrelated to this issue, it will happen during
the regular context switching involved in deleting the running task,
regardless.

-- 
Philippe.