790649 - Worker thread crash @ffi_call

Status: VERIFIED FIXED

(Toolkit Graveyard :: OS.File, defect)

Description

[Mats Palmgren (inactive)]

Attachment: stack

STR
1. load URL

(mozilla-inbound, rev 2bbc276ffd2a, debug build)

ACTUAL RESULTS

First-chance exception at 0x7736f9d2 in firefox.exe: 0xC0000008: An invalid handle was specified.

ffi_call
js::ctypes::CDataFinalizer::CallFinalizer
js::ctypes::CDataFinalizer::Methods::Dispose
js::CallJSNative
js::InvokeKernel
js::Interpret
...

see attached stack for details

Comment 1

[:Gavin Sharp [email: [e-mail]]]

Dupe of bug 790633?

Comment 2

[Mats Palmgren (inactive)]

Maybe, marking dependent for now.  I'll re-test when that bug is fixed.

Comment 3

[David Teller [:Yoric] - still alive but not very active]

Sounds like it's in my code. I'll investigate.

Comment 4

[David Teller [:Yoric] - still alive but not very active]

Attachment: Experimental fix

Attaching an experimental fix. Testing as soon as Windows build is complete.

Comment 5

[David Teller [:Yoric] - still alive but not very active]

I have not been able to reproduce the problem yet, and I suspect that it depends on how many images are present in the thumbnails cache. I will keep trying, but in the meantime, I have attached an experimental fix, if anybody wants to test it.

Comment 6

[Jim Mathies [:jimm]]

(In reply to David Rajchenbach Teller [:Yoric] from comment #5)
> I have not been able to reproduce the problem yet, and I suspect that it
> depends on how many images are present in the thumbnails cache. I will keep
> trying, but in the meantime, I have attached an experimental fix, if anybody
> wants to test it.

I'll test to see if I can still reproduce on the latest mc. Will post back today. If I can reproduce it easily I'll apply your patch and see if it fixes it.

One note, I was poking through crash stats looking for crashes that fit the signature I was seeing but didn't find any. So unless I'm looking for the wrong stack token this doesn't seem wide spread.

Comment 7

[Mats Palmgren (inactive)]

Fwiw, I can still reproduce with the attached patch.

Re: crash stats - I'm pretty sure I haven't seen this crash stack before
for this particular test.  There's about 200 or so reports matching
"ffi_call" in the past 4 weeks:
https://crash-stats.mozilla.com/query/query?product=Firefox&version=ALL%3AALL&range_value=4&range_unit=weeks&query_search=signature&query_type=contains&query=ffi_call&reason=&build_id=&process_type=any&hang_type=any&do_query=1

"_PR_SocketSetSocketOption | ffi_call_win32" seems similar to this
in the sense that it has "dom::workers" on the stack.  (the top stack
frame is bogus)
bp-ae38b16c-6324-457e-bb95-7ba3d2120905

"@0x0 | ffi_call_win32 " have reports for recent Nightlies, eg.
bp-65e93cba-9308-47ca-bb51-c7a632120914
these are on the main thread, with "js::CrossCompartmentWrapper::call"
on the stack.

Comment 8

[David Teller [:Yoric] - still alive but not very active]

I tend to believe that the PR_SocketSetSocketOption crash is unrelated.

Comment 9

[David Teller [:Yoric] - still alive but not very active]

Attachment: Experimental fix, v2

Found a second error in the code. Mats, could you try it?

Comment 10

[Mats Palmgren (inactive)]

v2 crashed with the same stack

Comment 11

[David Teller [:Yoric] - still alive but not very active]

Attachment: Experimental fix, v3

Attaching fix v3.

Comment 12

[Mats Palmgren (inactive)]

v3 looks good so far; the crash used to occur within a couple of minutes,
but now it's still alive after an hour.  Note that I have commented out
the "compartment mismatch" assertion though, since that's easily triggered
by this test (I have a JS stack for that assertion if it helps).

I'll leave the test running overnight...

Comment 13

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

This effectively stops me from debugging on Windows, since anytime I attach a debugger I just get Invalid Handle errors over and over again.

Comment 14

[Mats Palmgren (inactive)]

Comment on attachment 662464 [details] [diff] [review]
Experimental fix, v3

fwiw, still no crash with this.  khuey, you want to review?  ;-)

Comment 15

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

Comment on attachment 662464 [details] [diff] [review]
Experimental fix, v3

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

Not really.  I'm not familiar with ctypes or the Windows APIs here.

Comment 16

[Nathan Froyd [:froydnj]]

Comment on attachment 662464 [details] [diff] [review]
Experimental fix, v3

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

::: toolkit/components/osfile/osfile_win_back.jsm
@@ +89,5 @@
>               // == would always return |false|.
>               return INVALID_HANDLE;
>             }
>           return ctypes.CDataFinalizer(maybe, _CloseHandle);
> +       };

Nit^2: I think the 'return' line above this is actually the one that's indented wrong.

@@ +106,5 @@
> +             // == would always return |false|.
> +             return INVALID_HANDLE;
> +           }
> +         return ctypes.CDataFinalizer(maybe, _FindClose);
> +       };

Please change this into something like:

function possibly_invalid_HANDLE_import_from_C(finalizer) {
  function import_from_C(maybe)
    if (Types.int.cast(maybe).value == INVALID_HANDLE) {
      // Explanatory comment
    }
    return ctypes.CDataFinalizer(maybe, finalizer);
  }
  return import_from_C;
}

and use that function in the appropriate places.  I don't have a lot of experience with the Win32 APIs, but hopefully the refactoring will avoid issues in the future.

Comment 17

[David Teller [:Yoric] - still alive but not very active]

(In reply to Nathan Froyd (:froydnj) from comment #16)
> @@ +106,5 @@
> > +             // == would always return |false|.
> > +             return INVALID_HANDLE;
> > +           }
> > +         return ctypes.CDataFinalizer(maybe, _FindClose);
> > +       };
> 
> Please change this into something like:
> 
> function possibly_invalid_HANDLE_import_from_C(finalizer) {
>   function import_from_C(maybe)
>     if (Types.int.cast(maybe).value == INVALID_HANDLE) {
>       // Explanatory comment
>     }
>     return ctypes.CDataFinalizer(maybe, finalizer);
>   }
>   return import_from_C;
> }
> 
> and use that function in the appropriate places.  I don't have a lot of
> experience with the Win32 APIs, but hopefully the refactoring will avoid
> issues in the future.

This is actually slightly more complicated, due to initialization order of variables, so cleanup and factorization of code will probably involve something a little more OO. Due to the blocker status of this bug, do you mind if I land the patch as is and cleanup in a followup?

Comment 18

[Nathan Froyd [:froydnj]]

(In reply to David Rajchenbach Teller [:Yoric] from comment #17)
> This is actually slightly more complicated, due to initialization order of
> variables, so cleanup and factorization of code will probably involve
> something a little more OO. Due to the blocker status of this bug, do you
> mind if I land the patch as is and cleanup in a followup?

I will take your word for it. :)  Landing this as-is is fine.  Please do file a followup after this bug has been made public.

Comment 19

[David Teller [:Yoric] - still alive but not very active]

Attachment: Temporary fix

Attaching the tested fix. Filed a followup refactoring as bug 792668.

Comment 20

[David Teller [:Yoric] - still alive but not very active]

I finally have a scenario that could explain why the testsuite passed but FF itself crashes for something that should not be a fatal error: according to http://msdn.microsoft.com/en-us/library/windows/desktop/ms724211%28v=vs.85%29.aspx 

« If the application is running under a debugger, the function will throw an exception if it receives either a handle value that is not valid or a pseudo-handle value. This can happen if you close a handle twice, or if you call CloseHandle on a handle returned by the FindFirstFile function instead of calling the FindClose function. »

In other words, it is possible that the crashes happen only in presence of a debugger.

Comment 21

[David Teller [:Yoric] - still alive but not very active]

If confirmed, this is not a security bug after all.

Comment 22

[David Teller [:Yoric] - still alive but not very active]

Comment on attachment 662810 [details] [diff] [review]
Temporary fix

[Approval Request Comment]
Bug caused by (feature/regressing bug #): 707681 (original error), 754671 (code is correct but triggers the dormant error).
User impact if declined: Attempting to debug Firefox under Windows fails because of crashes.
Testing completed (on m-c, etc.): With patch applied, we cannot reproduce the bug. Companion patch that makes the error visible to the testsuite will land soon on m-c.
Risk to taking this patch (and alternatives if risky): Very low. No API change. It fixes an error that was otherwise silent.
String or UUID changes made by this patch: None.

Comment 23

[Nathan Froyd [:froydnj]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/a5eaeae97650

Comment 24

[:Gavin Sharp [email: [e-mail]]]

(In reply to Nathan Froyd (:froydnj) from comment #16)
> Nit^2: I think the 'return' line above this is actually the one that's
> indented wrong.

Looks like this nit was not addressed?

Comment 25

[David Teller [:Yoric] - still alive but not very active]

Attachment: Temporary fix, nit addressed

Here is the same fix, with the whitespace nit^2 addressed. Anyway, the followup bug contains a patch that generally looks nicer.

Comment 26

[David Teller [:Yoric] - still alive but not very active]

Comment on attachment 663039 [details] [diff] [review]
Temporary fix, nit addressed

(Updated nitpick as per my understanding of Gavin's request)

[Approval Request Comment]
Bug caused by (feature/regressing bug #): 707681 (original error), 754671 (code is correct but triggers the dormant error).
User impact if declined: Attempting to debug Firefox under Windows fails because of crashes.
Testing completed (on m-c, etc.): With patch applied, we cannot reproduce the bug. Companion patch that makes the error visible to the testsuite will land soon on m-c.
Risk to taking this patch (and alternatives if risky): Very low. No API change. It fixes an error that was otherwise silent.
String or UUID changes made by this patch: None.

Comment 27

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/a5eaeae97650

Comment 28

[Alex Keybl [:akeybl]]

Comment on attachment 663039 [details] [diff] [review]
Temporary fix, nit addressed

[Triage Comment]
Approving for Aurora/Beta based upon the risk evaluation and the benefit to debugging.

Comment 29

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/c7280b298af5

This doesn't apply cleanly to beta. Please post a new patch for it.

Comment 30

[David Teller [:Yoric] - still alive but not very active]

Attachment: Temporary fix (uplift to mozilla-beta)

Same fix, this time for mozilla-beta.
Try run: https://tbpl.mozilla.org/?tree=Try&rev=baea0e889d23

Comment 31

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/28b930feb615

Comment 32

[David Teller [:Yoric] - still alive but not very active]

Post-mortem for this bug, for future reference:

1. The design Microsoft APIs, as often, is "interesting": a |HANDLE| must be closed with |CloseHandle|. However, there are exceptions, and a |HANDLE| obtained through |FindFirstFile| must be closed with |FindClose|.
2. In the Windows back-end of OS.File, I made the double error of closing a find |HANDLE| with |CloseHandle| and not checking the result for possible errors. Consequently, the test suite did not notice the error.
3. The corresponding code was triggered by Tim's work on thumbnails, and also passed Tim's test suite.
4. At some point, people started running that code in the Microsoft Visual Debugger, to catch unrelated bugs. "Interestingly", when the Visual Debugger is launched, the otherwise silent error of attempting to close a find |HANDLE| with |CloseHandle| becomes a C++-style "First-chance exception", i.e. a crash.
5. Hilarity ensues.

Comment 33

[Lukas Blakk [:lsblakk] use ?needinfo]

looks like the original code here is from FF12, marking esr10 unaffected.

Comment 34

[Al Billings [:abillings - ex-MoCo]]

Based on this being exposed by bug 754671, I assume that Firefox 15 is unaffected. Can someone confirm?

Comment 35

[Al Billings [:abillings - ex-MoCo]]

Marking for not-tracking based on talking to Dveditz.

Comment 36

[Matt Wobensmith [:mwobensmith][:matt:]]

Attachment: Crash logs for Beta, Nightly

In trying to regress this bug, it continues to crash. I'm seeing this on Windows 7, with the following builds:

2012-11-13, 17.0b6
2012-11-15, Aurora
2012-11-15, Nightly

The test URL in this bug seems to cycle through many tests. I don't know if we're guaranteed to be looking at the same tests when the crash occurs.

Can someone look at the the logs to determine if this is the same issue? Or if we should be filing new bug(s) instead? Thank you.

In the meantime, this fix can't be verified.

Comment 37

[David Teller [:Yoric] - still alive but not very active]

Are you sure it's the same bug? I don't see any sign in your crash logs that point to ffi_call.

Comment 38

[David Teller [:Yoric] - still alive but not very active]

(In reply to Matt Wobensmith from comment #36)
> Can someone look at the the logs to determine if this is the same issue? Or
> if we should be filing new bug(s) instead? Thank you.

I am nearly certain that this is a different issue.

Comment 39

[Matt Wobensmith [:mwobensmith][:matt:]]

Today I used the exact same builds on Win7 as in comment 36, and no crashes. 

I think the problem is that our baseline test (above) is a URL that contains a randomized suite of tests. Every time it's run, it is different. 

Based on this, I will mark this bug verified and chalk the other crashes up to something I cannot reproduce for now. If they resurface in the future, I'll file a new bug.

Verified original crash on 2012-9-12, nightly

Confirmed fixed:
2012-10-24, 16.02
2012-11-13, 17.0b6
2012-11-15, Aurora
2012-11-15, Nightly