1128457 - CookieServiceParent::RecvGetCookieString occasionally fails

Status: VERIFIED FIXED

Description

[Jim Mathies [:jimm]]

mozilla::net::PCookieServiceChild::SendGetCookieString occasionally fails, causing an abort of the child process.

https://dxr.mozilla.org/mozilla-central/source/netwerk/cookie/CookieServiceParent.cpp#74

Comment 1

[Jim Mathies [:jimm]]

This might be tear down related.

Comment 2

[Ben Turner (not reading bugmail, use the needinfo flag!)]

(In reply to Jim Mathies [:jimm] from comment #1)
> This might be tear down related.

It sounds like it's just some race where GetAppInfoFromParams is returning false: 
https://dxr.mozilla.org/mozilla-central/source/netwerk/cookie/CookieServiceParent.cpp#95

Comment 3

[Jim Mathies [:jimm]]

This is predominantly caused by these MsgNotAllowed errors:

(msgtype=0x340001,name=???) Message not allowed: cannot be sent/recvd in this state

Comment 4

[Ben Turner (not reading bugmail, use the needinfo flag!)]

Ah, so they just timed out.

http://mxr.mozilla.org/mozilla-central/source/ipc/glue/MessageChannel.cpp#1187

Comment 5

[Jim Mathies [:jimm]]

noticed this in today's data, for reasons:

'(msgtype=0x340001,name=???) Message not allowed: cannot be sent/recvd in this state'
'HangMonitor'

Comment 6

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

"HangMonitor" is the reason we give when the user kills a content process using the slow script/plugin hang UI.

Comment 7

[Jim Mathies [:jimm]]

oops, wrong bug.

Comment 8

[Blake Kaplan (:mrbkap)]

Hey Jim,

Is it possible to figure out if there are particular extensions that cause this or generally to get a list of crash reports that are caused by this indirect signature?

Comment 9

[Jim Mathies [:jimm]]

(In reply to Blake Kaplan (:mrbkap) (please use needinfo!) from comment #8)
> Hey Jim,
> 
> Is it possible to figure out if there are particular extensions that cause
> this or generally to get a list of crash reports that are caused by this
> indirect signature?

Use supersearch and key in on a part of the ipc error message you're interested in, like '0x340001' - 

https://crash-stats.mozilla.com/search/?product=Firefox&version=39.0a1&ipc_channel_error=~0x340001&_facets=signature&_columns=date&_columns=signature&_columns=product&_columns=version&_columns=build_id&_columns=platform#crash-reports

Note this hex message value I'm using can change over time: 0x34 is a message class, 0x01 is the message id. Message classes are defined in obj/ipc/ipdl/_ipdlheaders/IPCMessageStart.h, message ids are defined in the main auto-generated protocol header (like PContent.h and PPluginWidget.h).

Comment 10

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

I can reproduce this now. I'm in the middle of debugging it.

The basic STR is to install LastPass and visit a page where JS hangs (which is pretty easy because of bug 1113369). Then... do some stuff after it hangs. I see crashes from SendGetInputContext and SendGetCookieString, both urgent messages.

Comment 12

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Re-opening because of https://bugzilla.mozilla.org/show_bug.cgi?id=1056018#c20.

Comment 13

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Created attachment 8586350 [details] [diff] [review]
patch for possible problem

It's really hard to tell what's going on here, but I looked over the code again and found a potential problem. WaitForSyncNotify can return try (meaning a timeout) even if we received a message reply. Additionally, we can receive a reply during ShouldContinueFromTimeout since it releases the lock. So we should check for a reply before deciding to time out. Otherwise we'll never unset mTimedOutMessageSeqno.

Comment 14

[David Anderson [:dvander] - inactive, e-mail if emergency]

Comment on attachment 8586350 [details] [diff] [review]
patch for possible problem

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

Good catch.

Comment 15

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/966f9a3fa1f8

Comment 16

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/966f9a3fa1f8

Comment 17

[Jim Mathies [:jimm]]

fixed:
http://www.mathies.com/mozilla/client-abort-report.txt

Comment 18

[Jim Mathies [:jimm]]

Oops, sorry, I was looking at the wrong list.

Comment 19

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

It looks like this fixed the MsgNotAllowed errors for non-urgent messages. It didn't fix the problem for urgent messages like GetCookieString since won't process incoming CPOWs in ProcessPendingMessages. So I think we need a separate solution for that.

Comment 20

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Created attachment 8589358 [details] [diff] [review]
patch for urgent messages

This patch complements the patch in bug 1142109. They both address the problem where the parent is in the timed out state (i.e., it sent a CPOW that timed out and it hasn't gotten a reply for that CPOW yet). If we get a message in the timed out state, we need to decide what to do.

Originally, we always returned an error for the message. That was to ensure that we didn't start processing the incoming message at the same time the child started processing the timed out CPOW. In general, both sides processing messages at the same time is bad.

The patch in bug 1142109 ensured that we always process incoming messages before sending a message. That way, if the child sends something while a CPOW is in its input queue, it will handle the CPOW before sending its message.

However, it won't handle the CPOW if it's sending an urgent messages, since we defer everything when waiting for an urgent response. However, there's no reason why the parent can't process the child's message in that case, since the child is guaranteed to not process anything, thus avoiding the problem where both sides dispatch at once.

So this patch causes the parent to process incoming urgent messages when it has a timed out CPOW that it hasn't received a response for.

Comment 21

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/74b5bb9f1263

Comment 22

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/74b5bb9f1263

Comment 23

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

I think we can declare this fixed. There have been 9 crashes with "message not allowed" for the 2015-04-15 build so far. In a comparable time period, the 2015-04-14 build had 84 "message not allowed" crashes.

If the crash volume is still too high, we can make "message not allowed" be non-fatal for the child. I was avoiding doing that so we could monitor how often it happens. But as long as it's not too common, it's fine to make it non-fatal.

Comment 24

[Jim Mathies [:jimm]]

One hit in the last three days, definitely fixed!