QtInfoMsg is numerically above QtFatalMsg, so an INFO filter dropped every warning

A desktop app’s log file had about 20,000 lines in it, all of them INFO. There wasn’t a single WARN or ERROR line, even though the app had plenty of qWarning() and qCritical() calls. This was the filter in the custom message handler (trimmed):

void Logger::logMessage(QtMsgType msgType, const QMessageLogContext &context, const QString &message)
{
    if (msgType < minimumType && minimumType != QtFatalMsg && !message.startsWith("##")) {
        return; // below the configured level
    }
    ...
}

It assumes QtMsgType is ordered by severity. It isn’t:

enum QtMsgType {
    QtDebugMsg,     // 0
    QtWarningMsg,   // 1
    QtCriticalMsg,  // 2
    QtFatalMsg,     // 3
    QtInfoMsg,      // 4, added in Qt 5.5
    QtSystemMsg = QtCriticalMsg
};

At INFO, minimumType is QtInfoMsg (4). Warning (1) and critical (2) are both below 4, so they were thrown away. Info lines got through, so the log looked healthy.

If your Qt message handler compares QtMsgType values with < or >, it has this bug.

How it got there #

No single commit introduced this:

1. Before Qt 5.5 the enum was in severity order, so msgType < minimumType was correct when the handler was written.
2. Qt 5.5 added QtInfoMsg at the end, to keep the existing values stable. The app also added INFO to the end of its own level enum, and nobody looked at the comparison again.
3. Years later, a one-line change moved the fallback level from WARN to INFO. At WARN, the bug had only cost info lines. At INFO it cost warnings and errors, and since INFO was now the default, that became the normal behavior.

Each step looked harmless in its own diff. The cause only showed up when the history was read in order.

Red tests first #

Each test sets a level, sends one probe per message type through the real handler to a real log file, and records which probes ended up in the file:

// One letter per probe that reached the file: d(ebug), i(nfo), w(arning), c(ritical)
QString writtenAt(Logger::LogLevel level) {
    log->setLogLevel(level);
    qDebug("probe d");
    qInfo("probe i");
    qWarning("probe w");
    qCritical("probe c");
    const QString content { logContent() };
    QString written;
    for (const QChar probe : QStringLiteral("diwc")) {
        if (content.contains(QStringLiteral("probe ") + probe)) written += probe;
    }
    return written;
}

TEST_F(LoggerTest, logMessage_InfoLevel_WarningWritten) {
    ASSERT_EQ(writtenAt(Logger::LogLevel::INFO), "iwc");
}

Against the old handler, five of the twelve logger tests failed:

The two bottom rows are separate bugs. Info (4) is above every other type, so it got through at WARN and ERROR. The minimumType != QtFatalMsg exemption meant FATAL wrote everything.

The fifth failure was a different bug: a level saved as ERROR came back as INFO after a restart. The app’s enum key was Error (an all-caps ERROR collides with a Windows macro), the setting was stored as ERROR, and QMetaEnum::keyToValue is case-sensitive. The lookup failed, so it fell back to the default.

Fix #

Map the message types to severity explicitly, and compare those numbers instead:

// Qt numbers its message types in the order they were added, info last, not by severity
int severity(QtMsgType msgType) {
    switch (msgType) {
    case QtDebugMsg:    return 0;
    case QtInfoMsg:     return 1;
    case QtWarningMsg:  return 2;
    case QtCriticalMsg: return 3;
    case QtFatalMsg:    return 4;
    }
    return 4;
}

if (severity(msgType) < severity(minimumType) && !message.startsWith("##")) {
    return;
}

The FATAL exemption is gone. Each level now means “this severity and above.” If a future Qt version adds a type, the switch with no default makes the compiler warn about it, and the fallback treats the unknown type as most severe, so it gets logged rather than dropped.

The stored level is now matched without regard to case:

for (int i = 0; i < metaEnum.keyCount(); ++i) {
    if (stored.compare(metaEnum.key(i), Qt::CaseInsensitive) == 0) return LogLevel(metaEnum.value(i));
}
return LogLevel::INFO;

The same twelve tests passed after the fix, and so did the full suite.

The rollout catch #

Fixing a filter that has silently dropped messages turns on log statements that nobody has read in years. Here, some of those warnings included user file names. The fix couldn’t ship until we moved those down to DEBUG. Before you fix a filter like this, grep for every qWarning and qCritical call it was dropping, because those are the lines your users will start sending you.

Takeaway #

• QtMsgType values are not ordered by severity. Never compare them with < or >. Map them first.
• A log full of INFO lines with no warnings in it is suspicious, not reassuring.
• Test the filter through the real handler with one probe per type, one test per level. The four-letter strings make the whole matrix fit on one screen.
• Check enum-to-string round trips (QMetaEnum::keyToValue) with an actual save and reload, not just a set and get.