[Xenomai-help] task not being scheduled

[Xenomai-help] task not being scheduled

[Jeff Weber]

I have system where a 100Hz periodic task is occasionally over running it's
periodic task wakeup by 10s of msec.  To debug the problem, I froze an ipipe
verbose trace upon an -ETIMEDOUT error return from rt_task_wait_period().
A filtered output of the trace appears below.  This trace includes every
occurence of the task, which is pid 7380.

:|  # [ 7380] -<?>-   35 -25252+   5.587  xnpod_resume_thread+0x59 [xeno_nucleus ] (xnthread_periodic_handler+0x31 [xeno_nucleus])
:|  # [ 7380] -<?>-   35 -24820+   4.214  xnpod_schedule+0x6c0 [xeno_nucleus] (x npod_suspend_thread+0x118 [xeno_nucleus])
:|  # [ 7380] -<?>-   35 -24734+   1.501  xnpod_schedule+0x97 [xeno_nucleus] (xn intr_irq_handler+0x9a [xeno_nucleus])
:|  # [ 7380] -<?>-   35 -24589+   1.218  xnpod_schedule+0x6c0 [xeno_nucleus] (x nintr_irq_handler+0x9a [xeno_nucleus])
:   + func               -24587    0.493  __rt_task_wait_period+0x11 [xeno_native] (hisyscall_event+0x162 [xeno_nucleus])
:   + func               -24586    0.485  rt_task_wait_period+0xb [xeno_native] (__rt_task_wait_period+0x3f [xeno_native])
:   + func               -24586    0.464  xnpod_wait_thread_period+0xe [xeno_nucleus] (rt_task_wait_period+0x4b [xeno_native])
:|  + begin   0x80000001 -24586    0.718  xnpod_wait_thread_period+0x1ed [xeno_nucleus] (rt_task_wait_period+0x4b [xeno_native])
:|  # func               -24585    0.621  xnpod_suspend_thread+0xe [xeno_nucleus] (xnpod_wait_thread_period+0x91 [xeno_nucleus])
:|  # func               -24584    0.558  xnpod_schedule+0xe [xeno_nucleus] (xnpod_suspend_thread+0x118 [xeno_nucleus])
:|  # [ 7380] -<?>-   35 -24584    0.847  xnpod_schedule+0x97 [xeno_nucleus] (xn pod_suspend_thread+0x118 [xeno_nucleus])
:|  # [    0] -<?>-   -1 -10630    0.916  xnpod_schedule+0x6c0 [xeno_nucleus] (xnintr_irq_handler+0x9a [xeno_nucleus])
:|  # [    0] -<?>-   -1 -4632    0.886  xnpod_schedule+0x6c0 [xeno_nucleus] (xnintr_irq_handler+0x9a [xeno_nucleus])
:|  # [ 7380] -<?>-   35  -609+   1.747  xnpod_resume_thread+0x59 [xeno_nucleus] (xnthread_periodic_handler+0x31 [xeno_nucleus])
:|  # [ 7380] -<?>-   35  -186+   4.288  xnpod_schedule+0x6c0 [xeno_nucleus] (xn pod_suspend_thread+0x118 [xeno_nucleus])
:|  # [ 7380] -<?>-   35  -143+   1.554  xnpod_schedule+0x97 [xeno_nucleus] (xni ntr_irq_handler+0x9a [xeno_nucleus])
:|  # [ 7380] -<?>-   35    -6+   1.211  xnpod_schedule+0x6c0 [xeno_nucleus] (xn intr_irq_handler+0x9a [xeno_nucleus])
<   + freeze  0x00000007     0    0.929  xnshadow_sys_trace+0x8b [xeno_nucleus] (hisyscall_event+0x162 [xeno_nucleus])


At time -24587 usec, the task calls rt_task_wait_period(), presumable to
sleep for approx 10msec.  So, I would expect to see the task resumed at
approx clock -14587.  However, the task is not resumed until clock -609,
and not run until time -186.  So, the task wasn't sheduled for over 14msec.
During this time, the ROOT task, presumably pid=0 priority=-1,  ran  61
times.  I included a 2 samples of this in the above trace.
Thus a worse priority task ran many times, when my better priority
task was not being scheduled.

I am new to interpreting ipipe traces, and may be overlooking some of the details.
I would appreciate help understanding this problem, and how to fix it.

config:
arch = x86
Linux 2.6.17.14
Xenomai-2.2.4
ipipe 1.5-00


TIA,
	Jeff

Re: [Xenomai-help] task not being scheduled

[Jan Kiszka]

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

Jeff Weber wrote:
> I have system where a 100Hz periodic task is occasionally over running it's
> periodic task wakeup by 10s of msec.  To debug the problem, I froze an ipipe
> verbose trace upon an -ETIMEDOUT error return from rt_task_wait_period().
> A filtered output of the trace appears below.  This trace includes every
> occurence of the task, which is pid 7380.

Please post the unfiltered (but compressed) trace. It's not yet obvious
from the excerpt below what happens.

> 
> :|  # [ 7380] -<?>-   35 -25252+   5.587  xnpod_resume_thread+0x59 [xeno_nucleus ] (xnthread_periodic_handler+0x31 [xeno_nucleus])
> :|  # [ 7380] -<?>-   35 -24820+   4.214  xnpod_schedule+0x6c0 [xeno_nucleus] (x npod_suspend_thread+0x118 [xeno_nucleus])
> :|  # [ 7380] -<?>-   35 -24734+   1.501  xnpod_schedule+0x97 [xeno_nucleus] (xn intr_irq_handler+0x9a [xeno_nucleus])
> :|  # [ 7380] -<?>-   35 -24589+   1.218  xnpod_schedule+0x6c0 [xeno_nucleus] (x nintr_irq_handler+0x9a [xeno_nucleus])
> :   + func               -24587    0.493  __rt_task_wait_period+0x11 [xeno_native] (hisyscall_event+0x162 [xeno_nucleus])
> :   + func               -24586    0.485  rt_task_wait_period+0xb [xeno_native] (__rt_task_wait_period+0x3f [xeno_native])
> :   + func               -24586    0.464  xnpod_wait_thread_period+0xe [xeno_nucleus] (rt_task_wait_period+0x4b [xeno_native])
> :|  + begin   0x80000001 -24586    0.718  xnpod_wait_thread_period+0x1ed [xeno_nucleus] (rt_task_wait_period+0x4b [xeno_native])
> :|  # func               -24585    0.621  xnpod_suspend_thread+0xe [xeno_nucleus] (xnpod_wait_thread_period+0x91 [xeno_nucleus])
> :|  # func               -24584    0.558  xnpod_schedule+0xe [xeno_nucleus] (xnpod_suspend_thread+0x118 [xeno_nucleus])
> :|  # [ 7380] -<?>-   35 -24584    0.847  xnpod_schedule+0x97 [xeno_nucleus] (xn pod_suspend_thread+0x118 [xeno_nucleus])
> :|  # [    0] -<?>-   -1 -10630    0.916  xnpod_schedule+0x6c0 [xeno_nucleus] (xnintr_irq_handler+0x9a [xeno_nucleus])
> :|  # [    0] -<?>-   -1 -4632    0.886  xnpod_schedule+0x6c0 [xeno_nucleus] (xnintr_irq_handler+0x9a [xeno_nucleus])
> :|  # [ 7380] -<?>-   35  -609+   1.747  xnpod_resume_thread+0x59 [xeno_nucleus] (xnthread_periodic_handler+0x31 [xeno_nucleus])
> :|  # [ 7380] -<?>-   35  -186+   4.288  xnpod_schedule+0x6c0 [xeno_nucleus] (xn pod_suspend_thread+0x118 [xeno_nucleus])
> :|  # [ 7380] -<?>-   35  -143+   1.554  xnpod_schedule+0x97 [xeno_nucleus] (xni ntr_irq_handler+0x9a [xeno_nucleus])
> :|  # [ 7380] -<?>-   35    -6+   1.211  xnpod_schedule+0x6c0 [xeno_nucleus] (xn intr_irq_handler+0x9a [xeno_nucleus])
> <   + freeze  0x00000007     0    0.929  xnshadow_sys_trace+0x8b [xeno_nucleus] (hisyscall_event+0x162 [xeno_nucleus])
> 
> 
> At time -24587 usec, the task calls rt_task_wait_period(), presumable to
> sleep for approx 10msec.  So, I would expect to see the task resumed at
> approx clock -14587.  However, the task is not resumed until clock -609,
> and not run until time -186.  So, the task wasn't sheduled for over 14msec.
> During this time, the ROOT task, presumably pid=0 priority=-1,  ran  61
> times.  I included a 2 samples of this in the above trace.
> Thus a worse priority task ran many times, when my better priority
> task was not being scheduled.
> 
> I am new to interpreting ipipe traces, and may be overlooking some of the details.
> I would appreciate help understanding this problem, and how to fix it.
> 
> config:
> arch = x86
> Linux 2.6.17.14
> Xenomai-2.2.4
> ipipe 1.5-00
> 
> 
> TIA,
> 	Jeff
> 

Jan


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 250 bytes --]

Re: [Xenomai-help] task not being scheduled

[Jan Kiszka]

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

Jan Kiszka wrote:
> Jeff Weber wrote:
>> I have system where a 100Hz periodic task is occasionally over running it's
>> periodic task wakeup by 10s of msec.  To debug the problem, I froze an ipipe
>> verbose trace upon an -ETIMEDOUT error return from rt_task_wait_period().
>> A filtered output of the trace appears below.  This trace includes every
>> occurence of the task, which is pid 7380.
> 
> Please post the unfiltered (but compressed) trace. It's not yet obvious
> from the excerpt below what happens.
> 

...and include your .config as well, please.

Thanks,
Jan


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 250 bytes --]

Re: [Xenomai-help] task not being scheduled

[Jeff Weber]

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

trace and .config attached.
The board has a single 750MHz VIA Nehemiah CPU.

	Jeff

On Tuesday 27 February 2007 12:30, Jan Kiszka wrote:
> Jeff Weber wrote:
> > I have system where a 100Hz periodic task is occasionally over running

>
> Please post the unfiltered (but compressed) trace. It's not yet obvious
> from the excerpt below what happens.


[-- Attachment #2: frozen.gz --]
[-- Type: application/x-gzip, Size: 161200 bytes --]

[-- Attachment #3: config.gz --]
[-- Type: application/x-gzip, Size: 12061 bytes --]

Re: [Xenomai-help] task not being scheduled

[Jan Kiszka]

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

Jeff Weber wrote:
> trace and .config attached.

OK. Sorry for not believing in the first place :), but there are
actually timer events missing for your 10-ms-period task.

I saw in the .config that you are using the heap timer list. Already
tried the classic linked list as well? Maybe we see in issue related to
this queue implementation.

Gilles, I think the heap was your contribution. If it turns out to bite
us here, any idea where to look, what to instrument
(xntrace_special[_u64]...)?

Jan


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 250 bytes --]

Re: [Xenomai-help] task not being scheduled

[Gilles Chanteperdrix]

[-- Attachment #1: message body and .signature --]
[-- Type: text/plain, Size: 739 bytes --]

Jan Kiszka wrote:
 > Jeff Weber wrote:
 > > trace and .config attached.
 > 
 > OK. Sorry for not believing in the first place :), but there are
 > actually timer events missing for your 10-ms-period task.
 > 
 > I saw in the .config that you are using the heap timer list. Already
 > tried the classic linked list as well? Maybe we see in issue related to
 > this queue implementation.
 > 
 > Gilles, I think the heap was your contribution. If it turns out to bite
 > us here, any idea where to look, what to instrument
 > (xntrace_special[_u64]...)?

I used a dumper that I called at any time when I wanted to inspect the
contents of a binary heap. Here it comes, it probably needs to be
re-adapted.

-- 


					    Gilles Chanteperdrix.

[-- Attachment #2: aheap_dump.h --]
[-- Type: text/plain, Size: 2670 bytes --]

#ifndef AHEAP_DUMP_H
#define AHEAP_DUMP_H

#ifndef __KERNEL__
#include <stdlib.h>             /* For NULL */
#include <errno.h>              /* For EINVAL, EBUSY */
#include <string.h>             /* For memset */
#endif /* __KERNEL__ */

#if DUMPER && !defined(__KERNEL__)
#define flnz(word)                              \
({                                              \
    unsigned long out;                          \
    /* Derived from bitops.h's ffs() */         \
    __asm__ ("bsrl %1, %0"                      \
             : "=r" (out)                       \
             : "mr"  (word));                   \
    out;                                        \
})

static inline void
aheap_dumper_visit (FILE *file,
                    aheap_t *heap,
                    aheaph_t *node,
                    int (*prn)(char *, size_t, const aheaph_t *const),
                    const char *blank,
                    unsigned blank_sz,
                    char *buf,
                    unsigned indent,
                    unsigned len)
{
    aheaph_t *left, *right;

    right = aheaph_child(heap, node, 1);
    if(right) {
        if(blank_sz >= (unsigned) (buf-blank)) {
            snprintf(buf, len+2, "%*s\n", (int) len+1, "bug!");
            fputs(buf-blank_sz, file);
        } else
            aheap_dumper_visit(file, heap, right, prn, blank,
                               blank_sz+indent, buf, indent, len);
    }
    
    (*prn)(buf, len+1, node);
    buf[len] = '\n';
    buf[len+1] = '\0';
    
    fputs(buf-blank_sz, file);

    left = aheaph_child(heap, node, 0);    
    if(left) {
        if(blank_sz >= (unsigned) (buf-blank)) {
            snprintf(buf, len+2, "%*s\n", (int) len+1, "bug!");
            fputs(buf-blank_sz, file);
        } else
            aheap_dumper_visit(file, heap, left, prn, blank,
                               blank_sz+indent, buf, indent, len);
    }
}

static inline void
aheap_dump (FILE *file,
            aheap_t *heap,
            int (*prn)(char *, size_t, const aheaph_t *const),
            unsigned indent,
            unsigned len)
{
    aheaph_t *holder = aheap_gethead(heap);

    putc('\n', file);
    if (!holder)
        fputs("Empty.\n", file);
    else {
        size_t blank_sz = (flnz(heap->last - 1) + 1) * indent;
        char buffer[blank_sz+len+2];
        memset(buffer, ' ', blank_sz);

        aheap_dumper_visit(file, heap, holder, prn, buffer, 0,
                           buffer+blank_sz, indent, len);
    }
}
#else /* !DUMPER || __KERNEL__ */

#define aheap_dump(file, heap, prn, indent, len) do { } while(0)

#endif /* !DUMPER || __KERNEL__ */

#endif /* AHEAP_DUMP_H */

Re: [Xenomai-help] task not being scheduled

[Jeff Weber]

I will try the CONFIG_XENO_OPT_TIMER_LIST.  I have about 18 RT tasks,
of which only a few are ever runnable at the same time.

	Jeff

On Tuesday 27 February 2007 14:29, Jan Kiszka wrote:
> Jeff Weber wrote:
> > trace and .config attached.
>
> OK. Sorry for not believing in the first place :), but there are
> actually timer events missing for your 10-ms-period task.
>
> I saw in the .config that you are using the heap timer list. Already
> tried the classic linked list as well? Maybe we see in issue related to
> this queue implementation.

Re: [Xenomai-help] task not being scheduled

[Gilles Chanteperdrix]

Jeff Weber wrote:
 > I will try the CONFIG_XENO_OPT_TIMER_LIST.  I have about 18 RT tasks,
 > of which only a few are ever runnable at the same time.

The thing that matters for selecting the timer list data structure is
the number of pending timers.

-- 


					    Gilles Chanteperdrix.

Re: [Xenomai-help] task not being scheduled

[Jeff Weber]

Switching to the linked timer list from the heap list fixed it.

	thanks,
	Jeff

On Tuesday 27 February 2007 14:29, Jan Kiszka wrote:
> I saw in the .config that you are using the heap timer list. Already
> tried the classic linked list as well? Maybe we see in issue related to
> this queue implementation.

[Xenomai-core] Re: [Xenomai-help] task not being scheduled

[Philippe Gerum]

On Wed, 2007-02-28 at 07:50 -0600, Jeff Weber wrote:
> Switching to the linked timer list from the heap list fixed it.
> 

Ok people, that's a showstopper for v2.3.1.

> 	thanks,
> 	Jeff
> 
> On Tuesday 27 February 2007 14:29, Jan Kiszka wrote:
> > I saw in the .config that you are using the heap timer list. Already
> > tried the classic linked list as well? Maybe we see in issue related to
> > this queue implementation.
> 
> _______________________________________________
> Xenomai-help mailing list
> Xenomai-help@domain.hid
> https://mail.gna.org/listinfo/xenomai-help
-- 
Philippe.

Re: [Xenomai-help] task not being scheduled

[Jan Kiszka]

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

Jeff Weber wrote:
> Switching to the linked timer list from the heap list fixed it.
> 

OK, good to know.

Gilles, could you provide some ready-to-apply instrumentation patch?

Jeff, you have the ultimate test case now. Will you have some time to
run that test on your box so that we can quickly find and resolve the bug?

Jan


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 250 bytes --]

Re: [Xenomai-help] task not being scheduled

[Gilles Chanteperdrix]

Jan Kiszka wrote:
> Jeff Weber wrote:
> 
>>Switching to the linked timer list from the heap list fixed it.
>>
> 
> 
> OK, good to know.
> 
> Gilles, could you provide some ready-to-apply instrumentation patch?

Yes, the mail with attached patch did not make it to the list, but I
just finished my work on the ARM patch for Linux 2.6.19, so, I have time
to spend on this issue.

> 
> Jeff, you have the ultimate test case now. Will you have some time to
> run that test on your box so that we can quickly find and resolve the bug?

Is it possible to get a simplified version of the application you are
running with only timer-related events ? Some kind of model that I could
quietly run in the simulator ?

-- 
                                                 Gilles Chanteperdrix

Re: [Xenomai-help] task not being scheduled

[Jeff Weber]

On Wednesday 28 February 2007 08:20, Gilles Chanteperdrix wrote:
> Jan Kiszka wrote:
>
> > Jeff, you have the ultimate test case now. Will you have some time to
> > run that test on your box so that we can quickly find and resolve the
> > bug?

Yes.  I've rebuilt my kernel with the linked list scheduler, but I've saved 
the previous heap scheduler config.  I will recreate the bug config, and 
await a patch or instrumentation.
>
> Is it possible to get a simplified version of the application you are
> running with only timer-related events ? Some kind of model that I could
> quietly run in the simulator ?
That will be more difficult.  The application requires a custom kernel module, 
and has many dependencies upon our hardware.  Further, the app is written in 
C++, which I understand is not compatible with the simulator.

Let me know if you would like to move this discussion off the xenomai-help 
list, to xenomai-core, or a private email discussion.

And again, thanks for taking the time to look at my trace, config and 
recommend a solution.  It was causing considerable frustration on this end.

	Jeff

[Xenomai-core] Re: [Xenomai-help] task not being scheduled

[Gilles Chanteperdrix]

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

Jeff Weber wrote:
> On Wednesday 28 February 2007 08:20, Gilles Chanteperdrix wrote:
> 
>>Jan Kiszka wrote:
>>
>>
>>>Jeff, you have the ultimate test case now. Will you have some time to
>>>run that test on your box so that we can quickly find and resolve the
>>>bug?
> 
> 
> Yes.  I've rebuilt my kernel with the linked list scheduler, but I've saved 
> the previous heap scheduler config.  I will recreate the bug config, and 
> await a patch or instrumentation.
> 
>>Is it possible to get a simplified version of the application you are
>>running with only timer-related events ? Some kind of model that I could
>>quietly run in the simulator ?
> 
> That will be more difficult.  The application requires a custom kernel module, 
> and has many dependencies upon our hardware.  Further, the app is written in 
> C++, which I understand is not compatible with the simulator.
> 
> Let me know if you would like to move this discussion off the xenomai-help 
> list, to xenomai-core, or a private email discussion.
> 
> And again, thanks for taking the time to look at my trace, config and 
> recommend a solution.  It was causing considerable frustration on this end.

Ok. Following up on xenomai-core. Find attached a not too subtle
instrumentation that saves the state of the heap after each elementary
operation. This history is then dumped with printk on xntrace freeze.

-- 
                                                 Gilles Chanteperdrix

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: xeno-trace-bheap.diff --]
[-- Type: text/x-patch; name="xeno-trace-bheap.diff", Size: 6583 bytes --]

Index: include/nucleus/bheap.h
===================================================================
--- include/nucleus/bheap.h	(révision 2730)
+++ include/nucleus/bheap.h	(copie de travail)
@@ -25,6 +25,12 @@
 
 /* Priority queue implementation, using a binary heap. */
 
+typedef enum {
+	BHEAP_INSERT,
+	BHEAP_DELETE,
+	BHEAP_GETHEAD,
+} bheap_op_t;
+ 
 typedef unsigned long long bheap_key_t;
 
 typedef struct bheaph {
@@ -66,11 +72,18 @@
     __internal_bheap_gethead(_bheap);           \
 })
 
+void bheap_s_init(void);
+
+void bheap_save_push(bheap_t *q, bheap_op_t op, bheaph_t *elem);
+
+void bheap_ops_dump(void);
+
 static inline bheaph_t *__internal_bheap_gethead(bheap_t *heap)
 {
     if (heap->last == 1)
         return NULL;
 
+    bheap_save_push(heap, BHEAP_GETHEAD, heap->elems[1]);
     return heap->elems[1];
 }
 
@@ -158,6 +171,7 @@
     bheaph_pos(holder) = heap->last;
     ++heap->last;
     bheap_up(heap, holder);
+    bheap_save_push(heap, BHEAP_INSERT, holder);
     return 0;
 }
 
@@ -182,6 +196,7 @@
         bheaph_pos(lasth) = bheaph_pos(holder);
         bheap_down(heap, lasth);
     }
+    bheap_save_push(heap, BHEAP_DELETE, holder);
 
     return 0;
 }
Index: ksrc/nucleus/timer.c
===================================================================
--- ksrc/nucleus/timer.c	(révision 2730)
+++ ksrc/nucleus/timer.c	(copie de travail)
@@ -755,6 +755,9 @@
 
 void xntimer_set_aperiodic_mode(void)
 {
+#if defined(CONFIG_XENO_OPT_TIMER_HEAP)
+	bheap_s_init();
+#endif
 	nktimer = &timer_ops_aperiodic;
 }
 
@@ -771,3 +774,166 @@
 EXPORT_SYMBOL(xntimer_get_date);
 EXPORT_SYMBOL(xntimer_get_timeout);
 EXPORT_SYMBOL(nktimer);
+
+#if defined(CONFIG_XENO_OPT_TIMER_HEAP)
+typedef struct {
+	unsigned sz;
+	unsigned last;
+	bheaph_t elems[CONFIG_XENO_OPT_TIMER_HEAP_CAPACITY + 1];
+/* indexing starts at 1	*/
+} bheap_save_t;
+
+#define BHEAP_SAVE_SIZE 256
+typedef struct {
+	unsigned head;
+	unsigned tail;
+	struct {
+		bheap_op_t op;
+		unsigned long long ts;
+		bheap_save_t save;
+	} array [BHEAP_SAVE_SIZE];
+} bheap_s_t;
+
+bheap_s_t *_bheap_s[2], *bheap_s;
+
+static void bheap_save(bheap_save_t *save, bheap_t *q)
+{
+	unsigned i;
+	save->sz = q->sz;
+	save->last = q->last;
+	for (i = 1; i < save->last; i++)
+		save->elems[i] = *(q->elems[i]);
+}
+
+void bheap_s_init(void)
+{
+	_bheap_s[0] = vmalloc(sizeof(bheap_s_t));
+	BUG_ON(!_bheap_s[0]);
+	_bheap_s[0]->head = _bheap_s[0]->tail = 0;
+	_bheap_s[1] = vmalloc(sizeof(bheap_s_t));
+	BUG_ON(!_bheap_s[1]);
+	_bheap_s[1]->head = _bheap_s[1]->tail = 0;
+	bheap_s = _bheap_s[0];
+}
+
+void bheap_save_push(bheap_t *q, bheap_op_t op, bheaph_t *elem)
+{
+	if (bheap_s->tail == bheap_s->head + BHEAP_SAVE_SIZE)
+		bheap_s->head++;
+	bheap_s->array[bheap_s->tail % BHEAP_SAVE_SIZE].ts = xnarch_get_cpu_tsc();
+	bheap_s->array[bheap_s->tail % BHEAP_SAVE_SIZE].op = op;
+	bheap_s->array[bheap_s->tail % BHEAP_SAVE_SIZE].save.elems[0]=*elem;
+	bheap_save(&bheap_s->array[bheap_s->tail % BHEAP_SAVE_SIZE].save, q);
+	bheap_s->tail++;
+}
+
+static int ts_convert(char *buf, size_t sz, unsigned long long ts)
+{
+	unsigned long long ns = xnarch_tsc_to_ns(ts);
+	unsigned hrs, mins, secs, nsecs;
+	nsecs = do_div(ns, 1000000000);
+	secs = ns;
+	mins = secs / 60;
+	secs %= 60;
+	hrs = mins / 60;
+	mins %= 60;
+	return snprintf(buf, sz, "%3u:%02u:%02u.%09u", hrs, mins, secs, nsecs);
+}
+
+static int bheaph_prn(char *buf, size_t sz, const bheaph_t *const holder)
+{
+	return ts_convert(buf, sz, holder->key);
+}
+
+static void
+bheap_dumper_visit (bheap_save_t *heap,
+                    bheaph_t *node,
+                    int (*prn)(char *, size_t, const bheaph_t *const),
+                    const char *blank,
+                    unsigned blank_sz,
+                    char *buf,
+                    unsigned indent,
+                    unsigned len)
+{
+	unsigned pos = 2 * node->pos + 1;
+
+	if(pos < heap->last) {
+		bheaph_t *child = &heap->elems[pos];
+		if(blank_sz >= (unsigned) (buf-blank)) {
+			snprintf(buf, len+2, "%*s\n", (int) len+1, "bug!");
+			printk("%s", buf-blank_sz);
+		} else
+			bheap_dumper_visit(heap, child, prn, blank,
+					   blank_sz+indent, buf, indent, len);
+	}
+	
+	(*prn)(buf, len+1, node);
+	buf[len] = '\n';
+	buf[len+1] = '\0';
+	
+	printk("%s", buf-blank_sz);
+
+	--pos;
+	if(pos < heap->last) {
+		bheaph_t *child = &heap->elems[pos];
+		if(blank_sz >= (unsigned) (buf-blank)) {
+			snprintf(buf, len+2, "%*s\n", (int) len+1, "bug!");
+			printk("%s", buf-blank_sz);
+		} else
+			bheap_dumper_visit(heap, child, prn, blank,
+					   blank_sz+indent, buf, indent, len);
+	}
+}
+
+static void
+bheap_s_dump(bheap_save_t *heap,
+	     int (*prn)(char *, size_t, const bheaph_t *const),
+	     unsigned margin,
+	     unsigned indent,
+	     unsigned len)
+{
+	if (heap->last == 1) {
+		printk("%s", "Empty.\n");
+	} else {
+		size_t blank_sz = (fls(heap->last - 1) + 1) * indent + margin;
+		char buffer[blank_sz+len+2];
+		memset(buffer, ' ', blank_sz);
+
+		bheap_dumper_visit(heap, &heap->elems[1], prn, buffer, margin,
+				   buffer+blank_sz, indent, len);
+	}
+}
+
+void bheap_ops_dump(void)
+{
+	static const char *ops [] = {
+		[BHEAP_INSERT] = "insert",
+		[BHEAP_DELETE] = "delete",
+		[BHEAP_GETHEAD]= "gthead"
+	};
+	bheap_s_t *cur_s;
+	unsigned i;
+	spl_t s;
+
+	xnlock_get_irqsave(&nklock, s);
+	cur_s = bheap_s;
+	bheap_s = bheap_s == _bheap_s[0] ? _bheap_s[1] : _bheap_s[0];
+	xnlock_put_irqrestore(&nklock, s);
+
+	for(i = cur_s->head % BHEAP_SAVE_SIZE;
+	    i < cur_s->tail % BHEAP_SAVE_SIZE;
+	    i++) {
+		char bts[20], bkey[20];
+		ts_convert(bts, sizeof(bts), cur_s->array[i].ts);
+		ts_convert(bkey, sizeof(bkey),
+			   cur_s->array[i].save.elems[0].key);
+		
+		printk("%s: %s %s\n", bts, ops[cur_s->array[i].op], bkey);
+		bheap_s_dump(&cur_s->array[i].save, bheaph_prn, 8, 4, 19);
+		printk("\n");
+	}
+
+	cur_s->head = cur_s->tail = 0;
+}
+
+#endif
Index: ksrc/nucleus/shadow.c
===================================================================
--- ksrc/nucleus/shadow.c	(révision 2730)
+++ ksrc/nucleus/shadow.c	(copie de travail)
@@ -1330,6 +1330,9 @@
 		break;
 
 	case __xntrace_op_user_freeze:
+#if defined(CONFIG_XENO_OPT_TIMER_HEAP)
+		bheap_ops_dump();
+#endif
 		err = xnarch_trace_user_freeze(__xn_reg_arg2(regs),
 					       __xn_reg_arg3(regs));
 		break;

Re: [Xenomai-help] task not being scheduled

[Gilles Chanteperdrix]

Jeff Weber wrote:
 > 
 > On Wednesday 28 February 2007 08:20, Gilles Chanteperdrix wrote:
 > > Jan Kiszka wrote:
 > >
 > > > Jeff, you have the ultimate test case now. Will you have some time to
 > > > run that test on your box so that we can quickly find and resolve the
 > > > bug?
 > 
 > Yes.  I've rebuilt my kernel with the linked list scheduler, but I've saved 
 > the previous heap scheduler config.  I will recreate the bug config, and 
 > await a patch or instrumentation.
 > >
 > > Is it possible to get a simplified version of the application you are
 > > running with only timer-related events ? Some kind of model that I could
 > > quietly run in the simulator ?
 > That will be more difficult.  The application requires a custom kernel module, 
 > and has many dependencies upon our hardware.  Further, the app is written in 
 > C++, which I understand is not compatible with the simulator.
 > 
 > Let me know if you would like to move this discussion off the xenomai-help 
 > list, to xenomai-core, or a private email discussion.
 > 
 > And again, thanks for taking the time to look at my trace, config and 
 > recommend a solution.  It was causing considerable frustration on this end.

Thank you Jeff for helping. The issue should now be resolved by commit
#2280 in trunk and #2281 in branch 2.3.

-- 


					    Gilles Chanteperdrix.