1694796 - When trying to print certain messages, it takes a long time before the print dialogue box appears (if it appears at all)

Status: RESOLVED FIXED

(Thunderbird :: General, defect)

Description

[Arthur K. (he/him)]

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:87.0) Gecko/20100101 Firefox/87.0

Steps to reproduce:

I received two emails from a [e-mail] sender which is for ski lift tickets. I did a File > Print and also a CTRL-P to print the tickets but it took in excess of 120 seconds before the print dialogue box appeared (if at all). I tested with a few other emails (from eBay, Amazon, etc.) and the print dialogue box came up almost instantly.

Actual results:

When the print dialogue box did finally appear, error console shows this:

16:07:05.630
GEThttps://sr.rlcdn.com/465456.gif?s=20a78a53080adf4b49105c11177a49a7f9584ff2fedcace95bc41d7dab02cb00&n=1
[HTTP/2 200 OK 47ms]

16:07:05.637
GEThttps://sr.rlcdn.com/465456.gif?s=20a78a53080adf4b49105c11177a49a7f9584ff2fedcace95bc41d7dab02cb00&n=2
[HTTP/2 200 OK 57ms]

16:07:05.641
GEThttps://sr.rlcdn.com/465456.gif?s=20a78a53080adf4b49105c11177a49a7f9584ff2fedcace95bc41d7dab02cb00&n=3
[HTTP/2 200 OK 56ms]

16:07:05.644
GEThttps://sr.rlcdn.com/465456.gif?s=20a78a53080adf4b49105c11177a49a7f9584ff2fedcace95bc41d7dab02cb00&n=4
[HTTP/2 200 OK 56ms]

16:07:05.647
GEThttps://sr.rlcdn.com/465456.gif?s=20a78a53080adf4b49105c11177a49a7f9584ff2fedcace95bc41d7dab02cb00&n=5
[HTTP/2 200 OK 55ms]

16:07:05.649
GEThttps://t.myvisualiq.net/impression_pixel?r=1613428687&et=i&ago=212&ao=987&si=-11&ad=-11&sv1=-11&sz=7502&advt=11&chnl=-11&vndr=1144&u=EML_CNFDELIV_OTHR_000_WM_SR_00000_000000_TG0000_20210215_v00&pt=I
[HTTP/1.1 200 OK 115ms]

16:07:05.651
GEThttp://250analytics.vailresorts.com/ea/DKcE7fBHke/?e=<removed>@gmail.com

16:07:05.654
GEThttps://t.i.vailresorts.com/r/?id=h1b2d6e8,36c9875,1
[HTTP/1.1 200 OK 185ms]

and eventually ​followed by...

15:52:24.986 Uncaught (in promise) undefined msgPrintEngine.js:218:13

15:52:27.703 TypeError: browser is null BrowserElementParent.jsm:24:21
receiveMessage resource://gre/actors/BrowserElementParent.jsm:24
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65

15:52:42.973 Uncaught TypeError: window.opener is null msgPrintEngine.js:136:25
InitPrintEngineWindow chrome://messenger/content/msgPrintEngine.js:136

Expected results:

Whether using File > Print or CTRL-P, it should come up withing a second or two.

Two things I want to add:

• When I click a different email and then click back to one of the problem emails, the status bar shows "Loading Message..." for about 35 seconds before it finishes. I did a profile of that and it's here: https://share.firefox.dev/3bAEJHV

• At the message bottom, it has 36 clickable links in the body. Shouldn't make difference but noting it in here in case it might be related and TB is getting stuck parsing those 36 links in order to print

Comment 1

[Ping Chen [:rnons] (away)]

Thanks for reporting. Is it possible you can strip personal info from the mail and upload it here? Or you can forward it to me if you don't mind.

Comment 2

[Arthur K. (he/him)]

Attachment: Order Confirmation.eml

I saved the email as an attachment here. On my home PC, if I scroll through my inbox, click on the email and try to do a CTRL-P, it take around the same time as in my STR for the dialogue box to appear (if at all). If I try to print this saved .eml file, it's almost instant.

I'm not tech savvy enough to know what might be different from trying to print from the message that's in my Inbox versus this as a saved attachment but it seems to be different.

Comment 3

[Arthur K. (he/him)]

I was just trying to print this email again and I saw another error in Error Console.

TypeError: browser is nullBrowserElementParent.jsm:24:21

receiveMessage resource://gre/actors/BrowserElementParent.jsm:24
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65
startPrint chrome://messenger/content/msgPrintEngine.js:218
onStateChange chrome://messenger/content/msgPrintEngine.js:65

Comment 4

[Ping Chen [:rnons] (away)]

Attachment: a-slow-tracker.png

Turns out there are lots of tracking pixels in the mail. The worst one is 250analytics.vailresorts.com, as you can see from the attached image, it took 20 seconds on my computer to load it. And this blocked the printing dialog.

A workaround is to disable remote content in mail, or at least block 250analytics.vailresorts.com. To do that, go to Preferences, search for Mail Content, click Exceptions..., put 250analytics.vailresorts.com in the address input, click Block.

After blocking the tracker, print dialog shows up immediately.

Comment 5

[Arthur K. (he/him)]

(In reply to Ping Chen (:rnons) from comment #4)

Created attachment 9205596 [details]
a-slow-tracker.png

Turns out there are lots of tracking pixels in the mail. The worst one is 250analytics.vailresorts.com, as you can see from the attached image, it took 20 seconds on my computer to load it. And this blocked the printing dialog.

A workaround is to disable remote content in mail, or at least block 250analytics.vailresorts.com. To do that, go to Preferences, search for Mail Content, click Exceptions..., put 250analytics.vailresorts.com in the address input, click Block.

After blocking the tracker, print dialog shows up immediately.

Thanks for confirming. I had my suspicion it was one of these remote content links in the message. After removing the exception for allowing remote content from [e-mail], a CTRL-P works instantly.

So that being the case, there's no actual fix per se, right? I'm guessing that some poor user who doesn't happen upon this bug report and finds the "fix" is to remove the exception granted to the sender for allowing remote content. However, I'm wondering about instances where some sender requires the user to allow remote content in order to view, say, an image of concert tickets or some kind of map. They would then fall into this delay trap and think their printer is broken or TB is broken. Makes my head hurt. Is it possible to have some kind of timeout limit whereby after XX seconds it will just ignore requests that are slow or stuck and just plod on? Just thinking out loud here.

Comment 6

[Ping Chen [:rnons] (away)]

Attachment: 1694796.patch

This is a patch to start printing after 10 seconds even if remote contents are still loading. I'm not sure if we should take it because 10 seconds feel too arbitrary.

Comment 7

[Magnus Melin [:mkmelin]]

Comment on attachment 9205981 [details] [diff] [review]
1694796.patch

Review of attachment 9205981 [details] [diff] [review]:
-----------------------------------------------------------------

I guess this is ok as a workaround.

Or maybe we should only wait until the main content is loaded, i.e. wait for browser.contentDocument DOMContentLoaded

Comment 8

[Arthur K. (he/him)]

(In reply to Ping Chen (:rnons) from comment #6)

This is a patch to start printing after 10 seconds even if remote contents are still loading. I'm not sure if we should take it because 10 seconds feel too arbitrary.

Arbitrary yes, but 10 seconds would seem like an eternity to a user who did a File > Print or CTRL-P and then sat there for 10 seconds wondering if the action went through before they started the action again. I know even in 2021 there are still users of dial-up so I can imagine what something like this email would behave like for that small niche of people. 10 seconds seems to me to be on the high side.

Speaking as a user, are there any tests that (are they called ref tests?) that get what is considered an average time from the moment a print action is sent? I have emails from things like Airfare Watchdog and The Flight Deal that have far more links than the reference email I attached here and a CTRL-P take about 1 - 1.5s on my home PC. 5 seconds would probably seem like less of an eternity. In this instance, it's just FEW misbehaving servers (in this case, primarily 250analytics.vailresorts.com).

Is it more complicated to write something up to tell TB that "some server response is dragging its feet and stop waiting for server x, x, z, etc and fire off the print action" or to just kick off the print event after X seconds like in your patch?

Comment 9

[Ping Chen [:rnons] (away)]

Attachment: 1694796.patch

Use clearTimeout to prevent potential problems when print multiple messages.

Seems DOMContentLoaded doesn't wait for any stylesheets/images.

are there any tests that (are they called ref tests?) that get what is considered an average time from the moment a print action is sent?

I think this is usually called telemetry, we don't have such a telemetry probe.

Is it more complicated to write something up to tell TB that "some server response is dragging its feet and stop waiting for server x, x, z, etc and fire off the print action"

We're loading a document, but have no information about specific sub-requests it fired.

I intentionally set a "high" value, because I think in most cases the printing dialog loads fast and this value doesn't matter at all.

Comment 10

[Arthur K. (he/him)]

(In reply to Ping Chen (:rnons) from comment #9)

We're loading a document, but have no information about specific sub-requests it fired.

I intentionally set a "high" value, because I think in most cases the printing dialog loads fast and this value doesn't matter at all.

It's a pretty wide net to cast but probably a safe bet. But how to get some good telemetry going forward or for future reference? Hard to know how many servers out there are slowpokes in order to get a decent average. I can't imagine this being a common issue and it's not possible for TB to fix someone's slow server problem. Probably the best workaround for the moment. Thanks Ping!

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/comm-central/rev/f5fae7e68949
Start printing even if remote contents are still loading. r=mkmelin

Comment 12

[Arthur K. (he/him)]

Attachment: header-info-in-print-dialogue-after-cancel.png

So the print dialogue indeed seems to pop up after about 9 seconds on the affected email from which I was seeing the original issue. YAY!

Here's an odd thing though. So in testing this just now, I clicked the Cancel button on the print dialogue box after it popped up and for a split second I saw something weird. So I fired up Bandicam and recorded a vidcap. Just after pressing Cancel, I briefly see the header info in the print dialogue box. It repros about half the time but I did a screencap in case it's of interest to you guys. This was using TB 89.0b1.