Closed Bug 1520150 Opened Last year Closed Last year

XHR POST of a FormData object containing Blob and a File hangs indefinitely

Categories

(Core :: DOM: Core & HTML, defect, P2)

64 Branch
defect

Tracking

()

RESOLVED FIXED
mozilla67
Tracking Status
firefox67 --- fixed

People

(Reporter: mail, Assigned: baku)

Details

Attachments

(6 files, 2 obsolete files)

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:64.0) Gecko/20100101 Firefox/64.0

Steps to reproduce:

I'm a developer at https://p3d.in/ and we recently noticed that uploading larger models using Firefox 64.0.2 hangs indefinitely at random.

The problem seems very similar to one we reported bit over a year ago (https://bugzilla.mozilla.org/show_bug.cgi?id=1393063) and the previous test case reproduces the issue after only small modifications.

The bug seems to happen when a FormData object that contains BOTH a file and at least 3-6mb of constructed Blob data, is sent using XHR POST request. Our investigation indicates that the request opens a HTTP connection but never starts sending the payload, therefore hangs until the server terminates the connection.

Here is a test case that we have confirmed to replicate the bug on Windows 10, Ubuntu and Mac OS using the Firefox 64.0.2 release. Also the latest Nightly build of Firefox 66.0 seems to be affected.

Steps to reproduce:

  1. Open the test case HTML page: https://miikah.fi/other/firefox_blob_xhr_bug_2.html
  2. In the file dialog select any file or this file that has been confirmed to reproduce the issue: https://miikah.fi/other/test_texture.jpg
  3. When the file is selected javascript will send XHR request to "/dummyurl" containing the selected file and two randomly generated 7mb Blob() objects

Actual results:

What happens on latest Firefox version:

  • The status box will indefinitely display "Pending..."
  • The POST request appears at Developer Tools network tab but remains hanging without uploading any data
  • Note that this only seems to happen about 50% of the time in some of the systems we tested this with. If upload starts correctly please refresh the page and try again couple of times.

Expected results:

What is supposed to happen:

  • The status box should switch to "Sending..." and eventually to "Done"
  • Network tab should show the "/dummyurl" request active and eventually complete

This test case works fine in and all other browsers in cluding Google Chrome.

Hi,

I couldn't reproduce the issue using the above steps on the latest Nightly 66.0a1 20190120213632 on Win10 x64, indeed the status box seems to remain in pending status for a way longer while than on Chorme, but eventually the status changes to Done. Tried several times, but always got the same result. On Chrome indeed the file is uploaded successfully almost instantly.

I'm assigning the same component as on the mentioned bug 1393063.

Andrew, can you take a look if this is indeed a new issue as you seem to be familiar with the problem?

Component: Untriaged → HTML: Form Submission
Flags: needinfo?(bugmail)
Product: Firefox → Core

Ah sorry, I forgot to mention. It will indeed change to "Done" eventually after couple of minutes. This happens when the server (in test link's this case Nginx) terminates the hanging connection because no data is being transferred. Sounds like you were able to reproduce the issue then.

If you look at developer tools network tab the connection never receives a status code and displays "Transferred 0 B". I will attach a screenshot of this.

(In reply to MiikaH from comment #2)

Ah sorry, I forgot to mention. It will indeed change to "Done" eventually after couple of minutes. This happens when the server (in test link's this case Nginx) terminates the hanging connection because no data is being transferred. Sounds like you were able to reproduce the issue then.

If you look at developer tools network tab the connection never receives a status code and displays "Transferred 0 B". I will attach a screenshot of this.

Indeed "the connection never receives a status code and displays "Transferred 0 B"" as on the attached image, while on Chrome transfer data is shown. I'll mark this issue as New.

Status: UNCONFIRMED → NEW
Ever confirmed: true
Flags: needinfo?(bugmail) → needinfo?(amarchesini)

Here is the result of the debugging:

FormData, in the content process, creates a nsMultiplexInputStream composed by 7 substreams:

  1. nsStringInputStream: the initial multipart body (170 bytes)
  2. nsBufferedInputStream(nsStringInputStream): the first memory blob. 7mb of data.
  3. nsStringInputStream: another text part of the multipart body (154 bytes)
  4. nsBufferedInputStream(IPCBlobInputStream): the OS File blob (the size is known asynchronously) - ~0 byes when serialized via IPC.
  5. nsStringInputStream: another text part of the multipart body (179 bytes)
  6. nsBufferedInputStream(nsStringInputStream): the second memory blob. 7mb of data
  7. nsStringInputStream: the last text part of the multipart body (62 bytes)

When we serialize it we call this code:

https://searchfox.org/mozilla-central/rev/39265dd58298c40bed029617ad408bf806cce761/ipc/glue/IPCStreamUtils.cpp#188-196

In order to serialize it, we calculate the expected size (which is how much data must be sent via IPC). This is: 15000565 bytes. This is not the size of the stream, because IPCBlobInputStream doesn't need to send data to the parent process.

The expected size is greater then kTooLargeStream (1mb) and we decide to send a pipe stream.

This decision triggers several problems:

  1. the content process is unable to calculate the length of the stream synchronously because IPCBlobInputStream doesn't know the OS File size yet. The reading of this information is async (for several reasons which are out of topic here).

https://searchfox.org/mozilla-central/rev/39265dd58298c40bed029617ad408bf806cce761/ipc/glue/IPCStreamUtils.cpp#129-136
Because of that, we send length = -1. When the stream is received by the parent process, it tries to calculate the length, but the stream is async and we crash (in debug builds) here:
https://searchfox.org/mozilla-central/rev/39265dd58298c40bed029617ad408bf806cce761/xpcom/io/InputStreamLengthHelper.cpp#153-158
As the comment says: we need to fix the caller.

  1. Let's assume that we have the inputStream size, somehow, in order to read the content, the parent process needs to read data from the pipe Stream, which means that, when it needs to read the OS File, it must send the whole file, in chunks, to the content process, and read it back.

The way I would fix this is to let the single inputStream to choose if a pipe should be used or not. If we do so, the parent process will deserialize a stream like this:

nsMultiplexInputStream containing

  1. nsStringInputStream: the initial multipart body (170 bytes)
  2. pipeStream: the first memory blob. 7mb of data.
  3. nsStringInputStream: another text part of the multipart body (154 bytes)
  4. FileInputStream: the OS File blob
  5. nsStringInputStream: another text part of the multipart body (179 bytes)
  6. pipeStream: the second memory blob. 7mb of data
  7. nsStringInputStream: the last text part of the multipart body (62 bytes)

The size would be known and sent by the content process, together with the serialized stream.

Flags: needinfo?(amarchesini)
Priority: -- → P2
Assignee: nobody → amarchesini
Attachment #9039037 - Flags: review?(bugs)
Attached patch part 2 - IPCStream refactoring (obsolete) — Splinter Review
Attachment #9039038 - Flags: review?(bugs)

and the tests are where? ;)

Flags: needinfo?(amarchesini)
Comment on attachment 9039037 [details] [diff] [review]
part 1 - passing IPC managers


>-  // If a stream is known to be larger than 1MB, prefer sending it in chunks.
>-  const uint64_t kTooLargeStream = 1024 * 1024;
>-
>   nsCOMPtr<nsIIPCSerializableInputStream> serializable =
>       do_QueryInterface(aStream);
> 
>-  // ExpectedSerializedLength() returns the length of the stream if serialized.
>-  // This is useful to decide if we want to continue using the serialization
>-  // directly, or if it's better to use IPCStream.
>-  uint64_t expectedLength =
>-      serializable ? serializable->ExpectedSerializedLength().valueOr(0) : 0;
>-  if (serializable && expectedLength < kTooLargeStream) {
So why do we make this behavioral change in this patch which otherwise just new, still rather dummy methods.


> 
> class NS_NO_VTABLE nsIIPCSerializableInputStream : public nsISupports {
>  public:
>   typedef nsTArray<mozilla::ipc::FileDescriptor> FileDescriptorArray;
> 
>   NS_DECLARE_STATIC_IID_ACCESSOR(NS_IIPCSERIALIZABLEINPUTSTREAM_IID)
> 
>   virtual void Serialize(mozilla::ipc::InputStreamParams& aParams,
>-                         FileDescriptorArray& aFileDescriptors) = 0;
>+                         FileDescriptorArray& aFileDescriptors,
>+                         bool aDelayedStart,
>+                         mozilla::dom::nsIContentChild* aManager) = 0;
>+
>+  virtual void Serialize(mozilla::ipc::InputStreamParams& aParams,
>+                         FileDescriptorArray& aFileDescriptors,
>+                         bool aDelayedStart,
>+                         mozilla::ipc::PBackgroundChild* aManager) = 0;
>+
>+  virtual void Serialize(mozilla::ipc::InputStreamParams& aParams,
>+                         FileDescriptorArray& aFileDescriptors,
>+                         bool aDelayedStart,
>+                         mozilla::dom::nsIContentParent* aManager) = 0;
>+
>+  virtual void Serialize(mozilla::ipc::InputStreamParams& aParams,
>+                         FileDescriptorArray& aFileDescriptors,
>+                         bool aDelayedStart,
>+                         mozilla::ipc::PBackgroundParent* aManager) = 0;

This really needs some documentation. Especially, what is eDelayedStart for?

>+void nsStorageInputStream::SerializeInternal(InputStreamParams& aParams,
>+                                             bool aDelayedStart, M* aManager) {
>+  uint64_t remaining = 0;
>+  nsresult rv = Available(&remaining);
>+  MOZ_ASSERT(NS_SUCCEEDED(rv));
>+
>+  if (remaining > 0) {
>+    // TODO
>+  }
>+
>   nsCString combined;
>   int64_t offset;
>-  nsresult rv = Tell(&offset);
>-  MOZ_ASSERT(NS_SUCCEEDED(rv));
>-
>-  uint64_t remaining;
>-  rv = Available(&remaining);
>+  rv = Tell(&offset);
>   MOZ_ASSERT(NS_SUCCEEDED(rv));
I don't understand the changes here, but I assume this code will change in other patches.
Attachment #9039037 - Flags: review?(bugs) → review+
Comment on attachment 9039038 [details] [diff] [review]
part 2 - IPCStream refactoring

># HG changeset patch
># User Andrea Marchesini <amarchesini@mozilla.com>
># Parent  eb9fc8e94ab03e77e06bac26aad0211a6981613f
>Bug 1520150 - Single InputStreams can serialize themselves as IPCRemoteStreams (pipe) - part 2 - IPCRemoteSteam part of InputStreamParams union, r?smaug
>
>Before this patch, IPCStream as an union containing IPCRemoteSteam or a
>InputStreamParamsWithFds. Now InputStreamParamsWithFds is renamed IPCStrea and
>IPCRemoteSteam is one of the possible InputStreamParams structs.
Please fix the typos in the comment

>diff --git a/ipc/glue/InputStreamUtils.h b/ipc/glue/InputStreamUtils.h
>--- a/ipc/glue/InputStreamUtils.h
>+++ b/ipc/glue/InputStreamUtils.h
>@@ -39,16 +39,22 @@ class InputStreamHelper {
>                                    mozilla::dom::nsIContentParent* aManager);
> 
>   static void SerializeInputStream(nsIInputStream* aInputStream,
>                                    InputStreamParams& aParams,
>                                    nsTArray<FileDescriptor>& aFileDescriptors,
>                                    bool aDelayedStart,
>                                    PBackgroundParent* aManager);
> 
>+  static void PostSerializationCleanup(InputStreamParams& aParams,
>+                                       bool aConsumedByIPC, bool aDelayedStart);
>+
>+  static void PostSerializationCleanup(OptionalInputStreamParams& aParams,
>+                                       bool aConsumedByIPC, bool aDelayedStart);
>+
Ok, I have no idea what these methods are for. When should one use them?
I think I'd like to look at this again after those methods are documented.
Attachment #9039038 - Flags: review?(bugs) → review-
Comment on attachment 9039039 [details] [diff] [review]
part 3 - pipe stream for storage and string

But tests!
Attachment #9039039 - Flags: review?(bugs) → review+

Ok, I have no idea what these methods are for. When should one use them?
I think I'd like to look at this again after those methods are documented.

I wrote a comment, but check the CleanupIPCStream methods in IPCStreamUtils.cpp. I could have that code in those functions, but IPCStreamUtils doesn't have knowledge of the internal InputStreamParams values and I don't want to expose them. Better to keep the cleanup in InputStreamUtils together with the deserialization and serialization.

Flags: needinfo?(amarchesini)
Attached patch part 2 - IPCStream refactoring (obsolete) — Splinter Review
Attachment #9039038 - Attachment is obsolete: true
Attachment #9039316 - Flags: review?(bugs)
Attached patch part 4 -testsSplinter Review
Attachment #9039385 - Flags: review?(bugs)
Attachment #9039385 - Flags: review?(bugs) → review+
Comment on attachment 9039316 [details] [diff] [review]
part 2 - IPCStream refactoring


>+void InputStreamHelper::PostSerializationCleanup(InputStreamParams& aParams,
>+                                                 bool aConsumedByIPC,
>+                                                 bool aDelayedStart) {
>+  if (aParams.type() == InputStreamParams::TBufferedInputStreamParams) {
>+    BufferedInputStreamParams& params = aParams.get_BufferedInputStreamParams();
>+    InputStreamHelper::PostSerializationCleanup(params.optionalStream(),
>+                                                aConsumedByIPC, aDelayedStart);
>+    return;
>+  }
>+
>+  if (aParams.type() == InputStreamParams::TMIMEInputStreamParams) {
>+    MIMEInputStreamParams& params = aParams.get_MIMEInputStreamParams();
>+    InputStreamHelper::PostSerializationCleanup(params.optionalStream(),
>+                                                aConsumedByIPC, aDelayedStart);
>+    return;
>+  }
>+
>+  if (aParams.type() == InputStreamParams::TMultiplexInputStreamParams) {
>+    MultiplexInputStreamParams& params =
>+        aParams.get_MultiplexInputStreamParams();
>+    for (InputStreamParams& subParams : params.streams()) {
>+      InputStreamHelper::PostSerializationCleanup(subParams, aConsumedByIPC,
>+                                                  aDelayedStart);
>+    }
>+    return;
>+  }
>+
>+  if (aParams.type() == InputStreamParams::TSlicedInputStreamParams) {
>+    SlicedInputStreamParams& params = aParams.get_SlicedInputStreamParams();
>+    InputStreamHelper::PostSerializationCleanup(params.stream(), aConsumedByIPC,
>+                                                aDelayedStart);
>+    return;
>+  }
>+
>+  if (aParams.type() == InputStreamParams::TInputStreamLengthWrapperParams) {
>+    InputStreamLengthWrapperParams& params =
>+        aParams.get_InputStreamLengthWrapperParams();
>+    InputStreamHelper::PostSerializationCleanup(params.stream(), aConsumedByIPC,
>+                                                aDelayedStart);
>+    return;
>+  }
>+
>+  if (aParams.type() == InputStreamParams::TIPCRemoteStreamParams) {
>+    IPCRemoteStreamType& remoteInputStream =
>+        aParams.get_IPCRemoteStreamParams().stream();
>+
>+    IPCStreamSource* source = nullptr;
>+    if (remoteInputStream.type() ==
>+        IPCRemoteStreamType::TPChildToParentStreamChild) {
>+      source = IPCStreamSource::Cast(
>+          remoteInputStream.get_PChildToParentStreamChild());
>+    } else {
>+      MOZ_ASSERT(remoteInputStream.type() ==
>+                 IPCRemoteStreamType::TPParentToChildStreamParent);
>+      source = IPCStreamSource::Cast(
>+          remoteInputStream.get_PParentToChildStreamParent());
>+    }
>+
>+    MOZ_ASSERT(source);
>+
>+    // If the source stream has not been taken to be sent to the other side,
>+    // we can destroy it.
>+    if (!aConsumedByIPC) {
>+      source->StartDestroy();
>+      return;
>+    }
>+
>+    if (!aDelayedStart) {
>+      // If we don't need to do a delayedStart, we start it now. Otherwise,
>+      // the Start() will be called at the first use by the
>+      // IPCStreamDestination::DelayedStartInputStream.
>+      source->Start();
>+    }
I know this is just moving code, but it is really hard to understand how a method called PostSerializationCleanup
"Starts" an IPCStreamSource. How is starting something a cleanup?
Could this code be restructured to be a tad easier to understand. Or change the name "Cleanup"
Attachment #9039316 - Flags: review?(bugs) → review-

Better naming

Attachment #9039316 - Attachment is obsolete: true
Attachment #9039396 - Flags: review?(bugs)
Comment on attachment 9039396 [details] [diff] [review]
part 2 - IPCStream refactoring

>+void InputStreamHelper::PostSerializationActivation(InputStreamParams& aParams,
>+                                                    bool aConsumedByIPC,
>+                                                    bool aDelayedStart) {
>+  if (aParams.type() == InputStreamParams::TBufferedInputStreamParams) {
>+    BufferedInputStreamParams& params = aParams.get_BufferedInputStreamParams();
>+    InputStreamHelper::PostSerializationActivation(
>+        params.optionalStream(), aConsumedByIPC, aDelayedStart);
>+    return;
>+  }
>+
>+  if (aParams.type() == InputStreamParams::TMIMEInputStreamParams) {
>+    MIMEInputStreamParams& params = aParams.get_MIMEInputStreamParams();
>+    InputStreamHelper::PostSerializationActivation(
>+        params.optionalStream(), aConsumedByIPC, aDelayedStart);
>+    return;
>+  }
>+
>+  if (aParams.type() == InputStreamParams::TMultiplexInputStreamParams) {
>+    MultiplexInputStreamParams& params =
>+        aParams.get_MultiplexInputStreamParams();
>+    for (InputStreamParams& subParams : params.streams()) {
>+      InputStreamHelper::PostSerializationActivation(subParams, aConsumedByIPC,
>+                                                     aDelayedStart);
>+    }
>+    return;
>+  }
>+
>+  if (aParams.type() == InputStreamParams::TSlicedInputStreamParams) {
>+    SlicedInputStreamParams& params = aParams.get_SlicedInputStreamParams();
>+    InputStreamHelper::PostSerializationActivation(
>+        params.stream(), aConsumedByIPC, aDelayedStart);
>+    return;
>+  }
>+
>+  if (aParams.type() == InputStreamParams::TInputStreamLengthWrapperParams) {
>+    InputStreamLengthWrapperParams& params =
>+        aParams.get_InputStreamLengthWrapperParams();
>+    InputStreamHelper::PostSerializationActivation(
>+        params.stream(), aConsumedByIPC, aDelayedStart);
>+    return;
>+  }
Just that I understand this... we end up recursively calling PostSerializationActivation with the inner streams.
So, perhaps add a comment after the last 'if' about the types of InputStreamParams which don't need any special handling.

In fact, I think this method would be easier to read if it wasn't using 'if' but switch-case, and have a separate case for all the
types and then assert hard in the default: .
Attachment #9039396 - Flags: review?(bugs) → review+
Pushed by amarchesini@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/89e6f6b8ed7a
Single InputStreams can serialize themselves as IPCRemoteStreams (pipe) - part 1 - Passing IPC managers around, r=smaug
https://hg.mozilla.org/integration/mozilla-inbound/rev/8d9941bfde76
Single InputStreams can serialize themselves as IPCRemoteStreams (pipe) - part 2 - IPCRemoteSteam part of InputStreamParams union, r=smaug
https://hg.mozilla.org/integration/mozilla-inbound/rev/63ad0c3533f3
Single InputStreams can serialize themselves as IPCRemoteStreams (pipe) - part 3 - pipe for string and storage streams, r=smaug
https://hg.mozilla.org/integration/mozilla-inbound/rev/b046b1295521
Single InputStreams can serialize themselves as IPCRemoteStreams (pipe) - part 4 - tests, r=smaug
Component: HTML: Form Submission → DOM: Core & HTML
QA Whiteboard: [qa-triaged]
Flags: qe-verify+
QA Whiteboard: [qa-triaged]

I think this issue is still reproducing. I used an affected build of Nightly (2019-01-15) on Windows 10 x64 and the steps from comment 0. These are the results I got:

The problem is that I got the same results on latest Nightly 68.0a1 as I did on the older build.

Or maybe I'm doing something wrong.

Flags: needinfo?(amarchesini)

I'm not able to reproduce this issue with linux. Can you please check if this is just a windows10 issue?
I'm also curios to know if this is a regression, because this bug was fixed, right? Can you tell me the regression window? Thanks.

Flags: needinfo?(amarchesini) → needinfo?(oana.botisan)

I can reproduce the issue from comment 21 using Ubuntu 18.04 x64 and latest Nightly, too. I don't think this is a regression. I can reproduce the same issue on a build from 2014-01-02. Should I log this issue separately?

I can't be sure if the bug is fixed, because I can't seem to be able to reproduce it. I will ask the reporter for information.

Flags: needinfo?(oana.botisan) → needinfo?(amarchesini)

Can you please verify if this problem is still reproducing?
Thank you.

Flags: needinfo?(mail)

Would be great if you can see if the issue is reproducible and if it happens only on windows. Another important information would be to see if it's a regressions from the landing of these patches.
A separate bug is probably the right way to continue. Thanks!

Flags: needinfo?(amarchesini)

It seems to be working on latest Nightly here on Windows 10. The file transfer starts, uploads whole thing and I also get progress events in the console logs.

"Transferred" size doesn't seem to reflect amount of uploaded data. I'm not sure if it is intented to only display received data, but other than that it appears to be working here.

Flags: needinfo?(mail)
You need to log in before you can comment on or make changes to this bug.