Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Stream protocols and fs.createReadStream sometimes never complete in Electron 7 #21018

Closed
3 tasks done
itsananderson opened this issue Nov 7, 2019 · 43 comments · Fixed by #21113 or #21733
Closed
3 tasks done

Comments

@itsananderson
Copy link
Contributor

itsananderson commented Nov 7, 2019

Preflight Checklist

  • I have read the Contributing Guidelines for this project.
  • I agree to follow the Code of Conduct that this project adheres to.
  • I have searched the issue tracker for an issue that matches the one I want to file, without success.

Issue Details

  • Electron Version:
    • 7.0.0-beta.4 - 8.0.0-beta.2
  • Operating System:
    • macOS 10.14.6, Windows 10
  • Last Known Working Electron version:
    • 7.0.0-beta.3

Expected Behavior

According to the docs, one should be able to register a stream protocol handler which serves files from the file system.

The following code snippet is suggested by the docs:

const { protocol } = require('electron')
const fs = require('fs')

protocol.registerStreamProtocol('atom', (request, callback) => {
  callback(fs.createReadStream('index.html'))
}, (error) => {
  if (error) console.error('Failed to register protocol')
})

The expected behavior is that Electron should read from the stream and (assuming no read errors etc.) serve a valid response for the custom protocol request.

Actual Behavior

Starting with Electron 7.0.0-beta.4 it looks like the request sometimes randomly never completes on the Renderer side. This can be seen in the Network tab as well as by inspecting AJAX calls at runtime. The read stream seems to be created successfully, and the response starts to be sent back to the renderer, but the final state change never happens.

To Reproduce

Run the following Fiddle to see the behavior change. In Electron < 7.0.0-beta4, the page can make an AJAX request to the custom scheme in a loop and print the contents. In Electron >= 7.0.0-beta4 the page can occasionally make a few AJAX requests, but it will eventually halt when one request never reaches a XMLHttpRequest.DONE state.

https://gist.github.com/33a9b357c606c7cbe7c2cac99bbda973

Good console output (7.0.0-beta3 and bellow) looks like:

index.html:22 ajaxStateChange readyState: 1 statusCode: 0
index.html:22 ajaxStateChange readyState: 2 statusCode: 200
index.html:22 ajaxStateChange readyState: 3 statusCode: 200
index.html:22 ajaxStateChange readyState: 4 statusCode: 200
index.html:25 // Just using this file as an example file to be served by the custom scheme handler
index.html:22 ajaxStateChange readyState: 1 statusCode: 0
index.html:22 ajaxStateChange readyState: 2 statusCode: 200
index.html:22 ajaxStateChange readyState: 3 statusCode: 200
index.html:22 ajaxStateChange readyState: 4 statusCode: 200
index.html:25 // Just using this file as an example file to be served by the custom scheme handler
index.html:22 ajaxStateChange readyState: 1 statusCode: 0
index.html:22 ajaxStateChange readyState: 2 statusCode: 200
index.html:22 ajaxStateChange readyState: 3 statusCode: 200
index.html:22 ajaxStateChange readyState: 4 statusCode: 200
index.html:25 // Just using this file as an example file to be served by the custom scheme handler
... and repeat

Bad console output (7.0.0-beta4+) looks like:

index.html:22 ajaxStateChange readyState: 1 statusCode: 0
index.html:22 ajaxStateChange readyState: 2 statusCode: 200
index.html:22 ajaxStateChange readyState: 3 statusCode: 200
index.html:22 ajaxStateChange readyState: 4 statusCode: 200
index.html:25 // Just using this file as an example file to be served by the custom scheme handler
index.html:22 ajaxStateChange readyState: 1 statusCode: 0
index.html:22 ajaxStateChange readyState: 2 statusCode: 200
index.html:22 ajaxStateChange readyState: 3 statusCode: 200
index.html:22 ajaxStateChange readyState: 4 statusCode: 200
index.html:25 // Just using this file as an example file to be served by the custom scheme handler
index.html:22 ajaxStateChange readyState: 1 statusCode: 0
index.html:22 ajaxStateChange readyState: 2 statusCode: 200
index.html:22 ajaxStateChange readyState: 3 statusCode: 200  <-- stop getting updates here

Screenshots

Network info for request that completes successfully:

image

image

image

Network info for request that never completes:

image

image

image

Additional Information

@itsananderson
Copy link
Contributor Author

Also worth noting, these incomplete network requests don't happen if you read files into memory and create a stream from them:

https://gist.github.com/e442a020541a0e7470abf603812159bb

function createStream (text) {
  const rv = new PassThrough() // PassThrough is also a Readable stream
  rv.push(text)
  rv.push(null)
  return rv
}

protocol.registerStreamProtocol("custom", (request, callback) => {
    let requestUrl = url.parse(request.url, /*parseQueryString*/ true, /*slashesDenoteHost*/ true);
    let filePath = requestUrl.pathname.replace(
      /^\/static/,
      path
        .join(__dirname)
        .replace(/[?#&].*/, '')
    );

    console.log(filePath);


    if (filePath.endsWith(".js")) {
      callback({
        statusCode: 200,
        headers: {
          'Content-Type': 'text/plain',
        },
        data: createStream(fs.readFileSync(filePath))
      })
    } else {
      callback({
        statusCode: 200,
        headers: {
          'Content-Type': 'text/html',
        },
        data: createStream(fs.readFileSync(filePath))
      })
    }
})

@pfrazee
Copy link
Contributor

pfrazee commented Nov 8, 2019

Can confirm that I'm seeing the same behavior in my work

@pfrazee
Copy link
Contributor

pfrazee commented Nov 8, 2019

I also found that @itsananderson's fix does work, but using into-stream with fs.readFileSync() does not.

@KoenLav
Copy link
Contributor

KoenLav commented Nov 11, 2019

Same problem here; it seems like the responses randomly get cut off.

May be related/similar to: #16213

@KoenLav
Copy link
Contributor

KoenLav commented Nov 11, 2019

This PR may be of interest: #19869

@sofianguy sofianguy added this to Fixed in 8.0.0-beta.3 in 8.2.x Nov 21, 2019
@sofianguy sofianguy added this to Fixed in 7.1.2 in 7.2.x Nov 21, 2019
@electron7User
Copy link

The proposed fix does not fix this problem for me. After upgrading electron from version 6 to 7.1.2, I noticed that images randomly did not load when they have display: none; on them with an onload handler that shows them.

As the original project is quite big, I created an example project based on itsananderson's gist which shows that images sometimes do not complete loading. Also, you can see that the CAUTION: request is not finished yet message from itsananderson's screenshots still appears for requests that don't complete.

Feel free to clone the example project, build and run the app. Please note that the bug does not appear when starting the app with electron ..

My configuration:

  • Electron Version:
    7.1.2
  • Operating System:
    macOS 10.14.6

@nornagon
Copy link
Member

nornagon commented Dec 2, 2019

...yep, looks like this isn't fixed after all. (Your example also reproduces for me when running npx electron .).

@nornagon nornagon reopened this Dec 2, 2019
@KoenLav
Copy link
Contributor

KoenLav commented Dec 18, 2019

Are there any updates on this? Or pointers towards where this regression might have originated?

@KoenLav
Copy link
Contributor

KoenLav commented Dec 18, 2019

Looking into the commits between 7.0.0-beta.3 and 4:

v7.0.0-beta.3...7-0-x

It looks like this commit could be the culprit:

36a5ba0

Pinging @codebytere

@pfrazee
Copy link
Contributor

pfrazee commented Jan 7, 2020

I spent the day digging through this and I think I've found the cause, but I don't have a solution yet.

The issue seems to occur only when responses exceed a certain size. In my tests, the failure would coincide with a DidWrite() call node_stream_loader.cc with a result code of MOJO_RESULT_FAILED_PRECONDITION. With some logging, I was able to find that DataPipeProducerDispatcher::BeginWriteData was hitting the case where available_capacity_ == 0 but the peer is not closed. Which means, I believe, it's a backpressure issue. The write is failing because the write-target doesn't have available memory available to accept the data.

I can't say for certain that's the correct diagnosis, but it seems logical that it would be a backpressure issue given that it only manifests on larger responses.

I believe this should be handled by watching the producer for available capacity and then trying the write. I'm going to spend a little more time this evening trying to implement that, but I'm fairly unfamiliar with the Electron/Chromium codebase so I may need to punt it to the pros.

@pfrazee
Copy link
Contributor

pfrazee commented Jan 7, 2020

UPDATE - Unfortunately I'm less sure about this now that I've dug in more. DataPipeProducer seems to correctly handle backpressure. Digging more.

@pfrazee
Copy link
Contributor

pfrazee commented Jan 7, 2020

Okay here's all I've found:

Based on some logging, I've found the failure seems to consistently occur when mojo tells the producer to wait (MOJO_RESULT_SHOULD_WAIT). This should be handled correctly by the DataPipeProducer. However, when the watcher attempts to resume, I appear to see two kinds of errors:

  • An error where DidWrite() fails with MOJO_RESULT_FAILED_PRECONDITION, or
  • An error where DidWrite() does not fail, but NotifyComplete() is called with the generic net failure code (-2) after data_pipe_producer_dispatcher.cc hits the "peer closed" condition.

I can't venture any guesses toward a cause, but finding the MOJO_RESULT_SHOULD_WAIT condition to be consistently involved may be a helpful clue.

@nornagon
Copy link
Member

nornagon commented Jan 8, 2020

Thanks for the info, @pfrazee! I'm picking this up again after the break. I've been trying to reproduce it consistently without using fs.createReadStream but unfortunately without much luck. Here's the fiddle I've been playing with: https://gist.github.com/cf281af81f415285acacafdb998b637e

It uses fetch() to pull the resource, and tries a bunch of different chunk sizes from 16 bytes to 1MB. I've not been able to trigger the "stream doesn't complete" condition with this fiddle, though. @electron7User's fiddle still produces the issue for me though. I'm not sure what the difference might be.

@pfrazee
Copy link
Contributor

pfrazee commented Jan 9, 2020

@nornagon Have you tried reading from a data source via a stream, as opposed to responding with a buffer? The workaround that @itsananderson shared reads the file synchronously, so I'm wondering if the async streaming read affects it somehow.

@nornagon
Copy link
Member

nornagon commented Jan 9, 2020

@pfrazee hm, i'm not sure exactly what you're suggesting. I'm attempting to replicate this without fs if possible, to try to isolate the issue. If the issue is with fs and not protocol that would be interesting to know! If the issue is caused by some odd interaction between the two, then hopefully it would be possible to create a stream that acted similarly enough to an fs stream to cause the same issue in protocol.

@pfrazee
Copy link
Contributor

pfrazee commented Jan 10, 2020

@nornagon Okay this Electron Fiddle is demonstrating the failure without using any other component: https://gist.github.com/pfrazee/9df2dacc935afdfe4ea6f6d2a28f7786

I basically introduced a bunch of async into the stream. There's a commented-out bit in main.js you can uncomment to prove the stream is not broken. When I run it, I just get no response from fetch() (not even an error).

@nornagon
Copy link
Member

@pfrazee thanks for that repro case! I was able to track down what I believe was the issue. #21733 fixes the gist you made, as well as the repro that @electron7User created, I believe.

@pfrazee
Copy link
Contributor

pfrazee commented Jan 11, 2020

@nornagon you rock! 🍻

@pfrazee
Copy link
Contributor

pfrazee commented Jan 21, 2020

Unfortunately I've updated to 8.0.0-beta.7, which includes the recent fix, and I'm still seeing the issue.

@pfrazee
Copy link
Contributor

pfrazee commented Jan 21, 2020

The testcase fiddle I created is working correctly in 8.0.0-beta.7, but my application is still failing. I'll try to produce another test case.

@pfrazee
Copy link
Contributor

pfrazee commented Jan 22, 2020

Okay I was able to produce an example case, this time I did need to use the fs and a <video> element. You'll need to change the fiddle to point to some test mp4 on your device.

https://gist.github.com/pfrazee/9200ecc8edb63c415748a9b825b67a2a

@electron7User
Copy link

Similar situation here. I now updated our main application to 7.1.10 and videos in the <video>-tag do not load at all. However images seem to load quite consistently.

If necessary, I can also try to update the example project I posted earlier. I didn't do that yet, because we're very busy at the moment, but if you need that, I'll see what I can do.

@KoenLav
Copy link
Contributor

KoenLav commented Jan 23, 2020

For us the problem does seem to be resolved in Electron 7.1.10 (using meteor-desktop), but we're not using videos (simply a relatively large minified JS bundle).

@pfrazee
Copy link
Contributor

pfrazee commented Jan 23, 2020

FWIW I used <video> because it most clearly demonstrates the issue, but I've seen the "stream fails to complete" issue in my app on regular files.

@nornagon nornagon reopened this Jan 28, 2020
@pfrazee
Copy link
Contributor

pfrazee commented Feb 3, 2020

I found something useful here.

The /src/media/blink/webmediaplayer_impl.cc uses a MultibufferDataSource to manage it's read-stream. The MultibufferDataSource has logic where if AssumeFullyBuffered() returns true, then the url_data it's tracking needs to have a length set by the time of initialization or the player will consider init to have failed. The AssumeFullyBuffered() is defined as "true if not http or https" so that applies to our custom protocols. If I change that function to always return false, the video player works.

I'm not sure what the right fix is. It might indicate we need to be able to hook into AssumeFullyBuffered() and add our custom protocols. Then again, perhaps it should be possible for custom protocols to "fully buffer"? (It depends on what that means.) The fix should be one or the other, I assume.

@electron7User
Copy link

Anything new here?

I just tried Electron 8.2.0, but the problem still exists.

@danielweck
Copy link

danielweck commented Mar 30, 2020

With Electron 8.2.0, the way I am using registerStreamProtocol() is by creating an HTTP request from within the callback (unlike the examples / repro test cases shown in this issue discussion thread, which use filesystem streams), and then to pipe the response’s stream into the result data structure (alongside HTTP response headers, etc.).

This seems to work reliably, whereas before when I was using registerHttpProtocol(), this was consistently failing for large image files, 100% reproducible. So for me registerStreamProtocol() is a definite improvement over registerHttpProtocol(), however ... support for video/audio “streaming” (HTTP 206 byte range partial requests/responses) is totally broken ... the Chromium media player just hangs there. I tried with both HTTP and secure HTTPS (which is my default, with self-signed certificates). I tested different ways to pipe the streams, just to double-check the possibility of my data source not reaching the media player because of a paused stream flow (stalled producer, starving consumer, stream back-pressure issues, etc.). To no avail.

I worked around this issue by bypassing registerStreamProtocol() entirely for audio/video resources (basically, I am forced to patch content URLs so that they point directly to my local Express HTTP server via ip+port, rather than using the custom protocol scheme). For my use case this workaround is adequate, as strictly-speaking audio/video media does not need to be served via the custom protocol handler. However I had to introduce a ton of heavy-lifting in order to patch content URLs, so there is a performance cost, and there is collateral damage in term of code architecture (messy!)

So, hopefully Electron folks will figure out what the culprit is, I will be watching this space. Keep up the good work, much appreciated!! :)

@danielweck
Copy link

danielweck commented Mar 30, 2020

PS (to my comment above): I reported about broken registerHttpProtocol() in this (closed) issue #8302 (comment)

@pfrazee
Copy link
Contributor

pfrazee commented Mar 30, 2020

I'm fairly sure based on my research that Chromium' media player just doesnt support custom streaming protocols at the moment, and the fix will be a patch to its AssumeFullyBuffered() method.

@electron7User
Copy link

Playing videos and audio files did work with Electron 6, but doesn't anymore since Electron 7. And as for your comment from 23 Jan, you said you've seen this issue for regular files as well.

FWIW I used <video> because it most clearly demonstrates the issue, but I've seen the "stream fails to complete" issue in my app on regular files.

@pfrazee
Copy link
Contributor

pfrazee commented Mar 31, 2020

@electron7User I forgot about that! What I found with the media player was that video/audio would start working when I made the modification I noted. So either we're dealing with 2 separate issues (a streaming issue and a media-player issue) or I was mistaken about other large files - I'd need to try to reproduce again to confirm.

@danielweck
Copy link

With large image files (5MB PNG), I had major issues when using registerHttpProtocol(), but registerStreamProtocol() worked fine. I just had to implement my own HTTP request in order to handle the response and pipe its stream into the result callback (which I assume is what registerHttpProtocol() does under the hood).

Classic dev story: fixing the PNG image bug introduced the audio/video media "streaming" issue :) (which is why I was forced to bypass registerStreamProtocol() specifically in the case of HTTP 206 partial byte range requests)

@pfrazee
Copy link
Contributor

pfrazee commented Apr 2, 2020

I'm working on a fix which adds a registry of "streaming protocols" which registerStreamProtocol() could add to, and then which the media-player code can reference to correctly self-configure buffering behaviors.

I'm stuck at the moment with a linker error related to my chromium patch:

Undefined symbols for architecture x86_64:
  "url::AddStreamingScheme(char const*, url::SchemeType)", referenced from:
      electron::RendererClientBase::RendererClientBase() in renderer_client_base.o
ld: symbol(s) not found for architecture x86_64

I'm going to try to get into the electronhq slack to get more help but it'll take some time. If anybody knows what I'm missing, please point me in the right direction!

@electron7User
Copy link

I updated my example project to directly show the video streaming bug in electron 7, 8, and 9. After building the project, the video at the top does not load. When building the same project with electron 6, the video does load and can be viewed (update the package.json, run yarn, yarn build).

@Strangerxxx
Copy link

Strangerxxx commented Nov 9, 2020

I can't reproduce it with electron 10.1.5

@danielweck
Copy link

I can't reproduce it with electron 10.1.5

Surprising, as this will be fixed in v11, apparently:
#22955 (comment)

@danielweck
Copy link

I can't reproduce it with electron 10.1.5

Electron 11 registerSchemesAsPrivileged() and registerStreamProtocol():
https://unpkg.com/browse/electron@11.0.1/electron.d.ts#L6207

Protocols that use streams (http and stream protocols) should set `stream:
true`. The `<video>` and `<audio>` HTML elements expect protocols to buffer
their responses by default. The `stream` flag configures those elements to
correctly expect streaming responses.

...but not in Electron 10:
https://unpkg.com/browse/electron@10.1.5/electron.d.ts#L12931

@danielweck
Copy link

danielweck commented Nov 17, 2020

I confirm that registerStreamProtocol() "works" in Electron 11.0.1, including with stream: true in registerSchemesAsPrivileged(). However, audio seeking (and presumably, video, although I haven't had time to test this yet) fails. I am seeing the following event sequence emitted by the HTML audio element, but no requests are made to registerStreamProtocol() when seeking with a mouse click towards the end of the audio resource (i.e. where buffers haven't been fetched yet ... or for that matter, even if they have been fetched already):

  1. seeking
  2. waiting
  3. seeked
  4. canplay
  5. playing
  6. canplaythrough

Anybody experiencing seeking issues?

@pfrazee
Copy link
Contributor

pfrazee commented Nov 17, 2020

@danielweck Unfortunately yes, I've experienced the same

@danielweck
Copy link

danielweck commented Nov 17, 2020

I have a debug mode to visualize audio buffers, and here's what I see:

Seeking working (regular HTTP 1.1 byte-range partial requests):

AudioSeekOK

Seeking not working (registerStreamProtocol):

AudioSeekFAIL

@vbourgeois
Copy link

Anybody experiencing seeking issues?

Same for me with video...

@IhorKobylinskiy
Copy link

IhorKobylinskiy commented Feb 16, 2021

I confirm that registerStreamProtocol() "works" in Electron 11.0.1, including with stream: true in registerSchemesAsPrivileged(). However, audio seeking (and presumably, video, although I haven't had time to test this yet) fails. I am seeing the following event sequence emitted by the HTML audio element, but no requests are made to registerStreamProtocol() when seeking with a mouse click towards the end of the audio resource (i.e. where buffers haven't been fetched yet ... or for that matter, even if they have been fetched already):

  1. seeking
  2. waiting
  3. seeked
  4. canplay
  5. playing
  6. canplaythrough

Anybody experiencing seeking issues?

Yes - I have faced with issue related to seeking when try play local stored video. When you open video the first time clicking on scrub bar(or another seek action) restarts video but when you open the same video in the second time everything works fine

@electron-triage
Copy link

The Electron version reported on this issue is no longer supported. See our supported versions documentation.

If you're still experiencing this issue on a supported version, please open a new issue with an updated repro - a Fiddle is very appreciated.

Electron has a large issues backlog. To help our team prioritize, we're closing older issues and asking for new issues with updated repro steps if it affects a supported version. This helps sort what issues are still relevant and helps us fix them more quickly.

Thanks for your patience and understanding!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
No open projects
7.2.x
Fixed in 7.1.2
8.2.x
Fixed in 8.0.0-beta.3
10 participants