mafintosh / torrent-stream

The low level streaming torrent engine that peerflix uses
MIT License
1.94k stars 227 forks source link

Issues Streaming to VLC #158

Open jaruba opened 8 years ago

jaruba commented 8 years ago

I have this long time issue in my player, which uses wcjs and therefore VLC. I've tested this with VLC directly too and it's showing the same symptoms.

The issue seems to start after seeking a few times through the stream with VLC. At one point VLC will start to buffer a lot (long buffers) even if the file is fully downloaded. And when it's not buffering it's stuttering a lot (an unwatchable state).

From debugging, it seems like the method called to serve the pieces to the player from the streaming server, which normally gets called about 4 times after a normal seek, starts going in an infinite loop. This in turn fulls up the memory buffer and forces frequent major garbage collection that makes electron (in my case) lag a lot. The method that is being flooded is: https://github.com/mafintosh/torrent-stream/blob/master/lib/file-stream.js#L36-L69

After doing a console.log(this._piece), I saw that when the bug happens it's just requesting the same 4 pieces, over and over, tens of times per second.

The issue itself is pretty serious and I tried my best to find some vlc command line arg that may fix this, but I had no luck. I also tried debugging VLC, but it's just showing errors for time desync with the streaming server, this does not seem to be the cause of it, just a secondary effect of the bug.

I'm wondering if there is anything that can be done from torrent-stream's side to prevent this.. Any thoughts?

mafintosh commented 8 years ago

just noticed that we're relying on stream there. we should move to readable-stream as streams behave differently across node versions would could contribute to weird behaviour like you're describing

Ivshti commented 8 years ago

@mafintosh is it a drop-in change?

mafintosh commented 8 years ago

@Ivshti yup

Ivshti commented 8 years ago

@jaruba can you try an older electron?

jaruba commented 8 years ago

@mafintosh I just tried with var stream = require('readable-stream') and the issue still persists.

@Ivshti I doubt it's from electron, i had the same issue with nw.js too, which was using chrome 41 (in electron i have chrome 45)

Ivshti commented 8 years ago

@jaruba every electron ships different node.js versions, latest are on the latest io.js I think evaluate process.versions["io.js"] or something like this

Also I've never been a huge fan of the logic in lib/file-stream. It lacks very solid debouncing/queuing. If the player goes insane (possible with VLC) it will generate a lot of reads on one piece

jaruba commented 8 years ago

@Ivshti

process.versions['electron'] == "0.33.9"
process.versions['chrome'] == "45.0.2454.85"
process.versions['node'] == "4.1.1"
process.versions['node-webkit'] == "0.12.3"
process.versions['chromium'] == "41.0.2272.76"
process.versions['node'] == "1.2.0"

^ these are the ones I tested and have this issue

Ivshti commented 8 years ago

@jaruba may i suggest you try with an even older one? try with something that's with node 0.12 or node 0.10, possibly even node.js itself. Let's first exclude the environment

jaruba commented 8 years ago

@mafintosh I've traced this back a few more steps to try to understand where the actual flood is coming from..

https://github.com/jaruba/torrent-stream/blob/master/index.js#L205

https://github.com/jaruba/torrent-stream/blob/master/index.js#L549

mafintosh commented 8 years ago

@jaruba is this reproducible across multiple torrents?

jaruba commented 8 years ago

@mafintosh refresh() seems to be called from these 2 points, infinitely:

https://github.com/jaruba/torrent-stream/blob/master/index.js#L650

and

https://github.com/jaruba/torrent-stream/blob/master/index.js#L665

This happens on pretty much any torrent for me with VLC. Some even break on the first seek, others break after a few seeks.

jaruba commented 8 years ago

torrent-stream-flood ^ this is a console.log of this line:

https://github.com/jaruba/torrent-stream/blob/master/index.js#L168

I guess the deselect after it also gets triggered immediately.

Ivshti commented 8 years ago

@jaruba Can you please log the part in peerflix where it receives an HTTP request? Log it's headers as well

jaruba commented 8 years ago

@Ivshti

request-headers

well this is interesting...

jaruba commented 8 years ago

From what I can see, VLC always sends connection: "close". so that should not be of any relevance.

Looking through the huge list of headers, I can see a pattern, when it breaks it starts requesting very small byte range differences, very fast, sometimes even gets fixated on 2 exact ranges. From torrent-stream's view though, it's just requesting the exact same pieces.

VLC's debug log looks like this when it's happening: vlc-log

Ivshti commented 8 years ago

This is smelling like a VLC issue.

It's either a VLC issue or torrent-stream/peerflix serving corrupt data and confusing VLC.

Can you also log the times of each request, relative to the start of your app (Date.now()-start) so we can see how often they fire?

jaruba commented 8 years ago

@Ivshti explode

jaruba commented 8 years ago

request-response-difference ^ screenshot of the requests made by VLC, the responses given by Peerflix, and the difference between the previously requested range.start and the current range.start, there is a strange pattern to this bug..

bsuh commented 8 years ago

I'm still using 0.21.3 and could not reproduce seeking about ~20 times randomly in VLC. Haven't had time to investigate the changes leading to 1.0.0 and frankly 0.21.3 is rock solid for me.

jaruba commented 8 years ago

@bsuh I've had this issue with torrent-stream 0.21.x too, in all cases I tested with VLC 2.2.1. What OS are you on? Me and 2 more users (that reported this to me) wore all on Windows.

bsuh commented 8 years ago

I'm on Mac OS X. It seems like an issue with VLC on Windows then.

jaruba commented 8 years ago

@mafintosh @bsuh

I don't think it's OS specific, it might not happen on every file though, it may be specific to the electron / nw.js environment, I'm not sure yet.

jaruba commented 8 years ago

I've currently tested with:

Electron 0.29.2 + VLC 2.2.1 = bug exists Electron 0.33.9 + VLC 2.2.0 = bug exists Electron 0.33.9 + VLC 2.2.1 = bug exists Electron 0.36.5 + VLC 2.2.1 = bug exists Electron 0.33.9 + VLC 3.0.0 (Nightly) = works

Interestingly enough, Electron 0.29.2 handled this bug best, althought it was flooded like the rest, it did not seem to cause harm to the stream, no grey frames or re-buffering for no reason.

VLC 3.0.0 seems to have a fix for this, it does very short request floods then stops, but knowing the VLC team it might be released as stable years from now..

I still hope there's something that can be done in peerflix / torrent-stream to prevent a request flooding of this magnitude..

Ivshti commented 7 years ago

I can once again confirm this.

  1. Play something in VLC
  2. Seek randomly a few times
  3. VLC starts sending a few requests per second for similar ranges from this point onward

@jaruba in your cases, does it happen with mkv or mp4?

jaruba commented 7 years ago

@Ivshti well.. i know for sure it happens with mp4, as seen in my previous log screenshots on this issue (also happened y-day with my nightly version that doesn't have the partial workaround that i made in v0.98 of my player), don't know about mkv

I did test this issue rigorously in the past with probably hundreds of videos, and although I didn't check the video encoding types at all, it seemed to happen to 100% of them, so it might not be video encoding specific, but I can't prove that.. most are mkv and mp4 anyway.