Jump to content

Development/Tutorials/Debugging/Debugging symbols and Development/Tutorials/Debugging/Using Error Messages: Difference between pages

From KDE TechBase
(Difference between pages)
Icwiener (talk | contribs)
m Fix syntax highlighting.
 
Pippin (talk | contribs)
No edit summary
 
Line 1: Line 1:
== Overview ==
= Qt 4 / kdelibs 4 =
Debugging symbols allow you to debug your application better. They are added to your binary by the compiler. For KDE, you have to decide during the cmake step if you want debugging symbols or not. To compile your application with debugging symbols, use
<pre>
cmake . -DCMAKE_BUILD_TYPE=debugfull
</pre>
to compile it without debugging symbols, use
<pre>
cmake . -DCMAKE_BUILD_TYPE=release
</pre>
Depending on your decision, output generated with the command kDebug will also be (debugfull) or not be (release) added to your application.


== Example app ==
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.
As an example, let's write an application that crashes:


'''main.cpp'''
To use these functions in your code, you need to include the correct header file <syntaxhighlight lang="cpp-qt">
<syntaxhighlight lang="cpp-qt">  
#include <KDebug>
#include <KApplication>
</syntaxhighlight>
#include <KAboutData>
and then you can use the functions <syntaxhighlight lang="cpp-qt">
#include <KCmdLineArgs>
kDebug() << "Something happened that only developers care about" << someVariable;
#include <KMessageBox>
kWarning() << "Something bad happened that users (end-users, or application developers using this library) should be aware of";
#include <iostream>
kError() << "Something even worse happened";
kFatal() << "Something happened so bad we had to terminate the application";
</syntaxhighlight>


using namespace std;
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).


int main (int argc, char *argv[])
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.
{
    KAboutData aboutData( "tutorial1", 0, ki18n("Tutorial 1"), "1.0",
                          ki18n("Displays a KMessageBox popup"),
                          KAboutData::License_GPL,
                          ki18n("(c) 2009"), ki18n("Some text..."),
                          "http://tutorial.com/",
                          "submit@bugs.kde.org");


    KCmdLineArgs::init( argc, argv, &aboutData );
== Debug Areas ==
    KApplication app;


    KMessageBox::questionYesNo( 0, i18n( "Hello World" ) );
The debugging output can be controlled at runtime using debugging areas.  This 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">
    int* i;
kDebug(299) << "Registering a client interface to the KStatusNotifierWatcher";
    cout << "i is at " << i << " value " << *i << endl;
</syntaxhighlight>
    i=(int*)0x0;
The file <tt>kdebug.areas</tt> in the <tt>kdecore</tt> directory of kdelibs indicates that the number 299 is associated with "kdeui (KNotification)".
    cout << "i is at " << i << " value " << *i << endl;


    return 0;
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>
}
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">
add_definition(-DKDE_DEFAULT_DEBUG_AREA=<number>)
</syntaxhighlight>
</syntaxhighlight>
to your <tt>CMakeLists.txt</tt> file.


'''CMakeLists.txt'''
== Improving Log Output ==
<pre>
project (tutorial1)
find_package(KDE4 REQUIRED)
include (KDE4Defaults)
include_directories(${KDE4_INCLUDES})
set(tutorial1_SRCS main.cpp)
kde4_add_executable(tutorial1 ${tutorial1_SRCS})
target_link_libraries(tutorial1 ${KDE4_KDEUI_LIBS})
install(TARGETS tutorial1  ${INSTALL_TARGETS_DEFAULT_ARGS})
</pre>
Now let's compile this without debugging symbols:
<pre>
cmake . -DCMAKE_BUILD_TYPE=release && make
</pre>
We see that the resulting file is small:
<pre>
# ls -lh tutorial1
-rwxr-xr-x 1 user user 15K Jul 11 18:07 tutorial1
</pre>
With debugging symbols, the file is bigger:
<pre>
cmake . -DCMAKE_BUILD_TYPE=debugfull && make
# ls -lh tutorial1
-rwxr-xr-x 1 root root 250K Jul 11 18:09 tutorial1
</pre>


== Backtraces ==
There are a couple of useful environment variables to control the output of <tt>kDebug</tt> and friends.  <syntaxhighlight lang="bash">
Now let's start the application and look at the backtrace:
export KDE_COLOR_DEBUG=1
<pre>
</syntaxhighlight> will make them produce colored output, and <syntaxhighlight lang="bash">
cmake . -DCMAKE_BUILD_TYPE=release && make
export KDE_DEBUG_TIMESTAMP=1
</pre>
</syntaxhighlight> will include timestamps in the output.  <syntaxhighlight lang="bash">
Gives you the backtrace
export KDE_DEBUG_TIMESTAMP=2
<pre>
</syntaxhighlight> can be used to include milliseconds in the timestamps.
Application: Tutorial 1 (tutorial1), signal SIGSEGV
�[?1034h[Thread debugging using libthread_db enabled]
0x00007f58abba4cb0 in nanosleep () from /lib64/libc.so.6
[Current thread is 1 (Thread 0x7f58b0cfd750 (LWP 21264))]


Thread 1 (Thread 0x7f58b0cfd750 (LWP 21264)):
== Managing Lots of Output ==
[KCrash Handler]
'''#5  0x00000000004016aa in main ()'''
</pre>
The debugging build
<pre>
cmake . -DCMAKE_BUILD_TYPE=debugfull && make
</pre>
Gives you the backtrace
<pre>
Application: Tutorial 1 (tutorial1), signal SIGSEGV
�[?1034h[Thread debugging using libthread_db enabled]
0x00007fd0b8161cb0 in nanosleep () from /lib64/libc.so.6
[Current thread is 1 (Thread 0x7fd0bd2ba750 (LWP 21327))]


Thread 1 (Thread 0x7fd0bd2ba750 (LWP 21327)):
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:
[KCrash Handler]
# Use <tt>kdebugdialog</tt> to disable some logging areas to limit the amount of output generated
'''#5  0x0000000000401625 in main (argc=1, argv=0x7fffc52f5138) at /root/kdehello/main.cpp:25'''
# 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.
</pre>
# 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>.
So you see: with debugging symbols, you see the line number where the crash occurred. Without, you do not see this.


== Where are they? ==
= Qt 5 / KDE Frameworks 5 =
Where are the debugging symbols stored? Use objdump -g to find out:
 
<pre>
<tt>kDebug()</tt> and friends have been deprecated in KDE Frameworks 5, and you should use Qt's built-in debugging instead. We recommend that you use [http://doc-snapshot.qt-project.org/qt5-stable/qloggingcategory.html QLoggingCategory], particularly for libraries and plugins.  Note that this is only available in Qt 5.2 and later.
# objdump -g tutorial1-release | wc -l
 
511
In particular, for a library or plugin called "Foo", you should have a common header that contains the following declaration <syntaxhighlight lang="cpp-qt">
# objdump  -g tutorial1-debugfull | wc -l
#include <QLoggingCategory>
40943
Q_DECLARE_LOGGING_CATEGORY(LOG_FOO)
</pre>
</syntaxhighlight> and exactly one source file containing <syntaxhighlight lang="cpp-qt">
It is important to know that the code lines (in assembler) to be executed actually do not differ a lot. We see this when disassembling the code:
Q_LOGGING_CATEGORY(LOG_FOO, "foo")
<pre>
</syntaxhighlight>
# objdump -d tutorial1-debugfull | wc -l
 
658
You should treat the string as something like reverse DNS; it cannot contain spaces, and dots indicate a heirarchy.  For example, a Plasma dataengine called "Foo" might use the category <tt>"plasma.engine.foo"</tt>.
# objdump -d tutorial1-release | wc -l
 
697
Logging lines then look like <syntaxhighlight lang="cpp-qt">
</pre>
qCDebug(LOG_FOO) << "Log something:" << someVariable;
This gives us hope that there will be no major speed difference between a debug- and a release-version of a binary.
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";
</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).
 
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">
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.  Qt 5.3 will hopefully include a way to change this configuration externally, without recompiling.
 
If you run your 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.  Otherwise, it 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.
 
== Improving 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">
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>


== Speed implications ==
== Managing Lots of Output ==
We remove the lines that cause the crash and the messagebox. Then we execute the program 100 times:
<pre>
cmake . -DCMAKE_BUILD_TYPE=debugfull && make -j4
time for i in $(seq 1 1 100); do ./tutorial1; done
real    0m6.201s
user    0m4.368s
sys    0m1.320s
</pre>
Lasts 6 seconds. Now with the release version:
<pre>
cmake . -DCMAKE_BUILD_TYPE=release && make -j4
time for i in $(seq 1 1 100); do ./tutorial1; done
real    0m6.259s
user    0m4.368s
sys    0m1.328s
</pre>
Also lasts 6 seconds. So the main difference is in the binaries size.


== And make? ==
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:
How does cmake propagate to make if a debug version is wanted? Do a
# [http://doc-snapshot.qt-project.org/qt5-stable/qloggingcategory.html#setFilterRules Disable some logging categories] to limit the amount of output generated
<pre>
# 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.
cmake . -DCMAKE_BUILD_TYPE=debugfull && make VERBOSE=1
# 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> to save the output to the file <tt>debug.log</tt> while still viewing it in the terminal.
</pre>
You will find a difference during the link step. The parameters
<pre>
-DNDEBUG -DQT_NO_DEBUG
</pre>
are unique for the release-version. There are further differences like the O2 optimization.

Revision as of 18:33, 25 November 2013

Qt 4 / kdelibs 4

kdelibs provides a family of functions that output information to stderr, 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 ~/.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.

To use these functions in your code, you need to include the correct header file

#include <KDebug>

and then you can use the functions

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";

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

Note that the kDebug 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 cmake should be run with the -DCMAKE_BUILD_TYPE=debugfull argument. The other functions, however, will produce output no matter how the code was compiled.

Debug Areas

The debugging output can be controlled at runtime using debugging areas. This allows enabling debugging output for only certain libraries or plugins, for example. Debugging areas are numbers, so the KStatusNotifierItemPrivate::registerToDaemon method in the kdeui library, for example, has the call

 kDebug(299) << "Registering a client interface to the KStatusNotifierWatcher";

The file kdebug.areas in the kdecore directory of kdelibs indicates that the number 299 is associated with "kdeui (KNotification)".

This information is used by the kdebugdialog utility (which you can just run from the commandline or using KRunner) to turn these areas on and off, enabling or disabling those kDebug statements. It is also used by kDebug, kWarning, kError and kFatal to indicate which component output the line. For example, the line in the above example would produce the line

kwalletmanager(642)/kdeui (KNotification) KStatusNotifierItemPrivate::registerToDaemon: Registering a client interface to the KStatusNotifierWatcher

when executed from within the application kwalletmanager, with PID 642.

For applications, you can generally just omit the area number, and kDebug 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 kDebug and friends, you can just add

add_definition(-DKDE_DEFAULT_DEBUG_AREA=<number>)

to your CMakeLists.txt file.

Improving Log Output

There are a couple of useful environment variables to control the output of kDebug and friends.

export KDE_COLOR_DEBUG=1

will make them produce colored output, and

export KDE_DEBUG_TIMESTAMP=1

will include timestamps in the output.

export KDE_DEBUG_TIMESTAMP=2

can be used to include milliseconds in the timestamps.

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. Use kdebugdialog to disable some logging areas 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; tee is useful for this. For example, you can run
    application 2>&1 | tee debug.log
    to save the output to the file debug.log while still viewing it in the terminal. This can also be used to capture output from startx.

Qt 5 / KDE Frameworks 5

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.

In particular, for a library or plugin called "Foo", you should have a common header that contains the following declaration

#include <QLoggingCategory>
Q_DECLARE_LOGGING_CATEGORY(LOG_FOO)

and exactly one source file containing

Q_LOGGING_CATEGORY(LOG_FOO, "foo")

You should treat the string as something like reverse DNS; it cannot contain spaces, and dots indicate a heirarchy. For example, a Plasma dataengine called "Foo" might use the category "plasma.engine.foo".

Logging lines then look like

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 kdelibs-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. Qt 5.3 will hopefully include a way to change this configuration externally, without recompiling.

If you run your application from within a terminal application, like Konsole, you will see the logging output in that terminal window. Otherwise, it 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.

Improving 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 kDebug's colored output:

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

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; tee is useful for this. For example, you can run
    application 2<&1 | tee debug.log
    
    to save the output to the file debug.log while still viewing it in the terminal.