How to find the calls that cause SQL debug messages

[Mark81]

When working with QSqlDatabase the output window might show some debug messages like these:

QSqlQuery::value: not positioned on a valid record
QSqlDatabasePrivate::removeDatabase: connection 'dbData' is still in use, all queries will cease to work.

but there is no indication which call(s) caused the warning. Because I have hundreds of queries it's quite tedious to debug them step-by-step. Is there a smarter way to find out the offenders?

[mrjj]

Hi
I was wondering if you used
http://doc.qt.io/qt-5/qtglobal.html#qInstallMessageHandler
and did a string compare to have a break point when text is one of them you are after,
then call stack should show its origin ?

[Mark81]

@mrjj said in How to find the calls that cause SQL debug messages:

I was wondering if you used
http://doc.qt.io/qt-5/qtglobal.html#qInstallMessageHandler
and did a string compare to have a break point when text is one of them you are after,
then call stack should show its origin ?

Interesting workaround, but unfortunately the debugger doesn't stop at the breakpoint set inside the message handler.

[mrjj]

@Mark81
Hi

• the debugger doesn't stop at the breakpoint set inside the message handler.

Like the text check never triggers or you are running release build ?
I am very sure it can break inside it as i just debug mine a few days ago :)

[Mark81]

@mrjj said in How to find the calls that cause SQL debug messages:

Like the text check never triggers

This one.
I can catch other debug messages (i.e. from QModbus or QSqlTableModel) but when the QSqlDatabase ones are printed they don't "walk across" the message handler.

[mrjj]

@Mark81
Hi
Ok, so those messages are special in some way. Not sure why exactly.
Hmm. no cigar. well it was worth a shot.
I also though about using the format changer to allow to have filenames with QDebug() but then i realized
it would come from inside the SQL module and not be very helpful.

Give it some days maybe someone has better idea :)

[Christian Ehrlicher]

The sql warnings are passed exactly as other warnings through qWarning() and therefore also pass the installed message handler. There is no special way or something else.
The first warning happens as soon as you call QSqlQuery::value() without calling QSqlQuery::next() first.
The second one happens when you have a QSqlQuery object somewhere and trying to close the database connection.

[Mark81]

@Christian-Ehrlicher said in How to find the calls that cause SQL debug messages:

The sql warnings are passed exactly as other warnings through qWarning() and therefore also pass the installed message handler.

I'm not sure about this because my message handler is like this:

[...]
QByteArray localMsg = msg.toLocal8Bit();
 switch (type) 
 {
 case QtDebugMsg:
     fprintf(stderr, "Debug: %s (%s:%u, %s)\n", localMsg.constData(), context.file, context.line, context.function);
     break;
 case QtInfoMsg:
     fprintf(stderr, "Info: %s (%s:%u, %s)\n", localMsg.constData(), context.file, context.line, context.function);
     break;
 case QtWarningMsg:
     fprintf(stderr, "Warning: %s (%s:%u, %s)\n", localMsg.constData(), context.file, context.line, context.function);
     break;
 case QtCriticalMsg:
     fprintf(stderr, "Critical: %s (%s:%u, %s)\n", localMsg.constData(), context.file, context.line, context.function);
     break;
 case QtFatalMsg:
     fprintf(stderr, "Fatal: %s (%s:%u, %s)\n", localMsg.constData(), context.file, context.line, context.function);
     break;
 }

And I see other messages that have the "Warning:" string prepended... but the ones from QSql* don't.
So I'm pretty sure this proves those messages don't come from a qWarning. Am I wrong?

[mrjj]

Hi
Just tested it.
For me they are logged.

update:
The idea seems to work fine. At least with Qt5.12 win 10.

Breakpoint is hit and it will show where offending call comes from.

[Mark81]

Interesting.
I'm running Qt5.11.1 mingw under Windows 7 64-bit.

[mrjj]

@Mark81
Well this was also mingw compiler.
Could you try the catcher msghandler ? (break point on dummy)

void myMessageOutput(QtMsgType type, const QMessageLogContext &context, const QString &msg)
{
    if (msg.contains("QSqlQuery",  Qt::CaseInsensitive)) {
        // found it
        int dummy = 0;
    }
}

i just tried in linux, Qt5.9 and worked there also so i have a feeling it should work for you too.

[Mark81]

@mrjj said in How to find the calls that cause SQL debug messages:

Could you try the catcher msghandler ? (break point on dummy)

I also put a breakpoint on the if line, so every message will stop the debugger. Most of them will, QSql* won't...

[mrjj]

@Mark81
Hi
so you stopped at all messages and its for 100% sure none of them was
QSqlQuery::xxxx
and even using the exact code, dummy would never trigger ?
I have no reasonable explanation for that

[Mark81]

@mrjj this is the actual screenshot of my IDE

the debugger doesn't stop at the breakpoints with those messages. But it stops with others.

EDIT: I've tried also adding QLoggingCategory::setFilterRules(QStringLiteral("QSql* = true"));

[mrjj]

@Mark81
Ok. that is truly odd.
Just to make sure it really behaves differently, could you run sample?
(im old fashioned. so i like to test with same code to be 100% sure but it does seems
something odd is happening)
just ignore test code and set break point dummy line 146

https://www.dropbox.com/s/q1rshkr2nxumvco/myfirstSQL.zip?dl=0

[Mark81]

Thanks for the time spent. I'm quite disappointed because your example works, indeed.
So now I have to find the differences between your code and mine.

EDIT: just found it.
It works if I install the message handler inside the constructor of the main window. It fails if, like my code, it is installed in the main function...

[mrjj]

@Mark81
Oh good found.
Well its better than some odd bug on win 7 ;)
But you did set message handler after QApplication correct ?

update. just had to test.
This also worked.

void myMessageOutput(QtMsgType type, const QMessageLogContext &context, const QString &msg)
{
    if (msg.contains("QSqlQuery",  Qt::CaseInsensitive)) {
        // found it
        int dummy = 0;
    }
}

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

[Mark81]

@mrjj unfortunately it's not shown in the screenshot above, anyway this was the code:

void messageOutput(QtMsgType type, const QMessageLogContext &context, const QString &msg)
{
    if (msg.contains("QSql", Qt::CaseInsensitive))
    {
        int foo = 0;
    }      
}

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

    MainWindow w;
    qInstallMessageHandler(messageOutput);
    w.showMaximized();

    return a.exec();
}

[mrjj]

@Mark81
hi
ok, but error/warning happens in constructor of mainwindow ( for the sample code )
so setting after we construct mainwindow wont work.
(not sure if that code is your code or test sample.)

[Mark81]

@mrjj ok, now I fully understand what happened. Yes, you're absolutely right. That was the real code and the messages came from the constructor. Now I discovered it, before I thought the came elsewhere.

I ended up to use two message handlers... one just for debug purposes. Because i need to install one after declaring the main window to forward some message to the UI.