Bug 442896 - Annoying "Unregistering type class N" output when running e.g. `kdevelop --help` or unit tests
Summary: Annoying "Unregistering type class N" output when running e.g. `kdevelop --he...
Status: RESOLVED FIXED
Alias: None
Product: kdevelop
Classification: Applications
Component: general (show other bugs)
Version: git master
Platform: Compiled Sources Linux
: NOR normal
Target Milestone: ---
Assignee: kdevelop-bugs-null
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-09-24 12:51 UTC by Igor Kushnir
Modified: 2023-09-15 12:50 UTC (History)
1 user (show)

See Also:
Latest Commit:
Version Fixed In: 5.13.231200
Sentry Crash Report:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Igor Kushnir 2021-09-24 12:51:03 UTC
SUMMARY
When I run KDevelop's tests or `kdevelop --help` or `kdevelop --rm <session name>`, the following lines appear at the very end of the program output:

kdevplatform.language: Unregistering type class 57
kdevplatform.language: Unregistering type class 58
kdevplatform.language: Unregistering type class 39
kdevplatform.language: Unregistering type class 9
kdevplatform.language: Unregistering type class 20
kdevplatform.language: Unregistering type class 14
kdevplatform.language: Unregistering type class 21
kdevplatform.language: Unregistering type class 7
kdevplatform.language: Unregistering type class 8
kdevplatform.language: Unregistering type class 4
kdevplatform.language: Unregistering type class 3
kdevplatform.language: Unregistering type class 6
kdevplatform.language: Unregistering type class 5
kdevplatform.language: Unregistering type class 2

Sometimes it's just "Unregistering type class N" without the "kdevplatform.language: " prefix.

The output is produced by the `qCDebug(LANGUAGE) << "Unregistering type class" << identity;` line in TypeSystem::unregisterTypeClassInternal() (https://invent.kde.org/kdevelop/kdevelop/-/blob/51e724364061a0a64576531dd0314a89fc688b05/kdevplatform/language/duchain/types/typeregister.cpp#L95), despite the fact that the logging level of all KDevelop logging categories (including kdevplatform.language) is above *debug*. I think, the issue is that this function is called very late, when some QLoggingCategory-related objects are already destroyed or uninitialized. In other words, this could be something like static de-initialization order fiasco issue.

SOFTWARE/OS VERSIONS
Manjaro GNU/Linux, Xfce
KDE Frameworks Version: 5.85.0
Qt Version: 5.15.2+kde+r222
Comment 1 nathan 2022-08-19 22:43:21 UTC
I receive this output when using opening files: `kdevelop file.js`
Comment 2 Bug Janitor Service 2023-09-12 14:19:01 UTC
A possibly relevant merge request was started @ https://invent.kde.org/kdevelop/kdevelop/-/merge_requests/487
Comment 3 Igor Kushnir 2023-09-15 12:50:14 UTC
Git commit 07c1748bf71a3b6b2f8182146672ddc7558a032c by Igor Kushnir.
Committed on 15/09/2023 at 14:50.
Pushed by igorkushnir into branch 'master'.

Revert "types: Remove unfilterable debug output"

TypeSystem::registerTypeClassInternal() is called in the constructor and
TypeSystem::unregisterTypeClassInternal() - in the destructor of each
global-variable object declared via the REGISTER_TYPE macro.
registerTypeClassInternal() does not log any messages, therefore these
global variables are constructed before the function-local static
QLoggingCategory constant LANGUAGE. So the global variables are
destroyed after LANGUAGE (in the reverse order of the completion of
constructors). unregisterTypeClassInternal() attempts to log a message
via qCDebug(LANGUAGE) when the function-local LANGUAGE is already
destroyed. This is undefined behavior, which in practice causes the
following two issues:
1. When KDevelop is started normally and
   kdevplatform.language.debug=true, the "Unregistering type class"
   messages lack the usual prefix "kdevplatform.language: ".
2. When KDevelop exits immediately without showing the UI (because of
   a command-line option such as --help or --list-sessions) and
   kdevplatform.language.debug=false (the default), the disabled debug
   messages clutter the program output (curiously, they do start with
   the "kdevplatform.language: " prefix).

Log a matching "Registering type class" message via qCDebug(LANGUAGE) in
registerTypeClassInternal() to complete the constructor of LANGUAGE
before the constructors of global variables that use LANGUAGE in their
destructors. This eliminates the undefined behavior and its two
practical consequences.

The reverted commit's message contains:
  This is printed before Qt categorized logging is properly set up and
  thus may be printed even though it's technically disabled via filters.
I haven't encountered the referenced issue during my testing of this
commit. Perhaps the implementation of Qt categorized logging has
improved since then (2017) and is now reliably set up in time. If not
and the original issue resurfaces, the qCDebug(LANGUAGE) line in
registerTypeClassInternal() can be replaced with the line `LANGUAGE();`,
which does not log anything but still initializes the function-local
static QLoggingCategory constant.

This reverts commit a5eac48a83fc6e443459e7e045b9230b011c537b.
FIXED-IN: 5.13.231200

M  +1    -0    kdevplatform/language/duchain/types/typeregister.cpp

https://invent.kde.org/kdevelop/kdevelop/-/commit/07c1748bf71a3b6b2f8182146672ddc7558a032c