TORRENT_FINISHED alert emitted twice

[masterwok]

Hello,

I'm seeing the torrent finished alert being emitted twice when working with magnets.

The first emitted finished event is occurring directly after ADD_TORRENT alert is emitted. The second event is occurring when the torrent download completes.

I believe the extra event is emitted due to how I'm "forcing" magnets to start in my code by invoking resume on the torrent handle. My reason for doing so is that when I start a download with a magnet using the SessionManager the ADD_TORRENT alert is emitted but the download never starts. I'm seeing the following in my logs:

2019-04-11 22:14:38.372 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: PORTMAP - portmap_alert - successfully mapped port using UPnP. external port: TCP/6881
2019-04-11 22:14:38.378 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: PORTMAP - portmap_alert - successfully mapped port using UPnP. external port: UDP/6881
2019-04-11 22:14:38.386 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_ERROR - dht_error_alert - DHT error [hostname_lookup] (1) Host not found (authoritative)
2019-04-11 22:14:39.092 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: b8ad357f2ab010a303160861c99323b3115fbecb
2019-04-11 22:14:42.683 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: b8ad357f2ab010a3031608618c212eff3f8a9558
2019-04-11 22:14:43.794 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: 41abba748832de530a7ab3a85ec0d7a708fe33c0
2019-04-11 22:14:45.019 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: ddd57dd72c6b650c1218f4fe2a3bdd6044f5984f
2019-04-11 22:14:45.022 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: 6f882e1f50be23953b88a707bf6a34153697edb4
2019-04-11 22:14:48.910 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: c42e7acda283d89f2f03eb8d55178b0b1c95dd63
2019-04-11 22:14:50.554 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: c42e6bf2e773906f433232d8d8c8be81ea5577d6
2019-04-11 22:14:51.475 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: c42e7acda283d89f2f03eb8d55178b0b1c95dd63
2019-04-11 22:14:52.598 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: 41abae4f66701bdcfe382121673e88331fa8413e
2019-04-11 22:14:52.906 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: 41ababf6a7033e018f26c5dbc28f3074528d24d0
2019-04-11 22:14:53.785 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: 6f8830a940a4318a95e124a956878a3364b6eb05
2019-04-11 22:14:56.284 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: c42e7acda283d89f2f03eb8d55178b0b1c95dd63
2019-04-11 22:14:56.755 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_BOOTSTRAP - dht_bootstrap_alert - DHT bootstrap complete
2019-04-11 22:14:56.812 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: ADD_TORRENT - add_torrent_alert - added torrent: Sintel
2019-04-11 22:14:56.877 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: STATE_CHANGED - state_changed_alert - Sintel: state changed to: dl metadata
2019-04-11 22:14:57.821 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_ANNOUNCE - dht_announce_alert - incoming dht announce: 213.254.111.41:32108 (c42e6bf2e773906f433232d8d8c8be81ea5577d6)
2019-04-11 22:14:59.664 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: ea0df7011863c0f9758e79449a6779e3ce9cb4d7
2019-04-11 22:15:00.791 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: 1b61ac665c281227a05e362001cb175c7a622831
2019-04-11 22:15:02.271 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: 6f8838f7074549b5cca126005b86596e2bc6a93f
2019-04-11 22:15:02.898 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: 6f8830a940a4318a95e124a956878a3364b6eb05
2019-04-11 22:15:03.484 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: c42e7acda283d89f2f03eb8d55178b0b1c95dd63
2019-04-11 22:15:03.503 4649-4939/com.masterwok.demosimpletorrentandroid D/TorrentSession: Received alert: DHT_GET_PEERS - dht_get_peers_alert - incoming dht get_peers: b8ad2e585b1c337719979f0d28406dd55f1544c0
... more dht logs ...

The only way I was able to get the download to start is by invoking resume on the torrent handle when the ADD_TORRENT alert is emitted. Doing so solves the issue where the magnet would not start, but it seems to have the unintended side effect of emitting a TORRENT_FINISHED alert. I'm almost positive this is where the problem occurs as I'm probably messing up some internal state somewhere.

I also want to add that I'm waiting for the DHT to initialize before starting the magnet download so I don't believe that's the cause of the issue.

I'm sure the solution to this problem is simple but I'm not sure what I'm missing. I would expect that once the DHT is initialized and download is invoked on the session manager using a magnet that the download would start and continue until completion.

The forced resume I mentioned can be seen here.

There is also a sample project in that repository. The issue can be reproduced by commenting out the line here, removing the resume invocation, and starting the download of the magnet.

Any advice would be greatly appreciated :)!

[gubatron]

is this still an issue after our 1.2.1.0 release?
https://github.com/frostwire/frostwire-jlibtorrent/releases/tag/release%2F1.2.1.0

[abbasshah17]

I'm facing similar issue; getting TORRENT_FINISHED twice same as described in the OP. However I see this behavior on only one specific torrent only, with a web torrent haven't checked the behavior on magnet link. I'm also calling resume after I receive an ADD_TORRENT alert.

If you want I can post the torrent link here, it is one of the copyright content and I remember, in another post I saw reluctance to accept/post copyright torrents.

[gubatron]

I wonder if you could write a test for it and submit a pull request, that way we could replicate it easily and perhaps track down why this alert is being fired twice. Maybe in the test you are not able to replicate the problem and then you'll be able to track down the issue to your own bittorrent client.

[gubatron]

Maybe something like DoubleTorrentFinishedAlertIssue220Test.java in https://github.com/frostwire/frostwire-jlibtorrent/tree/master/src/test/java/com/frostwire/jlibtorrent

[abbasshah17]

Can I add the torrent link? As I mentioned it is a copyright torrent.

Sorry for the late reply I had a broken hand.

[gubatron]

Please do not.
Ideally if there is a bug, it should happen with any torrent or a similar torrent.
You should try to understand what is different about that torrent, what the pieces are like.

[gubatron]

A fix from libtorrent 1.2.8 might help with this issue:

fixed issue where pop_alerts() could return old, invalid alerts