1451507 - Ctrl-P or File-Print menu item results in Print Error in Firefox 59.0.1, 59.0.2

Status: RESOLVED FIXED

(Core :: Printing: Output, defect, P3)

Description

[jws]

User Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:59.0) Gecko/20100101 Firefox/59.0
Build ID: 20180323154952

Steps to reproduce:

1.  If required, open Firefox v59.0.1 or 59.0.2 (64-bit) to any web page.
2.  In any open tab showing any web page, press Ctrl-P.
3.  In the Print window that opens, select any of the available printer choices (in my case Microsoft XPS Document Writer, Adobe PDF and Canon MX870 Series Printer, among others - I tested those three).
4.  Select other desired printing options, or don't.
5.  Click OK.


Actual results:

A.  For output requiring a file name (Microsoft XPS Document Writer or Adobe PDF) a Save the File window opens.  After a file name is entered and Save is clicked or the window is closed, a window captioned Print Preview (don't know why - I didn't ask for a preview) opens with the message "An error occurred while printing.".  No file is created.

B.  For output to be sent directly to a printer, a window captioned Print Preview opens with the message "An error occurred while printing.".  Printing does not happen.


Expected results:

A.  For output requiring a file name (Microsoft XPS Document Writer or Adobe PDF) a Save the File window should open.  After a file name is entered and Save is clicked, the appropriate file should be created and opened in the applicable viewer program.

B.  The output should be printed on the applicable printer.

This means that with v59.0.x, I can't print anything to any file or device.  Very frustrating.

The problem occurs with both my usual profile and a newly-created profile.

If I uninstall Firefox v59.0.x and reinstall Firefox v58.0.2 or earlier, printing works as expected.

I'm running Windows 7 Professional SP1 64-bit on a Dell Latitude E5520.

Comment 1

[Gingerbread Man]

(In reply to jws from comment #0)
> The problem occurs with both my usual profile and a newly-created profile.
> 
> If I uninstall Firefox v59.0.x and reinstall Firefox v58.0.2 or earlier,
> printing works as expected.

Please try to find the regression range and post it in a comment here.
https://mozilla.github.io/mozregression/quickstart.html

Comment 2

[jws]

Attachment: mozregression-gui.pdf

PDF of regression test GUI window.

Comment 3

[jws]

Attachment: Bisection Info.pdf

Bisection info from regression test

Comment 4

[jws]

Attachment: autoland_ pushlog.pdf

Pushlog from regression test

Comment 5

[jws]

Attachment: Log.txt

Log file from regression test

Comment 6

[jws]

Ran regression.  Results attached in 4 files.

Comment 7

[Alex Gaynor [:Alex_Gaynor]]

Hmmm. I'm unable to reproduce (Windows 10, not 7, but that shouldn't matter).

Bob, can you think of any good ways to help debug this further?

Comment 8

[Bob Owen (:bobowen)]

(In reply to Alex Gaynor [:Alex_Gaynor] from comment #7)
> Hmmm. I'm unable to reproduce (Windows 10, not 7, but that shouldn't matter).

That could matter, although printing on Fx59.0.2 win 7 is working for me.

> Bob, can you think of any good ways to help debug this further?

Have you tried with a clean profile, could be an issue with new print devices, doesn't look like your patch would have affected that though.

Other than that I guess you could look up some of the printing MOZ_LOG logging and maybe jws could turn some of that on.
I think there are a few different printing* ones, but I forget what they are off the top of my head.
That might help narrow it down.

Comment 9

[jws]

(In reply to Bob Owen (:bobowen) from comment #8)
> (In reply to Alex Gaynor [:Alex_Gaynor] from comment #7)
> > Hmmm. I'm unable to reproduce (Windows 10, not 7, but that shouldn't matter).
> 
> That could matter, although printing on Fx59.0.2 win 7 is working for me.
> 
> > Bob, can you think of any good ways to help debug this further?
> 
> Have you tried with a clean profile, could be an issue with new print
> devices, doesn't look like your patch would have affected that though.
> 
> Other than that I guess you could look up some of the printing MOZ_LOG
> logging and maybe jws could turn some of that on.
> I think there are a few different printing* ones, but I forget what they are
> off the top of my head.
> That might help narrow it down.

Any progress here?  I'm stuck on v58 unless/until this is resolved.

I'll be happy to turn on whatever logging is required.  Just let me know where/how.

Thanks.

Comment 10

[jws]

Just checked v59.0.3.  No change.  How can we move this forward?

Thanks.

Comment 11

[pkandlbinder]

I'd like to give this bug a nudge by offering to help with the collection any logs / debug info or running and instrumented build on the Win 7 machine with the regression.  I have occasional access to the machine.

I've tried to recreate the regression on 3 other Win 7 machines and 1 Win 7 VM with no success.  We're limited to debugging this on the reporting user's system.

It would be unfortunate both if the user (and possibly other users not reporting) had to move to another browser at some point because this regression wasn't fixed and we lost the opportunity to understand whatever subtlety was causing this regression by losing access to the target machine.  

My background is C so I'll need direction from someone who knows the code (Alex?) and I can be their hands on the machine.

Comment 12

[klk745]

@Jws: Can you check if printing works for you for the about:support page?

I created a bug report which is similar to yours and might be related:
https://bugzilla.mozilla.org/show_bug.cgi?id=1468465

Comment 13

[jws]

@klk745:  Upgraded to 60.0.2 (have been running 58.0.2, last version where printing works for me) and tried your test.  I was able to print the about:support page successfully.  Still can't print other pages.  So I'd say we're reporting the same bug.  Now that there are two of us, maybe we'll get some attention.  ;>)

Comment 14

[klk745]

Are you also running Intel graphics drivers?
And have you also tried to disable hardware acceleration (restart required) to see if printing works everywhere afterwards?

This really needs some attention, because it's a real show stopper for Firefox: when an average user realises that his Firefox doesn't do the basic print functionality anymore, he will switch to Edge or Chrome.

Comment 15

[jws]

Attachment: Graphics Drivers.15 Jun 18.pdf

Comment 16

[jws]

Yes, running Intel HD Graphics 3000, driver v. 9.17.10.3040.  Screen snip (Graphics Drivers.15 Jun 18.pdf) attached.

Attempted to print from Firefox v. 60.0.2 in each of the following configurations.  All failed.

  Hardware acceleration off, 1 thread
  Hardware acceleration off, 4 threads
  Hardware acceleration off, 7 threads
  Hardware acceleration on, 1 thread
  Hardware acceleration on, 4 threads
  Hardware acceleration on, 7 threads

So for me, at least, hardware acceleration and/or threading doesn't seem to be the issue.

@klk745: Suggest you run mozregression (https://mozilla.github.io/mozregression/quickstart.html) to see if you get the same result I do, i.e. to verify that we're reporting the same bug.

I agree this could be chasing people to Chrome or Edge.  Should get fixed.

We seen to be hung in a NeedInfo state.  Not sure how to nudge it forward.

Comment 17

[klk745]

@jws: I'm currently a bit short on time, but I'll try to do the mozregression testing next week.

Is there probably also a logfile in my profile folder to see what goes wrong when the message "An error occurred while printing" comes up?
Or can this be monitored in realtime using an internal console in Firefox?

I also found another report...
https://bugzilla.mozilla.org/show_bug.cgi?id=1399131
...where a whole college campus is affected. I guess they ditched Firefox in the meantime.

Comment 18

[klk745]

I just tried the following on the command line to get some kind of logging:

  set NSPR_LOG_FILE=%TEMP%\printing.log
  set NSPR_LOG_MODULES=printing:5,printing-layout:5,printing-widget:5
  "C:\Program Files\Mozilla Firefox\firefox.exe"

Then try to print to trigger the error.
Afterwards you can find the logs in the %TEMP% folder in printing.log and printing.log.child-X files.
An attachment of my result follows.

Comment 19

[klk745]

Attachment: printing.log NSPR

Comment 20

[Bob Owen (:bobowen)]

(In reply to klk745 from comment #19)
> Created attachment 8985834 [details]
> printing.log NSPR

Thanks for trying to get us some more information here.

That log appears to be truncated.
If that's how the file really is, then adding ,sync on the end of NSPR_LOG_MODULES (or MOZ_LOG see below) might help.

It's better to use the newer environment variables for logging, although I think they generally still give you the same results:
MOZ_LOG_FILE instead of NSPR_LOG_FILE
MOZ_LOG instead of NSPR_LOG_MODULES

Comment 21

[klk745]

Thank you Bob, I changed the environment variables and adding ',sync' did the trick:

  set MOZ_LOG_FILE=%TEMP%\printing.log
  set MOZ_LOG=printing:5,printing-layout:5,printing-widget:5,sync
  "C:\Program Files\Mozilla Firefox\firefox.exe"

My result follows as attachment.
@Jws: It would be great if you could post your results for the above as well.

Comment 22

[klk745]

Attachment: Printing attempt for Page 1 of https://www.heise.de/newsticker/

Comment 23

[klk745]

Attachment: printing.log.child-3_hw_accel_disabled

Successful printing attempt with HW acceleration disabled

Comment 24

[Bob Owen (:bobowen)]

(In reply to klk745 from comment #22)
> Created attachment 8986014 [details]
> Printing attempt for Page 1 of https://www.heise.de/newsticker/

Thanks for these.

I'm not sure if these problems are related.
The "An error occurred while printing." message can be caused by a number of different things.
I'll follow-up on your original bug.

Comment 25

[Bob Owen (:bobowen)]

(In reply to jws from comment #5)
> Created attachment 8965993 [details]
> Log.txt
> 
> Log file from regression test

Looking at this it appears that the file handle that we pass from the parent is either not getting created properly or something is going wrong with the passing.

Is there anything you can think of that is remarkable about the machine set-up?
Particularly whether the temp directory might have been changed.

The logging as explained in comment 21 might be useful.

In addition to that like I suggested for bug 1468465, would you mind trying a single debug build with the Mozregression-gui as well:
* File->"Run a single build"
* Select "Build Type:" debug, then Next
* Next on the "Profile Selection" panel
* It should automatically select a recent build date I think, if not select one from a few days ago and then Finish.

It will be pretty slow to start and run, assuming the print fails can you upload a copy of the log, thanks.

Comment 26

[jws]

(In reply to Bob Owen (:bobowen) from comment #25)
> (In reply to jws from comment #5)
> > Created attachment 8965993 [details]
> > Log.txt
> > 
> > Log file from regression test
> 
> Looking at this it appears that the file handle that we pass from the parent
> is either not getting created properly or something is going wrong with the
> passing.
> 
> Is there anything you can think of that is remarkable about the machine
> set-up?
> Particularly whether the temp directory might have been changed.
> 
> The logging as explained in comment 21 might be useful.
> 
> In addition to that like I suggested for bug 1468465, would you mind trying
> a single debug build with the Mozregression-gui as well:
> * File->"Run a single build"
> * Select "Build Type:" debug, then Next
> * Next on the "Profile Selection" panel
> * It should automatically select a recent build date I think, if not select
> one from a few days ago and then Finish.
> 
> It will be pretty slow to start and run, assuming the print fails can you
> upload a copy of the log, thanks.

No, there's nothing remarkable about my machine setup.  In general set up using defaults, including default TEMP locations for both user and system.

I ran four test cases using mozregression-gui - most recent nightly build (64-bit) and for completeness most recent nightly build (32-bit), current release version (64-bit) and last known good version (58.0.2 - 64-bit).  The return value for the first three was the same - 0x80520015 .  The last one completed successfully.

I'm uploading log files from all four cases.  Each case produced five files, but only two had any contents.  I'm attaching all eight of those, with the case identified by prepending to the file name.

I note that my return value is different from @klk745's, so maybe not the same bug after all.

Comment 27

[jws]

Attachment: 61.0a1 2018-06-17 64-bit.printing.log

Comment 28

[jws]

Attachment: 61.0a1 2018-06-17 64-bit.printing.log.child-4

Comment 29

[jws]

Attachment: 61.0a1 2018-06-17 32-bit.printing.log

Comment 30

[jws]

Attachment: 61.0a1 2018-06-17 32-bit.printing.log.child-4

Comment 31

[jws]

Attachment: 61.0a1 2018-03-12 64-bit.printing.log.child-3

Comment 32

[jws]

Attachment: 61.0a1 2018-03-12 64-bit.printing.log

Comment 33

[jws]

Attachment: 58.0.2 64-bit.printing.log

Comment 34

[jws]

Attachment: 58.0.2 64-bit.printing.log.child-2

Comment 35

[Bob Owen (:bobowen)]

(In reply to jws from comment #26)
... 
> I'm uploading log files from all four cases.  Each case produced five files,
> but only two had any contents.  I'm attaching all eight of those, with the
> case identified by prepending to the file name.
> 
> I note that my return value is different from @klk745's, so maybe not the
> same bug after all.

Thanks for those.
Yes, in your case it appears it is failing to create the temporary file in the parent process.

The only thing I can think of is that somehow the mozilla-temp-files dir has been created by something else and you don't have permissions.

Could you run the following commands from a command prompt please and paste the results:

  icacls %TEMP%
  icacls %TEMP%\mozilla-temp-files

Comment 36

[jws]

(In reply to Bob Owen (:bobowen) from comment #35)
> (In reply to jws from comment #26)
> ... 
> > I'm uploading log files from all four cases.  Each case produced five files,
> > but only two had any contents.  I'm attaching all eight of those, with the
> > case identified by prepending to the file name.
> > 
> > I note that my return value is different from @klk745's, so maybe not the
> > same bug after all.
> 
> Thanks for those.
> Yes, in your case it appears it is failing to create the temporary file in
> the parent process.
> 
> The only thing I can think of is that somehow the mozilla-temp-files dir has
> been created by something else and you don't have permissions.
> 
> Could you run the following commands from a command prompt please and paste
> the results:
> 
>   icacls %TEMP%
>   icacls %TEMP%\mozilla-temp-files

Good call on the permissions, Bob.  Turns out there were strange permissions set for %TEMP%\mozilla-temp-files, shown in the snip <mozilla-temp-files permissions.before.png>.  After I took ownership of the directory I somewhat automagically changed the permissions to those shown in <mozilla-temp-files permissions.after.png>.  Printing now works.

The question now is why printing worked at all in v58.0.2 and prior.

Thanks for your help.

Comment 37

[jws]

Attachment: mozilla-temp-files permissions.before.png

Comment 38

[jws]

Attachment: mozilla-temp-files permissions.after.png

Comment 39

[Bob Owen (:bobowen)]

(In reply to jws from comment #36)
> (In reply to Bob Owen (:bobowen) from comment #35)
> > (In reply to jws from comment #26)
...
> Good call on the permissions, Bob.  Turns out there were strange permissions
> set for %TEMP%\mozilla-temp-files, shown in the snip <mozilla-temp-files
> permissions.before.png>.

My guess is that Firefox was launched by another user on your behalf at some point, before mozilla-temp-files had been created and it then got created by that different user. Possibly as part of some install, they sometimes try to display a web page at the end.

> Printing now works.

\o/

> The question now is why printing worked at all in v58.0.2 and prior.
> 
> Thanks for your help.

No problem and thanks for your patience and help in diagnosing the problem.

Before Fx59, we used to create the files in the content process, in a special directory to which we can still write (nearly everywhere else is blocked by the sandbox now).
In Fx59, Alex landed an improvement so that we create the file in the parent and pass down a handle to it.
This used a mechanism that was added for our media cache originally in %TEMP%\mozilla-temp-files.
You might find some other issues are now resolved as a result of fixing this.

Comment 40

[Clara Guerrero ( Need Info Brindusa Tot Please)]

Hi,

I've tested this using Firefox Nightly version 75.0a1 (2020-02-12) (64-bit), Beta 74.0b2 (64-bit) and Release 73.0 (64-bit) for windows 10 pro and I’m not able to reproduce the issue. Based on this I will mark each respective flag as unaffected.

I've also tested this on ff59.0a1 (2017-12-09) (64-bit) and I cannot replicate it either. I'm not seeing the error, however I'm not seeing the quoted Expected results either for case A. For output requiring a file name (Microsoft XPS Document Writer or Adobe PDF) a Save the File window should open. After a file name is entered and Save is clicked, the appropriate file should be created and opened in the applicable viewer program. FIle is created but not opened simultaneously. User needs to do so. Let me know if I can update this status to verified despite of this.

Best,
Clara