Torrent not available after a while when using WebTorrent

[2m]

I used torrent download -seed 'magnet:?xt=urn:btih:...' to download and then seed the torrent via WebTorrent.

If I try to download the torrent (using instant.io or btorrent.xyz) just after download completes, so after

downloading "...": 288 MB/288 MB, 2197/2197 pieces completed (0 partial)

is printed to the logs, then everything is alright.

But then, after waiting for a while I see the following in the logs:

2020-06-23T11:19:49+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-23T11:20:32+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF

And immediately after those logs, I am unable to download the seeded file via WebTorrent using the websites mentioned above.

[anacrolix]

And immediately after those logs, I am unable to download the seeded file via WebTorrent using the websites mentioned above.

Do you mean that other BitTorrent clients using the trackers you mentioned, aren't able to locate your local client that should be seeding now? Are you using your own torrent, for which you expect only your own client to be seeding?

There's some timing behaviour with the Webtorrent trackers that seem to expect announces to occur every minute, or the websocket connection is closed. The anacrolix/torrent implementation currently doesn't re-announce unless a submitted offer is taken up. However it will reconnect the websocket if it is disconnected. Are you seeing the websocket disconnect errors on a persistent basis after you finish the download?

[2m]

Do you mean that other BitTorrent clients using the trackers you mentioned, aren't able to locate your local client that should be seeding now?

Yes. That is correct. Immediately after I finish downloading and start seeding the torrent with anacrolix/torrent I can reach the same torrent via instant.io or btorrent.xyz. But after a while, after I see the mentioned log messages, the torrent is not available via instant.io or btorrent.xyz even if anacrolix/torrent is still running in the seed mode.

Are you using your own torrent, for which you expect only your own client to be seeding?

Not exactly my own, but with very little seeders. And most likely without any WebTorrent seeders. So when I download that torrent using anacrolix/torrent I think it gets downloaded from regular seeds, and then I become the only WebTorrent seeder.

Are you seeing the websocket disconnect errors on a persistent basis after you finish the download?

Yes, that is correct. Here is an example output from anarcolix/torrent when seeding torrents:

2020-06-24T09:37:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T09:37:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T09:37:56+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:39:54+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:40:37+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:42:34+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:42:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T09:42:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T09:43:17+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:45:15+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:45:57+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:47:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T09:47:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T09:47:55+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:48:37+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:50:36+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:51:17+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:52:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T09:52:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T09:53:16+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:53:57+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:55:56+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:56:37+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:57:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T09:57:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T09:58:37+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T09:59:17+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:01:17+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:01:57+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:02:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T10:02:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T10:03:58+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:04:37+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:06:38+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:07:17+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:07:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T10:07:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T10:09:18+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:09:58+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:11:59+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:12:38+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:12:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T10:12:44+0300 NONE  dht.go:109: error looking up "router.silotis.us:6881": lookup router.silotis.us: no such host
2020-06-24T10:14:39+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.btorrent.xyz": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF
2020-06-24T10:15:18+0300 INFO  tracker_client.go:100: tracker client for "wss://tracker.openwebtorrent.com": websocket instance ended: read message error: websocket: close 1006 (abnormal closure): unexpected EOF

[anacrolix]

Thanks, I believe the issue is that the client needs to re-announce when it reconnects. Ideally it should re-announce regularly but that logic isn't as trivial to create.

[2m]

Could you give me a quick pointer where I should be looking at in the code to implement this? I am willing to create PR to fix this issue.

[anacrolix]

@2m Here a webtorrent tracker is first announced to after a new client reference to the tracker is obtained: https://github.com/anacrolix/torrent/blob/9d0ea150445aa5ecb1f8ab8b3c1176a95a0b03f6/torrent.go#L1358 Here a new announce is made when an answer is received for an offer: https://github.com/anacrolix/torrent/blob/c3696aa5a4a0e3e987fa0b4bb6f347da4b7e991e/webtorrent/tracker_client.go#L301 However here, websocket trackers are reconnected if they are drop, but no reannouncing is done. I'm not sure if Torrents should subscribe for connection events, or the webtorrent.TrackerClient should just reannounce automatically: https://github.com/anacrolix/torrent/blob/c3696aa5a4a0e3e987fa0b4bb6f347da4b7e991e/webtorrent/tracker_client.go#L93

[DigitalAlchemist]

Did some digging on this today. Per this file, OpenWebTorrent doesn't accept messages that aren't one of:

• "started"
• "stopped"
• "completed"
• ""

Where "" is an empty or missing field value, and instead throws an exception which kills the socket. https://github.com/OpenWebTorrent/openwebtorrent-tracker/blob/2a8eafab5e29912f69fba4b5ee957941441fe51f/src/FastTracker.h#L56

The array in the below file contains the string "empty" in lieu of an empty string. BEP3 isn't clear (to me) as to whether this should be the string "empty" or an empty string. I went hunting through the libtorrent source and have deduced it should be an empty string, not the string "empty". I'm not entirely familiar with this code, so it might be my mistake. https://github.com/anacrolix/torrent/blob/6e43db6a89fbc03b80ebc8b7c31cf50f1165c6a9/tracker/tracker.go#L40

Thoughts?

There's some other optimizations worth while, which include re-sending offers when the socket falls over, but that's probably a different issue.

[anacrolix]

@DigitalAlchemist thank you!

[anacrolix]

@DigitalAlchemist would your recommendation be to omit none/empty events entirely in webtorrent announces, or retain them with an empty value? My reading of OpenWebTorrent is that it doesn't differentiate, but I wonder about other implementations. See the way event is handled in HTTP announces for comparison: https://github.com/anacrolix/torrent/blob/14f2e8087e0d1c8fcbe00db059163867c01d9f23/tracker/http.go#L89-L91. I wonder if here I want omitempty: https://github.com/anacrolix/torrent/blob/0ab6d108be82c505b3ceac5e55bf25ab5d77dd6a/webtorrent/tracker_protocol.go#L15, in addition to changing "empty" in https://github.com/anacrolix/torrent/blob/b67ccab7f2a687ddf75a31bc0206f6c11c58bd39/tracker/tracker.go#L40 to "".

[anacrolix]

https://github.com/anacrolix/torrent/commit/29cc20ede9983f218953ab756438686ef0066c10 fixes the immediate problem described by @DigitalAlchemist in https://github.com/anacrolix/torrent/issues/416#issuecomment-751427001.

[2m]

Awesome, thanks! I will try it out.

On Wed, 30 Dec 2020, 02:45 Matt Joiner, notifications@github.com wrote:

29cc20e https://github.com/anacrolix/torrent/commit/29cc20ede9983f218953ab756438686ef0066c10 fixes the immediate problem described by @DigitalAlchemist https://github.com/DigitalAlchemist in #416 (comment) https://github.com/anacrolix/torrent/issues/416#issuecomment-751427001.

— You are receiving this because you were assigned. Reply to this email directly, view it on GitHub https://github.com/anacrolix/torrent/issues/416#issuecomment-752288328, or unsubscribe https://github.com/notifications/unsubscribe-auth/AADHBRXYC4BDLEU6IDI5BX3SXJZ2ZANCNFSM4OFNPD5Q .

[DigitalAlchemist]

Hey @anacrolix! Sorry about not getting back sooner. I logged out for the holidays... My intent was not to have you make the change, just to solicit inputs on what might be the correct answer.

This works for me for openwebtorrent. The omitempty addition is likely more correct, as it reads more in line with what BEP-3 states:

event This is an optional key which maps to started, completed, or stopped (or empty, which is the same as not being present). If not present, this is one of the announcements done at regular intervals. An announcement using started is sent when a download first begins, and one using completed is sent when the download is complete. No completed is sent if the file was complete when started. Downloaders send an announcement using stopped when they cease downloading. https://www.bittorrent.org/beps/bep_0003.html

Happy to put together a PR for the above, which will close out half of this ticket. I'm tracking two issues:

• [x] Don't disconnect from tracker once a WebRTC connection offer completes and we announce another offer to connect to us. The follow-up offer is causing this disconnect whenever we send an "empty" announce, which we've discussed above. Happy to submit a final PR for this to wrap up the omitempty piece.
• [x] Re-announce WebRTC peer connections on disconnect from the tracker. This is straightforward, and I'll submit a PR tonight. We have not covered this above.

[anacrolix]

Okay with those PRs merged, this issue should be fix. @2m, can you test your original issue with master? Let's reopen if it's not fixed.

[2m]

Thank you @DigitalAlchemist for fixing this. I will test it out after #455 gets merged.

[anacrolix]

That's been merged @2m .

[2m]

I've just tried the latest master and I am still not able to download the file via btorrent.xyz after a while. It works when I try just after starting seeding, but not after some time.

I also get this panic if I try to download via btorrent.xyz after anacrolix/torrent finishes downloading and starts seeding:

for "wss://tracker.btorrent.xyz": connected
panic: concurrent write to websocket connection

goroutine 40 [running]:
github.com/gorilla/websocket.(*messageWriter).flushFrame(0xc00129ad20, 0x1, 0x0, 0x0, 0x0, 0xc000054c00, 0x0)
        /home/martynas/.local/share/gopath/pkg/mod/github.com/gorilla/websocket@v1.4.2/conn.go:610 +0x60e
github.com/gorilla/websocket.(*messageWriter).Close(0xc00129ad20, 0xc0009b77c0, 0xc000511ad0)
        /home/martynas/.local/share/gopath/pkg/mod/github.com/gorilla/websocket@v1.4.2/conn.go:724 +0x65
github.com/gorilla/websocket.(*Conn).beginMessage(0xc0001e66e0, 0xc000ab0150, 0x1, 0x6a953f, 0xd2b060)
        /home/martynas/.local/share/gopath/pkg/mod/github.com/gorilla/websocket@v1.4.2/conn.go:473 +0x262
github.com/gorilla/websocket.(*Conn).NextWriter(0xc0001e66e0, 0x1, 0xc00007a3c0, 0xc00025ebc8, 0x1a14, 0x3)
        /home/martynas/.local/share/gopath/pkg/mod/github.com/gorilla/websocket@v1.4.2/conn.go:513 +0x53
github.com/gorilla/websocket.(*Conn).WriteMessage(0xc0001e66e0, 0x1, 0xc000a41500, 0x9be, 0xa80, 0xa80, 0xc000a4c000)
        /home/martynas/.local/share/gopath/pkg/mod/github.com/gorilla/websocket@v1.4.2/conn.go:766 +0x6e
github.com/anacrolix/torrent/webtorrent.(*TrackerClient).writeMessage(0xc00025eb60, 0xc000a41500, 0x9be, 0xa80, 0xa80, 0x0)
        /home/martynas/projects/torrent/webtorrent/tracker_client.go:237 +0xee
github.com/anacrolix/torrent/webtorrent.(*TrackerClient).Announce(0xc00025eb60, 0x1c51023600000002, 0x20776d66cbe8943e, 0x5dc7ddef3d7f0744, 0x0, 0x0)
        /home/martynas/projects/torrent/webtorrent/tracker_client.go:213 +0x666
github.com/anacrolix/torrent.(*Torrent).startWebsocketAnnouncer.func2(0xc00025eb60, 0xc000250500, 0xc00020c7e0)
        /home/martynas/projects/torrent/torrent.go:1410 +0x7c
created by github.com/anacrolix/torrent.(*Torrent).startWebsocketAnnouncer
        /home/martynas/projects/torrent/torrent.go:1409 +0x174

[DigitalAlchemist]

@anacrolix @2m

I believe the attached pull request fixes the panic issue - I was not holding the appropriate lock when I called WriteMessage per the existing code and the gorilla docs (https://pkg.go.dev/github.com/gorilla/websocket#hdr-Concurrency)

Still no idea why btorrent.xyz isn't working for you - I was able to use wss://tracker.btorrent.xyz with no issue.

[anacrolix]

Thanks, #460 merged.

[2m]

I have tested latest master. The panic and the original issue of this ticket has been fixed.

Thank you very much @DigitalAlchemist and @anacrolix!