Weird debugger behavior with events

Weird debugger behavior with events

[Russell Johnson]

[-- Attachment #1.1: Type: text/plain, Size: 1281 bytes --]

Hello,

 

I have a simple test app with two EVL threads (basics shown below). When I
run the app outside of a debugger, both threads run as expected with no
in-band switches or errors from the EVL core. However, when I run in the
debugger, I am seeing evl_timedwait_event returns -1 when the app is started
and then eventually it finally returns -110 (ETIMEDOUT). It makes it very
hard to debug. I would expect it to run like it does outside of the debugger
- thread 1 should just keep re-calling timedwait as it should keep timing
out. The other weird thing is that if I run thread 1 in the debugger without
thread 2 running, then it will work fine. Any ideas?

 

EVL Thread 1 does the following:

        evl_lock_mutex(&mutex);

        for (size_t i = 0; i < 1000; i++)

        {

            struct timespec tnow;

            evl_read_clock(EVL_CLOCK_MONOTONIC, &tnow);

            tnow.tv_sec += 1;

            int rv = evl_timedwait_event(&event, &mutex, &tnow);

            if ((rv < 0) && (rv != -ETIMEDOUT))

            {

                evl_printf("-1 error ocurred\n");

            }

        }

        evl_unlock_mutex(&mutex);

 

EVL Thread 2 does the following:

    while(true)

    {

        evl_usleep(1000);

    }

 

 

Thanks,

Russell

 

 

 


[-- Attachment #1.2: Type: text/html, Size: 4461 bytes --]

[-- Attachment #2: smime.p7s --]
[-- Type: application/pkcs7-signature, Size: 6759 bytes --]

Re: Weird debugger behavior with events

[Philippe Gerum]

Russell Johnson <russell.johnson@kratosdefense.com> writes:

> [[S/MIME Signed Part:Undecided]]
> Hello,
>
>  
>
> I have a simple test app with two EVL threads (basics shown below). When I run the app outside of a debugger, both threads run as expected with no in-band switches or errors from the EVL core. However, when I run in the debugger, I am seeing evl_timedwait_event returns -1 when the app is started and then eventually it finally returns -110 (ETIMEDOUT). It makes it very hard to debug. I would expect it to run like it does outside of the
> debugger – thread 1 should just keep re-calling timedwait as it should keep timing out. The other weird thing is that if I run thread 1 in the debugger without thread 2 running, then it will work fine. Any ideas?
>
>

I could not reproduce this with the provided test case so far. Receiving
-1 from evl_timedwait_event() would mean that the caller is not an evl
thread (i.e. not attached via evl_attach_thread/self()). I ran the test
after setting a breakpoint on the evl_timedwait_event() statement;
single-stepping and continuing from a break state from that line works
ok here. There must be something different in the way I'm testing this
compared to yours.

Could you provide me with the full test case, e.g. the one that includes
the attachment to the evl core, and also details about the user
interaction with gdb? For instance, do you set breakpoints and see
issues from the break state and on, or do you observe the weird behavior
as soon as you run the app over gdb, even without any interaction,
breakpoint, single-stepping etc?

-- 
Philippe.

Re: Weird debugger behavior with events

[Philippe Gerum]

Philippe Gerum <rpm@xenomai.org> writes:

> Russell Johnson <russell.johnson@kratosdefense.com> writes:
>
>> [[S/MIME Signed Part:Undecided]]
>> I ended up adding an xbuf and another thread to better replicate what I was 
>> seeing and exacerbate the issue. I can verify that all 3 threads show up as 
>> expected under "evl ps -l". You can just run the debugger with no breakpoints, 
>> and you should see the "-1 error occurred" message printed to the console at 
>> least once. You can also put a breakpoint on that print after the 
>> evl_timedwait_event call, and the breakpoint should get hit just about every 
>> time. Lastly, you can run the compiled app outside of gdb, and see that the 
>> error message is never printed out.
>>
>>
>> // g++ -Wall -g -o test 
>> test.cpp -I/opt/evl/include -L/opt/evl/lib -levl -lpthread
>>
>
> Ack. Working on this shortly. Thanks for the test code.

Please pull these kernel patches:
https://source.denx.de/Xenomai/xenomai4/linux-evl/-/commit/0d2d4fbfe3311a3ef419864cd4f1c6ddfd017a2c
https://source.denx.de/Xenomai/xenomai4/linux-evl/-/commit/6dd3b2e4c3a535f49595cb2463aadefec7f8670d

You may also want this one from libevl, although it is not required (but
recommended nevertheless):
https://source.denx.de/Xenomai/xenomai4/libevl/-/commit/c55ea95fdd4a790cf3905a2660d458e0cb518516

In short, the issue was due to unwanted syscall restart upon
signal. Fixing this was the opportunity to straighten the behavior of
the event mechanism upon interrupted wait.

The test code made it possible to spot the issue quickly, thanks.

-- 
Philippe.

Re: Weird debugger behavior with events

[Philippe Gerum]

Russell Johnson <russell.johnson@kratosdefense.com> writes:

> [[S/MIME Signed Part:Undecided]]
> I ended up adding an xbuf and another thread to better replicate what I was 
> seeing and exacerbate the issue. I can verify that all 3 threads show up as 
> expected under "evl ps -l". You can just run the debugger with no breakpoints, 
> and you should see the "-1 error occurred" message printed to the console at 
> least once. You can also put a breakpoint on that print after the 
> evl_timedwait_event call, and the breakpoint should get hit just about every 
> time. Lastly, you can run the compiled app outside of gdb, and see that the 
> error message is never printed out.
>
>
> // g++ -Wall -g -o test 
> test.cpp -I/opt/evl/include -L/opt/evl/lib -levl -lpthread
>

Ack. Working on this shortly. Thanks for the test code.

-- 
Philippe.

Re: Weird debugger behavior with events

[Russell Johnson]

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

I ended up adding an xbuf and another thread to better replicate what I was 
seeing and exacerbate the issue. I can verify that all 3 threads show up as 
expected under "evl ps -l". You can just run the debugger with no breakpoints, 
and you should see the "-1 error occurred" message printed to the console at 
least once. You can also put a breakpoint on that print after the 
evl_timedwait_event call, and the breakpoint should get hit just about every 
time. Lastly, you can run the compiled app outside of gdb, and see that the 
error message is never printed out.


// g++ -Wall -g -o test 
test.cpp -I/opt/evl/include -L/opt/evl/lib -levl -lpthread

#include <evl/evl.h>
#include <evl/thread.h>
#include <evl/mutex.h>
#include <evl/event.h>
#include <evl/clock.h>
#include <evl/xbuf.h>
#include <thread>
#include <unistd.h>
#include <vector>
#include <errno.h>

namespace
{
    struct evl_mutex mutex;
    struct evl_event event;

    int xbuf_fd = -1;
};

void Test_Event()
{
    cpu_set_t tkcpu;
    CPU_ZERO(&tkcpu);
    CPU_SET(4, &tkcpu);
    sched_setaffinity(0, sizeof(cpu_set_t), &tkcpu);

    struct sched_param sparam;
    sparam.sched_priority = 97;
    sched_setscheduler(0, SCHED_FIFO, &sparam);
    pthread_setname_np(pthread_self(), "Test_Event");

    int fd = evl_attach_thread(EVL_CLONE_OBSERVABLE | EVL_CLONE_NONBLOCK, 
"Test_Event");
    if (fd < 0)
    {
        evl_printf("Failed to attach to thread\n");
        return;
    }

    evl_set_thread_mode(fd, T_HMSIG | T_WOSS | T_WOLI | T_WOSX, NULL);

    while(true)
    {
        evl_lock_mutex(&mutex);
        struct timespec tnow;
        evl_read_clock(EVL_CLOCK_MONOTONIC, &tnow);
        tnow.tv_sec += 1;
        int rv = evl_timedwait_event(&event, &mutex, &tnow);
        if ((rv < 0) && (rv != -ETIMEDOUT))
        {
            evl_printf("-1 error ocurred\n");
        }
        evl_unlock_mutex(&mutex);

        // Sleep
        evl_usleep(1000);
    }
}

void Test_Sleep()
{
    cpu_set_t tkcpu;
    CPU_ZERO(&tkcpu);
    CPU_SET(3, &tkcpu);
    sched_setaffinity(0, sizeof(cpu_set_t), &tkcpu);

    struct sched_param sparam;
    sparam.sched_priority = 97;
    sched_setscheduler(0, SCHED_FIFO, &sparam);
    pthread_setname_np(pthread_self(), "Test_Sleep");

    int fd = evl_attach_thread(EVL_CLONE_OBSERVABLE | EVL_CLONE_NONBLOCK, 
"Test_Sleep");
    if (fd < 0)
    {
        evl_printf("Failed to attach to thread\n");
        return;
    }

    evl_set_thread_mode(fd, T_HMSIG | T_WOSS | T_WOLI | T_WOSX, NULL);

    while(true)
    {
        // Sleep
        evl_usleep(1000);
    }
}

void Test_Xbuf_OOB()
{
    // Not really used since no data goes into the xbuf
    size_t count = 10;
    std::vector<uint8_t> buffer(count);

    cpu_set_t tkcpu;
    CPU_ZERO(&tkcpu);
    CPU_SET(5, &tkcpu);
    sched_setaffinity(0, sizeof(cpu_set_t), &tkcpu);

    struct sched_param sparam;
    sparam.sched_priority = 97;
    sched_setscheduler(0, SCHED_FIFO, &sparam);
    pthread_setname_np(pthread_self(), "Test_Xbuf_OOB");

    int fd = evl_attach_thread(EVL_CLONE_OBSERVABLE | EVL_CLONE_NONBLOCK, 
"Test_Xbuf_OOB");
    if (fd < 0)
    {
        evl_printf("Failed to attach to thread\n");
        return;
    }

    evl_set_thread_mode(fd, T_HMSIG | T_WOSS | T_WOLI | T_WOSX, NULL);

    while(true)
    {
        evl_usleep(100);

        ssize_t ret = oob_read(xbuf_fd, buffer.data(), count);
        if (ret < 0)
        {
            // Not enough data
            if (errno == EAGAIN)
            {
                continue;
            }

            evl_printf("%d error occured while oob reading\n", errno);
            break;
        }
        else
        {
            evl_printf("Successful oob read\n");
        }
    }
}

int main(int argc, char *argv[])
{
    // Init EVL
    int ret = evl_init();
    if (ret != 0)
    {
        printf("EVL Init failed with error: %d\n", ret);
        return -1;
    }

    int res = evl_create_mutex(&mutex, EVL_CLOCK_MONOTONIC, 0, 
EVL_MUTEX_NORMAL|EVL_CLONE_PRIVATE, "test_mutex");
    if (res < 0)
    {
        printf("Failed to create mutex\n");
    }

    // event
    res = evl_create_event(&event, EVL_CLOCK_MONOTONIC, EVL_CLONE_PRIVATE, 
"test_event");
    if (res < 0)
    {
        printf("Failed to create event\n");
    }

    // xbuf
    xbuf_fd = evl_create_xbuf(1024, 1024, EVL_CLONE_NONBLOCK | 
EVL_CLONE_PRIVATE, "test_xbuf");
    if (xbuf_fd < 0)
    {
        printf("Failed to create xbuf\n");
    }

    // thread 1 (EVL) - call evl_timedwait_event over and over and expect to 
timeout
    std::thread t1([&]{Test_Event();});

    // thread 2 (EVL) - call evl_usleep over and over
    std::thread t2([&]{Test_Sleep();});

    // thread 3 (EVL) - out-of-band read on the xbuf
    std::thread t3([&]{Test_Xbuf_OOB();});

    // Do not exit so we can see stats
    while(true)
    {
        sleep(1);
    }

    return 0;
}

[-- Attachment #2: smime.p7s --]
[-- Type: application/pkcs7-signature, Size: 6759 bytes --]