1666938 - Consider starting the fetch of printer capabilities when a print is initiated

Status: RESOLVED WONTFIX

(Toolkit :: Printing, enhancement, P2)

Description

[Jonathan Watt [:jwatt]]

Right now we wait until init() is called in print.js before requesting the (async on background thread) fetch of printer capabilities. On my top spec MBP, init() seems to be called around 1.4 seconds after the first print initiation (around 0.8 seconds for subsequent initiations). For other users on slower hardware it will presumably be significantly longer. This time is directly added to the delay in showing the print preview document, since we can't start the print preview document construction (the long pole) until we have this information.

Perhaps we could have PrintUtils._openTabModalPrint initiate the async fetch of this printer information, and then have init() in print.js pick up the resulting Promise(s). Some means of associating the Promises with the particular doorhanger for which it was triggered would be needed (to avoid the issues that come with caching and sharing across multiple prints).

For context, we have the following telemetry for how long it takes for the print preview document to show: https://mzl.la/3jbjQWF . With only 722 pings it's too early to call this statistically significant, but currently 1.07% of prints take >10s.

Comment 1

[Mark Striemer [:mstriemer]]

I applied this diff and took a look at how long it takes to get the dialog on screen and these were my results.

diff --git a/toolkit/components/printing/content/print.js b/toolkit/components/printing/content/print.js
--- a/toolkit/components/printing/content/print.js
+++ b/toolkit/components/printing/content/print.js
@@ -169,16 +169,19 @@ var PrintEventHandler = {
     this.originalSourceContentTitle =
       sourceBrowsingContext.currentWindowContext.documentTitle;
     this.originalSourceCurrentURI =
       sourceBrowsingContext.currentWindowContext.documentURI.spec;
 
     // Let the dialog appear before doing any potential main thread work.
     await ourBrowser._dialogReady;
 
+    let params = new URLSearchParams(location.search);
+    dump("XXXXXXXXX " + (Date.now() - parseInt(params.get("printInitiationTime"),10)) + "\n");
+
     // First check the available destinations to ensure we get settings for an
     // accessible printer.
     let {
       destinations,
       defaultSystemPrinter,
       fallbackPaperList,
       selectedPrinter,
       printersByName,

• Windows PC (Ryzen 1600, 16GB RAM)
  • Initial load: 80ms, 110ms, 63ms
  • After that: 40-45ms, 59ms worst
• Ubuntu on WSL2/X (same PC)
  • Initial load: 258ms, 245ms
  • After that: 145-155ms
• 2016 MacBook Pro 13" (Mojave)
  • Initial load: 66ms, 175ms, 76ms, 80ms
  • After that: 45-55ms

I just added another timing point to right after init() is being called, and it looks like the time between init() getting called and the dialog._dialogReady promise telling us its shown to the user is about 10-15ms on my MacBook.

The reason we're waiting for the dialog to be ready is that sometimes the getPrintDestinations() call to the nsIPrinterList code would block the main thread. I haven't seen Firefox go into Not Responding mode lately, so maybe that isn't the case anymore. In that case we could at least move the printer list code to the beginning of init() and that would likely save a handful of ms.

If blocking the main thread does still happen at times then we should leave this code as is, since showing the loading indicator and making the user wait an extra 250ms is better than going 8 seconds without any visual feedback.

Comment 2

[Mark Striemer [:mstriemer]]

@Emily, we were seeing some main thread blocking on the printerList API before. I haven't seen that in a while so I was curious if it's known that we won't be blocking the main thread here anymore?

If that's the case we can at least move this call up a little bit.

Comment 3

[Jonathan Watt [:jwatt]]

I just tested with an artifact build and am getting times much more similar to you, Mark. I guess maybe my local build must be missing PGO or some other for-release optimizations. So probably this bug isn't super helpful. :-/

Particularly the 10-15ms from potentially moving the getPrintDestinations() call earlier in init() doesn't seem all that useful. If there is some sort of potential main thread blocking thing going on under some circumstances that we (I) am not aware of it doesn't sound like it's worth it. We should track that issue down though in a separate bug.

Comment 4

[Blake Winton (:bwinton) (:☕️)]

If we're not seeing large gains anymore, should this be changed to a P2 and/or print2020_v83? (Or morph this bug into the investigation of the main thread blocking?)

Comment 5

[Emily McDonough [:alaskanemily]]

That sounds reasonable. I think that this would mostly help with combining overhead from SupportsColor/SupportsDuplex/SupportsCollation, etc, rather than nsIPrinterList.printers time.

Comment 6

[Blake Winton (:bwinton) (:☕️)]

Okay, so I'll move this to 83, but Mark will continue working on it and on other things to speed the printer fetching up. Thanks!

Comment 7

[Mark Striemer [:mstriemer]]

I'm looking into other caching possibilities and I don't think this one will necessarily help as much.