713539 - NSInvalidArchiveOperationException (probably related to site icons) followed by NSKeyedArchiver dealloc warning

Status: RESOLVED FIXED

(Camino Graveyard :: Bookmarks, defect)

Description

[Chris Lawson (gone)]

This showed up in Console this morning:

26/12/2011 11:31:29	Camino[23315]	CGImageDestinationFinalize failed for output type 'public.tiff'
26/12/2011 11:31:29	Camino[23315]	Mozilla has caught an Obj-C exception [NSInvalidArchiveOperationException: Unable to produce TIFF data for bitmap NSBitmapImageRep 0x33b928f0 Size={16, 16} ColorSpace=Device RGB colorspace BPS=8 BPP=32 Pixels=16x16 Alpha=YES Planar=NO Format=2 CurrentBacking=<CGImageRef: 0x1c5d60e0> CGImageSource=0x330f51a0.  This is fatal for -[NSBitmapImageRep encodeWithCoder:].]
26/12/2011 11:31:29	Camino[23315]	*** -[NSKeyedArchiver dealloc]: warning: NSKeyedArchiver deallocated without having had -finishEncoding called on it.

The only URLs in History from around that time are:

http://www.reuters.com/article/2011/12/22/us-usa-airlines-fatigue-idUSTRE7BL1BX20111222
http://www.aopa.org/advocacy/articles/2011/111222faa-resumes-n-number-blocking.html?WT.mc_id=ebrief
http://www.washingtonpost.com/business/ups-pilots-go-to-court-seeking-protection-under-new-faa-rules-that-prevent-flying-while-sleepy/2011/12/22/gIQAJ42pBP_story.html

but I was unable to reproduce the problem by visiting those URLs a second or third time, even after clearing the site icon cache.

I'm *guessing* this is a site icon issue because of the size of the image (16x16) that's failing to be produced, but I don't really know for sure.

Comment 1

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

I thought we got it so Gecko was no longer trying to play with our UI exceptions?  That's definitely a Gecko exception-logging macro, and none of our code is wrapped in that.

That said, it otherwise does look like it could be our site icon code, and it's not like we've never had problems with those exceptions before (e.g., bug 394772).

Comment 2

[philippe (part-time)]

I was able to reproduce that on a default profile with the washingtonpost url. Then I noticed that the favicon was missing (blank) in the location bar.

(Safari also display the blank favicon issue)

http://www.washingtonpost.com/favicon.ico is the offender (multiple sizes in the file, displays blank/empty in Preview).

Comment 3

[philippe (part-time)]

Attachment: favicon from wapo

(funnily, Gecko is able to display that, when dragged into the content part of the window)

Comment 4

[Stuart Morgan]

> I thought we got it so Gecko was no longer trying to play with our UI exceptions?

What's the stack when the exception happens? If we're throwing a Cocoa exception from code that's called by Gecko code, and we aren't catching it, this is what should happen. We're never supposed to let exceptions bleed across boundaries where Gecko has called us (substantially bad things can happen), so it's our bad if that's happening.

Comment 5

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Someone on 10.6 will have to gdb this and get the stack, since I'm not seeing an the exception on 10.5 (even though NSImage is also unable to render the icon, which is a 4-member [64, 32, 24, 16] RGB+A .ico).

Note, though, that our site icon cache is already supposed to be catching NSKeyedUnarchiver exceptions since bug 394772 in the 1.5.x era: http://mxr.mozilla.org/camino/source/camino/src/browser/SiteIconCache.mm#127

Are we possibly hitting an exception trying to enumerate the members?  http://mxr.mozilla.org/camino/source/camino/src/browser/SiteIconProvider.mm#363  It looks like we should already be catching exceptions before that, though, and never hitting that code if we don't have an NSImage…

Anyway, I'm really puzzled here, but since I can't reproduce the exception, I'm out of wild guesses, and someone else will have to debug.  Since both cl and phiw can reproduce this at wapo, though, confirming.

Comment 6

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Oh, maybe it's one of the other callers of |setSiteIcon:forURL:withExpiration:memoryOnly:| (which doesn't catch exceptions when *archiving*)?

SIP's |doneRemoteLoad:| call to |setSiteIcon:…| is done inside the |if (gotImageData)|, so it should never get called if we don't have an image already, but it's possible it also gets called indirectly as a result of one of the other site icon-related UI bits (such as the similarly-named |setSiteIcon:| in HistoryItem).

Comment 7

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

(In reply to comment #6)
> Oh, maybe it's one of the other callers of
> |setSiteIcon:forURL:withExpiration:memoryOnly:| (which doesn't catch
> exceptions when *archiving*)?

http://mxr.mozilla.org/camino/source/camino/src/browser/SiteIconCache.mm#165

Comment 8

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Err, there are only two callers of |setSiteIcon:forURL:withExpiration:memoryOnly:| (where we *archive* the image), SIP's |doneRemoteLoad:| (which is inside the |if (gotImageData)| and post-exception-catching), and SIP's |registerFaviconImage:forPageURI:|, which is *only* called by MainController to register our own local icons for about:blank, history, bookmarks, and the local_file placeholder.

So I remain completely confused; I have no idea how we're triggering this exception at all, and even less idea why Gecko is involved :P

Comment 9

[philippe (part-time)]

Attachment: stack, gdb output

Comment 10

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

So, philippe's gdb-ing answered two of my questions: 

a) It is indeed when we try to archive, in |setSiteIcon:forURL:withExpiration:memoryOnly:|, and 

b) We're getting the Gecko nonsense presumably because the exception runs all the way through RemoteDataProvider's Necko stuff down to nsAppShell.mm's |nsAppShell::ProcessGeckoEvents|, which is of course wrapped in that macro.

It's raised two more questions, though: 

1) Why weren't cl and phiw seeing http://mxr.mozilla.org/camino/source/camino/src/browser/SiteIconCache.mm#168 ?  Does the exception b0rk that?

2) More importantly, how are we even calling |setSiteIcon:forURL:withExpiration:memoryOnly:| from inside |doneRemoteLoad:…|?  Is NSImage actually succeeding in giving us a valid NSImage from the ico but then NSKeyedArchiver balking at it?

2a) Why does gdb claim SiteIconProvider.mm:428, which is 
NSMutableArray* requestList = [mRequestDict objectForKey:inURI];
not the call to |setSiteIcon:forURL:withExpiration:memoryOnly:|?

Finally, I'm not sure exactly how to fix this.  Obviously we want to wrap the attempt to archive in @try; in @catch, should we just set the imageSaved to NO (presumably archiving can fail for non-exception-related reasons, too)?  

And what about the "-[NSKeyedArchiver dealloc]: warning: NSKeyedArchiver deallocated without having had -finishEncoding called on it." bit from the log?  Is that our responsibility to clean up, or Apple's?

---

Also, someone on a new enough large feline for Apple to care about should rdar:// NSImage's handling of the Washington Post icon, assuming NSImage is still busted there (on 10.3 we actually got colored garbage data instead of the almost-all-blank garbage data returned on 10.5 and presumably 10.6 :P ).

Comment 11

[Stuart Morgan]

(In reply to Smokey Ardisson (back-ish; no bugmail - do not email) from comment #10)
> 1) Why weren't cl and phiw seeing
> http://mxr.mozilla.org/camino/source/camino/src/browser/SiteIconCache.mm#168
> ?  Does the exception b0rk that?

Yes, exceptions unwind the stack, without finishing any of the methods they unwind, until a handler is reached. That's why letting them leak into Gecko code is so bad.

> Is NSImage actually succeeding in giving us a valid
> NSImage from the ico but then NSKeyedArchiver balking at it?

It does look that way, which is weird.

> 2a) Why does gdb claim SiteIconProvider.mm:428, which is 
> NSMutableArray* requestList = [mRequestDict objectForKey:inURI];
> not the call to |setSiteIcon:forURL:withExpiration:memoryOnly:|?

That's the next statement that would execute; that's not uncommon for things other than the top of the stack.

> Finally, I'm not sure exactly how to fix this.  Obviously we want to wrap
> the attempt to archive in @try; in @catch, should we just set the imageSaved
> to NO (presumably archiving can fail for non-exception-related reasons,
> too)?  

Yep, that way we'll get the logging about the URL that failed, so if someone files a bug it'll be easy to find the repro case.

> And what about the "-[NSKeyedArchiver dealloc]: warning: NSKeyedArchiver
> deallocated without having had -finishEncoding called on it." bit from the
> log?  Is that our responsibility to clean up, or Apple's?

That looks like framework-internal bustage from the stack unwinding in their code, so it's Apple's issue.

Comment 12

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Attachment: Protect against exceptions when archiving

Here's the patch to fix this.  It compiles, but I can't test it, since whatever it is down in framework land doesn't throw on 10.5.  

The expected result of a patched build is no Gecko exception-logging, but instead a "Failed to archive image for some_url to file."

Since I was changing the one comment, I went ahead and punctuated all of the comments in that method as sentences.  Since I was already doing sentence punctuation in the method, I also punctuated the NSLog as a sentence. :-P

Only one question: do we care about seeing the actual exception?  We don't currently care in the code Stuart added in |siteIconForURL:| for bug 394772 for unarchiving, but we do care apparently in SIP's |doneRemoteLoad:…| when trying to make the favicon (smfr added that code in 2002, in the early days of Cocoa exceptions unwinding into Gecko :P).

Comment 13

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

(In reply to comment #10)

> Also, someone on a new enough large feline for Apple to care about should
> rdar:// NSImage's handling of the Washington Post icon, assuming NSImage is
> still busted there (on 10.3 we actually got colored garbage data instead of
> the almost-all-blank garbage data returned on 10.5 and presumably 10.6 :P ).

Wevah says the icon renders correctly on 10.7; I'm not sure Apple would care enough about Safari 5.1.x not displaying the Washington Post site icon on 10.6 unless there were security implications?

Comment 14

[philippe (part-time)]

Comment on attachment 584627 [details] [diff] [review]
Protect against exceptions when archiving

This builds fine on 10.6. Console doesn't log any exceptions when loading the WaPo page(s).

Console output: 
12/29/11 9:45:12 AM	Camino[41079]	CGImageDestinationFinalize failed for output type 'public.tiff'
12/29/11 9:45:12 AM	Camino[41079]	Failed to archive image for http://www.washingtonpost.com/favicon.ico to file.
12/29/11 9:45:12 AM	Camino[41079]	*** -[NSKeyedArchiver dealloc]: warning: NSKeyedArchiver deallocated without having had -finishEncoding called on it.

Comment 15

[Stuart Morgan]

Comment on attachment 584627 [details] [diff] [review]
Protect against exceptions when archiving

sr=smorgan

It wouldn't hurt to log the exception details (in the catch block), but it's not a big deal; the only reason to do that would be to file a bug with Apple, and if we are going to do that we'd want to make sure we could repro it anyway, at which point we could add logging locally.

Comment 16

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

http://hg.mozilla.org/camino/rev/de75f803c31b

Landed as-is, since so far as we can tell, the exception part of the problem exists only on 10.6.

Comment 17

[Chris Lawson (gone)]

29/08/2012 17:33:38	Camino[172]	CGImageDestinationFinalize failed for output type 'public.tiff'
29/08/2012 17:33:38	Camino[172]	Failed to archive image for http://www.foxnews.com/favicon.ico to file.
29/08/2012 17:33:38	Camino[172]	*** -[NSKeyedArchiver dealloc]: warning: NSKeyedArchiver deallocated without having had -finishEncoding called on it.

I can repro that 100% just by visiting any foxnews.com URL.

The question is, is that warning something we care about fixing? (I assume we're still at the "this might be an Apple bug" stage, so maybe a better question is whether this is something that might have been fixed on 10.7 or 10.8 in the interim, and if not, where we go from here.)

Comment 18

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

See the last paragraph of comment 11, and comment 15.

Comment 19

[philippe (part-time)]

(In reply to Chris Lawson from comment #17)

Fwiw, I don't see anything in the logs when loading that site on 10.8.1.

Comment 20

[Chris Lawson (gone)]

(In reply to philippe (part-time) from comment #19)
> (In reply to Chris Lawson from comment #17)
> 
> Fwiw, I don't see anything in the logs when loading that site on 10.8.1.

I forget; do you still have a 10.6 or 10.7 box you can test on?

Comment 21

[philippe (part-time)]

(In reply to Chris Lawson from comment #20)
> (In reply to philippe (part-time) from comment #19)
> > (In reply to Chris Lawson from comment #17)
> > 
> > Fwiw, I don't see anything in the logs when loading that site on 10.8.1.
> 
> I forget; do you still have a 10.6 or 10.7 box you can test on?

I expect to see the same as you do on 10.6 (see comment 14). I'll double-check when I get a chance. I don't have 10.7 anymore, but I remember verifying that the logging was gone on 10.7 (and the favicon displayed correct).

Comment 22

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Also comment 13, which I missed earlier; it looks like Apple fixed the "NSImage can't display this ICO data" bug in 10.7.

I presume they also fixed the 10.6-only NSKeyedArchiver exception in 10.7, or else by fixing the underlying NSImage bug they avoided that exception.