Closed Bug 1409768 Opened 7 years ago Closed 7 years ago

It takes a long time to print a pdf file

Categories

(Firefox :: PDF Viewer, defect, P1)

58 Branch
defect

Tracking

()

VERIFIED FIXED
Firefox 58
Tracking Status
firefox-esr52 --- unaffected
firefox56 --- unaffected
firefox57 --- unaffected
firefox58 --- verified
firefox59 --- verified

People

(Reporter: obotisan, Assigned: Alex_Gaynor)

References

()

Details

(Keywords: regression)

Attachments

(3 files)

[Affected versions]:
- 58.0a1

[Affected platforms]:
- Ubuntu 16.04 x64

[Steps to reproduce]:
1. Open a pdf file (ex:https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=a1c1270e9ebb2449fd8fd7d7bdcf3d9eab755f37&tochange=3e0104c1ce80630d6f34b4ebc21651f844b93e4d)

2. Try to print a few pages
[Expected result]:
- The print process starts immediately.

[Actual result]:
- It takes a really long time to start the printing process. Sometimes it never starts. 
- An error appears. You can find it in the attachment.

[Regression range]:
-Last good revision: a1c1270e9ebb2449fd8fd7d7bdcf3d9eab755f37
- First bad revision: 3e0104c1ce80630d6f34b4ebc21651f844b93e4d
- Pushlog:
https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=a1c1270e9ebb2449fd8fd7d7bdcf3d9eab755f37&tochange=3e0104c1ce80630d6f34b4ebc21651f844b93e4d
 I will redo the test because I am not sure that this pushlog is helpful. I will re do the tests again as soon as possible. 

[Additional notes]:
- After I deactivated e10s, the process went smoothly with no problem.
The issue is reproducible also on Windows 7 x64 using latest Nightly 58.0a1 (2017-10-18) with e10s enabled.
Summary: [Ubuntu] It takes a long time to print a pdf file → It takes a long time to print a pdf file
OS: Linux → All
Hardware: Unspecified → All
Bug 1319423 would have been my first suspect given the rough regression window.
Ugh. Seems almost inevitable that it's that patch. It's probably the changes to the PrintTimer. Will dive in deeper later today.
Flags: needinfo?(agaynor)
After some testing on macOS, what I see is that (compared to beta) printing PDFs is slightly slower, on the 4 page PDF I tested with it was 3 seconds vs. 4 seconds.

However, I didn't see any errors or failures to print. Are there any particular PDFs you were seeing that behavior on, hopefully somewhere online so I can test them? (PS: I'm not able to open the attachment due the xcf format, is it possible to upload that as a JPG or PNG?)
Flags: needinfo?(agaynor) → needinfo?(oana.botisan)
(In reply to Alex Gaynor [:Alex_Gaynor] from comment #4)
> After some testing on macOS, what I see is that (compared to beta) printing
> PDFs is slightly slower, on the 4 page PDF I tested with it was 3 seconds
> vs. 4 seconds.
> 
> However, I didn't see any errors or failures to print. Are there any
> particular PDFs you were seeing that behavior on, hopefully somewhere online
> so I can test them? (PS: I'm not able to open the attachment due the xcf
> format, is it possible to upload that as a JPG or PNG?)
 
I initially could reproduce the bug only on Ubuntu 16.04 x64. Another colleague of mine discovered that it could be reproduce on Windows 7. As far as I could tell when I investigated the bug, macOS 10.11 was not affected nor was Windows 10. So I think you wouldn't be able to reproduce the bag on any macOS. 

The link I used (which I thought I attached to STR) was http://yoanaj.co.il/uploadimages/The_Little_Prince.pdf . 

I reattached the picture with the error.
Flags: needinfo?(oana.botisan)
Almost certainly unrelated to this, but on macOS release and beta channels, printing the little prince results in an error -- it works ok, albeit slowly on Windows 7/10.

I'm currently working on reproducing on Ubuntu 16.04.
On Ubuntu 16.04, with both beta and nightly I experience tab crashes attempting to print this PDF. For some reason they don't appear to be getting submitted to crash reporter (these are builds downloaded from us, not built locally).

Will work on getting the stacktrace for these crashes and digging into it.
Ok, finally nailed down (some?) of the performance problem -- it's not related to nsPagePrintTimer, as I expected. Instead it's related to file io!

On Linux, like 99% of the time was being spent in fsync, which was silly. Just not fsyncing is a perfectly cromulent solution. On macOS like 30% of time is being spent in write -- this is slightly harder since NSPR doesn't appear to have any native buffering support, will have to poke around and see if we have some other file abstraction which does buffering (and supports converting to/from native file handles).

Hopefully will have a patch up tomorrow.

(The crashes I was seeing on Linux no longer reproduce :-/)
Flags: needinfo?(agaynor)
Might be worth talking to baku about possible solutions, he's done a lot with streaming and files between the processes.

Do you think we need to back this out in the meantime?
I don't think a backout is required. The Linux patch is straightforward, I will do some profiling on Windows today to confirm that file IO is the issue there as well.
Assignee: nobody → agaynor
Flags: needinfo?(agaynor)
Priority: -- → P1
Comment on attachment 8922011 [details]
Bug 1409768 - Don't call fsync repeatedly when printing;

https://reviewboard.mozilla.org/r/192994/#review198264
Attachment #8922011 - Flags: review?(bobowencode) → review+
Keywords: checkin-needed
Pushed by ryanvm@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/b6a31566efe6
Don't call fsync repeatedly when printing; r=bobowen
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/b6a31566efe6
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 58
Flags: qe-verify+
I verified the fix using both latest Nightly 59 and beta 58.0b5 on Ubuntu 16.04 x64, Windows 10 x64 and Windows 7 x64. The bug is not reproducing anymore.
Status: RESOLVED → VERIFIED
Flags: qe-verify+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: