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

deluge-streaming doesn't work on linux #19

Open
wjtk4444 opened this issue Aug 23, 2018 · 16 comments
Open

deluge-streaming doesn't work on linux #19

wjtk4444 opened this issue Aug 23, 2018 · 16 comments

Comments

@wjtk4444
Copy link

I can't get deluge-streaming to work on linux. I tried the exact same configuration of tools and settings as I use on windows, but with no results. The file download itself seems to work file, I can play the file that's being downloaded directly and it seems to play just fine. The only problem is playing it via deluge-streaming.

--

Reproduction steps:

  • open a video torrent file in deluge, select start streaming option
  • paste the url to stream to either mpv (with youtube-dl) or vlc

--

Deluge version: 1.3.15 (default settings, one plugin only)
deluge-streaming version: latest release
mpv version: latest git (default settings)
youtube-dl version: latest git
vlc version: 3.0.3 (default settings)

--

Log from mpv on windows (warnings are marked, the rest are errors):

[ffmpeg] http: Unknown content coding: bytes //warning

Log from mpv on linux (warnings are marked, the rest are errors):

[ffmpeg] http: Unknown content coding: bytes
[mkv] Error parsing subelement length
[mkv] Error parsing element Attachments
[ffmpeg] http: Unknown content coding: bytes //warning                                                                                
[ffmpeg] http: HTTP error 416 Requested Range not satisfiable //warning                                                               
[ffmpeg] Seek failed
[ffmpeg] http: HTTP error 416 Requested Range not satisfiable //warning
[ffmpeg] Seek failed
[cache] Seek failed                                                                                                          
[mkv] Invalid EBML length at position 51822520                                                                               
[ffmpeg] http: Unknown content coding: bytes //warning
[ffmpeg] http: Unknown content coding: bytes //warning                                                                                
[ffmpeg] http: HTTP error 416 Requested Range not satisfiable //warning                                                               
[ffmpeg] Seek failed
[ffmpeg] http: HTTP error 416 Requested Range not satisfiable //warning
[ffmpeg] Seek failed
[cache] Seek failed                                                                                                          
[mkv] Invalid EBML length at position 52959615
...

Log from vlc on linux:

[00007f65a401ba30] mkv demux error: Dummy Element at unexpected position... corrupted file?
[00007f65a401ba30] mkv demux error: Dummy element too large or misplaced at 1016594500... skipping to next upper element
[00007f65a401ba30] mkv demux error: cannot find any cluster or chapter, damaged file ?
[00007f65a401ba30] mjpeg demux error: cannot peek
[00007f65a4006100] prefetch stream error: cannot seek (to offset 0)
@JohnDoee
Copy link
Owner

JohnDoee commented Aug 24, 2018

Can you try with the latest release, https://github.com/JohnDoee/deluge-streaming/releases/tag/0.10.0 ?

A little extra info, some of these video players doesn't like to wait for data, so when Deluge can't get the needed piece fast enough, they get angry and error out.

@wjtk4444
Copy link
Author

Sadly, it's still the same.

A little extra info, some of these video players doesn't like to wait for data, so when Deluge can't get the needed piece fast enough, they get angry and error out.

I don't think that's the issue. Example: I have 10% of file already downloaded, then I start to stream it. It still fails, whereas opening the file directly (at 10% completed) works just fine.

If anything changed, it's the errors. Now there are none, both in mpv and vlc.
I can provide full --verbose logs from players if you want me to.

@JohnDoee
Copy link
Owner

JohnDoee commented Aug 25, 2018

I found a few problems, let me fix them and lets see.

@JohnDoee
Copy link
Owner

JohnDoee commented Aug 25, 2018

I've been doing too many tests with small files and fast internet, so the errors I made were simply masked.

The new one should actually do sequential download. If you want to track what the plugin is actually doing, you can get Deluge-Pieces and see.

Try the new release, https://github.com/JohnDoee/deluge-streaming/releases/tag/0.10.1

@wjtk4444
Copy link
Author

wjtk4444 commented Aug 25, 2018

Great, it works now.

I still get some errors, but the file plays fine and there are no visible artifacts.

(Paused) AV: 00:00:00 / 00:23:42 (0%) A-V:  0.000 Cache: 10s+6MB
[mkv] Corrupt file detected. Trying to resync starting from position 13092177...
[mkv] Cluster found at 13179813.
[mkv] Corrupt file detected. Trying to resync starting from position 14081253...
AV: 00:00:01 / 00:23:42 (0%) A-V:  0.000 Cache: 18s+12MB
[mkv] Cluster found at 14137399.
AV: 00:00:01 / 00:23:42 (0%) A-V:  0.000 Cache: 18s+13MB
[mkv] Corrupt file detected. Trying to resync starting from position 15016056...
[mkv] Cluster found at 15291401.
[mkv] Corrupt file detected. Trying to resync starting from position 15584428...
AV: 00:00:03 / 00:23:42 (0%) A-V:  0.000 Cache: 18s+12MB
[mkv] Cluster found at 16251645.
[mkv] Corrupt file detected. Trying to resync starting from position 17001887...
(Paused) AV: 00:00:04 / 00:23:42 (0%) A-V:  0.000 Cache: 20s+11MB

Again, playing file the hard way (start downloading, start streaming, ignore streaming url, play the file from hard drive deluge's downloading to) yields no errors. It looks like deluge-streaming still omits a segment here and there while

-- UPDATE

I just tried another file, and this happend:

[ERROR   ] 12:57:03 core:210 Failed to cycle
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/streaming/core.py", line 208, in handle_cycle
    self._cycle()
  File "build/bdist.linux-x86_64/egg/streaming/core.py", line 297, in _cycle
    first_piece = f['offset'] // self.piece_length
ZeroDivisionError: integer division or modulo by zero
[ERROR   ] 12:57:03 txiobuffer:32 Failed to read
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/thomas/txiobuffer.py", line 30, in read
    data = yield threads.deferToThread(self.fileObject.read, num)
  File "/usr/lib/python2.7/site-packages/twisted/python/threadpool.py", line 250, in inContext
    result = inContext.theWork()
  File "/usr/lib/python2.7/site-packages/twisted/python/threadpool.py", line 266, in <lambda>
    inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/site-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/site-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
  File "build/bdist.linux-x86_64/egg/streaming/torrentfile.py", line 51, in read
    self.can_read_to = self.torrent.can_read(self.offset + tell) + tell
  File "build/bdist.linux-x86_64/egg/streaming/core.py", line 155, in can_read
    needed_piece, rest = divmod(from_byte, self.piece_length)
ZeroDivisionError: integer division or modulo by zero
[ERROR   ] 12:57:03 http:160 Failed SingleRangeStaticProducer
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/thomas/outputs/http.py", line 158, in resumeProducing
    yield self._resumeProducing()
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "build/bdist.linux-x86_64/egg/thomas/outputs/http.py", line 172, in _resumeProducing
    min(self.bufferSize, self.size - self.bytesWritten))
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "build/bdist.linux-x86_64/egg/thomas/txiobuffer.py", line 30, in read
    data = yield threads.deferToThread(self.fileObject.read, num)
  File "/usr/lib/python2.7/site-packages/twisted/python/threadpool.py", line 250, in inContext
    result = inContext.theWork()
  File "/usr/lib/python2.7/site-packages/twisted/python/threadpool.py", line 266, in <lambda>
    inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/site-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/site-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
  File "build/bdist.linux-x86_64/egg/streaming/torrentfile.py", line 51, in read
    self.can_read_to = self.torrent.can_read(self.offset + tell) + tell
  File "build/bdist.linux-x86_64/egg/streaming/core.py", line 155, in can_read
    needed_piece, rest = divmod(from_byte, self.piece_length)
ZeroDivisionError: integer division or modulo by zero
[ERROR   ] 12:57:33 core:210 Failed to cycle
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/streaming/core.py", line 208, in handle_cycle
    self._cycle()
  File "build/bdist.linux-x86_64/egg/streaming/core.py", line 297, in _cycle
    first_piece = f['offset'] // self.piece_length
ZeroDivisionError: integer division or modulo by zero
[ERROR   ] 12:57:33 txiobuffer:32 Failed to read
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/thomas/txiobuffer.py", line 30, in read
    data = yield threads.deferToThread(self.fileObject.read, num)
  File "/usr/lib/python2.7/site-packages/twisted/python/threadpool.py", line 250, in inContext
    result = inContext.theWork()
  File "/usr/lib/python2.7/site-packages/twisted/python/threadpool.py", line 266, in <lambda>
    inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/site-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/site-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
  File "build/bdist.linux-x86_64/egg/streaming/torrentfile.py", line 51, in read
    self.can_read_to = self.torrent.can_read(self.offset + tell) + tell
  File "build/bdist.linux-x86_64/egg/streaming/core.py", line 155, in can_read
    needed_piece, rest = divmod(from_byte, self.piece_length)
ZeroDivisionError: integer division or modulo by zero
[ERROR   ] 12:57:33 http:160 Failed SingleRangeStaticProducer
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/thomas/outputs/http.py", line 158, in resumeProducing
    yield self._resumeProducing()
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "build/bdist.linux-x86_64/egg/thomas/outputs/http.py", line 172, in _resumeProducing
    min(self.bufferSize, self.size - self.bytesWritten))
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "build/bdist.linux-x86_64/egg/thomas/txiobuffer.py", line 30, in read
    data = yield threads.deferToThread(self.fileObject.read, num)
  File "/usr/lib/python2.7/site-packages/twisted/python/threadpool.py", line 250, in inContext
    result = inContext.theWork()
  File "/usr/lib/python2.7/site-packages/twisted/python/threadpool.py", line 266, in <lambda>
    inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/site-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/site-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
  File "build/bdist.linux-x86_64/egg/streaming/torrentfile.py", line 51, in read
    self.can_read_to = self.torrent.can_read(self.offset + tell) + tell
  File "build/bdist.linux-x86_64/egg/streaming/core.py", line 155, in can_read
    needed_piece, rest = divmod(from_byte, self.piece_length)
ZeroDivisionError: integer division or modulo by zero

The file itself doesn't seem corrupted, mpv plays it with no errors.

As from 5 files tested this happend with one file only, I'll link it here. No idea whether github cares or not, therefore I'm going to add some spaces to the link.
https ://nyaa. si/view/1069331/torrent
It's a direct link to the file, torrent description page has no "/torrent" at the end.

Note: It could be illegal in your country to download / share file this torrent points to, as it is a copyright protected content (anime).

-- UPDATE 2

I missed your previous commend due to it being edited

Can you run deluge daemon with -d -L debug

I found a few problems, let me fix them and lets see.

I'll check it a bit later and post the results if there's something interesting in the output.

@JohnDoee
Copy link
Owner

I still get some errors, but the file plays fine and there are no visible artifacts.

It seems like there's a math error somewhere when doing a range request. So, mpv buffers so fast from Deluge it gets some null bytes but doesn't do that when playing from disk.

I just tried another file, and this happend: ... ZeroDivisionError

That's an interesting error because that means Deluge told me that the torrent has a piece length of zero. There is probably a race condition, I'll add a small safeguard against it.

I missed your previous commend due to it being edited

You can ignore the "before edit" part 😄

Thanks for the feedback!

@wjtk4444
Copy link
Author

wjtk4444 commented Aug 25, 2018

I looked at the pieces plugin. Something doesn't seem quite right here. Either math is a bit off when calculating which piece should be downloaded next, or maybe it's mpv requesting them in a weird order.

VLC refuses to open any stream now, but it can play the "raw files".

So, mpv buffers so fast from Deluge it gets some null bytes but doesn't do that when playing from disk.

this could be the case, as I have mpv (youtube-dl) set up this way:

[network-stream]
cache=yes
cache-secs=36000
cache-backbuffer=10000000
cache-default=10000000
demuxer-max-bytes=2147483647
demuxer-max-back-bytes=2147483647
user-agent='Mozilla/5.0'

which basically means "load as much as possible to the ram, because my internet connection is really slow"

It's probably not the most optimal way to

  • download a torrent to the hard drive
  • stream a file locally to the player
  • have player keep the whole file in ram

but for network streams in gerenal this is the setting I like the most. I would use mpv's cache-file option instead of wasting my ram, but apparently it doesn't work as advised so I have to stick with filling up my ram at the moment.

EDIT: Ooops, I made a missclick. Sorry. How does one re-open an issue?

@JohnDoee JohnDoee reopened this Aug 25, 2018
@JohnDoee
Copy link
Owner

It seems like either Linux or Python buffers when reading from disk. If you read 1024 bytes, it might actually read 2048 and just save 1024 in memory. Since Deluge haven't downloaded the data we need yet it caches garbage data.

I'm busting that now, all media player errors should be gone.

I also ensure the torrent is added correctly, or at least, the piece length is correct. This should fix the ZeroDivision exception.

Anyways, check out https://github.com/JohnDoee/deluge-streaming/releases/tag/0.10.2

It seems like it's not actually possible to force Deluge to do 100% sequential download. If it seems mostly-sequential, then it's probably the best we can get.

@wjtk4444
Copy link
Author

Well done, now it seems to work perfectly. I'll do some more tests later today or tomorrow, but everything seems to be fixed.

It seems like it's not actually possible to force Deluge to do 100% sequential download. If it seems mostly-sequential, then it's probably the best we can get.

I just checked Deluge-Pieces output when using SequentialDownload plugin (and streaminig plugin disabled), and it seems to be more or less the same.

@JohnDoee
Copy link
Owner

JohnDoee commented Sep 8, 2018

Any updates ?

@wjtk4444
Copy link
Author

wjtk4444 commented Sep 9, 2018

Actually, yes. I'm not certain if it's still platform-related as I don't have any windows machine laying around, but it seems that both downloading and seeking works much better when the client is running and is connected to the daemon. If it's just the deluge daemon being somewhere in the background the plugin still works, but seeks seem to take longer (requires firther testing) and the cache-bar in mpv either doesn't fill at all or fills very slowly.

Steps to reproduce this behavior:

  • leave just deluged in background
  • add a torrent and start streaming via your script
  • open the url with mpv
    -- wait about 30 seconds to one minute (my connection is pretty slow)
  • start deluge client, connect to the daemon
  • see how cache-bar in mpv fills almost instantly for the part that's already downloaded
    -- or
  • make a seek before starting deluge client and watch the cache-bar start filling in the right place after client is started and conntected to the daemon (seek freezes (no further buffering visible) with no client open, but it seems to still request the correct parts of the video as the first frame of the selected segment always shows up on screen after a few seconds)

It all seems weird, but that's what happens for me. Maybe I'll do some more digging tomorrow or the day after when I'll have some more time.

@JohnDoee
Copy link
Owner

JohnDoee commented Sep 9, 2018

I think Deluge might do something weird to Twisted and its event loop. The reason I'm not using deluge-web to serve files is because it simply doesn't work.

Your description is consistent with a broken/slow event loop as every write require the loop to run.

@JohnDoee
Copy link
Owner

JohnDoee commented Sep 11, 2018

It seems like Deluge has an internal cache for states....

I've tried to fix it in 0.10.3 (Note, probably doesn't work with Deluge 2 was the update mechanism is different)

@wjtk4444
Copy link
Author

wjtk4444 commented Sep 15, 2018

Now for some reason deluge reports download speed of 1 MiB/s (for example) and mpv's cache is feeling at much slower rate, about 1/10th of download speed. The torrent completition percentage also seems to move at slower pace than advertised. (1 MiB/s downloads 100MiB file in ~15 minutes rather than 100 seconds). Is it possible that some (a lot actually, 90% would be my bet) of downloaded segments are getting discarded? I don't think I've seen this behavior when using previous versions of the plugin.

Edit:
For example, this download started about 10 minutes ago (speed didn't vary over the time). ETA is the same since the beginning, not to mention that the download should complete several minutes ago. screenshot

@JohnDoee
Copy link
Owner

I was testing with speeds capped at 1MB/s so I noticed nothing. I can see what the problem is though.

man, this is hard to get right.

@JohnDoee
Copy link
Owner

The saga continues, I've tried to limit how often it sets priority on pieces while still doing it when it is necessary.

Interestingly enough the original design was the same as Quasar used so they must've had same problem for small torrents.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants