JohnDoee / deluge-streaming

Streaming plugin for deluge, making it possible to read torrents and download required parts on-demand.
Other
138 stars 15 forks source link

deluge-streaming doesn't work on linux #19

Open wjtk4444 opened 6 years ago

wjtk4444 commented 6 years ago

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:

--

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 commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

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

JohnDoee commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

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 :smile:

Thanks for the feedback!

wjtk4444 commented 6 years ago

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

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 commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

Any updates ?

wjtk4444 commented 6 years ago

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:

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 commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

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.