QElapsedTimer reporting strange values from within QThread

JeKK666

I want to measure the speed of my bycicle using an embedded system: i'm using an NXP i.MX6UL arm7 single core processor, running Yocto Linux 2.4 (Pyro) with Qt 5.9.
Thanks to the sysfs library i can poll() on the GPIO endpoint to know then the magnet on the wheel passes next to the reed sensor, so i can catch the interrupt; the QThread containing poll() blocks, waiting for the event, and upon each subsequent event it sends the return value of QElapsedTimer::restart() to the main application thread, so that the speed can be calculated.

WheelProbeThread::WheelProbeThread(QObject *parent) : QThread(parent) {
    pollingFileDescriptor[0].fd = open(SYS_INT_WHEEL_VALUE, O_RDWR);
    pollingFileDescriptor[0].events = POLLPRI;
    
    speedTimer = new QElapsedTimer();
    speedTimer->start(); //a QElapsedTimer never started is invalid, and calling elapsed() on invalid timer causes undefined behavior
}

void WheelProbeThread::run() {
    char* buf[4];
    short len;
    Q_UNUSED(len);

    while (1) {
        pollRetVal = poll(pollingFileDescriptors, 1, -1);
        if(pollingFileDescriptors[0].revents & POLLPRI) { //probe click
            len = read(pollingFileDescriptors[0].fd, buf, 4); //mandatory to make system register interrupt as served
            lseek(pollingFileDescriptors[0].fd, 0, 0);
            emit probeClick();
            emit timeBetweenClicks(speedTimer->restart()); //measure delta t between reed pulses
        }
    }
}

I'm testing this device with a relay switch operated by a microcontroller, so i am sure the frequency is stable.

The problem i'm facing is as follows: from time to time, the output of QElapsedTimer::restart() will be roughly half of the real time, doubling the calculated speed.
This puzzles me a lot, since i was expecting that if the blocking thread was descheduled at the worst possible time, then a delay would enter my time reading, and i would therefore get a longer reported time, and a lower overall speed.

The time measurement occurs within this thread because i thought this thread had the best possible chance of performing a significant measurement, instead of demanding to the main thread who receives the signal, who would also account for the context switching time.

Since direct speed calculation over a single time value was giving me trouble, i though about using an array to perform an average, but still there are times when more than a single reading is off, like in this pic from the debugger:
debugger screenshot
the correct value is around 200 in this case, but i got two subsequent time readings about half of that.

If i test with different frequencies the issue doesn't change, reported time is sometimes half of the real time.

I suspect the problem might not lie within Qt itself but in the underlying system instead, though i thought to post my thread code here anyway to see if that itself is at least correct.

The slots receiving the two signals from the thread are connected using Qt::QueuedConnection, so slots would be executed when this thread returns; it should also be the default for Qt::AutoConnection with two different threads, i tried specifying it anyway, no changes whatsoever.

Do you think there is something fundamentally wrong with this approach? I'd really rather avoid writing a kernel driver to replace the sysfs interface, since frequencies at play are in the order of tens of hertz, that would seem like a real overkill, so i hope i made some mistakes in my Qt code :)

Thanks,
Jack

JonB

@CP71
Suggestion from me. (I know nothing about devices/embedded/real-time! Nor about bicycles.)

If @KroMignon's latest sorts you out, well and good.

Otherwise, given your use of poll(), can't you write a test, standalone, non-thread, non-UI, non-even-Qt command-line program which just sits and returns the times? Having by-passed everything else, at least you then know whether your timings are just they way they are because they are generated like that from whatever lower-level?

KroMignon

@JeKK666 Maybe I am not really give you the answer you want to have. But I see some fundamental issues with your code.

First: it is not a good idea to subclassing QThread. QThread is a container class with handles a thread. The instance thread affinity is thread in which the instance has been created, but the run() slot will be executed in the holded thread.
Also signal/slots will be handled by the event loop of the class instance, and not in the holded thread.

Second: you have subclassed the run() slots, so this thread does not have any event loop ==> signal/slots cannot work!

You should never sub-class QThread , especially if you want to use it in combination with QObject, the best way is to use a worker classe:

JeKK666

@KroMignon I always appreciate criticism, especially when it leads to better understanding of the problems i'm facing.
I admit i'm not the best when it comes to reading fundamentals, i prefer to dive in full bore and work out the quirks as i go, it might be a bit more frustrating but most of the time i manage to make things work xD

Onto your points:

in the first link you passed, it says "If you have something that’s just a pure calculation or something that connects to hardware, then you will often use a QThread subclass.": this is my case, the thread needs to block and wait for hardware to do its things, until awaken by a notification by the OS;
your second point: i've overridden run() with my event loop so that it does the things i want it to, inside the thread; slots might not work but this class doesn''t have any, and signals do in fact work, since the main thread receives them and forwards the data to the appropriate slot of the receiving object.

However: i see your point about the worker class extending QObject instead of QThread, and then being passed to a worker thread; the last 3 links you passed give a short and perfectly clear explanation.
Since i just want this to work with the least possible effort (xD) i'm now going to test this method which i never used before, and come back with the results.

Hope for the best, thanks
Jack

JeKK666

I changed the WheelProbeThread to subclass QObject instead of QThread, changed its void run() method to be a void process() slot, and added the folllowing in the main thread:

    QThread *t = new QThread();
    wheelProbeMonitor->moveToThread(t);
    connect(t, SIGNAL(started()), wheelProbeMonitor, SLOT(process()));
    t->start();

following the directions given here, but unfortunately the glitches didn't stop (value to be read should be consistent around 200):
debugger screenshot
I'm getting even more inclined to think this doesn't concern Qt at all, as much as the underlying scheduler or the sysfs library, although i'm still open to any other suggestion to improve the Qt part.

Thanks,
Jack

KroMignon

@JeKK666 Do you still have a forever loop in your process() slot?

JeKK666

@KroMignon yes i do; is that conceptually wrong?

CP71

@JeKK666
Maybe you already moved the following code into the process function!

speedTimer = new QElapsedTimer();
speedTimer->start();

If not I'd try

JeKK666

@CP71 If i understand correctly, you are referring to the issue where objects in the QThread object constructor are actually instantiated by the parent thread: i thought this problem would be bypassed by using the worker thread way suggested by @KroMignon

J.Hilk

@JeKK666 maybe you should give your processor/process time to actually write into that file, that you're polling?

I'm unsure how the system will handle such a permanent poll!

Add a msleep to that of maybe 1 ms ? (200ms to 1 seems like a decent enough resolution)

Not the kind of advice I give often :P

CP71

@JeKK666
From my experience is better to allocate any objects into run/process for thread affinity.

From maya post:

KroMignon

@JeKK666 said in QElapsedTimer reporting strange values from within QThread:

yes i do; is that conceptually wrong?

As written before, using a forever loop will lock the event loop, so no signal/slot are handled for all instances runing in this thread.
I would suggest you to:

create the QEleapsed timer in the rigth thread
call processEvents(QEventLoop::AllEvents);in foreverloop

void WheelProbeThread::run() {
    char* buf[4];
    short len;

    QElapsedTimer speedTimer;
    speedTimer.start();
    while (1) {
        pollRetVal = poll(pollingFileDescriptors, 1, -1);
        if(pollingFileDescriptors[0].revents & POLLPRI) { //probe click
            len = read(pollingFileDescriptors[0].fd, buf, 4); //mandatory to make system register interrupt as served
            lseek(pollingFileDescriptors[0].fd, 0, 0);
            emit probeClick();
            emit timeBetweenClicks(speedTimer.restart()); //measure delta t between read pulses
        }
        QThread::currentThread()->eventDispatcher()->processEvents(QEventLoop::AllEvents);
    }
}

JonB

@CP71
Suggestion from me. (I know nothing about devices/embedded/real-time! Nor about bicycles.)

If @KroMignon's latest sorts you out, well and good.

Otherwise, given your use of poll(), can't you write a test, standalone, non-thread, non-UI, non-even-Qt command-line program which just sits and returns the times? Having by-passed everything else, at least you then know whether your timings are just they way they are because they are generated like that from whatever lower-level?

CP71

@JonB
Don't warry! You, be patient with my English! ;)

Did you move the creation of QEleapsedTimer?
Did you see any improvements?

JeKK666

@J-Hilk thanks, i tried to add a QThread::msleep(1) after fseek, didn' seem to make a percivable difference; also, please note that no file writing occurs on my side, unless we consider the cursor moving performed by fseek as writing.

@CP71 thanks, i also tried your suggestion by moving all the allocations in the run() method/process() slot, didn't seem to change the overall behavior.

@KroMignon thank you for your interest in my question; i'm sorry i don't fully understand your statement concerning "no signal/slot are handled for all instances runing in this thread": it seems to me that you are implying my code should not work at all because of the infinite loop, but that clearly isn't a problem: the thread is descheduled as soon as its operations are done, i.e. when hitting the next blocking poll(), so that the main thread can resume and carry on execution with the values reported via the timeBetweenClicks signal; could you please elaborate more?

@JonB that is the silliest and most brilliant suggestion i could have dreamed of... >.<'
it occured to me while reading your post that i have already cross compiled at least five CLI c programs that test hardware and its functionalities, so obviously the first thing to do would be to test the whole lower level below Qt...
Excellent point!

J.Hilk

@KroMignon said in QElapsedTimer reporting strange values from within QThread:

As written before, using a forever loop will lock the event loop, so no signal/slot are handled for all instances runing in this thread.

the OP only emits a signal, that is handled in the parent thread with an even loop running, so that should be no problem here

KroMignon

@JeKK666 said in QElapsedTimer reporting strange values from within QThread:

thank you for your interest in my question; i'm sorry i don't fully understand your statement concerning "no signal/slot are handled for all instances runing in this thread": it seems to me that you are implying my code should not work at all because of the infinite loop, but that clearly isn't a problem: the thread is descheduled as soon as its operations are done, i.e. when hitting the next blocking poll(), so that the main thread can resume and carry on execution with the values reported via the timeBetweenClicks signal; could you please elaborate more?

Sorry, my failure. The problem is only if you want to handle slots with this thread. By emitting a signal, the event is stored in the receiver thread event loop. So if this loop is not locked, there is no problem.

But as @JonB suggest, you should look with a simple C program if the problem is not at low level (driver and/or system level).

JeKK666

So, i'm back with results from the lower levels:
console screenshot

After logging a 100 values or so, results would suggest the problem lies somewhere in the Qt infrastructure; might as well be some unknown (to me) overhead, or some werid stuff going on about QElapsedTimer.

The next logical step, to me, would be to try using the simpler c code i wrote for the CLI program that runs in the screenshot to exclude QElapsedTimer from the equation, and see what results i can get.
Thanks @JonB for reminding me of stuff i made in the last year or so, at work, which i had completely forgot about!
We'll see how it goes from there.

Thanks,
Jack

JeKK666

I've substituted the QElapsedTimer with the C library time.h, using the clock_gettime(...) function in the same way i did in the cli test program: i get the same inconsistent results, nothing changed (implementation as described here).

I can then conclude it's not the fault of the QElapsedTimer class, instead it has likely more to do with QThread, or threads in general, anyways the system i devised does not seem reliable enough to do what i need.

Since the CLI program itself seems quite precise instead, i might as well run something similar in the background, and the use IPC to retreive the value from Qt, or perhaps i could simply write the value to a file on one side and read it from Qt.

JeKK666

Update! @JonB
While i was tampering and not making any useful test, i accidentally left the CLI program running in an ssh shell, telling me the time deltas between clicks, and i noticed that everything was going fine, until... i launched the Qt application.
All of a sudden i was getting the same randomly halved times in CLI as i was getting before within Qt, using QElapsedTimer!

This begged further investigation, and i was able to determine that the glitches persist even after the Qt app is closed, until the next reboot; this led me to think that there is something that I did during the app initialization that messed up some system timers or whatnot.
So the first test that i performed was to remove my whole application from its cointainer (basically everything is contained within the mainwindow class) and running only this snippet, which prints an image on the framebuffer and then loiters around doing nothing:

#include <QSplashScreen>
//#include <QApplication>
#include "mainwindow.h"

int main(int argc, char *argv[]) {
	QApplication a(argc, argv);

	QPixmap pixmap(":images/logo.jpg");
	QSplashScreen splash(pixmap);
	splash.show();

    // MainWindow w;
	// w.show();
    
    return a.exec();
}

Surprisingly enough, this was enough to witness the glitches on the interrupt's time reading... so, do i have to conclude that the Qt framework in itself has a way of messing around with my system, rendering it unusable even after the Qt application is closed?
Perhaps it's too heavy for the CPU or stuff? Or maybe i should find a more up to date BSP, which might contain several bugfixes and hopefully concerning this specific use case?

I also narrowed down that the exact reason of why the reported times are almost exactly half of the nominal time, the reason being the interrupt is fired twice (or poll() returns twice, who knows), but why would such a thing happen or how is this related to the Qt application being executed is far beyond me...

For now it looks like i'll have to use different hardware, unless some miracle happens.
Thanks,
Jack

JonB

@JeKK666
I don't know. It would be interesting if someone else comments, because they will know more than I. But your claim/finding that having had a Qt program show a splashscreen and then exit, and still affect timings after that, sounds fishy.

Qt doesn't somehow do things which are not provided by your OS. It just makes appropriate calls. If there is something wrong in its code that would be a Qt bug, but otherwise it's down to your OS.

Since this has become a discussion, there is one thing I don't get, and I hope an expert will clarify. My lack of understanding is because I know nothing about embedded/Yocto. For a desktop Linux or Windows at least, it seems to me: you are relying on a timer to tell you how far apart some events are. But how do you know when your thread or process will be scheduled for a time slice? In a desktop OS at least, after your poll() gets notified of one event, it could take ages and miss events till the next time that piece of code with the poll() gets called again. Is that not right?