[WebTorrent] instant.io has trouble downloading from libtorrent seeds

lucybythec commented 3 years ago

Hi! Thank you for this project. I discovered the following issue. When libtorrent is built with -Dwebtorrent=on, it can successfully and quickly download from magnet links created on instant.io. However, it doesn't work very well in reverse:

Seed with instant.io, download with instant.io: Success
Seed with libtorrent, download with libtorrent: Success
Seed with instant.io, download with libtorrent: Success
Seed with libtorrent, download with instant.io: Failure

In the last case, instant.io either forever stays at "Downloading torrent", or succeeds after a long time (over 10 minutes). Perhaps there is a compatibility issue?

Here is the test program for seeding:

import os
import os.path
import time

import libtorrent as lt

lt_session = lt.session()

fn = 'testfile.bin'
with open(fn, 'wb') as f:
    f.write(os.urandom(1024 * 1024))

lt_file_storage = lt.file_storage()
lt.add_files(lt_file_storage, fn)

lt_create_torrent = lt.create_torrent(lt_file_storage)
# Same tracker list as used by instant.io
lt_create_torrent.add_tracker('wss://tracker.btorrent.xyz')
lt_create_torrent.add_tracker('wss://tracker.openwebtorrent.com')
lt_create_torrent.add_tracker('udp://tracker.leechers-paradise.org:6969')
lt_create_torrent.add_tracker('udp://tracker.coppersurfer.tk:6969')
lt_create_torrent.add_tracker('udp://tracker.opentrackr.org:1337')
lt_create_torrent.add_tracker('udp://explodie.org:6969')
lt_create_torrent.add_tracker('udp://tracker.empire-js.us:1337')

lt.set_piece_hashes(lt_create_torrent, '.')

lt_torrent_info = lt.torrent_info(lt_create_torrent.generate())
lt_add_torrent_params = {
    'ti': lt_torrent_info,
    'save_path': '.',
}

lt_torrent_handle = lt_session.add_torrent(lt_add_torrent_params)

torrent_magnet_uri = lt.make_magnet_uri(lt_torrent_handle)
print('* Seeding: ' + torrent_magnet_uri)

while True:
    s = lt_torrent_handle.status()

    state_str = ['queued', 'checking', 'downloading metadata',
                 'downloading', 'finished', 'seeding', 'allocating',
                 'checking fastresume']

    print('%.2f%% complete (down: %.1f kb/s up: %.1f kB/s peers: %d) %s' %
          (s.progress * 100, s.download_rate / 1000, s.upload_rate / 1000,
           s.num_peers, state_str[s.state]),)

    for a in lt_session.pop_alerts():
        print(f"[Alert] {a}")

    time.sleep(1)

Using libtorrent d5b27eeacb573d5b6c7b30357c8d27ef1231b7eb on Linux.

arvidn commented 3 years ago

It would be helpful if you enabled logging (torrent and peer logging specifically) in the alert_mask, and logged all alerts to a file.

If you no peer actually ends up successfully requesting data from you, there shouldn't be too much in the log. But there may be some hint of the peer trying to connect.

@paullouisageneau do you have any more ideas? does libdatachannel have a separate log?

lucybythec commented 3 years ago

Thank you for the quick reply!

It would be helpful if you enabled logging (torrent and peer logging specifically) in the alert_mask, and logged all alerts to a file.

Apologies, how does one do that exactly? With 'alert_mask': lt.alert.category_t.all_categories, I don't see any relevant alerts, even when a libtorrent-based peer successfully connects and downloads the file.

arvidn commented 3 years ago

settings = {'alert_mask': lt.alert.category_t.all_categories}
lt_session = lt.session(settings)

Do you at least see more alerts than previously?

lucybythec commented 3 years ago

settings = {'alert_mask': lt.alert.category_t.all_categories}
lt_session = lt.session(settings)

Yes, like that.

Do you at least see more alerts than previously?

Hmm, no. Looks about the same number of alerts.

paullouisageneau commented 3 years ago

This could have different causes, but the most probable is either some issue with establishing WebRTC connections or a compatibility issue with the WebTorrent client on Instant.io.

There is a debug flag to output the logs of libdatachannel, you could try enabling it: https://github.com/arvidn/libtorrent/blob/eb62b96da845bf4aa9aa7f3283b16dbe03c7866d/src/rtc_signaling.cpp#L35

I'll do some tests on my side when I get the time.

lucybythec commented 3 years ago

settings = {'alert_mask': lt.alert.category_t.all_categories}
lt_session = lt.session(settings)
Yes, like that.

Do you at least see more alerts than previously?

Hmm, no. Looks about the same number of alerts.

I have investigated why this happens, and filed a new issue: #5848

It would be helpful if you enabled logging (torrent and peer logging specifically) in the alert_mask, and logged all alerts to a file.

There are indeed a lot more messages with the alert mask set. I searched for the IP address of the machine running the web browser with instant.io, and it only occurs once, on a WEBSOCKET_TRACKER_READ line. There are also some "RTC negotiation failed" lines. Is there anything specific that I need to look for?

paullouisageneau commented 3 years ago

There are also some "RTC negotiation failed" lines. Is there anything specific that I need to look for?

Yes, this confirms the WebRTC connection couldn't be established. Could you please link the entire log?

lucybythec commented 3 years ago

Ok, here is the complete log of a failed attempt to download a file using instant.io, with all alerts enabled and the DEBUG_RTC parameter set to 1. The test seed program was allowed to run for about 10 minutes.

test.log

paullouisageneau commented 3 years ago

Thanks for the log!

For now I see three potential problems:

There was only a single connection attempt over 10 minutes, which doesn't seem like a lot.
Libtorrent receives a WebRTC offer lacking a server reflexive candidate, probably the remote peer's STUN server is unreachable. It should still manage to connect though.
When libtorrent tries to answer, the tracker wss://tracker.openwebtorrent.com closes the WebSocket connection immediately: tracker error: (1) stream truncated [sock_read] stream truncated. As a result the answer might be dropped and this is probably why the connection never happens.

The answer sent through the tracker seems valid, so this might come from the lack of keepalive on the WebSocket. I'll investigate further.

paullouisageneau commented 3 years ago

The problem seems to come from the trackers instant.io uses: tracker.btorrent.xyz, which times out all the time and tracker.openwebtorrent.com which tends to close or lose connection, particularly when connected from libtorrent. Once signaling is successfully done via the tracker, the connection succeeds.

The issue could have been an invalid answer format from libtorrent. I tried deploying the same tracker locally than on tracker.openwebtorrent.com which is at https://github.com/OpenWebTorrent/openwebtorrent-tracker since error handling is basically non-existent, it abruptly closes the connection if any error happens. However, downloading from instant.io works fine in that case.

So I would conclude the tracker is just unreliable. I added a keepalive in https://github.com/arvidn/libtorrent/pull/5882, it seems to help a bit but it still fails regularly.

A way to mitigate the issue could be to randomize the WebSocket tracker retry interval to break the non-working pattern, but it isn't very satisfying as it won't connect quick enough.

lucybythec commented 3 years ago

Thank you for looking into this. If it's okay, I have a few more questions.

Any idea why instant.io isn't having this problem downloading from itself? Is it doing something that libtorrent can't?
What about the DHT, doesn't it help in this case?
What is the practical solution? Probably we should let the tracker maintainers know as they may be interested in fixing the problem on their part. Otherwise, there are other, better public WebSocket trackers, or should we host our own, and if so, with what software? What would you recommend?

paullouisageneau commented 3 years ago

* Any idea why instant.io isn't having this problem downloading from itself? Is it doing something that libtorrent can't?

The connection to the tracker is lost randomly because the tracker seems to be overloaded anyway. It is still regularly lost in the browser but it seems less frequent. I still don't know why the connection to libtorrent is closed but there are two possibilities:

The browser is better at keeping the connection alive. That's why I though adding a keepalive would solve the problem. For now I don't see any difference, both the WebTorrent client of instant.io and libtorrent reconnect the WebSocket at the same frequency (after the polling time of 2 min).
The tracker closes the connection because libtorrent sends an invalid message. However, everything looks fine and the same tracker deployed locally does not close the connection. Additionally, the WebSocket is not closed properly, instead the connection is lost.

* What about the DHT, doesn't it help in this case?

There is no possibility of using the DHT with WebTorrent. That's a limitation of WebRTC.

* What is the practical solution? Probably we should let the tracker maintainers know as they may be interested in fixing the problem on their part. Otherwise, there are other, better public WebSocket trackers, or should we host our own, and if so, with what software? What would you recommend?

I'll contact the tracker maintainers to see if they have more information. Sadly I don't know of other public WebTorrent trackers. If you want to host your own tracker, openwebtorrent-tracker (C++) seems to work fine, otherwise you could deploy the reference tracker implementation (node.js, less performant). There is also wt-tracker but I haven't tried it.

Sl0ppie commented 3 years ago

You can try wss://tracker.sloppyta.co https://tracker.sloppyta.co/wsstats It runs the reference tracker.

arvidn commented 3 years ago

It seems to me that the WebTorrent client also regularly disconnects after having requested a bunch of pieces, and then reconnects again to resume requesting pieces. I haven't looked any closer into whether this is deliberate or caused by some failure yet. I'll try to take a closer look.

arvidn commented 3 years ago

I set up a test torrent, seeding a web-torrent compatible torrent, here:

magnet:?xt=urn:btih:8c3c639e90b4d06bb59c746eb569f4b2dbfa2000&xt=urn:btmh:1220db736898b9fd6799695f9830d333c14e8105f237b437a6c1ca0d42fb604630b1&dn=webtorrent-test&tr=wss%3a%2f%2ftest.libtorrent.org

This is a v1,v2 hybrid torrent. I also set up a tracker (openwebtorrent-tracker) at wss://test.libtorrent.org.

arvidn commented 3 years ago

it seems openwebtorrent-tracker terminates with bad_alloc regularly

paullouisageneau commented 3 years ago

@arvidn @Sl0ppie Thanks, I'll have a look.

@arvidn I've experienced similar disconnections of the JS WebTorrent client when downloading on localhost, but I don't think I've seen it otherwise.

arvidn commented 3 years ago

I believe the issue is that WebTorrent does not support the REJECT message. So when it sends too many requests, hitting libtorrent's limit, this happens:

<== REQUEST [ piece: 2756 s: 48000 l: 4000 ]
*** INVALID_REQUEST [ incoming request queue full 501 ]
==> REJECT_PIECE [ piece: 2756 s: 48000 l: 4000 too many requests ]

This repeats quite a few times (as one would expect). However, if WebTorrent ignores this message, it still thinks it has outstanding piece requests, and libtorrent doesn't. That would explain the stall. Both parties thinks the ball is in the other's court.

If I set the max_allowed_in_request_queue setting to a very large number it works without disconnects. I got it to work setting the limit to 50000, but 5000 was not enough. It seems the WebTorrent client is willing to have quite a lot of bytes outstanding in client requests. The default limit in libtorrent is 500, which could probably be raised some. It's pretty cheap to queue up requests, but I think much higher than 2000 seems a bit high as the default.

Apart from raising the max_allowed_in_request_queue limit to 2000, and filing a bug report against WebTorrent, I'm open to other suggestions on how to improve this situation.

arvidn commented 3 years ago

in fact, WebTorrent does not advertize support for the 2008 FAST extension, so there is in fact no REJECT_PIECE being sent. My log is a bit misleading there. (log addressed here)

arvidn commented 3 years ago

I filed this: https://github.com/webtorrent/webtorrent/issues/1995 posted this: https://github.com/arvidn/libtorrent/pull/5934 (I will merge that up into master soon) and this, which I encountered while testing: https://github.com/arvidn/libtorrent/pull/5933

paullouisageneau commented 3 years ago

@arvidn Great, thanks for taking the time to investigate that issue!

shengchl commented 3 years ago

Thank you all guys for working hard on bringing webtorrent to libtorrent!

stale[bot] commented 3 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

ThaUnknown commented 3 years ago

@arvidn is this sill WIP? I assume you're waiting for webtorrent to implement FAST?

arvidn commented 3 years ago

I've mitigated the issue to some extent by increasing the default number of queued incoming requests. But the original BitTorrent protocol doesn't support any form of back pressure, so I can't ask webtorrent to back off unless it implements the FAST extensions (specifically, REJECT_REQUEST)

It's working better, but still with intermittent slow-downs when it overruns the request queue limit.

ThaUnknown commented 3 years ago

I've mitigated the issue to some extent by increasing the default number of queued incoming requests. But the original BitTorrent protocol doesn't support any form of back pressure, so I can't ask webtorrent to back off unless it implements the FAST extensions (specifically, REJECT_REQUEST)

It's working better, but still with intermittent slow-downs when it overruns the request queue limit.

is there any chance for this to make it into a major release so libtorrent based BT clients can support WRTC, or is there something that's still missing/needs work?

ThaUnknown commented 2 years ago

@paullouisageneau is this still an issue now that https://github.com/webtorrent/webtorrent/pull/2243 is implemented?

paullouisageneau commented 2 years ago

@ThaUnknown No, the issue should be solved by https://github.com/webtorrent/webtorrent/pull/2243

ThaUnknown commented 2 years ago

@ThaUnknown No, the issue should be solved by webtorrent/webtorrent#2243

is there anything else on the roadmap for BT over WebRTC left?

paullouisageneau commented 2 years ago

is there anything else on the roadmap for BT over WebRTC left?

Feature-wise, I don't think there is, however more testing would be welcome. I've just open a PR #6826 to update libdatachannel.

arvidn / libtorrent

[WebTorrent] instant.io has trouble downloading from libtorrent seeds #5831