Issues Streaming to VLC

[jaruba]

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]

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]

@mafintosh is it a drop-in change?

[mafintosh]

@Ivshti yup

[Ivshti]

@jaruba can you try an older electron?

[jaruba]

@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]

@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]

@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]

@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]

@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]

@jaruba is this reproducible across multiple torrents?

[jaruba]

@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]

^ 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]

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

[jaruba]

@Ivshti

well this is interesting...

[jaruba]

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:

[Ivshti]

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]

@Ivshti

[jaruba]

^ 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]

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]

@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]

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

[jaruba]

@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]

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]

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]

@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.