qpcpp 7.3.0 POSIX port, high CPU load

[Eddie_1066]

Hi Miro,

My project was based on qpcpp version 7.2.1 and the qp/qpcpp/examples/workstation/dpp example. Running on the Beaglebone black with Linux 5.10.168-g991c5ce91e #1 PREEMPT.
After updating to the latest qp release v7.3.0, my application now loads the cpu up to %95 in both Idle and running states.
To isolate the issue, I downloaded qpcpp v7.3.0 onto the Beaglebone black and run the dpp posix example, which presented the same issue, high cpu usage when running the dpp application.
The qpcpp v7.2.1 dpp example does not have this issue when running in the same conditions. Are there any changes that I need to make for my application to be compatible with qpcpp v7.3.0?

Thanks,
Eddie

[Quantum Leaps]

Hi Eddie,
Which POSIX port are you using (the multithreaded POSIX port or the single-threaded POSIX-QV)?

The most implicated change in the POSIX ports between QP 7.2.1 and QP 7.3.0 is in the "ticker" thread that provides a time base for calling the QP time events. The "ticker" thread in the older port used the nanosleep() POSIX call. The problem with nanosleep() was that it caused drift in the clock ticks.

To avoid such drift, the newer QP ports to POSIX use the clock_nanosleep() POSIX call with the absolute time specification.

The clock_nanosleep() seems to behave reasonably on the deskopt Linux (i.e., I don't see high CPU loading on the desktop). You might want to run the DPP example on your Linux computer.

I suspect that in your embedded Linux on your Beaglebone this call might be doing some busy-polling or something. You might want to experiment with that by writing a small application (without QP) that would just call clock_nanosleep() in a loop.

I'm not sure how to square this circle with the POSIX "standard". It seems impossible to get a simple, periodic time base that would work for all POSIX implementations.

--MMS

[Eddie_1066]

Hi Miro,

I'm using the multithreaded POSIX port. Testing nanosleep() and clock_nanosleep() with a simple application running on a Beaglebone black, shows clock_nanosleep() loading the CPU. I'm not sure why this is the case. The DDP example on a Linux desktop works as expected.

I will investigate why this is not the case on the Beaglebone black.

Thanks for your time,
Eddie

[Quantum Leaps]

Hi Eddie,
It's disturbing to hear that clock_nanosleep() behaves so poorly on some embedded Linux distros.

All that's really needed is a reliable way of periodically calling the QP tick-processing (QTIMEEVT_TICK_X() in QP/C and QTimeEvt::TICK_X() in QP/C++). Still, this is apparently proving surprisingly tricky, which is getting really frustrating. Several methods have been tried over the years, including select(), nanosleep(), etc. The use of clock_nanosleep() was recommended in several posts on stackoverflow to avoid a drift in clock tick.

But anyway, this is actually a minor aspect of the QP ports to POSIX, and this aspect could be handled by the application, where you can use the most suitable method (not necessarily widely portable). This option has been already available in the single-threaded QP port (POSIX-QV). Now, this option is extened to the multi-threaded QP port as well (POSIX). The code has been already checked into GitHub, please see:
- QF_run() in QP/C POSIX port
- QF::run() in QP/C++ POSIX port

Specifically, you can disable the standard clock tick implementation by calling QF_setTickRate(0, 0) in QP/C and QP::QF::setTickRate(0, 0) in QP/C++. (This need to happen before entering QF::run()). With this setting, the QF_onClockTick() callback (defined in the application) will need to be an endless loop that calls QTimeEvt::TICK_X() periodically using any way you see fit.

Examples of customizing the clock tick service are provided as follows:
- qpc/examples/posix-win32/dpp-posix
- qpcpp/examples/posix-win32/dpp-posix

Please try it out!

--MMS

[Eddie_1066]

Hi Miro,
Thanks for the update. TI has just released a new processor sdk for the Beaglebone black, I will try the - qpcpp/examples/posix-win32/dpp-posix example on both the new and older sdk. I will update you on findings.
Thanks
Eddie

[Eddie_1066]

Hi Miro,

I have tested the new ~/qpcpp/examples/posix-win32/dpp-posix# example that uses the select() api.
This is the output I get

Dining Philosophers Problem example
QP 7.3.1
Press 'p' to pause
Press 's' to serve
Press ESC to quit...
Philosopher 0 is thinking
Philosopher 1 is thinking
Philosopher 2 is thinking
Philosopher 3 is thinking
Philosopher 4 is thinking

Then the application just freezes and the board becomes unresponsive.
I have added a print statement before select is called as bellow

void QF::onClockTick() {

    // NOTE:
    // The standard clock-tick service has been DISABLED in QF::onStartup()
    // by setting the clock tick rate to zero.
    // Therefore QF::onClockTick() must implement an alternative waiting
    // mechanism for the clock period. This particular implementation is
    // based on the select() system call to block for the desired timeout.

    struct timeval tv;
    tv.tv_sec = 0;
    tv.tv_usec = (1000000/BSP::TICKS_PER_SEC);

    PRINTF_S("\n%s\n", "calling select !");
    select(0, NULL, NULL, NULL, &tv); // block for the timevalue

    QTimeEvt::TICK_X(0U, &l_clock_tick); // process time events at rate 0

    QS_RX_INPUT(); // handle the QS-RX input
    QS_OUTPUT();   // handle the QS output

With this addition I get the same output without the printf, which seems to indicate that the issue is before QF::onClockTick() is called. I have tried using a debugger, but the cpu usage is way too high.
Do you have any ideas as to what could be going on?

I'm testing the code on a beaglebone black

Thanks
Eddie

[Quantum Leaps]

Hi Eddie,

First, have you tried to run the example qpcpp/examples/posix-win32/dpp-posix on your desktop linux? Please do! This will establish a baseline. The example should run with minimal CPU loading.

Next, if it does not work on your Beaglebone, be creative. Use some other blocking call, for instance sleep(1). (Just ignore for a minute that it sleep for a full second):

void QF::onClockTick() {

    // NOTE:
    // The standard clock-tick service has been DISABLED in QF::onStartup()
    // by setting the clock tick rate to zero.
    // Therefore QF::onClockTick() must implement an alternative waiting
    // mechanism for the clock period. This particular implementation is
    // based on the select() system call to block for the desired timeout.

    struct timeval tv;
    tv.tv_sec = 0;
    tv.tv_usec = (1000000/BSP::TICKS_PER_SEC);

    PRINTF_S("\n%s\n", "calling select !");
    //select(0, NULL, NULL, NULL, &tv); // block for the timevalue
    sleep(1); // <== for testing only
   . . . 
    QTimeEvt::TICK_X(0U, &l_clock_tick); // process time events at rate 0
   . . .

If this produces the printf output about every second, it means that it runs. Then you might want to experiment with other sleeping mechanisms. (nanosleep(), microsleep(), etc.)

In the end, please remember that this is POSIX: Nobody knows what it will do...

--MMS

[Panopticon]

Sorry for thread-hijacking but this reminds me of the quote:

"The nice thing about standards is that you have so many to choose from; furthermore, if you do not like any of them, you can just wait for next year's model." (Andrew Tanenbaum)

When I worked at a big company that everybody's heard of (2 decades ago), everyone was drinking the POSIX Kool Aid until it turned out to be a clown show.

And then on the ops side, Java promised "write once, run everywhere" (particularly with GUI apps) and that was utter bunk.

Maybe both of these have gotten better since then, but when I hear someone say "it should just work" (no one on this thread is saying that, BTW) I just roll my eyes.

[Eddie_1066]

The example runs fine on a laptop running Ubuntu 20.04. I have also tested in WSL Unbutu 22.04 without any issues.
I did try using poll() blocking call with the same results. I will try sleep() next.
If i replace the clock_nanosleep() with the nanosleep() in the run function in qf_port.cpp, will this be a valid test?

        // sleep without drifting till next_time (absolute), see NOTE03
        if (clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME,
                            &next_tick, NULL) == 0) // success?
        {
            // clock tick callback (must call QTIMEEVT_TICK_X())
            onClockTick();
        }

        to
         if (nanosleep(&next_tick, NULL) == 0) // success?
        {

Eddie

[Quantum Leaps]

Hi Eddie,
The whole point of the changes in the QP port to POSIX (multithreaded) was precisely so that you don't need to change the official port. Instead, you can have full control over the sleeping mechanism in your application level. I hope this makes sense to you.
--MMS

[Eddie_1066]

Hi Miro,
Having full control the sleeping mechanism make sense, I was think of options that could help while debugging the issue I'm having.

I have tried just using sleep(1) as suggested got this output

Dining Philosophers Problem example
QP 7.3.1
Press 'p' to pause
Press 's' to serve
Press ESC to quit...
Philosopher 0 is thinking
Philosopher 1 is thinking
Philosopher 2 is thinking
Philosopher 3 is thinking
Philosopher 4 is thinking
[ 785.781975] sched: RT throttling activated

the application stops here.

[Eddie_1066]

I have added some printf code in the run()

int run() {

    onStartup(); // application-specific startup callback
    PRINTF_S("\n%s\n", "run() onStartup()!");
    // produce the QS_QF_RUN trace record
    QS_BEGIN_PRE_(QS_QF_RUN, 0U)
    QS_END_PRE_()

    // try to set the priority of the ticker thread, see NOTE01
    struct sched_param sparam;
    sparam.sched_priority = l_tickPrio;
    if (pthread_setschedparam(pthread_self(), SCHED_FIFO, &sparam) == 0) {
        // success, this application has sufficient privileges
    }
    else {
        // setting priority failed, probably due to insufficient privileges
    }

    // exit the startup critical section to unblock any active objects
    // started before calling QF_run()
    PRINTF_S("\n%s\n", "run() pthread_mutex_unlock(&l_startupMutex)!");
    pthread_mutex_unlock(&l_startupMutex);

    l_isRunning = true;
    PRINTF_S("\n%s\n", "run() l_isRunning = true;!");
    // The provided clock tick service configured?
    if ((l_tick.tv_sec != 0) || (l_tick.tv_nsec != 0)) {

        // get the absolute monotonic time for no-drift sleeping
        PRINTF_S("\n%s\n", "run() clock_gettime(CLOCK_MONOTONIC, &next_tick);!");
        static struct timespec next_tick;
        clock_gettime(CLOCK_MONOTONIC, &next_tick);


        // round down nanoseconds to the nearest configured period
        next_tick.tv_nsec
            = (next_tick.tv_nsec / l_tick.tv_nsec) * l_tick.tv_nsec;

        while (l_isRunning) { // the clock tick loop...
        PRINTF_S("\n%s\n", "run() while (l_isRunning) 1;!");
            // advance to the next tick (absolute time)
            next_tick.tv_nsec += l_tick.tv_nsec;
            if (next_tick.tv_nsec >= NSEC_PER_SEC) {
                next_tick.tv_nsec -= NSEC_PER_SEC;
                next_tick.tv_sec  += 1;

It's not elegant, but got this output

Dining Philosophers Problem example
QP 7.3.1
Press 'p' to pause
Press 's' to serve
Press ESC to quit...
Philosopher 0 is thinking
Philosopher 1 is thinking
Philosopher 2 is thinking
Philosopher 3 is thinking
Philosopher 4 is thinking

run() onStartup()!

run() pthread_mutex_unlock(&l_startupMutex)!
[ 213.026072] sched: RT throttling activated
it seems that execution is stuck waiting for this mutex?

[Eddie_1066]

I have changed the init() mutex initialization from the new recursive mutex back to
non-recursive initializer. This has resolved the issue were the application hangs after calling
pthread_mutex_unlock(&l_startupMutex); and high cpu usage is gone.

    // initialize the critical section mutex QF_critSectMutex_ as a
    // *recursive mutex* in a portable way according to the POSIX Standard
    // pthread_mutexattr_t attr;
    // pthread_mutexattr_init(&attr);
    // pthread_mutexattr_settype(&attr, PTHREAD_MUTEX_RECURSIVE);
    // pthread_mutex_init(&critSectMutex_, &attr);
    // pthread_mutexattr_destroy(&attr);

        // init the global mutex with the default non-recursive initializer
    pthread_mutex_init(&critSectMutex_, NULL);

    // init the startup mutex with the default non-recursive initializer
    pthread_mutex_init(&l_startupMutex, NULL);
    pthread_mutex_lock(&l_startupMutex);

On the other hand I have tested the posix dpp example on the standard Debian distro that comes with the Beaglebone black, the example runs fine without any issues. Not sure what changes TI has made to its kernel to cause this issue.

[Quantum Leaps]

Hi Eddie,
Thank you for identifying the recursive setting of the mutex (used for QF critical sections). In the next QP/C/C++ 7.3.1, this mutex in the POSIX and POSIX-QV ports will be reverted back to non-recursive, but this time around there will be checks (assertions) to make sure that:
- the critical sections indeed never nest
- the critical sections are "balanced" meaning that every entry is matched by exit.

--MMS