1197679 - [e10s] Can't open AmazonCloudDriveInstaller.dmg file downloaded when e10s is enabled: "Reason: Illegal Seek"

Status: RESOLVED FIXED

(Core :: Networking: HTTP, defect)

Description

[Chris Peterson [:cpeterson]]

STR:
1. Enable e10s and OS X.
2. Load https://www.amazon.com/gp/drive/app-download/desktop
3. Wait for AmazonCloudDriveInstaller.dmg to be downloaded.

RESULT:
The dmg file will be downloaded, but when Firefox tries to open it, a Finder error dialog says the dmg can't be opened, "Reason: Illegal Seek".

If you disable e10s, then the downloaded dmg can be opened successfully. This bug is not a regression. I tried to bisect this error, but the regression range just pointed to the day when e10s was enabled by default in Nightly 38.

Comment 1

[Brad Lassey [:blassey] (use needinfo?)]

Trying this with a debug Nightly, I the following during download:

[Parent 41460] WARNING: Appending an extra chunk for SourceBuffer: file /builds/slave/m-cen-m64-st-an-d-000000000000/build/src/image/SourceBuffer.cpp, line 70
[Parent 41460] WARNING: Appending an extra chunk for SourceBuffer: file /builds/slave/m-cen-m64-st-an-d-000000000000/build/src/image/SourceBuffer.cpp, line 70
Assertion failure: !mDiverted (child forwarding callbacks after request was diverted), at /builds/slave/m-cen-m64-st-an-d-000000000000/build/src/uriloader/exthandler/ExternalHelperAppParent.cpp:127
#01: mozilla::LoadInfo::RedirectChain()[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0x876884]
#02: mozilla::LoadInfo::RedirectChain()[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0x4e86cf]
#03: mozilla::LoadInfo::RedirectChain()[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0x4e7359]
#04: mozilla::LoadInfo::RedirectChain()[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0x4e1518]
#05: mozilla::LoadInfo::RedirectChain()[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0x4b55fc]
#06: mozilla::LoadInfo::RedirectChain()[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0x4b595b]
#07: mozilla::LoadInfo::RedirectChain()[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0x4ec115]
#08: XRE_AddJarManifestLocation[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0xea8e5]
#09: NS_UTF16ToCString[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0x1294df]
#10: mac_plugin_interposing_child_OnShowCursor[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0x2796524]
#11: mac_plugin_interposing_child_OnShowCursor[/Applications/NightlyDebug.app/Contents/MacOS/XUL +0x27eb0ee]
#12: __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__[/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation +0x80a01]
#13: __CFRunLoopDoSources0[/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation +0x72b8d]
#14: __CFRunLoopRun[/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation +0x721bf]


Rueben, you added this assert. Any thoughts?

Comment 2

[Reuben Morais [:reuben]]

This is very confusing. Here's what's going on up the stack in the corresponding SendOnDataAvailable call that triggers the assert:

(lldb) up 7
frame #7: 0x0000000100b189ba XUL`mozilla::net::HttpChannelChild::RecvOnTransportAndData(this=0x000000012754f800, channelStatus=0x00007fff5fbfb724, transportStatus=0x00007fff5fbfb720, progress=0x00007fff5fbfb718, progressMax=0x00007fff5fbfb710, data=0x00007fff5fbfb700, offset=0x00007fff5fbfb6f8, count=0x00007fff5fbfb6f4) + 522 at HttpChannelChild.cpp:576
   573 	    MOZ_RELEASE_ASSERT(!mDivertingToParent,
   574 	                       "ShouldEnqueue when diverting to parent!");
   575
-> 576 	    OnTransportAndData(channelStatus, transportStatus, progress, progressMax,
   577 	                       data, offset, count);
   578 	  }
   579 	  return true;
(lldb) p mDivertingToParent
(bool) $9 = true
(lldb) p mEventQ->ShouldEnqueue()
(bool) $10 = true

Note that I had a breakpoint on HttpChannelChild::RecvOnTransportAndData but for some reason it wasn't hit, even though it's clearly on the stack. According to my possibly broken debugger session:

1) We start the download
2) HttpChannelChild::DivertToParent is called, sets mDivertingToParent, does its thing
3) HttpChannelChild::RecvOnTransportAndData is called, calls OnTransportAndData (which ends up calling SendOnDataAvailable) even though mDivertingToParent is true and so is mEventQ->ShouldEnqueue()
4) what

Comment 3

[Reuben Morais [:reuben]]

Steve, any ideas why OnDataAvailable is getting called on the listener even though we've already called DivertToParent?

Comment 4

[Dragana Damjanovic [:dragana]]

I can look into this if Steve does not mind :)

Comment 5

[Steve Workman [:sworkman] (INACTIVE)]

I do not mind at all, and I was actually intending on asking you to look at it :) Thanks Dragana!

Comment 6

[Dragana Damjanovic [:dragana]]

So we have:

HttpChannelChild -> nsUnknownDecoder -> ExternalHelperAppChild

nsUnknownDecoder some times need to wait for OnDataAvailable to decide about decoder. So it does not send OnStartRequest until it gets OnDataAvailable. When ExternalHelperAppChild::OnStartRequest is call HttpChannelChild::DivertToParent gets called but OnDataAvailable has already been called....

Comment 7

[Dragana Damjanovic [:dragana]]

Attachment: bug_1197679_v1.patch

Comment 8

[Dragana Damjanovic [:dragana]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=59e2fd588c7c

Comment 9

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

Jason, this is one of our M8 bugs. How's the review coming? :-)

Comment 10

[Jason Duell]

Comment on attachment 8656526 [details] [diff] [review]
bug_1197679_v1.patch

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

This code all makes sense to me.  Ideally I'd like to see a test, but I can live w/o one if we're in a hurry and you've verified the STR in comment 0 no longer fail (and the download contains the correct bytes in the right order).

Make sure to update the uuid before you land.

::: netwerk/base/nsIDivertableChannel.idl
@@ +58,5 @@
>     */
>    ChannelDiverterChild divertToParent();
> +
> +  /**
> +   * nsUnknownDecoder delays calling OnStartRequest until it gets enought data

s/enought/enough/

@@ +60,5 @@
> +
> +  /**
> +   * nsUnknownDecoder delays calling OnStartRequest until it gets enought data
> +   * to decide about the content type (until OnDataAvaiable is called). In a
> +   * OnStartRequest DivertToParent can be call but some OnDataAvailables are

s/call/called/

@@ +61,5 @@
> +  /**
> +   * nsUnknownDecoder delays calling OnStartRequest until it gets enought data
> +   * to decide about the content type (until OnDataAvaiable is called). In a
> +   * OnStartRequest DivertToParent can be call but some OnDataAvailables are
> +   * already call and therefore can not be diverted to parent.

s/call/called/

@@ +69,5 @@
> +   * listener it will call UnknownDecoderInvolvedOnStartRequestCalled. In this
> +   * function Child process will decide to discarge data if it is not diverting
> +   * to parent or keep them if it is diverting to parent.
> +   */
> +  void unknownDecoderInvolvedKeepData();

You've added a method to the IDL, so you should update its UUID.

::: netwerk/ipc/ChannelEventQueue.h
@@ +130,5 @@
>  
> +inline nsresult
> +ChannelEventQueue::PrependEvents(nsTArray<nsAutoPtr<ChannelEvent> >& aEvents)
> +{
> +  if (!mEventQueue.InsertElementsAt(0, aEvents.Length())) {

Seems that you could use InsertElementsAt(aEvents) without needing to first insert a bunch of empty entries and then replacing them?

@@ +134,5 @@
> +  if (!mEventQueue.InsertElementsAt(0, aEvents.Length())) {
> +    return NS_ERROR_OUT_OF_MEMORY;
> +  }
> +
> +  for(uint32_t i = 0; i < aEvents.Length(); i++) {

Space between for and '(', you barbarian! :)

::: netwerk/protocol/ftp/FTPChannelChild.h
@@ +124,5 @@
>    nsRefPtr<ChannelEventQueue> mEventQ;
> +
> +  // If nsUnknownDecoder is involved OnStartRequest call will be delay and
> +  // this queue keeps OnDataAvailable and OnStopRequest until the end
> +  // OnStartRequest is called.

// If nsUnknownDecoder is involved we queue onDataAvailable (and possibly OnStopRequest) 
// so that we can divert them if needed when the listener's OnStartRequest is finally called.

::: netwerk/protocol/http/HttpChannelChild.h
@@ +190,5 @@
>    bool mIPCOpen;
>    bool mKeptAlive;            // IPC kept open, but only for security info
>    nsRefPtr<ChannelEventQueue> mEventQ;
>  
> +  // If nsUnknownDecoder is involved OnStartRequest call will be delay and

delayed

@@ +191,5 @@
>    bool mKeptAlive;            // IPC kept open, but only for security info
>    nsRefPtr<ChannelEventQueue> mEventQ;
>  
> +  // If nsUnknownDecoder is involved OnStartRequest call will be delay and
> +  // this queue keeps OnDataAvailable data until the end OnStartRequest is

until OnStartRequest is finally called

Comment 11

[Dragana Damjanovic [:dragana]]

Attachment: bug_1197679_v1.patch

Comment 12

[Dragana Damjanovic [:dragana]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=64629fb6c81e

Comment 13

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/2e9ee2819de4

Comment 14

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/2e9ee2819de4