Crash in [@ CrashReporter::TerminateHandler | std::__terminate][@ nsPrintSettingsX::SetToFileName] when printing to file on MacOS

RESOLVED FIXED in Firefox 62

Status

()

defect
P1
critical
RESOLVED FIXED
Last year
Last year

People

(Reporter: mccr8, Assigned: spohl)

Tracking

({crash, regression, topcrash-mac})

unspecified
mozilla63
Unspecified
macOS
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox-esr52 unaffected, firefox-esr60 unaffected, firefox61 unaffected, firefox62+ fixed, firefox63 fixed)

Details

(crash signature)

Attachments

(1 attachment)

This is the #2 top crash on OSX for the 6-6 Nightly. The stacks all involve printing, as do a number of user comments.

This bug was filed from the Socorro interface and is
report bp-4943e3d5-4e4a-4c83-b627-a41330180606.
=============================================================

Top 10 frames of crashing thread:

0 XUL CrashReporter::TerminateHandler toolkit/crashreporter/nsExceptionHandler.cpp:1434
1 libc++abi.dylib std::__terminate 
2 libc++abi.dylib __cxa_throw 
3 libobjc.A.dylib objc_begin_catch 
4 CoreFoundation CFPasteboardPromiseDataUsingBlock 
5 CoreFoundation _CFURLCreateWithFileSystemPath 
6 CoreFoundation CFReadStreamRead 
7 CoreFoundation -[CFPrefsCompatibilitySource alreadylocked_copyValueForKey:] 
8 AppKit -[NSPrintInfo initWithDictionary:] 
9 XUL nsPrintSettingsX::SetToFileName widget/cocoa/nsPrintSettingsX.mm:373

=============================================================
On Nightly, this seems to have started on the 20180603221731 build.

Only a few changesets landed in that build:
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=ad1249c83efb4c01bb86a1f4e4744af73d10acf8&tochange=0ee6b755ab2ee6d2ab79b17cc97bd4e83424cbfc

Could bug 1270217 have caused this? That's the only obviously OSX related thing in that range...
Flags: needinfo?(jwatt)
User comments: "Print Save as PDF", "Printing to PDF and it just died.", "Tried to print a document", "Saving a file when Printing as a PDF", "Printed a PDF"
FWIW, I printed a file on OSX, once to a printer and once to PDF, and it didn't crash.
There are 80 crashes from 67 installs, in the last week on nightly 62. 
Another user comment:

"Nightly crashes every time I print to PDF a web page.
The PDF file is created on disk and opens ok.
Nightly is crashing sometime after the PDF file is created."
I've tried all sorts of things to repro this, but without any luck. Alice, any chance you can come up with any ideas?
Flags: needinfo?(jwatt) → needinfo?(alice0775)
(In reply to Andrew McCreight [:mccr8] from comment #0)
> report bp-4943e3d5-4e4a-4c83-b627-a41330180606.
> 
> Top 10 frames of crashing thread:
> 
> 0 XUL CrashReporter::TerminateHandler
> toolkit/crashreporter/nsExceptionHandler.cpp:1434
> 1 libc++abi.dylib std::__terminate 
> 2 libc++abi.dylib __cxa_throw 
> 3 libobjc.A.dylib objc_begin_catch 
> 4 CoreFoundation CFPasteboardPromiseDataUsingBlock 
> 5 CoreFoundation _CFURLCreateWithFileSystemPath 
> 6 CoreFoundation CFReadStreamRead 
> 7 CoreFoundation -[CFPrefsCompatibilitySource alreadylocked_copyValueForKey:] 
> 8 AppKit -[NSPrintInfo initWithDictionary:] 
> 9 XUL nsPrintSettingsX::SetToFileName widget/cocoa/nsPrintSettingsX.mm:373

The actual stacks under nsPrintSettingsX::SetToFileName seem to vary. Also, although crashes under nsPrintSettingsX::SetToFileName seem to be the most common, there are other stacks with this same signature, such as this one under the accessibility code:

bp-b3266a61-8ea1-46d7-a045-8f3240180616
(In reply to Andrew McCreight [:mccr8] from comment #1)
> Could bug 1270217 have caused this? That's the only obviously OSX related
> thing in that range...

mstange, any ideas on why updating MACOS_DEPLOYMENT_TARGET to 10.9 could cause this? Maybe something changes so that instead of this Apple code throwing in a way that NS_OBJC_BEGIN_TRY_ABORT_BLOCK_NSRESULT can catch, it's now terminating?
Flags: needinfo?(mstange)
FWIW I tested a debug patch where I tried releasing mPrintInfo in nsPrintSettingsX::SetToFileName before we use it to see if maybe this crash would be triggered if mPrintInfo no longer points to something valid. But that causes the browser to terminate in SetToFileName earlier (at the point where we initialize 'printInfoDict') with EXC_BAD_ACCESS @0x18.
(In reply to Jonathan Watt [:jwatt] from comment #5)
> I've tried all sorts of things to repro this, but without any luck. Alice,
> any chance you can come up with any ideas?

Seems MAC specific crash. Sorry I cannot help
Flags: needinfo?(alice0775)
(In reply to Jonathan Watt [:jwatt] from comment #7)
> (In reply to Andrew McCreight [:mccr8] from comment #1)
> > Could bug 1270217 have caused this? That's the only obviously OSX related
> > thing in that range...
> 
> mstange, any ideas on why updating MACOS_DEPLOYMENT_TARGET to 10.9 could
> cause this? Maybe something changes so that instead of this Apple code
> throwing in a way that NS_OBJC_BEGIN_TRY_ABORT_BLOCK_NSRESULT can catch,
> it's now terminating?

I don't know. I don't have a good understanding of how well the Objective C exception handling code is working and how it's affected by this setting. You could experiment with it a bit by throwing your own exception and seeing what happens.

Maybe spohl has some ideas?
Flags: needinfo?(mstange) → needinfo?(spohl.mozilla.bugs)
Adding the 10.11 signature, which also appears to have started using the 6-6 build.
Crash Signature: [@ CrashReporter::TerminateHandler | std::__terminate] → [@ CrashReporter::TerminateHandler | std::__terminate] [@ CrashReporter::TerminateHandler | libc++abi.dylib@0x23ffd]
Mozilla/5.0 (Macintosh; Intel Mac OS X 10.13; rv:62.0) Gecko/20100101 Firefox/62.0 ID:20180618100844

I can perfectly reproduce this crash with the above build all the time when trying to print from any web page. Here an example:

https://crash-stats.mozilla.com/report/index/6bc014b5-0799-47c5-8e1f-4fd3c0180620

The bad thing additionally here is that it also seems to break session restore. It doesn't restore automatically after crash, and I can only do it once. When the crash happened the 2nd time no sessionrestore is available anymore.
Here is the regression range:

https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=1f62ecdf59b6ecaa3c0fdda39bb296ec092a156b&tochange=0ee6b755ab2ee6d2ab79b17cc97bd4e83424cbfc

I'm fairly sure this has been caused by bug 1270217 which changed the MacOS deployment target from 10.7 to 10.9.

Jonathan or Nathan, can you please have a look?
Blocks: 1270217
Flags: needinfo?(spohl.mozilla.bugs)
Flags: needinfo?(nfroyd)
Flags: needinfo?(jwatt)
As per IRC discussion, Henrik can't reproduce on his work Firefox profile. needinfo'ing as a reminder to investigate what's different between that profile and the other one that does repro.
Flags: needinfo?(jwatt) → needinfo?(hskupin)
And putting back the unintentionally removed needinfo for spohl.
Flags: needinfo?(spohl.mozilla.bugs)
Flags: needinfo?(jwatt)
Running the profile with my debug artifact build I get the following exception raised:

> 2018-06-20 13:29:03.951 firefox[54352:2937674] *** Terminating app due to uncaught exception 'NSInvalidArgumentException', reason: '*** -[__NSPlaceholderDictionary initWithObjects:forKeys:count:]: attempt to insert nil object from objects[30]'
> *** First throw call stack:
> (
> 	0   CoreFoundation                      0x00007fff41a3732b __exceptionPreprocess + 171
> 	1   libobjc.A.dylib                     0x00007fff68ba5c76 objc_exception_throw + 48
> 	2   CoreFoundation                      0x00007fff41a78634 _CFThrowFormattedException + 202
> 	3   CoreFoundation                      0x00007fff4193a962 -[__NSPlaceholderDictionary initWithObjects:forKeys:count:] + 322
> 	4   CoreFoundation                      0x00007fff419a53d9 -[NSDictionary initWithDictionary:copyItems:] + 505
> 	5   CoreFoundation                      0x00007fff41b18979 -[__NSPlaceholderDictionary initWithDictionary:copyItems:] + 137
> 	6   AppKit                              0x00007fff3f1c6182 -[NSPrintInfo initWithDictionary:] + 29
> 	7   XUL                                 0x000000010917d1ad _ZTWN7mozilla3dom15FlushRejections11sDispatchedE + 3706477
> 	8   XUL                                 0x00000001090ed71c _ZTWN7mozilla3dom15FlushRejections11sDispatchedE + 3118044
> 	9   XUL                                 0x000000010917c291 _ZTWN7mozilla3dom15FlushRejections11sDispatchedE + 3702609
> 	10  XUL                                 0x00000001090ef6bf _ZTWN7mozilla3dom15FlushRejections11sDispatchedE + 3126143
> 	11  XUL                                 0x000000010917c3f1 _ZTWN7mozilla3dom15FlushRejections11sDispatchedE + 3702961
> 	12  XUL                                 0x000000010a973e90 workerlz4_maxCompressedSize + 1962112
> 	13  XUL                                 0x000000010a97455e workerlz4_maxCompressedSize + 1963854
> 	14  XUL                                 0x000000010655b005 _ZN14nsXPTCStubBase7Stub249Ev + 8865749
> 	15  XUL                                 0x00000001063cd427 _ZN14nsXPTCStubBase7Stub249Ev + 7236599
> 	16  XUL                                 0x000000010630ad1b _ZN14nsXPTCStubBase7Stub249Ev + 6440171
> 	17  XUL                                 0x0000000106309125 _ZN14nsXPTCStubBase7Stub249Ev + 6433013
> 	18  XUL                                 0x0000000106309b7d _ZN14nsXPTCStubBase7Stub249Ev + 6435661
> 	19  XUL                                 0x000000010630a1a6 _ZN14nsXPTCStubBase7Stub249Ev + 6437238
> 	20  XUL                                 0x0000000105cc694a _ZTWN7mozilla14SchedulerGroup20sTlsValidatingAccessE + 76106
> 	21  XUL                                 0x0000000105cd5f43 _ZTWN7mozilla14SchedulerGroup20sTlsValidatingAccessE + 139075
> 	22  XUL                                 0x00000001090daae1 _ZTWN7mozilla3dom15FlushRejections11sDispatchedE + 3041185
> 	23  XUL                                 0x000000010914ef0e _ZTWN7mozilla3dom15FlushRejections11sDispatchedE + 3517390
> 	24  CoreFoundation                      0x00007fff419cfa61 __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17
> 	25  CoreFoundation                      0x00007fff41a8947c __CFRunLoopDoSource0 + 108
> 	26  CoreFoundation                      0x00007fff419b24c0 __CFRunLoopDoSources0 + 208
> 	27  CoreFoundation                      0x00007fff419b193d __CFRunLoopRun + 1293
> 	28  CoreFoundation                      0x00007fff419b11a3 CFRunLoopRunSpecific + 483
> 	29  HIToolbox                           0x00007fff40c97d96 RunCurrentEventLoopInMode + 286
> 	30  HIToolbox                           0x00007fff40c97b06 ReceiveNextEventCommon + 613
> 	31  HIToolbox                           0x00007fff40c97884 _BlockUntilNextEventMatchingListInModeWithFilter + 64
> 	32  AppKit                              0x00007fff3ef49a73 _DPSNextEvent + 2085
> 	33  AppKit                              0x00007fff3f6dfe34 -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 3044
> 	34  XUL                                 0x000000010914e099 _ZTWN7mozilla3dom15FlushRejections11sDispatchedE + 3513689
> 	35  AppKit                              0x00007fff3ef3e885 -[NSApplication run] + 764
> 	36  XUL                                 0x000000010914f6ce _ZTWN7mozilla3dom15FlushRejections11sDispatchedE + 3519374
> 	37  XUL                                 0x000000010a8b166e workerlz4_maxCompressedSize + 1165406
> 	38  XUL                                 0x000000010a9b407f catch_exception_raise + 161151
> 	39  XUL                                 0x000000010a9b4deb catch_exception_raise + 164587
> 	40  XUL                                 0x000000010a9b5b47 catch_exception_raise + 168007
> 	41  firefox                             0x00000001055fdfcd firefox + 4045
> 	42  libdyld.dylib                       0x00007fff697bf015 start + 1
> )

I will try now to narrow down which setting in this profile causes this crash.
Flags: needinfo?(hskupin)
So it's basically the pref `print.print_to_filename` which you have to set to an invalid / not existent directory. This always triggers the crash in a new profile.
Looking into it.
Assignee: nobody → spohl.mozilla.bugs
Component: Printing: Output → Widget: Cocoa
Flags: needinfo?(spohl.mozilla.bugs)
Flags: needinfo?(nfroyd)
Flags: needinfo?(jwatt)
Priority: -- → P1
Bug 1270217 exposed this, but this was introduced by bug 675709. Patch and explanations coming up.
Blocks: 675709
No longer blocks: 1270217
Depends on: 1270217
Posted patch PatchSplinter Review
There appears to have been a misunderstanding about what [mPrintInfo dictionary] does: this returns the dictionary of the NSPrintInfo object without making a copy. Changes to this dictionary are reflected in the NSPrintInfo object directly[1]. Therefore, it is unnecessary to create new NSPrintInfo objects after changing key/value pairs in this dictionary.

The reason why we crash here is due to the following:
1. We set an NSURL with an invalid path for the NSPrintJobSavingURL key when the print.print_to_filename pref is set to an invalid path.
2. The OS recognizes that this is an invalid path and does two things:
2.a It resets the object for NSPrintJobDisposition from NSPrintSaveJob set here[2] back to the default of NSPrintSpoolJob, and
2.b It appears to set the object for NSPrintJobSavingURL to [NSNull null] before removing the key/value pair completely.
3. There appears to be a timing issue and the call to [[NSPrintInfo alloc] initWithDictionary: printInfoDict] crashes because it is called with the dictionary still having [NSNull null] set for NSPrintJobSavingURL[3] before the key/value pair is removed from the dictionary.

Since printInfoDict is pointing to [mPrintInfo dictionary] already, this entire problem can be avoided by simply forgoing the [[NSPrintInfo alloc] initWithDictionary: printInfoDict] here.

It turned out that creating new NSPrintInfo objects was unnecessary throughout this file and I took this opportunity to clean things up.

Haik, I'm asking you to review because :mstange is on PTO and you've reviewed the patch in bug 675709. Thanks in advance!

[1] https://developer.apple.com/documentation/appkit/nsprintinfo/1524990-dictionary?language=objc
[2] https://dxr.mozilla.org/mozilla-central/rev/681eb7dfa324dd50403c382888929ea8b8b11b00/widget/cocoa/nsPrintSettingsX.mm#364
[3] https://dxr.mozilla.org/mozilla-central/rev/681eb7dfa324dd50403c382888929ea8b8b11b00/widget/cocoa/nsPrintSettingsX.mm#372-373
Attachment #8986880 - Flags: review?(haftandilian)
Note that this may not fix all the crashes with "CrashReporter::TerminateHandler | std::__terminate" as top frame. We will have to file new bugs for the remaining crashes.
whimboo: thanks for narrowing the issue down to the `print.print_to_filename` pref.

spohl: thanks for debugging and fixing this.

I'm more than a little happy not to have to figure out how to back out bug 1270217 without breaking local Mac builds or backing out emilio's mega patches!
Friendly review ping.
Flags: needinfo?(haftandilian)
Comment on attachment 8986880 [details] [diff] [review]
Patch

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

Change looks good to me. Nice catch. I missed how [NSPrintInfo dictionary] works when I touched this file before.

Just to confirm I understand the crash, it happens when we call "[[NSPrintInfo alloc] initWithDictionary: printInfoDict];" when printInfoDict has an invalid NSPrintJobSavingURL?
Attachment #8986880 - Flags: review?(haftandilian) → review+
(In reply to Haik Aftandilian [:haik] from comment #24)
> Comment on attachment 8986880 [details] [diff] [review]
> Just to confirm I understand the crash, it happens when we call
> "[[NSPrintInfo alloc] initWithDictionary: printInfoDict];" when
> printInfoDict has an invalid NSPrintJobSavingURL?

Correct. More specifically, when the printInfoDict has a value of [NSNull null] for the NSPrintJobSavingURL key. This appears to be the case when the OS evaluates the NSURL to be invalid and instead of assigning an invalid value to NSPrintJobSavingURL, it directly assigns [NSNull null] and then appears to remove the key/value pair. The OS appears to perform this verification because we're operating on [mPrintInfo dictionary] directly, rather than a copy of the NSDictionary.
Flags: needinfo?(haftandilian)
https://hg.mozilla.org/integration/mozilla-inbound/rev/cf8f41907eb84464dd816b69cf731bb0b880edcc
Bug 1467582: Prevent crashes on macOS when an invalid path is specified in the print.print_to_filename pref. r=haik
https://hg.mozilla.org/mozilla-central/rev/cf8f41907eb8
Status: NEW → RESOLVED
Closed: Last year
Resolution: --- → FIXED
Target Milestone: --- → mozilla63
Seems promising! If we don't see crashes here in nightly tomorrow, please request uplift since this is a high % of the crashes on beta/dev ed right now.
Flags: needinfo?(spohl.mozilla.bugs)
I can at least verify that this fixes the crash for me with the build of the merge to mozilla-central. Lets hope that this was the one and only problem with that stacktrace.
(In reply to Henrik Skupin (:whimboo) from comment #29)
> I can at least verify that this fixes the crash for me with the build of the
> merge to mozilla-central. Lets hope that this was the one and only problem
> with that stacktrace.

It definitely isn't the only problem. See for example this crash report, which will not be fixed by this patch:

https://crash-stats.mozilla.com/report/index/f88469be-860d-4688-aff2-ff0330180626

However, it does seem like the patch here will fix a significant number of the crashes and it will make it easier to file separate bugs for the remaining crashes.
(In reply to Stephen A Pohl [:spohl] from comment #30)
> However, it does seem like the patch here will fix a significant number of
> the crashes and it will make it easier to file separate bugs for the
> remaining crashes.

You should really submit a pull request to Soccorro to add some of these frames to the skip or prefix signature lists so that the different issues will show up as different signatures.
Summary: Crash in CrashReporter::TerminateHandler | std::__terminate while printing on OSX → Crash in [@ CrashReporter::TerminateHandler | std::__terminate][@ nsPrintSettingsX::SetToFileName] when printing to file on MacOS
(In reply to Stephen A Pohl [:spohl] from comment #30)
> https://crash-stats.mozilla.com/report/index/f88469be-860d-4688-aff2-
> ff0330180626

I filed that as bug 1471363.
Depends on: 1471379
(In reply to Andrew McCreight [:mccr8] from comment #31)
> (In reply to Stephen A Pohl [:spohl] from comment #30)
> > However, it does seem like the patch here will fix a significant number of
> > the crashes and it will make it easier to file separate bugs for the
> > remaining crashes.
> 
> You should really submit a pull request to Soccorro to add some of these
> frames to the skip or prefix signature lists so that the different issues
> will show up as different signatures.

I don't have the bandwidth to work on Socorro at the moment, but I've filed bug 1471379 for this.
Comment on attachment 8986880 [details] [diff] [review]
Patch

There are only a handful of crashes after the 20180626220124 build so far and they're unrelated to print-to-file.

Approval Request Comment
[Feature/Bug causing the regression]: We started seeing these crashes after bug 1270217 landed, although it is not believed that this is the cause of the crashes.
[User impact if declined]: Printing to file will crash the browser if an invalid path was previously specified.
[Is this code covered by automated tests?]: no
[Has the fix been verified in Nightly?]: yes
[Needs manual test from QE? If yes, steps to reproduce]: no
[List of other uplifts needed for the feature/fix]: none
[Is the change risky?]: no
[Why is the change risky/not risky?]: This is a small and well understood change.
[String changes made/needed]: none
Flags: needinfo?(spohl.mozilla.bugs)
Attachment #8986880 - Flags: approval-mozilla-beta?
Comment on attachment 8986880 [details] [diff] [review]
Patch

Crash fix, moderate volume in beta, let's uplift this for beta 5 or 6.
Attachment #8986880 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Blocks: 1290972
No longer depends on: 1270217
You need to log in before you can comment on or make changes to this bug.