Don't log messages go in the stderr by default?

[ratijas]

Don't they go in the stderr by default?

I mean, they follow the default Qt handler which is also quite configurable with env variable: https://doc.qt.io/qt-5/debug.html#warning-and-debugging-messages / https://doc.qt.io/qt-5/qloggingcategory.html#configuring-categories

Originally posted by @ogoffart in #86 (comment)

After years of looking for a cause or at least a working solution, I have finally been pointed in the right direction. This whole time Qt apps were trying to log into system journal, and not to stdout/stderr. It can be reverted by simply setting QT_LOGGING_TO_CONSOLE environment variable, as suggested in QTCREATORBUG-24756 (check out linked issues and mail thread as well). Note that QT_LOGGING_TO_CONSOLE does NOT appear in the documentation pages linked above.

I filled as issue QTCREATORBUG-25935 for Qt Creator to set it on by default when running apps from IDE.

If I knew it at the time of #86, I'd rather pass logs from Rust to Qt side. But oh well… Now we have a reason to implement it too.

[ratijas]

Actually, hold on a second.

Searching 123489 files for "QT_LOGGING_TO_CONSOLE" (regex, case sensitive)

/home/ratijas/projects/qt/qt5/qtdoc/doc/src/platforms/qnx.qdoc:
  262              \c{QT_DEBUG_PLUGINS} when a plugin failed to load because it
  263              could not load other shared libraries.
  264:         \li Setting \c{QT_LOGGING_TO_CONSOLE} will force sending all logging
  265              messages to \c{stderr} instead of \c{slog2}. This is useful for
  266              analyzing application startup problems, as you do not need to use

/home/ratijas/projects/qt/qt5/qtbase/src/corelib/global/qlogging.cpp:
  260              return false;
  261  
  262:         if (qEnvironmentVariableIntValue("QT_LOGGING_TO_CONSOLE")) {
  263:             fprintf(stderr, "warning: Environment variable QT_LOGGING_TO_CONSOLE is deprecated, use\n"
  264                              "QT_ASSUME_STDERR_HAS_CONSOLE and/or QT_FORCE_STDERR_LOGGING instead.\n");
  265              return true;

/home/ratijas/projects/qt/qt5/qtbase/dist/changes-5.11.0:
   25  
   26   - Logging (including qDebug and qWarning):
   27:    * The QT_LOGGING_TO_CONSOLE environment variable has been deprecated.
   28       Use the more specific QT_ASSUME_STDERR_HAS_CONSOLE or
   29       QT_FORCE_STDERR_LOGGING, depending on your usecase.

/home/ratijas/projects/qt/qt5/qtbase/dist/changes-5.4.0:
   56     * Support for the deprecated environment variables QT_NO_JOURNALD_LOG
   57       and QT_ANDROID_PLAIN_LOG has been removed. Instead, set
   58:      QT_LOGGING_TO_CONSOLE to 1 to force logging to the console (stderr).
   59       Set that variable to 0 to force logging to the system-specific event
   60       log (if any).
   61     * [QTCREATORBUG-12564] Log output will now go to the system log (if
   62       support for it was compiled into Qt) if the application has no
   63:      controlling terminal or console window. Set QT_LOGGING_TO_CONSOLE to 1
   64       to force logging to go to stderr.
   65  

6 matches across 4 files

Doesn't look so good. They've been changing things for two times already. And it's still close to being not documented at all. Not publicly, at least.

Also, an interesting note on stderrHasConsoleAttached():

    \note Qt Creator does not implement a pseudo TTY, nor does it launch apps with
    the override environment variable set, but it will read stderr and print it to
    the user, so in effect this function cannot be used to conclude that stderr
    output will _not_ be visible to the user, as even if this function returns false,
    the output might still end up visible to the user. For this reason, we don't guard
    the stderr output in the default message handler with stderrHasConsoleAttached().

    \internal
    \sa systemHasStderr()

[ratijas]

I found it somewhat hilarious that Qt build system (yes, the one for building Qt itself from source) printed, among other things, this message to stdout:

$ cd qt6/qtbase
$ cmake -S . -B ../build-$(basename $PWD) -LA

[...]

Note: journald, syslog or slog2 integration is enabled.  If your users intend to develop applications against this build, ensure that the IDEs they use either set QT_FORCE_STDERR_LOGGING to 1 or are able to read the logged output from journald, syslog or slog2.

[...]

[ratijas]

I looked into this closely one more time. It is a documented fact that logging a message at "fatal" level should abort (exit) immediately after printing it. But I was worried that out implementation of Qt-to-log! proxy does nothing like that.

So, according to code flow, all printing is done in qt_message_print function which also grabs a registered message handler (if there is one) or a default one (which chooses backends at QtCore-compile-time based on config variables and target system). It is expected that provided handler just prints a message as requested, and does nothing else. Which is exactly what we do in Rust.

Message type of QtFatalMsg is obviously always fatal, but other levels such as "critical" and "warning" can be configured to be fatal too. If message's type is considered fatal, AFTER printing qt_message_fatal function will be called to terminate application, possibly using platform- and compiler-specific workarounds.

So, in conclusion: we are doing it right. Nice.

[ratijas]

Somehow, even more information on Qt logging, for those who still don't want to skim through source code:

KaiKoehne - Qt Logging Framework 16_9_0.pdf