Bug 504487

Created attachment 181472 [details]
New crash information added by DrKonqi

DrKonqi auto-attaching complete backtrace.

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

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

(In reply to Roke Julian Lockhart Beedell from comment #3)

I've reported about 30 instances of this to Sentry across about 30 different applications. However, I can't access Sentry, so can't link them here. Instead, I tried to put a link to this, and useful description, in each report. Otherwise, see https://bugzilla.redhat.com/show_bug.cgi?id=2367102#c0 and its linked reports for FAF data. If you wait > P6M, though, the FAF data shall be gone (although their RHBZ reports shall remain).

Created attachment 181477 [details]
A Screenshot Of The Affected Button In The Affected Modal Window

Created attachment 181478 [details]
A Reproduction Screencast (In KHelpCenter)

(In reply to Roke Julian Lockhart Beedell from comment #4)

Of note is that despite this affecting:

1. KWalletManager

2. Okular

3. KMenuEdit

4. KRFB

5. KRDC

6. Konsole

7. KGPG

8. KDE Partition Manager

9. KCharSelect

10. KAddressBook

11. Gwenview

12. Dolphin

13. DigiKam

14. KDenLive

15. KHelpCenter

This *does not* affect Krita, nor SkanPage, no matter what I try. IDK what differs about them.

For me the Print dialog appears, and while it's open, I can't close the Keyboard Shortcuts window.

It may take a little bit of time for the Print dialog to appear; maybe that's what's happening? If you wait 10 or 15 seconds, does it eventually appear?

(In reply to Nate Graham from comment #7)

> If you wait 10 or 15 seconds, does it eventually appear?

It does, but it takes such an inordinate amount of time that the first few times I hit this, I really was just trying to escape from what looked like a hung window. That's why I reported this – it looks like invoking the print dialog isn't cancellable by its caller, which is a problem when the dialog can't appear, or takes too long (without a loading progress indicator) for it to be useful.

I have no printer connected, so it should be instantaneous. If it's somehow expected to take > 10s on a system with 32 GiB of SDRAM and a ≥ 4 GHz CPU, one would expect there to be a loading indicator. 😅

The fact that the print dialog takes a long time to appear when it shouldn't is probably the real issue to dig into here; if it was fast, you wouldn't try to close its parent window — and in fact could not, because by the time you tried, the print dialog would already be visible.

I'm not sure there's much we can do here though, since the print dialog comes from Qt directly.

CCing a printer-savvy person who may know more.

P.S. why were you trying to open the print dialog if you don't have a printer? To make a PDF?

Nate is correct, this is essentially an "app" using print services provided by Qt.  In my case, I get modal behavior immediately, meaning once the print button is clicked, I can't close the window while waiting for the modal print dialog to present.  Even then, it still acts modal.  And I too, am on Qt6.9.

I'm more familiar with the config/setup side of printer management, not so much print services provided by Qt, but I can tell you this: there is at least one timeout in the code path, maybe two.  It's been a while, but IIRC, Qt is looking for/initializing print services backend (CUPS) and then CUPS is looking/waiting for it's own backends to enumerate.  The latter can take a some seconds I've noticed and it appears to be directly related to not just CUPS backends installed, but also the number of "filters" you have installed, ie. cups-filters, hplip-*, epson, etc...

One thing you could try is to turn off your networking, then try the print and see if the dialog still takes "a while" to present.  CUPS will do some IPP/network "stuff" to discover printers on your net.

In addition, you could disable CUPS `sudo systemctl stop cups.service` and then try the print and see what happens there.  Turn it back on later with systemctl start cups, fyi.

Not sure this helps but it might give some clues on where to dig in first.

Created attachment 181658 [details]
A KCrash Of Krita, For Comment 11

(In reply to Nate Graham from comment #9)

> Why were you trying to open the print dialog if you don't have a printer? To make a PDF?

Yes. I thought it might be a useful way to visualise (or, crudely, backup) keyboard shortcuts.

(In reply to Mike from comment #10)

> there is at least one timeout in the code path, maybe two.

I've captured a Perf and STrace record, if of use. I've plonked them in https://collaborate.kde.org/apps/files/files/684451?dir=/%27Custom%27%23.dir/%27Publicly%20Accessible%27%23.dir/%27bugs.KDE.org%27%23.dir/%27504487%27%23.dir, but shall attach them once I've submitted this comment.

About STrace, I saw, whilst the printer is loading, a multitude of ultimately quite quick calls, repeatedly occurring until the dialog appears:

> 0.000048 read(28, "W", 10)         = 1 <0.000011>  
> 0.000030 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050086>  
> 0.050137 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050083>  
> 0.050127 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050084>  
> 0.050134 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050091>  
> 0.050139 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050088>  
> 0.050154 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050088>  
> 0.050147 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050088>  
> 0.050135 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050088>  
> 0.050134 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050078>  
> 0.050122 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050081>  
> 0.050126 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050080>  
> 0.050126 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050097>  
> 0.050146 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050041>  
> 0.050095 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050088>  
> 0.050139 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050089>  
> 0.050148 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050090>  
> 0.050160 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 0 (Timeout) <0.050088>  
> 0.050151 poll([{fd=28, events=POLLIN}, {fd=30, events=POLLIN}], 2, 50) = 1 ([{fd=30, revents=POLLIN}]) <0.048304>  
> 0.048380 recvmsg(30, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\4\1\1\0\0\0\0\220\0\0\0\215\0\0\0\1\1o\0\31\0\0\0/Client1"..., iov_len=2048}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 320 <0.000034>

From what I see, this doesn't occur before or after I invoke the dialog.

...About CUPS:

> One thing you could try is to turn off your networking, then try the print and see if the dialog still takes "a while" to present.  CUPS will do some IPP/network "stuff" to discover printers on your net.
> 
> You could disable CUPS `sudo systemctl stop cups.service` and then try the print and see what happens there.

I stopped it, and verified it was:

> Loaded: loaded (/usr/lib/systemd/system/cups.service; disabled; preset: disabled)

This made it almost ⪆ 4s faster, but it still takes ⪅ 2.5s to appear, which is still bad on a system with 32 GiB of DDR5 SDRAM! 😆 However, disabling Ethernet reduced it by *maybe* ⪅ 0.5s, if I'm not merely experiencing confirmation bias / placebo / whatever. I suppose we can consider CUPS the most *significant* culprit, but on Windows, this is instantaneous, so there's more at play.

(In reply to Roke Julian Lockhart Beedell from comment #6)

> This *does not* affect Krita, nor SkanPage

It *does* affect Krita too, per https://discuss.kde.org/t/is-a-kde-application-not-providing-a-bug-reporting-address-a-bug/34640?u=rokejulianlockhart. The reason SkanPage doesn't appear affected appears to be that it solely exposes one keyboard shortcut. At least that demonstrates that the quantity of shortcuts affects invocation time. I'll presume you knew this, though, you backtrace-reading nutters.

Created attachment 181659 [details]
A Screencast Of STrace Attached To KWrite, For Comment 11

Created attachment 181660 [details]
A KWrite Perf Record, For Comment 11

Created attachment 181661 [details]
A KWrite STrace Record, For Comment 11

(In reply to Roke Julian Lockhart Beedell from comment #11)

...Ignore that NextCloud URI. I wrote that comment in a text editor, and meant to leave that as a note to self to remove once I published the comment. Apologies for the noise.

Created attachment 181687 [details]
A Screencast Demonstrating That This Affects All Qt 6 Applications

(In reply to Roke Julian Lockhart Beedell from comment #11)

> I suppose we can consider CUPS the most *significant* culprit, but on Windows, this is instantaneous, so there's more at play.

Per [`bbs.archlinux.org/viewtopic.php?pid=1279792#p1279792`][1], I've ascertained that the cause is `avahi-daemon.service` (or, at least, its default configuration). Consequently, I have filed https://github.com/avahi/avahi/issues/701#issue-3087466051 to, hopefully, replace this. If not, it's at worst a Qt issue, rather than a KDE one, since it affects a custom PyQt6 application of mine, too.

[1]: https://bbs.archlinux.org/viewtopic.php?pid=1279792#p1279792:~:text=but%20after%20I%20setup%20my%20network(with%20help%20of%20a%20question%20created%20by%20me%20on%20unix.stackexchange.com)%20I%20discovered%20that%20problem%20isn't%20cups%20and%20isn't%20network%2C%20the%20problem%20is%20the%20avahi%2Ddaemon%2C%20if%20it's%20runnig%20the%20cups%20is%20slow%2C%20if%20it%20isn't%20cups%20is%20normal...