Guidelines and HOWTOs/Debugging/Using Error Messages: Difference between revisions

From KDE Community Wiki
(→‎Controlling Messages: Link to the article how to use journalctl to see messages)
m (Replace redirect link 2)
 
(16 intermediate revisions by 3 users not shown)
Line 1: Line 1:
= Qt 5 / KDE Frameworks 5 =
A screen recording version is available https://www.youtube.com/watch?v=oTAfNb9Pcj4


== Example ==
This requires at least Qt version 5.
 
See https://doc.qt.io/qt-6/qtglobal.html#qSetMessagePattern
 
<pre>
# E.g. you can reproduce an issue in dolphin (the KDE file manager).
QT_LOGGING_RULES="*=true;qt.*=false" dolphin |& tee ~/a.txt
# Or
QT_MESSAGE_PATTERN="%{time yyyy-MM-ddThh:mm:ss.zzz t}, %{pid}, %{threadid}-%{qthreadptr}, %{type}-%{category}, %{file}:%{line}, %{function} - %{message}, %{backtrace}" QT_LOGGING_RULES="*=true;qt.*=false" dolphin |& tee ~/a.txt
# Inside dolphin, reproduce the issue. Write down the current time. Wait one minute. Close dolphin.
kate ~/a.txt
</pre>
 
If you have debug symbols, then "%{file}", "%{function}", "%{backtrace}" will work correctly:
<pre>
2023-02-02T10:27:35.501 EET, 596781, 596781-0x55a112906010, debug-kf.iconthemes, /home/username/kde/src/kiconthemes/src/kicontheme.cpp:708, KIconThemeDir::KIconThemeDir - Invalid Context= "FileSystems" line for icon theme:  "/usr/share/icons/hicolor/scalable/filesystems/", KIconThemeDir::KIconThemeDir|KIconTheme::KIconTheme|?libKF6IconThemes.so.6?|?libKF6IconThemes.so.6?|?libKF6IconThemes.so.6?
</pre>


== Controlling Messages ==
== Controlling Messages ==
Line 24: Line 8:


The source code for a library, plugin, or program named "Foo" may contain statements like
The source code for a library, plugin, or program named "Foo" may contain statements like
<syntaxhighlight lang="cpp-qt">
{{bc-hl|lang=cpp-qt|code=
qCDebug(LOG_FOO) << "Log something:" << someVariable;
qCDebug(LOG_FOO) << "Log something:" << someVariable;
</syntaxhighlight>
}}
Here, <tt>LOG_FOO</tt> is a ''logging category''.  If debug-level messages have been enabled for that logging category, then the statement will write a message to <tt>stderr</tt>.
Here, <tt>LOG_FOO</tt> is a ''logging category''.  If debug-level messages have been enabled for that logging category, then the statement will write a message to <tt>stderr</tt>.


Some source file will define the logging category:
Some source file will define the logging category:
<syntaxhighlight lang="cpp-qt">
{{bc-hl|lang=cpp-qt|code=
Q_LOGGING_CATEGORY(LOG_FOO, "some.namespace.foo")
Q_LOGGING_CATEGORY(LOG_FOO, "some.namespace.foo")
</syntaxhighlight>
}}
Here, <tt>"some.namespace.foo"</tt> is the ''category name''.  Once you know the category's name, you can
Here, <tt>"some.namespace.foo"</tt> is the ''category name''.  Once you know the category's name, you can
set the <tt>QT_LOGGING_RULES</tt> environment variable to enable debug-level messages for the category:
set the <tt>QT_LOGGING_RULES</tt> environment variable to enable debug-level messages for the category:
<syntaxhighlight lang="bash">
{{bc-hl|lang=bash|code=
QT_LOGGING_RULES="some.namespace.foo.debug=true"
QT_LOGGING_RULES="some.namespace.foo.debug=true"
</syntaxhighlight>
}}


You can also enable debug-level messages for the default category (when using <tt>qDebug</tt>), by setting:
You can also enable debug-level messages for the default category (when using <tt>qDebug</tt>), by setting:
<syntaxhighlight lang="bash">
{{bc-hl|lang=bash|code=
QT_LOGGING_RULES="default.debug=true"
QT_LOGGING_RULES="default.debug=true"
</syntaxhighlight>
}}


Logging rules can be more complex than the examples above. They can specify wildcards in the category name, enable or disable more than one message level, and control more than one logging category.
Logging rules can be more complex than the examples above. They can specify wildcards in the category name, enable or disable more than one message level, and control more than one logging category.


To specify several categories, separate them with semicolon:
To specify several categories, separate them with semicolon:
<syntaxhighlight lang="bash">
{{bc-hl|lang=bash|code=
QT_LOGGING_RULES="*.debug=false;driver.usb.debug=true"
QT_LOGGING_RULES="*.debug=false;driver.usb.debug=true"
</syntaxhighlight>
QT_LOGGING_RULES="*.debug=true;qt.*.debug=false"
 
}}
You can control the message pattern depending on message type:
<syntaxhighlight lang="bash">
QT_MESSAGE_PATTERN="[%{time hh:mm:ss.zzz} %{if-debug}D%{endif}%{if-info}I%{endif}%{if-warning}W%{endif}%{if-critical}C%{endif}%{if-fatal}F%{endif}] %{category} %{message}"
</syntaxhighlight>


They can also be stored in various configuration files. Please see the [https://doc.qt.io/qt-5/qloggingcategory.html#logging-rules QLoggingCategory documentation] for details.
They can also be stored in various configuration files. Please see the [https://doc.qt.io/qt-5/qloggingcategory.html#logging-rules QLoggingCategory documentation] for details.


If you run the application from within a terminal application, like [http://www.kde.org/applications/system/konsole/ Konsole], you will see the logging output in that terminal window.  If you use an [[Get_Involved/development/IDE_configuration|Integrated Development Environment]] like [https://kde.org/applications/en/development/org.kde.kdevelop KDevelop] it will display the output in its windows. In Qt Creator debug messages goes to systemd journal by default. You want to see them in Application Output, so you need to specify this variable in Run Environment:
If you run the application from within a terminal application, like [http://www.kde.org/applications/system/konsole/ Konsole], you will see the logging output in that terminal window.  If you use an [https://develop.kde.org/docs/getting-started/building/ide/ Integrated Development Environment] like [https://kde.org/applications/en/development/org.kde.kdevelop KDevelop] it will display the output in its windows. In Qt Creator debug messages goes to systemd journal by default. You want to see them in Application Output, so you need to specify this variable in Run Environment:
<syntaxhighlight lang="bash">
{{bc-hl|lang=bash|code=
QT_FORCE_STDERR_LOGGING=1
QT_FORCE_STDERR_LOGGING=1
</syntaxhighlight>
}}


Also check the [https://wiki.archlinux.org/title/Systemd/Journal systemd journal], since the application could be its direct child process. Otherwise, if you happen to still use X11, the messages will usually appear in {{path|~/.xsession-errors}} or {{path|~/.X.err}} if you use a login manager like KDM, or on the console you ran <tt>startx</tt> from if you started X that way.
Also check the [https://wiki.archlinux.org/title/Systemd/Journal systemd journal], since the application could be its direct child process. Otherwise, if you happen to still use X11, the messages will usually appear in {{path|~/.xsession-errors}} or {{path|~/.X.err}} if you use a login manager like KDM, or on the console you ran <tt>startx</tt> from if you started X that way.
Line 67: Line 47:
== Adding Logging to Your Code ==
== Adding Logging to Your Code ==
For a library or plugin called "Foo", you should have a common header that contains the following declaration  (e.g. called "foo-debug.h")
For a library or plugin called "Foo", you should have a common header that contains the following declaration  (e.g. called "foo-debug.h")
<syntaxhighlight lang="cpp-qt">
 
{{bc-hl|lang=cpp-qt|code=
#include <QLoggingCategory>
#include <QLoggingCategory>
Q_DECLARE_LOGGING_CATEGORY(LOG_FOO)
Q_DECLARE_LOGGING_CATEGORY(LOG_FOO)
</syntaxhighlight> and exactly one source file containing <syntaxhighlight lang="cpp-qt">
}}
 
and exactly one source file containing
 
{{bc-hl|lang=cpp-qt|code=
#include "foo-debug.h"
#include "foo-debug.h"
Q_LOGGING_CATEGORY(LOG_FOO, "some.namespace.foo")
Q_LOGGING_CATEGORY(LOG_FOO, "some.namespace.foo")
</syntaxhighlight>
}}


You should treat the category name (<tt>"some.namespace.foo"</tt> in the example) as something like reverse DNS; it cannot contain spaces, and dots indicate a hierarchy.  For example, KDE PIM category names all start with <tt>"org.kde.pim."</tt>.
You should treat the category name (<tt>"some.namespace.foo"</tt> in the example) as something like reverse DNS; it cannot contain spaces, and dots indicate a hierarchy.  For example, KDE PIM category names all start with <tt>"org.kde.pim."</tt>.


To simplify the setup, you can use the ECM macro <tt>[https://api.kde.org/ecm/module/ECMQtDeclareLoggingCategory.html ecm_qt_declare_logging_category]</tt>, which generates the respective source files for you:
To simplify the setup, you can use the ECM macro <tt>[https://api.kde.org/ecm/module/ECMQtDeclareLoggingCategory.html ecm_qt_declare_logging_category]</tt>, which generates the respective source files for you:
<syntaxhighlight lang="cmake">
 
{{bc-hl|lang=cmake|code=
include(ECMQtDeclareLoggingCategory)
include(ECMQtDeclareLoggingCategory)
ecm_qt_declare_logging_category(FOO_SRCS
ecm_qt_declare_logging_category(FOO_SRCS
Line 85: Line 71:
     CATEGORY_NAME "some.namespace.foo"
     CATEGORY_NAME "some.namespace.foo"
)
)
</syntaxhighlight>
}}
 
Logging lines then look like


Logging lines then look like <syntaxhighlight lang="cpp-qt">
{{bc-hl|lang=cpp-qt|code=
#include "foo-debug.hpp"
#include "foo-debug.hpp"
qCDebug(LOG_FOO) << "Log something:" << someVariable;
qCDebug(LOG_FOO) << "Log something:" << someVariable;
qCWarning(LOG_FOO) << "Something bad happened that users (end-users, or application developers using this library) should be aware of";
qCWarning(LOG_FOO) << "Something bad happened that users (end-users, or application developers using this library) should be aware of";
qCCritical(LOG_FOO) << "Something happened so bad we had to terminate the application";
qCCritical(LOG_FOO) << "Something happened so bad we had to terminate the application";
</syntaxhighlight>
}}


The syntax is much like <tt>cout</tt>, and most native C++ types, Qt-provided types and KF-provided types can be passed directly (like with <tt>someVariable</tt> in the example).
The syntax is much like <tt>cout</tt>, and most native C++ types, Qt-provided types and KF-provided types can be passed directly (like with <tt>someVariable</tt> in the example).


With Qt 5.2, the <tt>qCDebug</tt> line will not produce any output; this is because logging categories are disabled by default.  You need to include the line <syntaxhighlight lang="cpp-qt">
With Qt 5.2, the <tt>qCDebug</tt> line will not produce any output; this is because logging categories are disabled by default.  You need to include the line
 
{{bc-hl|lang=cpp-qt|code=
QLoggingCategory::setFilterRules(QStringLiteral("foo.debug = true"));
QLoggingCategory::setFilterRules(QStringLiteral("foo.debug = true"));
</syntaxhighlight>
}}
 
somewhere in the application code, generally in the <tt>main()</tt> function.  Of course, you would typically disable this call in release versions.
somewhere in the application code, generally in the <tt>main()</tt> function.  Of course, you would typically disable this call in release versions.


== Improving Logging Output ==
== Customize Logging Output ==


Qt provides a way of controlling the output of the logging methods via an environment variable.  You can tell it to include the application name and PID, as well as the debugging category, and color-code the text.  For example, running the following lines in your shell will produce something that looks quite like <tt>kDebug</tt>'s colored output: <syntaxhighlight lang="bash">
Qt provides a way of controlling the output of the logging methods via an {{ic|QT_MESSAGE_PATTERN}} environment variable.  
c=`echo -e "\033"`
export QT_MESSAGE_PATTERN="%{appname}(%{pid})/(%{category}) $c\[31m%{if-debug}$c\[34m%{endif}%{function}$c\[0m: %{message}"
unset c
</syntaxhighlight>
See [https://doc.qt.io/qt-5/qtglobal.html#qSetMessagePattern qSetMessagePattern documentation] for the full list of placeholders.


== Managing Lots of Output ==
You can control the message pattern depending on message type:


If you have lots of debugging statements, they may appear too fast and leave the terminal window before you can read them.  There are three main ways to deal with this:
{{bc-hl|lang=bash|code=
# [https://doc.qt.io/qt-5/qloggingcategory.html#setFilterRules Disable some logging categories] to limit the amount of output generated
QT_MESSAGE_PATTERN="[%{time hh:mm:ss.zzz} %{if-debug}D%{endif}%{if-info}I%{endif}%{if-warning}W%{endif}%{if-critical}C%{endif}%{if-fatal}F%{endif}] %{category} %{message}"
# Increase the amount of scrollback in the terminal so that output is not lost; in Konsole, you can go to <tt>Settings > Edit Current Profile...</tt> and click on the <tt>Scrollback</tt> tab to change this.  Konsole also has a useful search feature: just press <tt>Ctrl+Shift+F</tt> or click <tt>Find...</tt> on the <tt>Edit</tt> menu.
}}
# Save the output to a file; <tt>tee</tt> is useful for this.  For example, you can run <syntaxhighlight lang="bash">application 2>&1 | tee ~/debug.log</syntaxhighlight> or <syntaxhighlight lang="bash">application |& tee ~/debug.log</syntaxhighlight> to save the output to the file <tt>~/debug.log</tt> while still viewing it in the terminal.


= Qt 4 / kdelibs 4 =
You can tell it to include the application name and PID, as well as the debugging category. See [https://doc.qt.io/qt-6/qtglobal.html#qSetMessagePattern qSetMessagePattern documentation] for the full list of placeholders.


kdelibs provides a [http://api.kde.org/4.0-api/kdelibs-apidocs/kdecore/html/group__kdebug.html family of functions] that output information to <tt>stderr</tt>, meaning that if you run an application from the terminal, it will be displayed in that terminal window. If you run the application from the desktop (using KRunner or the application menu, for example), the output will normally appear in {{path|~/.xsession-errors}} or {{path|~/.X.err}} if you use a login manager like KDM, or on the console you ran <tt>startx</tt> from if you started X that way.
You even can use escape sequences to colorize the text. For example, running the following lines in your shell will produce something that looks quite like <tt>kDebug</tt>'s colored output:


To use these functions in your code, you need to include the correct header file <syntaxhighlight lang="cpp-qt">
{{bc-hl|lang=bash|code=
#include <KDebug>
c=`echo -e "\033"# escape symbol
</syntaxhighlight>
export QT_MESSAGE_PATTERN="%{appname}(%{pid})/(%{category}) $c\[31m%{if-debug}$c\[34m%{endif}%{function}$c\[0m: %{message}"
and then you can use the functions <syntaxhighlight lang="cpp-qt">
unset c
kDebug() << "Something happened that only developers care about" << someVariable;
}}
kWarning() << "Something bad happened that users (end-users, or application developers using this library) should be aware of";
kError() << "Something even worse happened";
kFatal() << "Something happened so bad we had to terminate the application";
</syntaxhighlight>


The syntax is much like <tt>cout</tt>, and most native C++ types, Qt-provided types and kdelibs-provided types can be passed directly (like with <tt>someVariable</tt> in the example).
It is possible to create hyperlinked text with [https://github.com/Alhadis/OSC8-Adoption/ OSC-8]. For example, instead of printing the {{ic|%{file<nowiki>}</nowiki>}} (a full path to file), you may want to print a class name, which is a hyperlink to the file and line of message.


Note that the <tt>kDebug</tt> calls will only do anything if the code was compiled with debugging enabled (and so will generally not work in packages from a distribution). This means <tt>cmake</tt> should be run with the <tt>-DCMAKE_BUILD_TYPE=debugfull</tt> argument.  The other functions, however, will produce output no matter how the code was compiled.
If using [https://develop.kde.org/docs/getting-started/building/ide/clion/ CLion], keep in mind that colorizing the hyperlinked text is currently broken. See  [https://youtrack.jetbrains.com/issue/IDEA-218793/Provide-visual-decoration-for-terminal-HTML-like-hyperlinks IDEA-218793].


== Debug Areas ==
== Managing Lots of Output ==


The debugging output can be controlled at runtime using debugging areasThis allows enabling debugging output for only certain libraries or plugins, for example. Debugging areas are numbers, so the <tt>KStatusNotifierItemPrivate::registerToDaemon</tt> method in the kdeui library, for example, has the call <syntaxhighlight lang="cpp-qt">
If you have lots of debugging statements, they may appear too fast and leave the terminal window before you can read themThere are three main ways to deal with this:
kDebug(299) << "Registering a client interface to the KStatusNotifierWatcher";
# [https://doc.qt.io/qt-5/qloggingcategory.html#setFilterRules Disable some logging categories] to limit the amount of output generated
</syntaxhighlight>
# Increase the amount of scrollback in the terminal so that output is not lost; in Konsole, you can go to Settings > Edit Current Profile... and click on the Scrollback tab to change this. Konsole also has a useful search feature: just press Ctrl+Shift+F or click Find... on the Edit menu.
The file <tt>kdebug.areas</tt> in the <tt>kdecore</tt> directory of kdelibs indicates that the number 299 is associated with "kdeui (KNotification)".
# Save the output to a file. The UNIX command line <code>tee</code> is useful for this.  For example, you can run <code>application 2>&1 | tee ~/debug.log</code> or <code>application |& tee ~/debug.log</code> to save the output to the file <code>~/debug.log</code> while still viewing it in the terminal.


This information is used by the <tt>kdebugdialog</tt> utility (which you can just run from the commandline or using KRunner) to turn these areas on and off, enabling or disabling those <tt>kDebug</tt> statements.  It is also used by <tt>kDebug</tt>, <tt>kWarning</tt>, <tt>kError</tt> and <tt>kFatal</tt> to indicate which component output the line.  For example, the line in the above example would produce the line <pre>kwalletmanager(642)/kdeui (KNotification) KStatusNotifierItemPrivate::registerToDaemon: Registering a client interface to the KStatusNotifierWatcher</pre>
== Example ==
when executed from within the application kwalletmanager, with PID 642.


For applications, you can generally just omit the area number, and <tt>kDebug</tt> will use the default area. If you are developing a library or a plugin, though, you should get a number assigned (via the kde-core-devel mailing list) for your library or plugin, and use it in your code.  Rather than using the number directly in every call to <tt>kDebug</tt> and friends, you can just add<syntaxhighlight lang="cmake">
<pre>
add_definition(-DKDE_DEFAULT_DEBUG_AREA=<number>)
export QT_FORCE_STDERR_LOGGING=1
</syntaxhighlight>
export QT_MESSAGE_PATTERN="%{time yyyy.MM.dd, hh:mm:ss.zzz}, %{pid}, %{appname}, %{category}, %{type}, %{file}:%{line}, %{function} - %{message}"
to your <tt>CMakeLists.txt</tt> file.
export QT_LOGGING_RULES="*.debug=true;qt*.debug=false"


== Improving Log Output ==
kcalc |& tee ~/a.txt
# kate ~/a.txt &
</pre>


There are a couple of useful environment variables to control the output of <tt>kDebug</tt> and friends.  <syntaxhighlight lang="bash">
You can append at the end of QT_MESSAGE_PATTERN the string ", %{backtrace}".
export KDE_COLOR_DEBUG=1
</syntaxhighlight> will make them produce colored output, and <syntaxhighlight lang="bash">
export KDE_DEBUG_TIMESTAMP=1
</syntaxhighlight> will include timestamps in the output.  <syntaxhighlight lang="bash">
export KDE_DEBUG_TIMESTAMP=2
</syntaxhighlight> can be used to include milliseconds in the timestamps.


 
"qt*.debug=false" is there because there are few errors in the Qt Framework source code, because there are some very verbose log lines there (e.g. "qt.qpa.events", "qt.qpa.input.events", "qt.quick.hover.trace") and because we are more interested in the KDE source code than in the Qt source code.
 
<syntaxhighlight lang="bash">
export KDE_DEBUG_NOPROCESSINFO=1
export KDE_DEBUG_NOAREANAME=1
export KDE_DEBUG_NOMETHODNAME=1
export KDE_DEBUG_FILELINE=1
</syntaxhighlight>The above commands toggle various components of the debug messages.
 
== Managing Lots of Output ==
 
If you have lots of debugging statements, they may appear too fast and leave the terminal window before you can read them.  There are three main ways to deal with this:
# Use <tt>kdebugdialog</tt> to disable some logging areas to limit the amount of output generated
# Increase the amount of scrollback in the terminal so that output is not lost; in Konsole, you can go to <tt>Settings > Edit Current Profile...</tt> and click on the <tt>Scrollback</tt> tab to change this. Konsole also has a useful search feature: just press <tt>Ctrl+Shift+F</tt> or click <tt>Find...</tt> on the <tt>Edit</tt> menu.
# Save the output to a file; <tt>tee</tt> is useful for this. For example, you can run <pre>application 2&gt;&amp;1 | tee debug.log</pre> to save the output to the file <tt>debug.log</tt> while still viewing it in the terminal.  This can also be used to capture output from <tt>startx</tt>.

Latest revision as of 17:51, 18 April 2024

A screen recording version is available https://www.youtube.com/watch?v=oTAfNb9Pcj4

This requires at least Qt version 5.

Controlling Messages

kDebug() and friends have been deprecated in KDE Frameworks 5, and you should use Qt's built-in debugging instead. We recommend that you use QLoggingCategory, particularly for libraries and plugins. Note that this is only available in Qt 5.2 and later.

The source code for a library, plugin, or program named "Foo" may contain statements like

qCDebug(LOG_FOO) << "Log something:" << someVariable;

Here, LOG_FOO is a logging category. If debug-level messages have been enabled for that logging category, then the statement will write a message to stderr.

Some source file will define the logging category:

Q_LOGGING_CATEGORY(LOG_FOO, "some.namespace.foo")

Here, "some.namespace.foo" is the category name. Once you know the category's name, you can set the QT_LOGGING_RULES environment variable to enable debug-level messages for the category:

QT_LOGGING_RULES="some.namespace.foo.debug=true"

You can also enable debug-level messages for the default category (when using qDebug), by setting:

QT_LOGGING_RULES="default.debug=true"

Logging rules can be more complex than the examples above. They can specify wildcards in the category name, enable or disable more than one message level, and control more than one logging category.

To specify several categories, separate them with semicolon:

QT_LOGGING_RULES="*.debug=false;driver.usb.debug=true"
QT_LOGGING_RULES="*.debug=true;qt.*.debug=false"

They can also be stored in various configuration files. Please see the QLoggingCategory documentation for details.

If you run the application from within a terminal application, like Konsole, you will see the logging output in that terminal window. If you use an Integrated Development Environment like KDevelop it will display the output in its windows. In Qt Creator debug messages goes to systemd journal by default. You want to see them in Application Output, so you need to specify this variable in Run Environment:

QT_FORCE_STDERR_LOGGING=1

Also check the systemd journal, since the application could be its direct child process. Otherwise, if you happen to still use X11, the messages will usually appear in ~/.xsession-errors or ~/.X.err if you use a login manager like KDM, or on the console you ran startx from if you started X that way.

Adding Logging to Your Code

For a library or plugin called "Foo", you should have a common header that contains the following declaration (e.g. called "foo-debug.h")

#include <QLoggingCategory>
Q_DECLARE_LOGGING_CATEGORY(LOG_FOO)

and exactly one source file containing

#include "foo-debug.h"
Q_LOGGING_CATEGORY(LOG_FOO, "some.namespace.foo")

You should treat the category name ("some.namespace.foo" in the example) as something like reverse DNS; it cannot contain spaces, and dots indicate a hierarchy. For example, KDE PIM category names all start with "org.kde.pim.".

To simplify the setup, you can use the ECM macro ecm_qt_declare_logging_category, which generates the respective source files for you:

include(ECMQtDeclareLoggingCategory)
ecm_qt_declare_logging_category(FOO_SRCS
    HEADER foo-debug.h
    IDENTIFIER "LOG_FOO"
    CATEGORY_NAME "some.namespace.foo"
)

Logging lines then look like

#include "foo-debug.hpp"
qCDebug(LOG_FOO) << "Log something:" << someVariable;
qCWarning(LOG_FOO) << "Something bad happened that users (end-users, or application developers using this library) should be aware of";
qCCritical(LOG_FOO) << "Something happened so bad we had to terminate the application";

The syntax is much like cout, and most native C++ types, Qt-provided types and KF-provided types can be passed directly (like with someVariable in the example).

With Qt 5.2, the qCDebug line will not produce any output; this is because logging categories are disabled by default. You need to include the line

QLoggingCategory::setFilterRules(QStringLiteral("foo.debug = true"));

somewhere in the application code, generally in the main() function. Of course, you would typically disable this call in release versions.

Customize Logging Output

Qt provides a way of controlling the output of the logging methods via an QT_MESSAGE_PATTERN environment variable.

You can control the message pattern depending on message type:

QT_MESSAGE_PATTERN="[%{time hh:mm:ss.zzz} %{if-debug}D%{endif}%{if-info}I%{endif}%{if-warning}W%{endif}%{if-critical}C%{endif}%{if-fatal}F%{endif}] %{category} %{message}"

You can tell it to include the application name and PID, as well as the debugging category. See qSetMessagePattern documentation for the full list of placeholders.

You even can use escape sequences to colorize the text. For example, running the following lines in your shell will produce something that looks quite like kDebug's colored output:

c=`echo -e "\033"`  # escape symbol
export QT_MESSAGE_PATTERN="%{appname}(%{pid})/(%{category}) $c\[31m%{if-debug}$c\[34m%{endif}%{function}$c\[0m: %{message}"
unset c

It is possible to create hyperlinked text with OSC-8. For example, instead of printing the %{file} (a full path to file), you may want to print a class name, which is a hyperlink to the file and line of message.

If using CLion, keep in mind that colorizing the hyperlinked text is currently broken. See IDEA-218793.

Managing Lots of Output

If you have lots of debugging statements, they may appear too fast and leave the terminal window before you can read them. There are three main ways to deal with this:

  1. Disable some logging categories to limit the amount of output generated
  2. Increase the amount of scrollback in the terminal so that output is not lost; in Konsole, you can go to Settings > Edit Current Profile... and click on the Scrollback tab to change this. Konsole also has a useful search feature: just press Ctrl+Shift+F or click Find... on the Edit menu.
  3. Save the output to a file. The UNIX command line tee is useful for this. For example, you can run application 2>&1 | tee ~/debug.log or application |& tee ~/debug.log to save the output to the file ~/debug.log while still viewing it in the terminal.

Example

export QT_FORCE_STDERR_LOGGING=1
export QT_MESSAGE_PATTERN="%{time yyyy.MM.dd, hh:mm:ss.zzz}, %{pid}, %{appname}, %{category}, %{type}, %{file}:%{line}, %{function} - %{message}"
export QT_LOGGING_RULES="*.debug=true;qt*.debug=false"

kcalc |& tee ~/a.txt
# kate ~/a.txt &

You can append at the end of QT_MESSAGE_PATTERN the string ", %{backtrace}".

"qt*.debug=false" is there because there are few errors in the Qt Framework source code, because there are some very verbose log lines there (e.g. "qt.qpa.events", "qt.qpa.input.events", "qt.quick.hover.trace") and because we are more interested in the KDE source code than in the Qt source code.