[Xenomai-help] Debug/trace tools for xenomai applications.

[Xenomai-help] Debug/trace tools for xenomai applications.

[ronny meeus]

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

Hello

I'm currently fighting with a problem in the pSOS+ skin.
This my system information:

[    2.314676] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    2.416025] I-pipe: Domain Xenomai registered.
[    2.418183] Xenomai: hal/i386 started.
[    2.422780] Xenomai: scheduling class idle registered.
[    2.424116] Xenomai: scheduling class rt registered.
[    2.566737] Xenomai: real-time nucleus v2.5.4 (Sleep Walk) loaded.
[    2.590628] Xenomai: starting native API services.
[    2.604491] Xenomai: starting pSOS+ services.
[    2.619941] HugeTLB registered 4 MB page size, pre-allocated 0 pages

This is a piece of testcode I have created:

        check("tm_evevery",tm_evevery(4,3,&tmr_id),0);
        check("tm_cancel",tm_cancel(tmr_id),0);
        ev_rcvd = 0;
        ret = ev_receive(4,EV_ANY|EV_WAIT,10,&ev_rcvd);
        check("ev_receive",ret,ERR_TIMEOUT);

I just start a periodic timer that expires every 3 ticks and at expiry sends
event 4 to my task.
I want to check the cancel of the timer, so I cancel it and I would expect
not to receive any event.

What I observe is that this code is not working: I immediately receive the
event after starting the timer.
If I change the code like shown below (I added the ev_receive with the
NO_WAIT option after starting the timer), the code works fine.

        check("tm_evevery",tm_evevery(4,3,&tmr_id),0);
        ret = ev_receive(4,EV_ANY|EV_NOWAIT,0,&ev_rcvd);
        check("tm_cancel",tm_cancel(tmr_id),0);
        ev_rcvd = 0;
        ret = ev_receive(4,EV_ANY|EV_WAIT,10,&ev_rcvd);
        check("ev_receive",ret,ERR_TIMEOUT);

Now my question is: how do I investigate an issue like this? In other words,
which are the best tools since this code involves both user and kernel space
debugging.
Are there some trace tools available that are able to generate a kind of
sequence / trace of what is happing over time.

I also have other issues that are not consistently reproducible. For this
kind of problems trace tools would also be useful.

Thanks
Ronny

[-- Attachment #2: Type: text/html, Size: 2267 bytes --]

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[Philippe Gerum]

On Sun, 2010-11-14 at 01:24 +0100, ronny meeus wrote:
> Hello
> 
> I'm currently fighting with a problem in the pSOS+ skin.
> This my system information:
> 
> [    2.314676] pci 0000:00:01.0: Activating ISA DMA hang workarounds
> [    2.416025] I-pipe: Domain Xenomai registered.
> [    2.418183] Xenomai: hal/i386 started.
> [    2.422780] Xenomai: scheduling class idle registered.
> [    2.424116] Xenomai: scheduling class rt registered.
> [    2.566737] Xenomai: real-time nucleus v2.5.4 (Sleep Walk) loaded.
> [    2.590628] Xenomai: starting native API services.
> [    2.604491] Xenomai: starting pSOS+ services.
> [    2.619941] HugeTLB registered 4 MB page size, pre-allocated 0
> pages
> 
> This is a piece of testcode I have created:
> 
>         check("tm_evevery",tm_evevery(4,3,&tmr_id),0);
>         check("tm_cancel",tm_cancel(tmr_id),0);
>         ev_rcvd = 0;
>         ret = ev_receive(4,EV_ANY|EV_WAIT,10,&ev_rcvd);
>         check("ev_receive",ret,ERR_TIMEOUT);
> 
> I just start a periodic timer that expires every 3 ticks and at expiry
> sends event 4 to my task.

You test rather arms a timer for sending event_list=0x3 each 4 ticks.

> I want to check the cancel of the timer, so I cancel it and I would
> expect not to receive any event.
> 
> What I observe is that this code is not working: I immediately receive
> the event after starting the timer.

Please try this test code as well:

#include <stdio.h>
#include <unistd.h>
#include <sys/types.h>
#include <sys/mman.h>
#include <psos+/psos.h>

void foo (u_long a0, u_long a1, u_long a2, u_long a3)
{
	u_long ret, ev = 0, tmid;

	printf("Started... (%lu, %lu, %lu, %lu)\n", a0, a1, a2, a3);
	ret = tm_evevery(4, 3, &tmid);
	printf("tm_evevery(4, 3, &tmid) => %lu\n", ret);

	ret = tm_cancel(tmid);
	printf("tm_cancel(&tmid) => %lu\n", ret);

	ret = ev_receive(4, EV_ANY|EV_WAIT, 10, &ev);
	printf("ev_receive(4, EV_ANY|EV_WAIT, 10, &ev) => %lu, ev=0x%lx\n", ret, ev);
}

int main (int ac, char **av)
{
	u_long ret, tid = 0, args[4];
	
	mlockall(MCL_CURRENT | MCL_FUTURE);

	ret = t_create("TEST", 1, 0, 0, 0, &tid);
	printf("t_create(tid=%lu) = %lu\n", tid, ret);
	args[0] = 1;
	args[1] = 2;
	args[2] = 3;
	args[3] = 4;
	ret = t_start(tid, 0, foo, args);
	printf("t_start(tid=%lu) = %lu\n", tid, ret);

	return 0;
}

> If I change the code like shown below (I added the ev_receive with the
> NO_WAIT option after starting the timer), the code works fine.
> 
>         check("tm_evevery",tm_evevery(4,3,&tmr_id),0);
>         ret = ev_receive(4,EV_ANY|EV_NOWAIT,0,&ev_rcvd);

Do you receive ERR_NOEVS as expected here?

>         check("tm_cancel",tm_cancel(tmr_id),0);
>         ev_rcvd = 0;
>         ret = ev_receive(4,EV_ANY|EV_WAIT,10,&ev_rcvd);
>         check("ev_receive",ret,ERR_TIMEOUT);
> 


> Now my question is: how do I investigate an issue like this? In other
> words, which are the best tools since this code involves both user and
> kernel space debugging.
> Are there some trace tools available that are able to generate a kind
> of sequence / trace of what is happing over time.
> 
> I also have other issues that are not consistently reproducible. For
> this kind of problems trace tools would also be useful.
> 

If you want to validate the pSOS emulation core, the best tool is the
simulator. Unfortunately, this tools still requires to be built with an
antiquated C++ toolchain, so the only sane way to enable it nowadays is
via qemu. You would need ~2 hours to set this up.

If you want to try this, I can help. Otherwise, other suggestions you
already got on this list will do.

> Thanks
> Ronny
> _______________________________________________
> Xenomai-help mailing list
> Xenomai-help@domain.hid
> https://mail.gna.org/listinfo/xenomai-help

-- 
Philippe.

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[Gilles Chanteperdrix]

Philippe Gerum wrote:
> If you want to validate the pSOS emulation core, the best tool is the
> simulator. Unfortunately, this tools still requires to be built with an
> antiquated C++ toolchain, so the only sane way to enable it nowadays is
> via qemu. You would need ~2 hours to set this up.
> 
> If you want to try this, I can help. Otherwise, other suggestions you
> already got on this list will do.

Maybe we should put a page on the wiki on how to use the simulator?

-- 
                                                                Gilles.

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[Philippe Gerum]

On Mon, 2010-11-15 at 14:10 +0100, Gilles Chanteperdrix wrote:
> Philippe Gerum wrote:
> > If you want to validate the pSOS emulation core, the best tool is the
> > simulator. Unfortunately, this tools still requires to be built with an
> > antiquated C++ toolchain, so the only sane way to enable it nowadays is
> > via qemu. You would need ~2 hours to set this up.
> > 
> > If you want to try this, I can help. Otherwise, other suggestions you
> > already got on this list will do.
> 
> Maybe we should put a page on the wiki on how to use the simulator?
> 

The problem is that we have no bandwidth to maintain it properly, this
is a project in itself; so this should be clearly stated on such
documentation. The gcc-based (2.95.x) instrumenter is 12-years old now,
and rewriting this part would a very significant work. It's really a
pity, since the simulator is definitely the ultimate tool for finding
functional bugs in emulators. Oh, well.

-- 
Philippe.

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[ronny meeus]

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

Hello

Thanks for the information.
I was testing on QEMU but I have seen that there are issue with the timing
anyhow.
I'm currently changing to a target environment. Once this is completed, I
will re-run my tests and get back with the result.

I do not really understand what you mean with the simulator.
Where can I find more information about it?

Thanks
Ronny

On Mon, Nov 15, 2010 at 4:07 PM, Philippe Gerum <rpm@xenomai.org> wrote:

> On Mon, 2010-11-15 at 14:10 +0100, Gilles Chanteperdrix wrote:
> > Philippe Gerum wrote:
> > > If you want to validate the pSOS emulation core, the best tool is the
> > > simulator. Unfortunately, this tools still requires to be built with an
> > > antiquated C++ toolchain, so the only sane way to enable it nowadays is
> > > via qemu. You would need ~2 hours to set this up.
> > >
> > > If you want to try this, I can help. Otherwise, other suggestions you
> > > already got on this list will do.
> >
> > Maybe we should put a page on the wiki on how to use the simulator?
> >
>
> The problem is that we have no bandwidth to maintain it properly, this
> is a project in itself; so this should be clearly stated on such
> documentation. The gcc-based (2.95.x) instrumenter is 12-years old now,
> and rewriting this part would a very significant work. It's really a
> pity, since the simulator is definitely the ultimate tool for finding
> functional bugs in emulators. Oh, well.


> --
> Philippe.
>
>
>

[-- Attachment #2: Type: text/html, Size: 2058 bytes --]

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[Philippe Gerum]

On Mon, 2010-11-15 at 21:26 +0100, ronny meeus wrote:
> Hello
> 
> Thanks for the information.
> I was testing on QEMU but I have seen that there are issue with the
> timing anyhow.
> I'm currently changing to a target environment. Once this is
> completed, I will re-run my tests and get back with the result.
> 
> I do not really understand what you mean with the simulator.
> Where can I find more information about it?

http://git.xenomai.org/?p=xenosim.git;a=blob;f=doc/mvm-manual.txt;h=1c6767ea2890d68e1c1c5cfe1420e189b3cc5328;hb=06919eb3a6b6baf7880ea3ade1ecc5f610c35794

> 
> Thanks
> Ronny
> 
> On Mon, Nov 15, 2010 at 4:07 PM, Philippe Gerum <rpm@xenomai.org>
> wrote:
>         On Mon, 2010-11-15 at 14:10 +0100, Gilles Chanteperdrix wrote:
>         > Philippe Gerum wrote:
>         > > If you want to validate the pSOS emulation core, the best
>         tool is the
>         > > simulator. Unfortunately, this tools still requires to be
>         built with an
>         > > antiquated C++ toolchain, so the only sane way to enable
>         it nowadays is
>         > > via qemu. You would need ~2 hours to set this up.
>         > >
>         > > If you want to try this, I can help. Otherwise, other
>         suggestions you
>         > > already got on this list will do.
>         >
>         > Maybe we should put a page on the wiki on how to use the
>         simulator?
>         >
>         
>         
>         The problem is that we have no bandwidth to maintain it
>         properly, this
>         is a project in itself; so this should be clearly stated on
>         such
>         documentation. The gcc-based (2.95.x) instrumenter is 12-years
>         old now,
>         and rewriting this part would a very significant work. It's
>         really a
>         pity, since the simulator is definitely the ultimate tool for
>         finding
>         functional bugs in emulators. Oh, well. 
>         
>         --
>         Philippe.
>         
>         
> 

-- 
Philippe.

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[ronny meeus]

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

Hello

I did some more tests on QEMU since the behavior on Simics is identical to
the behavior I see on QEMU.
This is the testcode I have used:

void test_timer_cancel(void)
{
        unsigned long tmr_id,ev,ret,i;
        unsigned long failed = 0;

        for (i=1;i<3;i++)
        {
                ret = tm_evevery(i,1,&tmr_id);
                ut_printf("tm_evevery(%lu,1,&tmr_id) => %lu\n", i,ret);

                ret = tm_cancel(tmr_id);
                ut_printf("tm_cancel(&tmid) => %lu\n", ret);

                ev = 0;
                ret = ev_receive(1, EV_ANY|EV_WAIT, 200, &ev);
                ut_printf("ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => %lu,
ev=0x%lx\n", ret, ev);

                tm_wkafter(2);

                if (ret == 0)
                        failed++;
        }
        ut_printf("#events received after cancel %lu
(loopcount=%lu)\n\n",failed,i);
}

void run_test(void)
{
        test_timer_cancel();
}

static void task_body_wrapper(unsigned long func,unsigned long
count,unsigned long smid,unsigned long d)
{
    unsigned long i;
    ut_printf("In task_body_wrapper\n");
    test_function test = (test_function)func;
    for (i=0;i<count;i++)
        test();
    sm_v(smid);
}

static void task_wrapper(test_function f,unsigned long count)
{
        unsigned long tid,smid;
        unsigned long args[4] = {(unsigned long)f,count,0,0};

        sm_create("BLOC",0,SM_PRIOR,&smid);
        args[2] = smid;

        t_create("TEST",25,16000,16000,0,&tid);
        t_start(tid,0,task_body_wrapper,args);

       sm_p(smid,SM_WAIT,0);
       sm_delete(smid);

       t_delete(tid);
}

int main(int argc, char **argv)
{
    unsigned long rnid,rsize,i;

    mlockall(MCL_CURRENT|MCL_FUTURE);
    rt_print_auto_init(1);

    /* Body of the test goes here */
    while (1)
    {
        task_wrapper(run_test,1);

        for (i=0;i<1;i++)
            run_test();

        task_wrapper(run_test,1);
    }
}

(The ut_printf function is mapped on rt_printf.)
So this test is identical to the test you proposed.
The function "test_timer_cancel" is called both from the context of the main
thread and a TEST thread.

This is the output I get when running the test:

In task_body_wrapper
tm_evevery(1,1,&tmr_id) => 0
tm_cancel(&tmid) => 0
ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
tm_evevery(2,1,&tmr_id) => 0
tm_cancel(&tmid) => 0
ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
#events received after cancel 0 (loopcount=3)

tm_evevery(1,1,&tmr_id) => 0
tm_cancel(&tmid) => 0
ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 0, ev=0x1
tm_evevery(2,1,&tmr_id) => 0
tm_cancel(&tmid) => 0
ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
#events received after cancel 1 (loopcount=3)

In task_body_wrapper
tm_evevery(1,1,&tmr_id) => 0
tm_cancel(&tmid) => 0
ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 0, ev=0x1
tm_evevery(2,1,&tmr_id) => 0
tm_cancel(&tmid) => 0
ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
#events received after cancel 1 (loopcount=3)

In task_body_wrapper
tm_evevery(1,1,&tmr_id) => 0
tm_cancel(&tmid) => 0
ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
tm_evevery(2,1,&tmr_id) => 0
tm_cancel(&tmid) => 0

As you can see in most of the cases the system behaves correctly.
In some cases, the event is received. This is the case both from the context
of the main thread and the special thread.
I just copy-pasted a part of the output. In most cases, the event is not
received. I think something like 1 times out of 50 I see the event being
received.

It looks like, if it happens, it is always the first iteration of the loop
(the one with a timeout of 1 tick). Even if I change the initial timeout
value to 2, the event is also received sporadically.

[ Phillippe, please note that in your test code, you have also swapped the
parameters. You send event 3 and lateron check whether you have received
event 4. :-) ]

Another observation is that after removing the ut_printf statements, I do
not see the issue anymore.
It looks like the printf/rt_printf has an impact on the system behavior.

I had a quick look to the LTTng as well, but I need to fix the patches
before I will be able to integrate.
I think this will be my next step.

Best regards,
Ronny


On Mon, Nov 15, 2010 at 10:30 AM, Philippe Gerum <rpm@xenomai.org> wrote:

> On Sun, 2010-11-14 at 01:24 +0100, ronny meeus wrote:
> > Hello
> >
> > I'm currently fighting with a problem in the pSOS+ skin.
> > This my system information:
> >
> > [    2.314676] pci 0000:00:01.0: Activating ISA DMA hang workarounds
> > [    2.416025] I-pipe: Domain Xenomai registered.
> > [    2.418183] Xenomai: hal/i386 started.
> > [    2.422780] Xenomai: scheduling class idle registered.
> > [    2.424116] Xenomai: scheduling class rt registered.
> > [    2.566737] Xenomai: real-time nucleus v2.5.4 (Sleep Walk) loaded.
> > [    2.590628] Xenomai: starting native API services.
> > [    2.604491] Xenomai: starting pSOS+ services.
> > [    2.619941] HugeTLB registered 4 MB page size, pre-allocated 0
> > pages
> >
> > This is a piece of testcode I have created:
> >
> >         check("tm_evevery",tm_evevery(4,3,&tmr_id),0);
> >         check("tm_cancel",tm_cancel(tmr_id),0);
> >         ev_rcvd = 0;
> >         ret = ev_receive(4,EV_ANY|EV_WAIT,10,&ev_rcvd);
> >         check("ev_receive",ret,ERR_TIMEOUT);
> >
> > I just start a periodic timer that expires every 3 ticks and at expiry
> > sends event 4 to my task.
>
> You test rather arms a timer for sending event_list=0x3 each 4 ticks.
>
> > I want to check the cancel of the timer, so I cancel it and I would
> > expect not to receive any event.
> >
> > What I observe is that this code is not working: I immediately receive
> > the event after starting the timer.
>
> Please try this test code as well:
>
> #include <stdio.h>
> #include <unistd.h>
> #include <sys/types.h>
> #include <sys/mman.h>
> #include <psos+/psos.h>
>
> void foo (u_long a0, u_long a1, u_long a2, u_long a3)
> {
>        u_long ret, ev = 0, tmid;
>
>        printf("Started... (%lu, %lu, %lu, %lu)\n", a0, a1, a2, a3);
>        ret = tm_evevery(4, 3, &tmid);
>        printf("tm_evevery(4, 3, &tmid) => %lu\n", ret);
>
>        ret = tm_cancel(tmid);
>        printf("tm_cancel(&tmid) => %lu\n", ret);
>
>        ret = ev_receive(4, EV_ANY|EV_WAIT, 10, &ev);
>        printf("ev_receive(4, EV_ANY|EV_WAIT, 10, &ev) => %lu, ev=0x%lx\n",
> ret, ev);
> }
>
> int main (int ac, char **av)
> {
>        u_long ret, tid = 0, args[4];
>
>        mlockall(MCL_CURRENT | MCL_FUTURE);
>
>        ret = t_create("TEST", 1, 0, 0, 0, &tid);
>        printf("t_create(tid=%lu) = %lu\n", tid, ret);
>        args[0] = 1;
>        args[1] = 2;
>        args[2] = 3;
>        args[3] = 4;
>        ret = t_start(tid, 0, foo, args);
>        printf("t_start(tid=%lu) = %lu\n", tid, ret);
>
>        return 0;
> }
>
> > If I change the code like shown below (I added the ev_receive with the
> > NO_WAIT option after starting the timer), the code works fine.
> >
> >         check("tm_evevery",tm_evevery(4,3,&tmr_id),0);
> >         ret = ev_receive(4,EV_ANY|EV_NOWAIT,0,&ev_rcvd);
>
> Do you receive ERR_NOEVS as expected here?
>
> >         check("tm_cancel",tm_cancel(tmr_id),0);
> >         ev_rcvd = 0;
> >         ret = ev_receive(4,EV_ANY|EV_WAIT,10,&ev_rcvd);
> >         check("ev_receive",ret,ERR_TIMEOUT);
> >
>
>
> > Now my question is: how do I investigate an issue like this? In other
> > words, which are the best tools since this code involves both user and
> > kernel space debugging.
> > Are there some trace tools available that are able to generate a kind
> > of sequence / trace of what is happing over time.
> >
> > I also have other issues that are not consistently reproducible. For
> > this kind of problems trace tools would also be useful.
> >
>
> If you want to validate the pSOS emulation core, the best tool is the
> simulator. Unfortunately, this tools still requires to be built with an
> antiquated C++ toolchain, so the only sane way to enable it nowadays is
> via qemu. You would need ~2 hours to set this up.
>
> If you want to try this, I can help. Otherwise, other suggestions you
> already got on this list will do.
>
> > Thanks
> > Ronny
> > _______________________________________________
> > Xenomai-help mailing list
> > Xenomai-help@domain.hid
> > https://mail.gna.org/listinfo/xenomai-help
>
> --
> Philippe.
>
>
>

[-- Attachment #2: Type: text/html, Size: 10427 bytes --]

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[Philippe Gerum]

On Wed, 2010-11-17 at 14:49 +0100, ronny meeus wrote:
> Hello
> 
> I did some more tests on QEMU since the behavior on Simics is
> identical to the behavior I see on QEMU.
> This is the testcode I have used:
> 
> void test_timer_cancel(void)
> {
>         unsigned long tmr_id,ev,ret,i;
>         unsigned long failed = 0;
> 
>         for (i=1;i<3;i++)
>         {
>                 ret = tm_evevery(i,1,&tmr_id);
>                 ut_printf("tm_evevery(%lu,1,&tmr_id) => %lu\n",
> i,ret);
> 
>                 ret = tm_cancel(tmr_id);
>                 ut_printf("tm_cancel(&tmid) => %lu\n", ret);
> 
>                 ev = 0;
>                 ret = ev_receive(1, EV_ANY|EV_WAIT, 200, &ev);
>                 ut_printf("ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => %
> lu, ev=0x%lx\n", ret, ev);
> 
>                 tm_wkafter(2);
> 
>                 if (ret == 0)
>                         failed++;
>         }
>         ut_printf("#events received after cancel %lu (loopcount=%lu)\n
> \n",failed,i);
> }
> 
> void run_test(void)
> {
>         test_timer_cancel();
> }
> 
> static void task_body_wrapper(unsigned long func,unsigned long
> count,unsigned long smid,unsigned long d)
> {
>     unsigned long i;
>     ut_printf("In task_body_wrapper\n");
>     test_function test = (test_function)func;
>     for (i=0;i<count;i++)
>         test();
>     sm_v(smid);
> }
> 
> static void task_wrapper(test_function f,unsigned long count)
> {
>         unsigned long tid,smid;
>         unsigned long args[4] = {(unsigned long)f,count,0,0};
> 
>         sm_create("BLOC",0,SM_PRIOR,&smid);
>         args[2] = smid;
> 
>         t_create("TEST",25,16000,16000,0,&tid);
>         t_start(tid,0,task_body_wrapper,args);
> 
>        sm_p(smid,SM_WAIT,0);
>        sm_delete(smid);
> 
>        t_delete(tid);
> }
> 
> int main(int argc, char **argv)
> { 
>     unsigned long rnid,rsize,i;
> 
>     mlockall(MCL_CURRENT|MCL_FUTURE);
>     rt_print_auto_init(1);
> 
>     /* Body of the test goes here */
>     while (1)
>     {
>         task_wrapper(run_test,1);
>         
>         for (i=0;i<1;i++)
>             run_test();
> 
>         task_wrapper(run_test,1);
>     }
> }
> 
> (The ut_printf function is mapped on rt_printf.)
> So this test is identical to the test you proposed.

No, the reason I sent you this frag, is because we are currently
assuming that no tick will happen between tm_evevery() and ev_receive(),
which is wrong, at least in theory. So this small frag is actually
reducing the complexity to the bare minimum, so that we don't chase wild
gooses uselessly.

The clock is not synchronized with your application in periodic mode, so
you can't be sure that a pending tick won't hit the kernel - and thus
deliver the event - prior to entering ev_receive(). The odds of being
preempted by ev_send() on behalf of the tick handler before entering
ev_receive() is even higher with a period set to one tick, like in your
example, which is therefore wrong once again. Slowing down the code with
trace output may introduce variations if timing is involved.

Besides, you did not answer to the question regarding ERR_NOEVS, which
might be useful to assess where the problem might be.

> The function "test_timer_cancel" is called both from the context of
> the main thread and a TEST thread.
> 
> This is the output I get when running the test:
> 
> In task_body_wrapper
> tm_evevery(1,1,&tmr_id) => 0
> tm_cancel(&tmid) => 0
> ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
> tm_evevery(2,1,&tmr_id) => 0
> tm_cancel(&tmid) => 0
> ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
> #events received after cancel 0 (loopcount=3)
> 
> tm_evevery(1,1,&tmr_id) => 0
> tm_cancel(&tmid) => 0
> ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 0, ev=0x1
> tm_evevery(2,1,&tmr_id) => 0
> tm_cancel(&tmid) => 0
> ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
> #events received after cancel 1 (loopcount=3)
> 
> In task_body_wrapper
> tm_evevery(1,1,&tmr_id) => 0
> tm_cancel(&tmid) => 0
> ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 0, ev=0x1
> tm_evevery(2,1,&tmr_id) => 0
> tm_cancel(&tmid) => 0
> ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
> #events received after cancel 1 (loopcount=3)
> 
> In task_body_wrapper
> tm_evevery(1,1,&tmr_id) => 0
> tm_cancel(&tmid) => 0
> ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
> tm_evevery(2,1,&tmr_id) => 0
> tm_cancel(&tmid) => 0
>  
> As you can see in most of the cases the system behaves correctly.
> In some cases, the event is received. This is the case both from the
> context of the main thread and the special thread.
> I just copy-pasted a part of the output. In most cases, the event is
> not received. I think something like 1 times out of 50 I see the event
> being received.
> 
> It looks like, if it happens, it is always the first iteration of the
> loop (the one with a timeout of 1 tick). Even if I change the initial
> timeout value to 2, the event is also received sporadically.
> 
> [ Phillippe, please note that in your test code, you have also swapped
> the parameters. You send event 3 and lateron check whether you have
> received event 4. :-) ]
> 
> Another observation is that after removing the ut_printf statements, I
> do not see the issue anymore.
> It looks like the printf/rt_printf has an impact on the system
> behavior.
> 
> I had a quick look to the LTTng as well, but I need to fix the patches
> before I will be able to integrate.
> I think this will be my next step.
> 
> Best regards,
> Ronny
> 
> 
> On Mon, Nov 15, 2010 at 10:30 AM, Philippe Gerum <rpm@xenomai.org>
> wrote:
>         On Sun, 2010-11-14 at 01:24 +0100, ronny meeus wrote:
>         > Hello
>         >
>         > I'm currently fighting with a problem in the pSOS+ skin.
>         > This my system information:
>         >
>         > [    2.314676] pci 0000:00:01.0: Activating ISA DMA hang
>         workarounds
>         > [    2.416025] I-pipe: Domain Xenomai registered.
>         > [    2.418183] Xenomai: hal/i386 started.
>         > [    2.422780] Xenomai: scheduling class idle registered.
>         > [    2.424116] Xenomai: scheduling class rt registered.
>         > [    2.566737] Xenomai: real-time nucleus v2.5.4 (Sleep
>         Walk) loaded.
>         > [    2.590628] Xenomai: starting native API services.
>         > [    2.604491] Xenomai: starting pSOS+ services.
>         > [    2.619941] HugeTLB registered 4 MB page size,
>         pre-allocated 0
>         > pages
>         >
>         > This is a piece of testcode I have created:
>         >
>         >         check("tm_evevery",tm_evevery(4,3,&tmr_id),0);
>         >         check("tm_cancel",tm_cancel(tmr_id),0);
>         >         ev_rcvd = 0;
>         >         ret = ev_receive(4,EV_ANY|EV_WAIT,10,&ev_rcvd);
>         >         check("ev_receive",ret,ERR_TIMEOUT);
>         >
>         > I just start a periodic timer that expires every 3 ticks and
>         at expiry
>         > sends event 4 to my task.
>         
>         
>         You test rather arms a timer for sending event_list=0x3 each 4
>         ticks.
>         
>         > I want to check the cancel of the timer, so I cancel it and
>         I would
>         > expect not to receive any event.
>         >
>         > What I observe is that this code is not working: I
>         immediately receive
>         > the event after starting the timer.
>         
>         
>         Please try this test code as well:
>         
>         #include <stdio.h>
>         #include <unistd.h>
>         #include <sys/types.h>
>         #include <sys/mman.h>
>         #include <psos+/psos.h>
>         
>         void foo (u_long a0, u_long a1, u_long a2, u_long a3)
>         {
>                u_long ret, ev = 0, tmid;
>         
>                printf("Started... (%lu, %lu, %lu, %lu)\n", a0, a1, a2,
>         a3);
>                ret = tm_evevery(4, 3, &tmid);
>                printf("tm_evevery(4, 3, &tmid) => %lu\n", ret);
>         
>                ret = tm_cancel(tmid);
>                printf("tm_cancel(&tmid) => %lu\n", ret);
>         
>                ret = ev_receive(4, EV_ANY|EV_WAIT, 10, &ev);
>                printf("ev_receive(4, EV_ANY|EV_WAIT, 10, &ev) => %lu,
>         ev=0x%lx\n", ret, ev);
>         }
>         
>         int main (int ac, char **av)
>         {
>                u_long ret, tid = 0, args[4];
>         
>                mlockall(MCL_CURRENT | MCL_FUTURE);
>         
>                ret = t_create("TEST", 1, 0, 0, 0, &tid);
>                printf("t_create(tid=%lu) = %lu\n", tid, ret);
>                args[0] = 1;
>                args[1] = 2;
>                args[2] = 3;
>                args[3] = 4;
>                ret = t_start(tid, 0, foo, args);
>                printf("t_start(tid=%lu) = %lu\n", tid, ret);
>         
>                return 0;
>         }
>         
>         > If I change the code like shown below (I added the
>         ev_receive with the
>         > NO_WAIT option after starting the timer), the code works
>         fine.
>         >
>         >         check("tm_evevery",tm_evevery(4,3,&tmr_id),0);
>         >         ret = ev_receive(4,EV_ANY|EV_NOWAIT,0,&ev_rcvd);
>         
>         
>         Do you receive ERR_NOEVS as expected here?
>         
>         >         check("tm_cancel",tm_cancel(tmr_id),0);
>         >         ev_rcvd = 0;
>         >         ret = ev_receive(4,EV_ANY|EV_WAIT,10,&ev_rcvd);
>         >         check("ev_receive",ret,ERR_TIMEOUT);
>         >
>         
>         
>         > Now my question is: how do I investigate an issue like this?
>         In other
>         > words, which are the best tools since this code involves
>         both user and
>         > kernel space debugging.
>         > Are there some trace tools available that are able to
>         generate a kind
>         > of sequence / trace of what is happing over time.
>         >
>         > I also have other issues that are not consistently
>         reproducible. For
>         > this kind of problems trace tools would also be useful.
>         >
>         
>         
>         If you want to validate the pSOS emulation core, the best tool
>         is the
>         simulator. Unfortunately, this tools still requires to be
>         built with an
>         antiquated C++ toolchain, so the only sane way to enable it
>         nowadays is
>         via qemu. You would need ~2 hours to set this up.
>         
>         If you want to try this, I can help. Otherwise, other
>         suggestions you
>         already got on this list will do.
>         
>         > Thanks
>         > Ronny
>         > _______________________________________________
>         > Xenomai-help mailing list
>         > Xenomai-help@domain.hid
>         > https://mail.gna.org/listinfo/xenomai-help
>         
>         
>         --
>         Philippe.
>         
>         
> 

-- 
Philippe.

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[ronny meeus]

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

Hello Phillippe,
thanks for the instant reply.

Here is the output of your test code:

# while `true`
> do
> ./simple_test
> done

t_create(tid=54) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=54) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=57) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=57) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=60) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=60) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=63) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=63) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=66) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=66) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=69) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=69) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=72) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=72) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=75) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 0, ev=0x3
t_start(tid=75) = 0
t_create(tid=78) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=78) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=81) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=81) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=84) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=84) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=87) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=87) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=90) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=90) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=93) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=93) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=96) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=96) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=99) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=99) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=102) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=102) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=105) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=105) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=108) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=108) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=111) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=111) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=114) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=114) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=117) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 0, ev=0x3
t_start(tid=117) = 0
t_create(tid=120) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=120) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=123) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 0, ev=0x3
t_start(tid=123) = 0
t_create(tid=126) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=126) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=129) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=129) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=132) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=132) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=135) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=135) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
t_create(tid=138) = 0
Started... (1, 2, 3, 4)
tm_evevery(4, 3, &tmid) => 0
tm_cancel(&tmid) => 0
t_start(tid=138) = 0
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0

As you can see, in some cases the event is received, even it the timeout
value is 4.
This is the same observation as I did in my code. I also see the event being
received with timeout values of 1 AND 2.

This is the testcode I have used. It is almost identical with the code you
have send me, I needed to change 2 things to make it work:
- "ret = ev_receive(4, EV_ANY|EV_WAIT, 10, &ev)" replaced by "ret =
ev_receive(3, EV_ANY|EV_WAIT, 10, &ev);"
- added a sleep at the end of main and foo to make the output printed on the
screen. If the sleep is not there, the last printf statement is not visible.

#include <stdio.h>
#include <unistd.h>
#include <sys/types.h>
#include <sys/mman.h>
#include <psos+/psos.h>

void foo (u_long a0, u_long a1, u_long a2, u_long a3)
{
        u_long ret, ev = 0, tmid;

        printf("Started... (%lu, %lu, %lu, %lu)\n", a0, a1, a2, a3);
        ret = tm_evevery(4, 3, &tmid);
        printf("tm_evevery(4, 3, &tmid) => %lu\n", ret);

        ret = tm_cancel(tmid);
        printf("tm_cancel(&tmid) => %lu\n", ret);

        ret = ev_receive(3, EV_ANY|EV_WAIT, 10, &ev);
        printf("ev_receive(3, EV_ANY|EV_WAIT, 10, &ev) => %lu, ev=0x%lx\n",
ret, ev);
        tm_wkafter(100);

}

int main (int ac, char **av)
{
        u_long ret, tid = 0, args[4];

        mlockall(MCL_CURRENT | MCL_FUTURE);

        ret = t_create("TEST", 1, 0, 0, 0, &tid);
        printf("t_create(tid=%lu) = %lu\n", tid, ret);
        args[0] = 1;
        args[1] = 2;
        args[2] = 3;
        args[3] = 4;
        ret = t_start(tid, 0, foo, args);
        printf("t_start(tid=%lu) = %lu\n", tid, ret);

        tm_wkafter(100);
        return 0;
}


About the pending question: I indeed recieve error code 60 (ERR_NOEVS) in
case no event is pending.

Best regards,
Ronny

On Wed, Nov 17, 2010 at 3:01 PM, Philippe Gerum <rpm@xenomai.org> wrote:

> On Wed, 2010-11-17 at 14:49 +0100, ronny meeus wrote:
> > Hello
> >
> > I did some more tests on QEMU since the behavior on Simics is
> > identical to the behavior I see on QEMU.
> > This is the testcode I have used:
> >
> > void test_timer_cancel(void)
> > {
> >         unsigned long tmr_id,ev,ret,i;
> >         unsigned long failed = 0;
> >
> >         for (i=1;i<3;i++)
> >         {
> >                 ret = tm_evevery(i,1,&tmr_id);
> >                 ut_printf("tm_evevery(%lu,1,&tmr_id) => %lu\n",
> > i,ret);
> >
> >                 ret = tm_cancel(tmr_id);
> >                 ut_printf("tm_cancel(&tmid) => %lu\n", ret);
> >
> >                 ev = 0;
> >                 ret = ev_receive(1, EV_ANY|EV_WAIT, 200, &ev);
> >                 ut_printf("ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => %
> > lu, ev=0x%lx\n", ret, ev);
> >
> >                 tm_wkafter(2);
> >
> >                 if (ret == 0)
> >                         failed++;
> >         }
> >         ut_printf("#events received after cancel %lu (loopcount=%lu)\n
> > \n",failed,i);
> > }
> >
> > void run_test(void)
> > {
> >         test_timer_cancel();
> > }
> >
> > static void task_body_wrapper(unsigned long func,unsigned long
> > count,unsigned long smid,unsigned long d)
> > {
> >     unsigned long i;
> >     ut_printf("In task_body_wrapper\n");
> >     test_function test = (test_function)func;
> >     for (i=0;i<count;i++)
> >         test();
> >     sm_v(smid);
> > }
> >
> > static void task_wrapper(test_function f,unsigned long count)
> > {
> >         unsigned long tid,smid;
> >         unsigned long args[4] = {(unsigned long)f,count,0,0};
> >
> >         sm_create("BLOC",0,SM_PRIOR,&smid);
> >         args[2] = smid;
> >
> >         t_create("TEST",25,16000,16000,0,&tid);
> >         t_start(tid,0,task_body_wrapper,args);
> >
> >        sm_p(smid,SM_WAIT,0);
> >        sm_delete(smid);
> >
> >        t_delete(tid);
> > }
> >
> > int main(int argc, char **argv)
> > {
> >     unsigned long rnid,rsize,i;
> >
> >     mlockall(MCL_CURRENT|MCL_FUTURE);
> >     rt_print_auto_init(1);
> >
> >     /* Body of the test goes here */
> >     while (1)
> >     {
> >         task_wrapper(run_test,1);
> >
> >         for (i=0;i<1;i++)
> >             run_test();
> >
> >         task_wrapper(run_test,1);
> >     }
> > }
> >
> > (The ut_printf function is mapped on rt_printf.)
> > So this test is identical to the test you proposed.
>
> No, the reason I sent you this frag, is because we are currently
> assuming that no tick will happen between tm_evevery() and ev_receive(),
> which is wrong, at least in theory. So this small frag is actually
> reducing the complexity to the bare minimum, so that we don't chase wild
> gooses uselessly.
>
> The clock is not synchronized with your application in periodic mode, so
> you can't be sure that a pending tick won't hit the kernel - and thus
> deliver the event - prior to entering ev_receive(). The odds of being
> preempted by ev_send() on behalf of the tick handler before entering
> ev_receive() is even higher with a period set to one tick, like in your
> example, which is therefore wrong once again. Slowing down the code with
> trace output may introduce variations if timing is involved.
>
> Besides, you did not answer to the question regarding ERR_NOEVS, which
> might be useful to assess where the problem might be.
>
> > The function "test_timer_cancel" is called both from the context of
> > the main thread and a TEST thread.
> >
> > This is the output I get when running the test:
> >
> > In task_body_wrapper
> > tm_evevery(1,1,&tmr_id) => 0
> > tm_cancel(&tmid) => 0
> > ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
> > tm_evevery(2,1,&tmr_id) => 0
> > tm_cancel(&tmid) => 0
> > ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
> > #events received after cancel 0 (loopcount=3)
> >
> > tm_evevery(1,1,&tmr_id) => 0
> > tm_cancel(&tmid) => 0
> > ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 0, ev=0x1
> > tm_evevery(2,1,&tmr_id) => 0
> > tm_cancel(&tmid) => 0
> > ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
> > #events received after cancel 1 (loopcount=3)
> >
> > In task_body_wrapper
> > tm_evevery(1,1,&tmr_id) => 0
> > tm_cancel(&tmid) => 0
> > ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 0, ev=0x1
> > tm_evevery(2,1,&tmr_id) => 0
> > tm_cancel(&tmid) => 0
> > ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
> > #events received after cancel 1 (loopcount=3)
> >
> > In task_body_wrapper
> > tm_evevery(1,1,&tmr_id) => 0
> > tm_cancel(&tmid) => 0
> > ev_receive(1, EV_ANY|EV_WAIT, 10, &ev) => 1, ev=0x0
> > tm_evevery(2,1,&tmr_id) => 0
> > tm_cancel(&tmid) => 0
> >
> > As you can see in most of the cases the system behaves correctly.
> > In some cases, the event is received. This is the case both from the
> > context of the main thread and the special thread.
> > I just copy-pasted a part of the output. In most cases, the event is
> > not received. I think something like 1 times out of 50 I see the event
> > being received.
> >
> > It looks like, if it happens, it is always the first iteration of the
> > loop (the one with a timeout of 1 tick). Even if I change the initial
> > timeout value to 2, the event is also received sporadically.
> >
> > [ Phillippe, please note that in your test code, you have also swapped
> > the parameters. You send event 3 and lateron check whether you have
> > received event 4. :-) ]
> >
> > Another observation is that after removing the ut_printf statements, I
> > do not see the issue anymore.
> > It looks like the printf/rt_printf has an impact on the system
> > behavior.
> >
> > I had a quick look to the LTTng as well, but I need to fix the patches
> > before I will be able to integrate.
> > I think this will be my next step.
> >
> > Best regards,
> > Ronny
> >
> >
> > On Mon, Nov 15, 2010 at 10:30 AM, Philippe Gerum <rpm@xenomai.org>
> > wrote:
> >         On Sun, 2010-11-14 at 01:24 +0100, ronny meeus wrote:
> >         > Hello
> >         >
> >         > I'm currently fighting with a problem in the pSOS+ skin.
> >         > This my system information:
> >         >
> >         > [    2.314676] pci 0000:00:01.0: Activating ISA DMA hang
> >         workarounds
> >         > [    2.416025] I-pipe: Domain Xenomai registered.
> >         > [    2.418183] Xenomai: hal/i386 started.
> >         > [    2.422780] Xenomai: scheduling class idle registered.
> >         > [    2.424116] Xenomai: scheduling class rt registered.
> >         > [    2.566737] Xenomai: real-time nucleus v2.5.4 (Sleep
> >         Walk) loaded.
> >         > [    2.590628] Xenomai: starting native API services.
> >         > [    2.604491] Xenomai: starting pSOS+ services.
> >         > [    2.619941] HugeTLB registered 4 MB page size,
> >         pre-allocated 0
> >         > pages
> >         >
> >         > This is a piece of testcode I have created:
> >         >
> >         >         check("tm_evevery",tm_evevery(4,3,&tmr_id),0);
> >         >         check("tm_cancel",tm_cancel(tmr_id),0);
> >         >         ev_rcvd = 0;
> >         >         ret = ev_receive(4,EV_ANY|EV_WAIT,10,&ev_rcvd);
> >         >         check("ev_receive",ret,ERR_TIMEOUT);
> >         >
> >         > I just start a periodic timer that expires every 3 ticks and
> >         at expiry
> >         > sends event 4 to my task.
> >
> >
> >         You test rather arms a timer for sending event_list=0x3 each 4
> >         ticks.
> >
> >         > I want to check the cancel of the timer, so I cancel it and
> >         I would
> >         > expect not to receive any event.
> >         >
> >         > What I observe is that this code is not working: I
> >         immediately receive
> >         > the event after starting the timer.
> >
> >
> >         Please try this test code as well:
> >
> >         #include <stdio.h>
> >         #include <unistd.h>
> >         #include <sys/types.h>
> >         #include <sys/mman.h>
> >         #include <psos+/psos.h>
> >
> >         void foo (u_long a0, u_long a1, u_long a2, u_long a3)
> >         {
> >                u_long ret, ev = 0, tmid;
> >
> >                printf("Started... (%lu, %lu, %lu, %lu)\n", a0, a1, a2,
> >         a3);
> >                ret = tm_evevery(4, 3, &tmid);
> >                printf("tm_evevery(4, 3, &tmid) => %lu\n", ret);
> >
> >                ret = tm_cancel(tmid);
> >                printf("tm_cancel(&tmid) => %lu\n", ret);
> >
> >                ret = ev_receive(4, EV_ANY|EV_WAIT, 10, &ev);
> >                printf("ev_receive(4, EV_ANY|EV_WAIT, 10, &ev) => %lu,
> >         ev=0x%lx\n", ret, ev);
> >         }
> >
> >         int main (int ac, char **av)
> >         {
> >                u_long ret, tid = 0, args[4];
> >
> >                mlockall(MCL_CURRENT | MCL_FUTURE);
> >
> >                ret = t_create("TEST", 1, 0, 0, 0, &tid);
> >                printf("t_create(tid=%lu) = %lu\n", tid, ret);
> >                args[0] = 1;
> >                args[1] = 2;
> >                args[2] = 3;
> >                args[3] = 4;
> >                ret = t_start(tid, 0, foo, args);
> >                printf("t_start(tid=%lu) = %lu\n", tid, ret);
> >
> >                return 0;
> >         }
> >
> >         > If I change the code like shown below (I added the
> >         ev_receive with the
> >         > NO_WAIT option after starting the timer), the code works
> >         fine.
> >         >
> >         >         check("tm_evevery",tm_evevery(4,3,&tmr_id),0);
> >         >         ret = ev_receive(4,EV_ANY|EV_NOWAIT,0,&ev_rcvd);
> >
> >
> >         Do you receive ERR_NOEVS as expected here?
> >
> >         >         check("tm_cancel",tm_cancel(tmr_id),0);
> >         >         ev_rcvd = 0;
> >         >         ret = ev_receive(4,EV_ANY|EV_WAIT,10,&ev_rcvd);
> >         >         check("ev_receive",ret,ERR_TIMEOUT);
> >         >
> >
> >
> >         > Now my question is: how do I investigate an issue like this?
> >         In other
> >         > words, which are the best tools since this code involves
> >         both user and
> >         > kernel space debugging.
> >         > Are there some trace tools available that are able to
> >         generate a kind
> >         > of sequence / trace of what is happing over time.
> >         >
> >         > I also have other issues that are not consistently
> >         reproducible. For
> >         > this kind of problems trace tools would also be useful.
> >         >
> >
> >
> >         If you want to validate the pSOS emulation core, the best tool
> >         is the
> >         simulator. Unfortunately, this tools still requires to be
> >         built with an
> >         antiquated C++ toolchain, so the only sane way to enable it
> >         nowadays is
> >         via qemu. You would need ~2 hours to set this up.
> >
> >         If you want to try this, I can help. Otherwise, other
> >         suggestions you
> >         already got on this list will do.
> >
> >         > Thanks
> >         > Ronny
> >         > _______________________________________________
> >         > Xenomai-help mailing list
> >         > Xenomai-help@domain.hid
> >         > https://mail.gna.org/listinfo/xenomai-help
> >
> >
> >         --
> >         Philippe.
> >
> >
> >
>
> --
> Philippe.
>
>
>

[-- Attachment #2: Type: text/html, Size: 22864 bytes --]

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[Andreas Glatz]

> Now my question is: how do I investigate an issue like this? In other words,
> which are the best tools since this code involves both user and kernel space
> debugging.
> Are there some trace tools available that are able to generate a kind of
> sequence / trace of what is happing over time.
>
> I also have other issues that are not consistently reproducible. For this
> kind of problems trace tools would also be useful.
>

I have debugged such issues with LTTng ( http://lttng.org/ ). There
are trace points in the Xenomai nucleus ( grep -rw xn_nucleus
/path/to/xenomai/* ) and skins (at least the native skin). You could
for example set up 'one-shot' tracing where events are continuously
added to the Lttng event ring buffer until a condition is satisfied
(i.e. your error condition) and analyse it either with Lttv or by
looking at the textual output.

It takes some time to set things up. You need (1) to add the LTTng
patches to your kernel and recompile the whole thing. In general,
there are just LTTng patches for vanilla kernels available. So you
have to expect some manual work there. (2) You have to compile the
user-space daemon for your target: You need it to control the tracing.
(3) Lttv for your host (if you like a little bit of comfort when
analysing your traces).

Andreas

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[Gilles Chanteperdrix]

Andreas Glatz wrote:
>> Now my question is: how do I investigate an issue like this? In other words,
>> which are the best tools since this code involves both user and kernel space
>> debugging.
>> Are there some trace tools available that are able to generate a kind of
>> sequence / trace of what is happing over time.
>>
>> I also have other issues that are not consistently reproducible. For this
>> kind of problems trace tools would also be useful.
>>
> 
> I have debugged such issues with LTTng ( http://lttng.org/ ). There
> are trace points in the Xenomai nucleus ( grep -rw xn_nucleus
> /path/to/xenomai/* ) and skins (at least the native skin). You could
> for example set up 'one-shot' tracing where events are continuously
> added to the Lttng event ring buffer until a condition is satisfied
> (i.e. your error condition) and analyse it either with Lttv or by
> looking at the textual output.
> 
> It takes some time to set things up. You need (1) to add the LTTng
> patches to your kernel and recompile the whole thing. In general,
> there are just LTTng patches for vanilla kernels available. So you
> have to expect some manual work there. (2) You have to compile the
> user-space daemon for your target: You need it to control the tracing.
> (3) Lttv for your host (if you like a little bit of comfort when
> analysing your traces).

Other means of debugging are gdb in user-space, and the I-pipe tracer in
kernel-space:
http://www.xenomai.org/index.php/I-pipe:Tracer

-- 
                                                                Gilles.

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[Andreas Glatz]

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

>
> On Mon, 2010-11-15 at 21:26 +0100, ronny meeus wrote:
>> Hello
>>
>> Thanks for the information.
>> I was testing on QEMU but I have seen that there are issue with the
>> timing anyhow.
>> I'm currently changing to a target environment. Once this is
>> completed, I will re-run my tests and get back with the result.
>>
>> I do not really understand what you mean with the simulator.
>> Where can I find more information about it?
>
> http://git.xenomai.org/?p=xenosim.git;a=blob;f=doc/mvm- 
> manual.txt;h=1c6767ea2890d68e1c1c5cfe1420e189b3cc5328;hb=06919eb3a6b6b 
> af7880ea3ade1ecc5f610c35794
>

So in other words the simulator is a good debugging tool if your  
application doesn't (i) directly access hardware (mmap aso...)
(ii) doesn't used assembly code written for another platform and  
(iii) can be compiled with the gcc 2.95.3.

For the first two restrictions this means in other words that the  
application should follow the golden design standard which
proposes to put all hardware depended code into rtdm drivers and  
everything else into the application.

Could one (partly) work around the first two restrictions by letting  
the simulator run inside of qemu which emulates the
target architecture?

Andreas

[-- Attachment #2: Type: text/html, Size: 3255 bytes --]

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[Philippe Gerum]

On Tue, 2010-11-16 at 11:46 +0000, Andreas Glatz wrote: 
> > 
> > 
> > On Mon, 2010-11-15 at 21:26 +0100, ronny meeus wrote: 
> > > Hello 
> > > 
> > > 
> > > Thanks for the information. 
> > > I was testing on QEMU but I have seen that there are issue with
> > > the 
> > > timing anyhow. 
> > > I'm currently changing to a target environment. Once this is 
> > > completed, I will re-run my tests and get back with the result. 
> > > 
> > > 
> > > I do not really understand what you mean with the simulator. 
> > > Where can I find more information about it? 
> > 
> > 
> > http://git.xenomai.org/?p=xenosim.git;a=blob;f=doc/mvm-manual.txt;h=1c6767ea2890d68e1c1c5cfe1420e189b3cc5328;hb=06919eb3a6b6baf7880ea3ade1ecc5f610c35794 
> > 
> > 
> 
> 
> So in other words the simulator is a good debugging tool if your
> application doesn't (i) directly access hardware (mmap aso...)
> (ii) doesn't used assembly code written for another platform and (iii)
> can be compiled with the gcc 2.95.3. 
> 
> 
> For the first two restrictions this means in other words that
> the application should follow the golden design standard which
> proposes to put all hardware depended code into rtdm drivers and
> everything else into the application. 

Exactly. The hardware-dependent code should be either:
- stubbed or replaced with some C/C++ code providing limited feedback,
enough to have the application running.
- left in, but connected internally to a software component partially or
fully modeling the hardware. Such component would run within the
simulator directly, which is actually an extensible event-driven
simulation engine, with a C++ interface to build add-ons/models.

> 
> 
> Could one (partly) work around the first two restrictions by letting
> the simulator run inside of qemu which emulates the
> target architecture?

Maybe for the inline assembly code which is not directly device-related.
Running RTDM drivers in simulation mode would require to simulate the
devices with a model though.

> 
> Andreas
> _______________________________________________
> Xenomai-help mailing list
> Xenomai-help@domain.hid
> https://mail.gna.org/listinfo/xenomai-help

-- 
Philippe.

Re: [Xenomai-help] Debug/trace tools for xenomai applications.

[Jan Kiszka]

Am 17.11.2010 09:43, Philippe Gerum wrote:
> On Tue, 2010-11-16 at 11:46 +0000, Andreas Glatz wrote: 
>>>
>>>
>>> On Mon, 2010-11-15 at 21:26 +0100, ronny meeus wrote: 
>>>> Hello 
>>>>
>>>>
>>>> Thanks for the information. 
>>>> I was testing on QEMU but I have seen that there are issue with
>>>> the 
>>>> timing anyhow. 
>>>> I'm currently changing to a target environment. Once this is 
>>>> completed, I will re-run my tests and get back with the result. 
>>>>
>>>>
>>>> I do not really understand what you mean with the simulator. 
>>>> Where can I find more information about it? 
>>>
>>>
>>> http://git.xenomai.org/?p=xenosim.git;a=blob;f=doc/mvm-manual.txt;h=1c6767ea2890d68e1c1c5cfe1420e189b3cc5328;hb=06919eb3a6b6baf7880ea3ade1ecc5f610c35794 
>>>
>>>
>>
>>
>> So in other words the simulator is a good debugging tool if your
>> application doesn't (i) directly access hardware (mmap aso...)
>> (ii) doesn't used assembly code written for another platform and (iii)
>> can be compiled with the gcc 2.95.3. 
>>
>>
>> For the first two restrictions this means in other words that
>> the application should follow the golden design standard which
>> proposes to put all hardware depended code into rtdm drivers and
>> everything else into the application. 
> 
> Exactly. The hardware-dependent code should be either:
> - stubbed or replaced with some C/C++ code providing limited feedback,
> enough to have the application running.
> - left in, but connected internally to a software component partially or
> fully modeling the hardware. Such component would run within the
> simulator directly, which is actually an extensible event-driven
> simulation engine, with a C++ interface to build add-ons/models.
> 
>>
>>
>> Could one (partly) work around the first two restrictions by letting
>> the simulator run inside of qemu which emulates the
>> target architecture?

Most Xenomai core development I do takes place over qemu/kvm - for years
now. Before that I was using plain qemu, but that's comparatively slow.
It can be fast, in fact, if your target is at least an order of
magnitude slower than the qemu host...

> 
> Maybe for the inline assembly code which is not directly device-related.
> Running RTDM drivers in simulation mode would require to simulate the
> devices with a model though.

Depending on the device complexity, of course, writing such a model for
qemu(/kvm) can be a few hundred lines of code. Moreover, using kvm on
the target, you could also pass peripherals through. Right now there are
good chances that this works on x86 with PCI devices. We should see more
support for this in the future, including PowerPC (partially working
already) and ARM.

Still, virtualization can easily ruin timing. The best results I've seen
were a few hundred microseconds timer latency (from the hardware to the
RT task in the guest) when running kvm over preempt-rt. Fine for
functional test, problematic to find latency issues.

Emulation can work around the timing problem to some degree. Qemu has a
special mode, -icount, that emulates the TSC based on the guest
progress. Haven't tried recently, but it promises to give the guest the
illusion of proper time progress and compensate for stolen time due to
emulation and host scheduling effects. Just makes emulation yet a bit
slower.

Jan

-- 
Siemens AG, Corporate Technology, CT T DE IT 1
Corporate Competence Center Embedded Linux