When I rebooted a while back it stopped for a bit, but it's back now. So it may take a while after opening a session until it shows up?

Is this reproducible in 6.0?

I've been getting this on my system too. Plasma 6.0 with Qt 6.7.

Please provide more details about your system. As is, there's not that much that can make this bug report actionable.

Operating System: Arch Linux 
KDE Plasma Version: 6.0.0
KDE Frameworks Version: 6.0.0
Qt Version: 6.7.0
Kernel Version: 6.7.6-arch1-2 (64-bit)
Graphics Platform: Wayland
Processors: 16 × AMD Ryzen 7 2700X Eight-Core Processor
Memory: 31.3 GiB of RAM
Graphics Processor: AMD Radeon RX 6500 XT

I'm using kde-unstable/testing on ArchLinux.

I'm experiencing the same on Arch Linux. Something that I noticed is that it happens everytime my Razer devices resumes from Power Saving mode:

This is the log from journalctl -b -3:

> kwin_wayland[2751]: QObject::startTimer: Timers cannot have negative intervals
> openrazer-daemon[2346]: 2024-02-29 11:24:04 | razer.device0                  | INFO     | Resuming RazerHuntsmanElite
> kwin_wayland[2751]: QObject::startTimer: Timers cannot have negative intervals
> openrazer-daemon[2346]: 2024-02-29 11:24:04 | razer.device0                  | INFO     | Putting device back into driver mode.
> openrazer-daemon[2346]: 2024-02-29 11:24:04 | razer.device1                  | INFO     | Resuming RazerNagaProWireless
> kwin_wayland[2751]: QObject::startTimer: Timers cannot have negative intervals
> kernel: razermouse: Command timed out. status: 04 transaction_id.id: 1f remaining_packets: 00 protocol_type: 00 data_size: 03, command_class: 0f, command_id.id: 04 Params: 0100bf00000000000000000000000000 .
> kernel: razermouse: Command timed out. status: 04 transaction_id.id: 1f remaining_packets: 00 protocol_type: 00 data_size: 03, command_class: 0f, command_id.id: 04 Params: 0104bf00000000000000000000000000 .
> kscreenlocker_greet[957590]: qt.qpa.wayland: Could not create EGL surface (EGL error 0x3000)
> kscreenlocker_greet[957590]: qt.qpa.wayland: Could not create EGL surface (EGL error 0x3000)
> kernel: razermouse: Command timed out. status: 04 transaction_id.id: 1f remaining_packets: 00 protocol_type: 00 data_size: 03, command_class: 0f, command_id.id: 04 Params: 0101bf00000000000000000000000000 .
> kscreenlocker_greet[957590]: qt.qpa.wayland: Could not create EGL surface (EGL error 0x3000)
> kscreenlocker_greet[957590]: Failed to write to the pipe: Bad file descriptor.
> kwin_wayland[2751]: QObject::startTimer: Timers cannot have negative intervals

Then again on journalctl -b -2:

> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals
> openrazer-daemon[4602]: 2024-02-29 19:08:35 | razer.device0                  | INFO     | Resuming RazerHuntsmanElite
> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals
> kscreenlocker_greet[491184]: qt.qpa.wayland: Could not create EGL surface (EGL error 0x3000)
> openrazer-daemon[4602]: 2024-02-29 19:08:35 | razer.device0                  | INFO     | Putting device back into driver mode.
> openrazer-daemon[4602]: 2024-02-29 19:08:35 | razer.device1                  | INFO     | Resuming RazerNagaProWireless
> kscreenlocker_greet[491184]: qt.qpa.wayland: Could not create EGL surface (EGL error 0x3000)
> kscreenlocker_greet[491184]: qt.qpa.wayland: Could not create EGL surface (EGL error 0x3000)
> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals
> kernel: razermouse: Command timed out. status: 04 transaction_id.id: 1f remaining_packets: 00 protocol_type: 00 data_size: 03, command_class: 0f, command_id.id: 04 Params: 0100bf00000000000000000000000000 .
> kscreenlocker_greet[491184]: Failed to write to the pipe: Bad file descriptor.
> kernel: razermouse: Command timed out. status: 04 transaction_id.id: 1f remaining_packets: 00 protocol_type: 00 data_size: 03, command_class: 0f, command_id.id: 04 Params: 0104bf00000000000000000000000000 .
> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals
> kernel: razermouse: Command timed out. status: 04 transaction_id.id: 1f remaining_packets: 00 protocol_type: 00 data_size: 03, command_class: 0f, command_id.id: 04 Params: 0101bf00000000000000000000000000 .
> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals

On “journalctl -b -1” it didn't happened because I booted, updated and restarted.

But now on -b0:

> kwin_wayland[2318]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2318]: QObject::startTimer: Timers cannot have negative intervals
> openrazer-daemon[1909]: 2024-03-02 02:03:50 | razer.device0                  | INFO     | Resuming RazerHuntsmanElite
> kwin_wayland[2318]: QObject::startTimer: Timers cannot have negative intervals
> kscreenlocker_greet[1597482]: qt.qpa.wayland: Could not create EGL surface (EGL error 0x3000)
> openrazer-daemon[1909]: 2024-03-02 02:03:50 | razer.device0                  | INFO     | Putting device back into driver mode.
> openrazer-daemon[1909]: 2024-03-02 02:03:50 | razer.device1                  | INFO     | Resuming RazerNagaProWireless
> kscreenlocker_greet[1597482]: qt.qpa.wayland: Could not create EGL surface (EGL error 0x3000)
> kscreenlocker_greet[1597482]: qt.qpa.wayland: Could not create EGL surface (EGL error 0x3000)
> kwin_wayland[2318]: QObject::startTimer: Timers cannot have negative intervals
> kernel: razermouse: Command timed out. status: 04 transaction_id.id: 1f remaining_packets: 00 protocol_type: 00 data_size: 03, command_class: 0f, command_id.id: 04 Params: 01000000000000000000000000000000 .
> kscreenlocker_greet[1597482]: Failed to write to the pipe: Bad file descriptor.
> kernel: razermouse: Command timed out. status: 04 transaction_id.id: 1f remaining_packets: 00 protocol_type: 00 data_size: 03, command_class: 0f, command_id.id: 04 Params: 01040000000000000000000000000000 .
> kwin_wayland[2318]: QObject::startTimer: Timers cannot have negative intervals
> kernel: razermouse: Command timed out. status: 04 transaction_id.id: 1f remaining_packets: 00 protocol_type: 00 data_size: 03, command_class: 0f, command_id.id: 04 Params: 01010000000000000000000000000000 .
> kwin_wayland[2318]: QObject::startTimer: Timers cannot have negative intervals

It obviously happens when I lock my screen because it means I'm going to be away for a while (all my power saving settings are disabled, so no automatic screen lock). Despite that, it also may happen if I don't use my mouse or keyboard for a while (both are Razer devices), because restoring from powersave mode is enough to trigger it.

I thought it was not related at first because the messages were interleaving, but after seeing it happen more than 3 times, I'm very suspicious that those are related somehow.

Also, I have logs of the last 7 boots with Plasma 6, the other 2 ones were with Plasma 5, and the only occurrences of those messages are from Krita. I use journalctl daily, and I've never seen it happen before Plasma 6.

If there's anything else I can provide to help, please let me know.

System:

> Operating System: Arch Linux
> KDE Plasma Version: 6.0.0
> KDE Frameworks Version: 6.0.0
> Qt Version: 6.6.2
> Kernel Version: 6.7.6-arch1-2 (64-bit)
> Graphics Platform: Wayland
> Processors: 24 × AMD Ryzen 9 5900X 12-Core Processor
> Memory: 62,7 GiB of RAM
> Graphics Processor: AMD Radeon RX 6800  

If the others can confirm that they do have openrazer installed, or similar log messages from devices, it would be great.

Though I don't have a razer device, I can confirm that this issue only seems to pop up for me after a long while of inactivity on my machine (i.e. leaving it powered up over night). Rebooting solves it until the next period of inactivity.

My mouse is a Razer Basilisk V2, but I don't have openrazer running or anything like that.
And I do tend to sleep my machine every night.
Hope that helps.

I just did a test, I disabled Power Saving on my mouse and keyboard, left my machine idling for an hour, connected through SSH and checked journalctl, no messages there. I then proceed to unlock it and check journalctl again, and there it is, flooded with the messages, but no openrazer logs interleaving this time:

> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> systemd[1]: Starting Fingerprint Authentication Daemon...
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals

So the problem lies on something going to “idle” mode (or something like that), and then being restored back when Plasma is unlocked. The openrazer log being there was just a coincidence. Sadly, this log message does not tell much, I'm trying to find on KDE sources, but it's a lot to look into.

This happens on my Arch Linux system too. So far I haven't been able to find a way to reproduce it but I suspect it's got something to do with input system. My Razer Deathadder v2 Pro mouse has 2 connection modes I use. Bluetooth is 125hz and 2.4G is 1000hz. When connected through bluetooth, kwin_wayland floods journal less compared to 2.4G wireless mode. I'm guessing it's got something to do with 125 and 1000hz difference. When mouse is disconnected, journal is only flood with each keystore with keyboard.

I found a way to reliably reproduce it, and a way to reliably stop it from happening (although not an ideal one).

So, to make it happen, just lock the screen and move your mouse on the lock screen, then unlock. That's it. Now you have the journalctl flooded with this message.

And how to reliably stop it until the next boot?

> kill -9 $PID

Whereas $PID is the pid of the process causing the flood in the first place, so in my case I see this in my journal:

> kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals

I run:

> kill -9 2296

That's all. It'll not happen ever again until the next boot, you can lock and unlock freely. I tried to compare the processes open before and after killing kwin_wayland, but I didn't find anything relevant, other than kded5 in my case, I'll uninstall kded5 and try again, but I doubt it is the root cause.

(In reply to Jonathan Lopes from comment #11)
> I found a way to reliably reproduce it, and a way to reliably stop it from
> happening (although not an ideal one).
> 
> So, to make it happen, just lock the screen and move your mouse on the lock
> screen, then unlock. That's it. Now you have the journalctl flooded with
> this message.
> 
> And how to reliably stop it until the next boot?
> 
> > kill -9 $PID
> 
> Whereas $PID is the pid of the process causing the flood in the first place,
> so in my case I see this in my journal:
> 
> > kwin_wayland[2296]: QObject::startTimer: Timers cannot have negative intervals
> 
> I run:
> 
> > kill -9 2296
> 
> That's all. It'll not happen ever again until the next boot, you can lock
> and unlock freely. I tried to compare the processes open before and after
> killing kwin_wayland, but I didn't find anything relevant, other than kded5
> in my case, I'll uninstall kded5 and try again, but I doubt it is the root
> cause.

I forgot to mention, this will kill your entire kwin session, if you gonna do it, do right after booting the system, otherwise anything that's open, will be gone.

On the matter of kded5, I uninstalled it and tried again, still the same problem, but killing kwin solved it.

Cannot reproduce that on my all-Intel hardware, FWIW.

(In reply to Jonathan Lopes from comment #11)
> So, to make it happen, just lock the screen and move your mouse on the lock
> screen, then unlock

That is not enough for me. I can reproduce only by suspending and waking up my laptop.
Also, killing the kwin_wayland process helps only until the next suspend.
________
Operating System: KDE neon 6.0
KDE Plasma Version: 6.0.0
KDE Frameworks Version: 6.0.0
Qt Version: 6.6.2
Kernel Version: 5.15.0-97-generic (64-bit)
Graphics Platform: Wayland
Processors: 12 × AMD Ryzen 5 7530U with Radeon Graphics
Graphics Processor: AMD Radeon Graphics
Manufacturer: LENOVO
Product Name: 21KK
System Version: ThinkBook 16 G6 ABP
________

I was able to reproduce the bug consistently on my Intel+NVIDIA laptop, and it triggers as soon as the screen is locked and unlocked. Either waiting for the system to lock the screen automatically or manually using Meta+L and then immediately unlocking it.

STEPS TO REPRODUCE
1. Press Meta+L to lock screen;
2. Unlock screen, open user journal
3. Move mouse

OBSERVED RESULT
kwin_wayland outputs many  `kwin_wayland[5005]: QObject::startTimer: Timers cannot have negative intervals`.
This also leads to screen tearing flickering & performance degradation on the screen.

——————
Operating System: Arch Linux 
KDE Plasma Version: 6.0.0
KDE Frameworks Version: 6.0.0
Qt Version: 6.6.2
Kernel Version: 6.7.4-arch1-1.1-g14 (64-bit)
Graphics Platform: Wayland
Processors: 20 × 13th Gen Intel® Core™ i9-13900H
Memory: 31.0 GiB of RAM
Graphics Processor: Mesa Intel® Graphics
Manufacturer: ASUSTeK COMPUTER INC.
Product Name: ROG Zephyrus M16 GU604VI_GU604VI
System Version: 1.0
——————

(In reply to alex from comment #14)
> (In reply to Jonathan Lopes from comment #11)
> > So, to make it happen, just lock the screen and move your mouse on the lock
> > screen, then unlock
>
> That is not enough for me. I can reproduce only by suspending and waking up
> my laptop.
> Also, killing the kwin_wayland process helps only until the next suspend.

It seems that the behaviour is very inconsistent across systems. I've just made a clean installation of NixOS Unstable on my Laptop with KDE Plasma 6, and I cannot reproduce it there, only on my Arch Linux machine.

For now, I'm just restraining myself from locking my computer unless it's absolutely necessary. I don't have any power saving feature enabled, so it'll never sleep or lock the screen automatically. I've been running it for 2 days straight without locking or sleeping and the problem did not manifest.

(In reply to Nate Graham from comment #13)
> Cannot reproduce that on my all-Intel hardware, FWIW.

My laptop is a full Intel machine as well, and it doesn't happen there, but I'm afraid that this is something else. Since my Intel machine has a clean installation of NixOS that I just did this weekend, there are virtually zero things to interact with Plasma 6 that could be the main cause of this (it's only Plasma 6, kf6, Firefox and neovim).

If I had enough time, I could try to plug a debugger on kwin_wayland to find what is causing this problem. However, I have basically zero experience with C++ debugging (although I can figure out with basic directions), so even if I find some time to do it, I don't even know where to start.

Just to let you know, 6.0.1 has just hit Arch Linux's stable repositories today, but the problem is still reproducible.

> Operating System: Arch Linux 
> KDE Plasma Version: 6.0.1
> KDE Frameworks Version: 6.0.0
> Qt Version: 6.6.2
> Kernel Version: 6.7.8-arch1-1 (64-bit)
> Graphics Platform: Wayland
> Processors: 24 × AMD Ryzen 9 5900X 12-Core Processor
> Memory: 62,7 GiB of RAM
> Graphics Processor: AMD Radeon RX 6800

I'm also experiencing this issue on Arch Linux with Plasma 6, kwin 6.0.1.

I don't have anything related to Razer. I have Logitech wireless mouse.

I'm experiencing this on my system with any mouse movement. I have tried Razer Deathadder V2, Corsair SABRE RGB PRO, Logitech G102 and OG Microsoft Arc Mouse. Indeed killing the PID stops the spam, just like others.

Operating System: Fedora Linux 40
KDE Plasma Version: 6.0.0
KDE Frameworks Version: 6.0.0
Qt Version: 6.6.2
Kernel Version: 6.8.0-0.rc7.55.fc40.1.x86_64 (64-bit)
Graphics Platform: Wayland
Processors: 24 × AMD Ryzen 9 5900X 12-Core Processor
Memory: 31.3 GiB of RAM
Graphics Processor: AMD Radeon RX 7900 XTX
Manufacturer: Micro-Star International Co., Ltd.
Product Name: MS-7C84
System Version: 1.0

Please do not post "me too" comments unless you have valuable information that can help with reproducing or pinpointing the issue.

Created attachment 166630 [details]
kwin_wayland

(In reply to Jonathan Lopes from comment #16)
> [...]
> If I had enough time, I could try to plug a debugger on kwin_wayland to find
> what is causing this problem. However, I have basically zero experience with
> C++ debugging (although I can figure out with basic directions), so even if
> I find some time to do it, I don't even know where to start.

It's described in https://community.kde.org/KWin/Debugging#TL;DR_for_bug_reporters
But I think "continue" there is wrong, atleast that didn't work for me, but this worked fine
$ sudo -E gdb -pid (pidof kwin_wayland) -batch -ex "thread apply all backtrace"

See attachment, but here's main thread:

Thread 1 (Thread 0x758d15893a00 (LWP 1067690) "kwin_wayland"):
#0  0x0000758d1a719616 in __GI_ppoll (fds=fds@entry=0x63fa9f7f1d40, nfds=nfds@entry=10, timeout=<optimized out>, timeout@entry=0x7ffc058d01b0, sigmask=sigmask@entry=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:42
#1  0x0000758d1ae98deb in ppoll (__ss=<optimized out>, __timeout=<optimized out>, __nfds=<optimized out>, __fds=<optimized out>) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qcore_unix.cpp:123
#2  qt_ppoll (timeout_ts=0x7ffc058d01b0, nfds=10, fds=0x63fa9f7f1d40) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qcore_unix.cpp:126
#3  qt_ppoll (timeout_ts=0x7ffc058d01b0, nfds=10, fds=0x63fa9f7f1d40) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qcore_unix.cpp:123
#4  qt_safe_poll (fds=0x63fa9f7f1d40, nfds=nfds@entry=10, timeout_ts=timeout_ts@entry=0x7ffc058d0260) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qcore_unix.cpp:158
#5  0x0000758d1ae9f65a in QEventDispatcherUNIX::processEvents (this=<optimized out>, flags=..., flags@entry=...) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/tools/qarraydatapointer.h:113
#6  0x0000758d1b7b26e2 in QUnixEventDispatcherQPA::processEvents (this=<optimized out>, flags=...) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/gui/platform/unix/qunixeventdispatcher.cpp:27
#7  0x0000758d1ad43d6e in QEventLoop::processEvents (flags=..., this=0x7ffc058d03b0) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qeventloop.cpp:100
#8  QEventLoop::exec (this=0x7ffc058d03b0, flags=...) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qeventloop.cpp:182
#9  0x0000758d1ad3c2b8 in QCoreApplication::exec () at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/global/qflags.h:74
#10 0x0000758d1bcf0f0a in QApplication::exec () at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/widgets/kernel/qapplication.cpp:2574
#11 0x000063fa9c538dee in main (argc=<optimized out>, argv=<optimized out>) at /usr/src/debug/kwin/kwin-6.0.1/src/main_wayland.cpp:609


Currently for me this looks like one of the biggest issues for Plasma 6, because my today's journal size (just last ~7 hours) since I updated is already ~20 GiB (might be other log spam bugs aswell). And compare that with last 5 days (not counting today) when it's 26 GiB.  So basically now in single day I generate more logs than previously in a week...

`kwin_wayland` generates this warning at a rate of ~17 messages/second. Right now I have over 500k such entries in my journal while using Plasma 6 just for a day...

Created attachment 166664 [details]
gdb output from QObject::startTimer breakpoint

(In reply to Dāvis from comment #21)
> Created attachment 166630 [details]
> kwin_wayland
> 
> (In reply to Jonathan Lopes from comment #16)
> > [...]
> > If I had enough time, I could try to plug a debugger on kwin_wayland to find
> > what is causing this problem. However, I have basically zero experience with
> > C++ debugging (although I can figure out with basic directions), so even if
> > I find some time to do it, I don't even know where to start.
> 
> It's described in
> https://community.kde.org/KWin/Debugging#TL;DR_for_bug_reporters
> But I think "continue" there is wrong, atleast that didn't work for me, but
> this worked fine
> $ sudo -E gdb -pid (pidof kwin_wayland) -batch -ex "thread apply all
> backtrace"

I should've read the documentation first, would've saved me a lot of time, but there it is, I've attached the backtrace from two calls to QObject::startTimer with a negative interval, both points to the same location:

> #0  QObject::startTimer
>     (this=0x58f34afb5dc0, interval=std::chrono::duration = { -1ms }, timerType=Qt::CoarseTimer)
>     at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qobject.cpp:1883
> #1  0x000077a34d9991f7 in QTimer::start (this=0x58f34afb5dc0)
>     at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qtimer.cpp:192
> #2  0x000077a3502041ee in KWin::IdleDetector::activity (this=0x58f34bc25920)
>     at /usr/src/debug/kwin/kwin-6.0.1/src/idledetector.cpp:53
> #3  KWin::IdleDetector::activity (this=0x58f34bc25920)
>     at /usr/src/debug/kwin/kwin-6.0.1/src/idledetector.cpp:50
> #4  0x000077a35021636d in KWin::InputRedirection::simulateUserActivity
>     (this=<optimized out>)
>     at /usr/src/debug/kwin/kwin-6.0.1/src/input.cpp:3235

Could you please add a breakpoint in KWin::IdleDetector::IdleDetector constructor? I wonder who passes -1 timeout to the IdleDetector.

if my theory is correct, it's KWinIdleTimePoller::addTimeout; the idle and the idle-notify-v1 protocols have uint32_t timeout values.

(In reply to Vlad Zahorodnii from comment #23)
> Could you please add a breakpoint in KWin::IdleDetector::IdleDetector
> constructor? I wonder who passes -1 timeout to the IdleDetector.

Relevant C++ code just in case: https://invent.kde.org/plasma/kwin/-/blob/Plasma/6.0/src/idledetector.cpp?ref_type=heads#L13

Can somebody share their ~/.config/kscreenlockerrc file please?

A possibly relevant merge request was started @ https://invent.kde.org/plasma/kwin/-/merge_requests/5386

I just noticed that my journal got flooded with several dozens of GiBs with this message, all night long :(((
This always starts after locking the screen for the first time and keeps logging until `kwin_wayland` gets terminated/killed. It doesn't matter if the lock screen is just showing a static image or a slideshow.

(In reply to Vlad Zahorodnii from comment #26)
> Can somebody share their ~/.config/kscreenlockerrc file please?

```
[$Version]
update_info=kscreenlocker.upd:0.1-autolock

[Daemon]
Autolock=false

[Greeter]
WallpaperPlugin=org.kde.slideshow

[Greeter][Wallpaper][org.kde.image][General]
Image=/usr/share/wallpapers/DarkestHour/
PreviewImage=/usr/share/wallpapers/DarkestHour/

[Greeter][Wallpaper][org.kde.slideshow][General]
SlideInterval=10
SlidePaths=/media/downloads/wallpapers/lockscreen/
UncheckedSlides=LONG LIST OF COMMA-SEPARATED file://URLs OF EXCLUDED IMAGES
```

(In reply to Bug Janitor Service from comment #27)
> A possibly relevant merge request was started @
> https://invent.kde.org/plasma/kwin/-/merge_requests/5386

I've included this commit (18e414443e500e39bb1ecc3244fceeebb63ceadd) in my kwin build, but it's still flooding the journal after locking the screen

A possibly relevant merge request was started @ https://invent.kde.org/frameworks/kidletime/-/merge_requests/46

> I've included this commit (18e414443e500e39bb1ecc3244fceeebb63ceadd) in my kwin build, but it's still flooding the journal after locking the screen

This is rather a sanity check. You could help my building kwin in the debug mode. Then the assert would trigger when kwin receives an invalid timeout value.

Git commit 18e414443e500e39bb1ecc3244fceeebb63ceadd by Vlad Zahorodnii.
Committed on 08/03/2024 at 09:09.
Pushed by vladz into branch 'master'.

Add timeout assert in IdleDetector

M  +3    -0    src/idledetector.cpp

https://invent.kde.org/plasma/kwin/-/commit/18e414443e500e39bb1ecc3244fceeebb63ceadd

Can somebody share their ~/.config/powerdevilrc alongside with ~/.config/kscreenlockerrc please?

(In reply to Vlad Zahorodnii from comment #30)
> > I've included this commit (18e414443e500e39bb1ecc3244fceeebb63ceadd) in my kwin build, but it's still flooding the journal after locking the screen
> 
> This is rather a sanity check. You could help my building kwin in the debug
> mode. Then the assert would trigger when kwin receives an invalid timeout
> value.

I can have a look as soon as I get the time this afternoon...

----

(In reply to Vlad Zahorodnii from comment #32)
> Can somebody share their ~/.config/powerdevilrc alongside with
> ~/.config/kscreenlockerrc please?

powerdevilrc
```
[AC][Display]
TurnOffDisplayWhenIdle=false

[AC][SuspendAndShutdown]
AutoSuspendAction=0
LidAction=0
PowerButtonAction=0
PowerDownAction=0

[BatteryManagement]
BatteryCriticalAction=1
```

kscreenlockerrc
comment #28

(In reply to Vlad Zahorodnii from comment #32)
> Can somebody share their ~/.config/powerdevilrc alongside with
> ~/.config/kscreenlockerrc please?

~/.config/powerdevilrc
> [AC][Display]
> DimDisplayWhenIdle=false
> TurnOffDisplayWhenIdle=false
> 
> [AC][Keyboard]
> KeyboardBrightness=0
> UseProfileSpecificKeyboardBrightness=true
> 
> [AC][SuspendAndShutdown]
> AutoSuspendAction=0
> 
> [Battery][Keyboard]
> KeyboardBrightness=0
> UseProfileSpecificKeyboardBrightness=true

~/.config/kscreenlockerrc 
> [Daemon]
> Autolock=false
> 
> [Greeter][Wallpaper][org.kde.image][General]
> Image=/home/reverier/*****/**.png
> PreviewImage=/home/reverier/*****/**.png

I disabled Autolock to prevent this bug.

Git commit e2cbed70609d6505e8c8a89d70373d9fc5f0c2f4 by Vlad Zahorodnii.
Committed on 08/03/2024 at 11:12.
Pushed by vladz into branch 'master'.

Port IdleDetector to QBasicTimer

QBasicTimer is lighter and it properly handles timeout values bigger
than INT32_MAX.

M  +13   -8    src/idledetector.cpp
M  +7    -2    src/idledetector.h

https://invent.kde.org/plasma/kwin/-/commit/e2cbed70609d6505e8c8a89d70373d9fc5f0c2f4

A possibly relevant merge request was started @ https://invent.kde.org/plasma/kwin/-/merge_requests/5389

Git commit 68a1e22b643e04cbe813108e4b1c5ec2460b097e by Vlad Zahorodnii.
Committed on 08/03/2024 at 11:36.
Pushed by vladz into branch 'master'.

Guard against invalid timeout values in KIdleTime::addTimeout()

The screenlocker converts user provided minutes to milliseconds.
kscreenlocker has a check to guard against negative timeouts, but
"timeout * 1000 * 60" can overflow.

M  +4    -0    src/kidletime.cpp

https://invent.kde.org/frameworks/kidletime/-/commit/68a1e22b643e04cbe813108e4b1c5ec2460b097e

Git commit aef8796c723e8ec40c19580b2147708aacfb59b0 by Vlad Zahorodnii.
Committed on 08/03/2024 at 11:27.
Pushed by vladz into branch 'Plasma/6.0'.

Port IdleDetector to QBasicTimer

QBasicTimer is lighter and it properly handles timeout values bigger
than INT32_MAX.
(cherry picked from commit e2cbed70609d6505e8c8a89d70373d9fc5f0c2f4)

M  +13   -8    src/idledetector.cpp
M  +7    -2    src/idledetector.h

https://invent.kde.org/plasma/kwin/-/commit/aef8796c723e8ec40c19580b2147708aacfb59b0

Git commit 18882eefdecf638e9421116b639bb16a2fca8ce3 by Vlad Zahorodnii.
Committed on 08/03/2024 at 11:26.
Pushed by vladz into branch 'Plasma/6.0'.

Add timeout assert in IdleDetector
(cherry picked from commit 18e414443e500e39bb1ecc3244fceeebb63ceadd)

M  +3    -0    src/idledetector.cpp

https://invent.kde.org/plasma/kwin/-/commit/18882eefdecf638e9421116b639bb16a2fca8ce3

I _think_ that with the patches above kwin should stop flooding the logs with messages about negative timer interval. BUT somebody still tries to pass a negative idle interval to kwin, which means that _some_ plasma functionality may still not work properly.

I've tried using kscreenlocker and powerdevil settings that kind people in this bug report have provided but I'm still unable to reproduce the bug. So if somebody can build kwin (I can provide patches with qDebug messages) or comfortable with using gdb, it would be very very appreciated if somebody could check who passes negative or (too big?) interval values to the IdleDetector constructor, i.e. https://bugs.kde.org/show_bug.cgi?id=482077#c23

I could only observe the log flooding with the screen locker. Applying the two commits
- 18882eefdecf638e9421116b639bb16a2fca8ce3
- aef8796c723e8ec40c19580b2147708aacfb59b0
to 6.0.1 fixed the issue for me.
I don't have any experience with gdb, so I can't help here, sorry.

Created attachment 166709 [details]
patch

can somebody apply the following patch, try to reproduce the bug, and then post kwin_wayland's log output

(In reply to bastimeyer123 from comment #41)
> I could only observe the log flooding with the screen locker. Applying the
> two commits
> - 18882eefdecf638e9421116b639bb16a2fca8ce3
> - aef8796c723e8ec40c19580b2147708aacfb59b0
> to 6.0.1 fixed the issue for me.
> I don't have any experience with gdb, so I can't help here, sorry.

That's okay, can you apply that patch and post kwin's output? Hopefully it's going to help to narrow down who tries to request an idle notification with invalid timeout value

Hmm my backtrace is different than Jonathan's.

#0  KWin::IdleDetector::IdleDetector (this=0x55b8773c4220, timeout=std::chrono::duration = { 4294967295ms }, parent=0x55b877124e50, this=<optimized out>, timeout=std::chrono::duration = { <optimized out>ms }, parent=<optimized out>) at /usr/src/debug/kwin/kwin-6.0.1/src/idledetector.cpp:13
#1  0x00007d066e8580d6 in KWin::IdleNotificationV1Interface::IdleNotificationV1Interface (timeout=std::chrono::duration = { <optimized out>ms }, id=<optimized out>, version=1, client=<optimized out>, this=0x55b877124e50) at /usr/src/debug/kwin/kwin-6.0.1/src/wayland/idlenotify_v1.cpp:59
#2  KWin::IdleNotifyV1InterfacePrivate::ext_idle_notifier_v1_get_idle_notification (this=<optimized out>, resource=<optimized out>, id=<optimized out>, timeout=<optimized out>, seat=<optimized out>) at /usr/src/debug/kwin/kwin-6.0.1/src/wayland/idlenotify_v1.cpp:53
#3  0x00007d066a230596 in ffi_call_unix64 () at ../src/x86/unix64.S:104
#4  0x00007d066a22d00e in ffi_call_int (cif=cif@entry=0x7ffd7e8cfa00, fn=<optimized out>, rvalue=<optimized out>, avalue=<optimized out>, closure=closure@entry=0x0) at ../src/x86/ffi64.c:673
#5  0x00007d066a22fbd3 in ffi_call (cif=cif@entry=0x7ffd7e8cfa00, fn=<optimized out>, rvalue=rvalue@entry=0x0, avalue=avalue@entry=0x7ffd7e8cfad0) at ../src/x86/ffi64.c:710
#6  0x00007d066db1bada in wl_closure_invoke (closure=closure@entry=0x55b877c2f510, target=<optimized out>, target@entry=0x55b876c7f520, opcode=opcode@entry=1, data=<optimized out>, data@entry=0x55b876a3fa80, flags=2) at ../wayland-1.22.0/src/connection.c:1025
#7  0x00007d066db20180 in wl_client_connection_data (fd=<optimized out>, mask=<optimized out>, data=<optimized out>) at ../wayland-1.22.0/src/wayland-server.c:438
#8  0x00007d066db1eae2 in wl_event_loop_dispatch (loop=0x55b875540920, timeout=<optimized out>) at ../wayland-1.22.0/src/event-loop.c:1027
#9  0x00007d066e848487 in KWin::Display::dispatchEvents (this=<optimized out>) at /usr/src/debug/kwin/kwin-6.0.1/src/wayland/display.cpp:118
#10 0x00007d066bf90ca9 in QtPrivate::QSlotObjectBase::call (a=0x7ffd7e8d0110, r=0x55b875540670, this=0x55b875aa3330, this=<optimized out>, r=<optimized out>, a=<optimized out>) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qobjectdefs_impl.h:433
#11 doActivate<false> (sender=0x55b8758cb410, signal_index=3, argv=0x7ffd7e8d0110) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qobject.cpp:4039
#12 0x00007d066bf98530 in QSocketNotifier::activated (_t3=..., _t2=<optimized out>, _t1=..., this=0x55b8758cb410) at /usr/src/debug/qt6-base/build/src/corelib/Core_autogen/include/moc_qsocketnotifier.cpp:231
#13 QSocketNotifier::event (this=0x55b8758cb410, e=<optimized out>) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qsocketnotifier.cpp:326
#14 0x00007d066cef438b in QApplicationPrivate::notify_helper (this=<optimized out>, receiver=0x55b8758cb410, e=0x7ffd7e8d0210) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/widgets/kernel/qapplication.cpp:3296
#15 0x00007d066bf39818 in QCoreApplication::notifyInternal2 (receiver=0x55b8758cb410, event=0x7ffd7e8d0210) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qcoreapplication.cpp:1121
#16 0x00007d066c09e749 in QCoreApplication::sendEvent (event=0x7ffd7e8d0210, receiver=<optimized out>) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qcoreapplication.cpp:1539
#17 QEventDispatcherUNIXPrivate::activateSocketNotifiers (this=this@entry=0x55b8754712b0) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qeventdispatcher_unix.cpp:267
#18 0x00007d066c09fbac in QEventDispatcherUNIX::processEvents (this=<optimized out>, flags=..., flags@entry=...) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qeventdispatcher_unix.cpp:476
#19 0x00007d066c9b26e2 in QUnixEventDispatcherQPA::processEvents (this=<optimized out>, flags=...) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/gui/platform/unix/qunixeventdispatcher.cpp:27
#20 0x00007d066bf43d6e in QEventLoop::processEvents (flags=..., this=0x7ffd7e8d03f0) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qeventloop.cpp:100
#21 QEventLoop::exec (this=0x7ffd7e8d03f0, flags=...) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qeventloop.cpp:182
#22 0x00007d066bf3c2b8 in QCoreApplication::exec () at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/global/qflags.h:74
#23 0x00007d066cef0f0a in QApplication::exec () at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/widgets/kernel/qapplication.cpp:2574
#24 0x000055b8740b4dee in main (argc=<optimized out>, argv=<optimized out>) at /usr/src/debug/kwin/kwin-6.0.1/src/main_wayland.cpp:609


It looks like some application is using ext_idle_notifier_v1::get_idle_notification() with 4294967295ms as timeout value, it's uint so this is kinda valid...
I don't know how to find out who is sending this message? But it seems like assert() would be wrong for this case and KWin probably should just drop such silly request.

Nothing special in my config:

$ cat ~/.config/powerdevilrc
[AC][Display]
TurnOffDisplayWhenIdle=false

[AC][SuspendAndShutdown]
AutoSuspendAction=0

[Battery][Display]
DisplayBrightness=60
UseProfileSpecificDisplayBrightness=true


$ cat ~/.config/kscreenlockerrc
[$Version]
update_info=kscreenlocker.upd:0.1-autolock

[Daemon]
Autolock=true
LockOnResume=true

[Greeter][Wallpaper][org.kde.image][General]
SlidePaths=/usr/share/wallpapers


Also to reproduce set lock screen time to 1min, then wait till lock screen comes and move mouse to unlock - now I start getting spammed.

(In reply to Vlad Zahorodnii from comment #23)
> Could you please add a breakpoint in KWin::IdleDetector::IdleDetector
> constructor? I wonder who passes -1 timeout to the IdleDetector.

I'll try to do this right now, give me a couple of minutes.

(In reply to Vlad Zahorodnii from comment #32)
> Can somebody share their ~/.config/powerdevilrc alongside with
> ~/.config/kscreenlockerrc please?

> cat ~/.config/kscreenlockerrc
> [$Version]
> update_info=kscreenlocker.upd:0.1-autolock
> 
> [Daemon]
> Autolock=false
> Timeout=20

> cat ~/.config/powerdevilrc
> [AC][Display]
> DimDisplayWhenIdle=false
> TurnOffDisplayWhenIdle=false
> 
> [AC][SuspendAndShutdown]
> AutoSuspendAction=0
> PowerButtonAction=0
> 
> [BatteryManagement]
> BatteryCriticalAction=1

> It looks like some application is using ext_idle_notifier_v1::get_idle_notification() with 4294967295ms as timeout value, it's uint so this is kinda valid...

can you apply the patch that I've attached to the bug report. it's going to be print the executable path and the pid of the offender

Created attachment 166711 [details]
Kwin IdleDetector breakpoint

(In reply to Vlad Zahorodnii from comment #23)
> Could you please add a breakpoint in KWin::IdleDetector::IdleDetector
> constructor? I wonder who passes -1 timeout to the IdleDetector.

There it is. I compiled kwin v6.0.1 from source and added a breakpoint on the constructor. I'll apply your patch and test it again.

(In reply to Vlad Zahorodnii from comment #46)
> > It looks like some application is using ext_idle_notifier_v1::get_idle_notification() with 4294967295ms as timeout value, it's uint so this is kinda valid...
> 
> can you apply the patch that I've attached to the bug report. it's going to
> be print the executable path and the pid of the offender

Done, this is what I get after locking and unlocking:

> kwin_wayland[2289]: "" 2652 wants an idle notification with too big timeout 4294967295

2652 is powerdevil

> $ ps -p 2652 -o command
> COMMAND
> /usr/lib/org_kde_powerdevil

(In reply to Jonathan Lopes from comment #48)
> 2652 is powerdevil
> 
> > $ ps -p 2652 -o command
> > COMMAND
> > /usr/lib/org_kde_powerdevil

Hmm, can you attach gdb to powerdevil and add a breakpoint in KIdleTime::addIdleTimeout please?

It looks like a regression after https://invent.kde.org/plasma/powerdevil/-/merge_requests/301/diffs

powerdevil used to have "timeout > 0" guards, which are missing now

Created attachment 166718 [details]
powerdevil.gdb

(In reply to Vlad Zahorodnii from comment #49)
> (In reply to Jonathan Lopes from comment #48)
> > 2652 is powerdevil
> > 
> > > $ ps -p 2652 -o command
> > > COMMAND
> > > /usr/lib/org_kde_powerdevil
> 
> Hmm, can you attach gdb to powerdevil and add a breakpoint in
> KIdleTime::addIdleTimeout please?

Sure. 

I noticed that if I enable my Energy Saving settings and then disable, this prevents the problem from happening until the next boot (but only if you change before the flood starts, it won't help if it's already flooding the logs). I looked at the source code and I found this relevant section:

https://invent.kde.org/plasma/powerdevil/-/blob/Plasma/6.0/daemon/actions/bundled/dpms.cpp?ref_type=heads#L220-227

There's no condition to check if the setting is enabled in the first place, while this one:

https://invent.kde.org/plasma/powerdevil/-/blob/Plasma/6.0/daemon/actions/bundled/dpms.cpp?ref_type=heads#L177-179

Which supports my first attempt to add a breakpoint to powerdevil after having changed its settings, when I enabled, it loaded the default values in memory, when I disabled, those values were not reset. But after rebooting, the problem was back since those values will not be set as the setting is disabled.

That's my guess, I don't really know if this is indeed the cause of the problem, but it looks like.

Does have a check.

(In reply to Jonathan Lopes from comment #51)
> Does have a check.

Ignore this last line, I mistakenly moved it to the end lmao.

Just a follow up, I just achieved to reproduce the same thing on my NixOS laptop, which was not suffering from this.

On Energy Saving settings, deselect “Turn Off screen” on all modes: On AC Power, On Batter and On Low Battery (it might not be needed to change all of them, but this was what I did), then reboot, if you lock and unlock, this problem will happen (locking is enough actually).

Yeah, with that, I'm able to reproduce the bug \o/

(In reply to Vlad Zahorodnii from comment #46)
> > It looks like some application is using ext_idle_notifier_v1::get_idle_notification() with 4294967295ms as timeout value, it's uint so this is kinda valid...
> 
> can you apply the patch that I've attached to the bug report. it's going to
> be print the executable path and the pid of the offender

I built KWin with that patch but didn't notice any extra log entries, then realized I didn't build debug build oops
Now with debug build I see same 

> "" 3469 wants an idle notification with too big timeout 4294967295
where 3469 is `org_kde_powerdevil`

But I disagree that this is Powerdevil's bug. KWin should either respect this and notify after ~50days or ignore it and potentially let application know this in some way.

Powerdevil doing some stupid shit is just another bug - of course should be fixed but that doesn't mean KWin shouldn't be fixed aswell because ANY application can send garbage to it.


(In reply to Vlad Zahorodnii from comment #49)
> 
> Hmm, can you attach gdb to powerdevil and add a breakpoint in
> KIdleTime::addIdleTimeout please?

Here

> #0  KIdleTime::addIdleTimeout (this=0x5e5e8b5506f0, msec=msec@entry=-1) at /usr/src/debug/kidletime/kidletime-6.0.0/src/kidletime.cpp:119
> #1  0x00007092748f3cf4 in KIdleTime::addIdleTimeout (msec=std::chrono::duration = { -1ms }, this=<optimized out>) at /usr/include/c++/13.2.1/bits/chrono.h:587
> #2  PowerDevil::Core::registerActionTimeout (this=0x709258002470, action=<optimized out>, timeout=std::chrono::duration = { <optimized out>ms }) at /usr/src/debug/powerdevil/powerdevil-6.0.1/daemon/powerdevilcore.cpp:848
> #3  0x0000709273790ca9 in QtPrivate::QSlotObjectBase::call (a=0x7ffc048b8890, r=0x5e5e8b4ce400, this=0x5e5e8b4f9b10, this=<optimized out>, r=<optimized out>, a=<optimized out>) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qobjectdefs_impl.h:433
> #4  doActivate<false> (sender=0x5e5e8b4b8a20, signal_index=6, argv=0x7ffc048b8890) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qobject.cpp:4039
> #5  0x000070927490dbe7 in PowerDevil::PolicyAgent::screenLockerActiveChanged (this=<optimized out>, _t1=<optimized out>) at /usr/src/debug/powerdevil/build/daemon/powerdevilcore_autogen/include/moc_powerdevilpolicyagent.cpp:425
> #6  0x0000709274905115 in PowerDevil::PolicyAgent::onScreenLockerActiveChanged (this=0x5e5e8b4b8a20, active=true) at /usr/src/debug/powerdevil/powerdevil-6.0.1/daemon/powerdevilpolicyagent.cpp:577
> #7  0x0000709273790ca9 in QtPrivate::QSlotObjectBase::call (a=0x7ffc048b8ac0, r=0x5e5e8b4b8a20, this=0x5e5e8b5d9ce0, this=<optimized out>, r=<optimized out>, a=<optimized out>) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qobjectdefs_impl.h:433
> #8  doActivate<false> (sender=0x5e5e8b5da460, signal_index=3, argv=0x7ffc048b8ac0) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qobject.cpp:4039
> #9  0x0000709274922bdb in OrgFreedesktopScreenSaverInterface::ActiveChanged (_t1=<optimized out>, this=<optimized out>) at /usr/src/debug/powerdevil/build/daemon/moc_screenlocker_interface.cpp:304
> #10 OrgFreedesktopScreenSaverInterface::qt_static_metacall (_o=_o@entry=0x5e5e8b5da460, _id=_id@entry=0, _a=_a@entry=0x7ffc048b8c88, _c=<optimized out>) at /usr/src/debug/powerdevil/build/daemon/moc_screenlocker_interface.cpp:235
> #11 0x00007092749278b1 in OrgFreedesktopScreenSaverInterface::qt_static_metacall (_a=0x7ffc048b8c88, _id=0, _c=QMetaObject::InvokeMetaMethod, _o=0x5e5e8b5da460) at /usr/src/debug/powerdevil/build/daemon/moc_screenlocker_interface.cpp:229
> #12 OrgFreedesktopScreenSaverInterface::qt_metacall (this=0x5e5e8b5da460, _c=QMetaObject::InvokeMetaMethod, _id=0, _a=0x7ffc048b8c88) at /usr/src/debug/powerdevil/build/daemon/moc_screenlocker_interface.cpp:290
> #13 0x00007092745f70ce in QDBusConnectionPrivate::deliverCall (this=0x7092640016a0, object=0x5e5e8b5da460, msg=..., metaTypes=<optimized out>, slotIdx=6) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/dbus/qdbusintegrator.cpp:977
> #14 0x000070927377c2c7 in QObject::event (this=0x5e5e8b5da460, e=0x709264031bc0) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qobject.cpp:1437
> #15 0x0000709273739818 in QCoreApplication::notifyInternal2 (receiver=0x5e5e8b5da460, event=event@entry=0x709264031bc0) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qcoreapplication.cpp:1121
> #16 0x0000709273739b9b in QCoreApplication::sendEvent (event=0x709264031bc0, receiver=<optimized out>) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qcoreapplication.cpp:1539
> #17 QCoreApplicationPrivate::sendPostedEvents (receiver=0x0, event_type=0, data=0x5e5e8b2ac900) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qcoreapplication.cpp:1901
> #18 0x00007092739758a4 in QCoreApplication::sendPostedEvents (receiver=0x0, event_type=0) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qcoreapplication.cpp:1760
> #19 postEventSourceDispatch (s=0x5e5e8b2aeae0) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qeventdispatcher_glib.cpp:243
> #20 0x0000709271f0df69 in g_main_dispatch (context=0x709264000ef0) at ../glib/glib/gmain.c:3476
> #21 0x0000709271f6c3a7 in g_main_context_dispatch_unlocked (context=0x709264000ef0) at ../glib/glib/gmain.c:4284
> #22 g_main_context_iterate_unlocked.isra.0 (context=context@entry=0x709264000ef0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/glib/gmain.c:4349
> #23 0x0000709271f0c162 in g_main_context_iteration (context=0x709264000ef0, may_block=1) at ../glib/glib/gmain.c:4414
> #24 0x00007092739739c4 in QEventDispatcherGlib::processEvents (this=0x5e5e8b2ae9f0, flags=...) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qeventdispatcher_glib.cpp:393
> #25 0x0000709273743d6e in QEventLoop::processEvents (flags=..., this=0x7ffc048b92a0) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qeventloop.cpp:100
> #26 QEventLoop::exec (this=0x7ffc048b92a0, flags=...) at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/kernel/qeventloop.cpp:182
> #27 0x000070927373c2b8 in QCoreApplication::exec () at /usr/src/debug/qt6-base/qtbase-everywhere-src-6.6.2/src/corelib/global/qflags.h:74
> #28 0x00005e5e8afb673f in main (argc=<optimized out>, argv=<optimized out>) at /usr/src/debug/powerdevil/powerdevil-6.0.1/daemon/powerdevilapp.cpp:165


Another interesting thing I found that if you restart KWin then it doesn't happen anymore, maybe because Powerdevil stops working?
This is what Powerdevil says after KWin restart

> The Wayland connection broke. Did the Wayland compositor die?
> qt.qpa.wayland: Attempting wayland reconnect
> Failed to write to the pipe: Bad file descriptor.
> qt.qpa.wayland: Creating a fake screen in order for Qt not to crash


But now if I restart Powerdevil (/usr/lib/org_kde_powerdevil --replace) then it starts happening again.


Also btw I see these messages in Powerdevil aswell

> org.kde.powerdevil: org.kde.powerdevil.chargethresholdhelper.getthreshold failed "Charge thresholds are not supported by the kernel for this hardware"
> org.kde.powerdevil: org.kde.powerdevil.backlighthelper.brightness failed
> org.kde.powerdevil: Handle button events action could not check for screen configuration

(In reply to Dāvis from comment #55)
> But I disagree that this is Powerdevil's bug. KWin should either respect
> this and notify after ~50days or ignore it and potentially let application
> know this in some way.
> 
> Powerdevil doing some stupid shit is just another bug - of course should be
> fixed but that doesn't mean KWin shouldn't be fixed aswell because ANY
> application can send garbage to it.

I think this was already addressed by this commit:

https://invent.kde.org/frameworks/kidletime/-/commit/68a1e22b643e04cbe813108e4b1c5ec2460b097e

(In reply to Vlad Zahorodnii from comment #50)
> It looks like a regression after
> https://invent.kde.org/plasma/powerdevil/-/merge_requests/301/diffs
> 
> powerdevil used to have "timeout > 0" guards, which are missing now

I didn't see your message but I think we both found the same thing. Thanks for looking out Vlad Zahorodnii, now it's just a matter of time until it's fixed. Thank everyone as well for helping!

> but that doesn't mean KWin shouldn't be fixed

kwin's already fixed, see commits above. It's just that powerdevil has to be fixed now so it doesn't pass garbage values to KIdleTime::addIdleTimeout(). If you update plasma to 6.0.2, kwin will not flood the logs (regardless whether powerdevil is fixed).

for me, it seems to stop the logging if i run `systemctl --user restart plasma-powerdevil.service`

if i lock my session, then unlock, it starts logging the "negative timer" events again.

anyways, for now that works for me. thanks!

also, I can follow the events using the script below running in a terminal.  this is helpful to me.

```sh
#!/bin/sh
i=0
journalctl -f | grep -e 'QObject::startTimer' | while read log
do
  i=$((i + 1))
  if [ $((i % 10)) -eq 9 ]; then
    echo $(date -u --iso-8601=seconds) :: $i :: $log
  fi
done
```

It looks like the culprit in the PowerDevil code is the same as the one that's causing unintended screen turn-off as per Bug 481308. I've submitted a merge request at https://invent.kde.org/plasma/powerdevil/-/merge_requests/332 to fix that bug, and will add a reference to this bug in the commit message as well. Sorry for causing this in the first place.

*** Bug 483158 has been marked as a duplicate of this bug. ***

Git commit be2b83615d879549ecf9a47b66dc66887419a2dc by Jakob Petsovits.
Committed on 12/03/2024 at 03:47.
Pushed by nicolasfella into branch 'master'.

actions/dpms: Ignore turn-off triggers when action is disabled

Early Plasma 6.0 releases saw many people reporting unintentional
screen turn-off when the screen locker activates/deactivates,
and when the system wakes up from sleep. On X11, this was visible
to the user immediately, whereas on Wayland it spammed system logs
with warnings of invalid -1 idle timeout registrations.

Ironically, this behavior would occur specifically when the DPMS
action (a.k.a. "When locked, turn screen off") was disabled.

The reason is that the DPMS object gets created either way, and
sets up its screen locker activation change handler as well as
suspend/resume handlers in the constructor. But timeout values
can remain invalid until the action is loaded/enabled and
timeout values are populated from profile settings.
Using invalid timeouts in these handlers caused this headache.

This bug was introduced by commit c58085b4, which fixed a bunch of
things, bug also removed checks for invalid timeout values.
Turns out we still need some kind of checks.

We now prevent bad timeout registrations by interpreting negative
values in m_idleTimeoutWhenUnlocked as "idle timeout disabled".
Checks for this value ensure that registerIdleTimeout() is only
called when the action is loaded, regardless of whether it's
triggered by screen locker changing its activation status,
resume after suspend, or any other event.

Alternatively, we could have also moved some signal connections
into loadAction() and disconnected them in onProfileUnload().
Checking on every registration call seems more robust though.
Related: bug 481308

M  +24   -10   daemon/actions/bundled/dpms.cpp
M  +1    -0    daemon/actions/bundled/dpms.h

https://invent.kde.org/plasma/powerdevil/-/commit/be2b83615d879549ecf9a47b66dc66887419a2dc

Git commit a150b9fa622b71420d3c231eb87be695d3f96483 by Nicolas Fella, on behalf of Jakob Petsovits.
Committed on 12/03/2024 at 11:15.
Pushed by nicolasfella into branch 'Plasma/6.0'.

actions/dpms: Ignore turn-off triggers when action is disabled

Early Plasma 6.0 releases saw many people reporting unintentional
screen turn-off when the screen locker activates/deactivates,
and when the system wakes up from sleep. On X11, this was visible
to the user immediately, whereas on Wayland it spammed system logs
with warnings of invalid -1 idle timeout registrations.

Ironically, this behavior would occur specifically when the DPMS
action (a.k.a. "When locked, turn screen off") was disabled.

The reason is that the DPMS object gets created either way, and
sets up its screen locker activation change handler as well as
suspend/resume handlers in the constructor. But timeout values
can remain invalid until the action is loaded/enabled and
timeout values are populated from profile settings.
Using invalid timeouts in these handlers caused this headache.

This bug was introduced by commit c58085b4, which fixed a bunch of
things, bug also removed checks for invalid timeout values.
Turns out we still need some kind of checks.

We now prevent bad timeout registrations by interpreting negative
values in m_idleTimeoutWhenUnlocked as "idle timeout disabled".
Checks for this value ensure that registerIdleTimeout() is only
called when the action is loaded, regardless of whether it's
triggered by screen locker changing its activation status,
resume after suspend, or any other event.

Alternatively, we could have also moved some signal connections
into loadAction() and disconnected them in onProfileUnload().
Checking on every registration call seems more robust though.
Related: bug 481308
(cherry picked from commit be2b83615d879549ecf9a47b66dc66887419a2dc)

M  +24   -10   daemon/actions/bundled/dpms.cpp
M  +1    -0    daemon/actions/bundled/dpms.h

https://invent.kde.org/plasma/powerdevil/-/commit/a150b9fa622b71420d3c231eb87be695d3f96483