search

mpetazzoni / ttorrent

BitTorrent Java library with tracker and download client
http://mpetazzoni.github.com/ttorrent/
Apache License 2.0
1.38k stars 502 forks source link

Download resume not working #91

Closed lalkmim closed 8 years ago

lalkmim commented 10 years ago

I'm trying to embed your torrent library on a android application. It's working very well but I'm facing a problem whenever I try to resume the download of a torrent that were forced to stop due to the application being closed.

What the program does is: 1) Starts downloading of a torrent file; 2) It starts fine and is downloading correctly; 3) Application is closed 4) Application is reopened 5) We (re)start the torrent that were stopped before 6) It runs correctly until the point where he tries to read messages from the peers (log below)

The problem below is happening to all peers, and that happens before anything is downloaded, no piece is completed.

03-15 03:03:24.761: I/System.out(2303): 10945 [bt-peer(..6B7030)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Could not read message from peer://66.68.162.6:51413/6b7030 [Ci|CI|730]: Unexpected end-of-stream while reading
03-15 03:03:24.761: I/System.out(2303): 10946 [bt-peer(..6B7030)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Peer exchange with peer://66.68.162.6:51413/6b7030 [Ci|CI|730] closed.

Log of only this peer:

03-15 03:03:23.169: I/System.out(2303): 9353 [bt-connect-13] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://66.68.162.6:51413/? [Ci|Ci|0]...
03-15 03:03:23.361: I/System.out(2303): 9547 [bt-connect-13] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Connected. Sending handshake to peer://66.68.162.6:51413/? [Ci|Ci|0]...
03-15 03:03:24.241: I/System.out(2303): 10426 [bt-connect-13] INFO com.turn.ttorrent.client.ConnectionHandler  - Handshaked with peer://66.68.162.6:51413/? [Ci|Ci|0], peer ID is 2d5452323832302d61326f6e313530636d6b7030.
03-15 03:03:24.241: I/System.out(2303): 10427 [bt-connect-13] INFO com.turn.ttorrent.client.Client  - Handling new peer connection with peer://66.68.162.6:51413/6b7030...
03-15 03:03:24.245: I/System.out(2303): 10429 [bt-connect-13] DEBUG com.turn.ttorrent.client.Client  - Found peer (by host ID): peer://66.68.162.6:51413/6b7030 [Ci|Ci|0].
03-15 03:03:24.265: I/System.out(2303): 10449 [bt-connect-13] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Started peer exchange with peer://66.68.162.6:51413/6b7030 [Ci|Ci|0] for How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv].
03-15 03:03:24.269: I/System.out(2303): 10452 [bt-connect-13] DEBUG com.turn.ttorrent.client.Client  - New peer connection with peer://66.68.162.6:51413/6b7030 [Ci|Ci|0] [2/28].
03-15 03:03:24.761: I/System.out(2303): 10945 [bt-peer(..6B7030)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Could not read message from peer://66.68.162.6:51413/6b7030 [Ci|CI|730]: Unexpected end-of-stream while reading
03-15 03:03:24.761: I/System.out(2303): 10946 [bt-peer(..6B7030)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Peer exchange with peer://66.68.162.6:51413/6b7030 [Ci|CI|730] closed.
03-15 03:03:24.769: I/System.out(2303): 10954 [bt-peer(..6B7030)-recv] DEBUG com.turn.ttorrent.client.SharedTorrent  - Peer peer://66.68.162.6:51413/6b7030 [Ci|CI|730] went away with 730 piece(s) [completed=35; available=0/730]
03-15 03:03:24.769: I/System.out(2303): 10955 [bt-peer(..6B7030)-recv] DEBUG com.turn.ttorrent.client.Client  - Peer peer://66.68.162.6:51413/6b7030 [Ci|CI|730] disconnected, [0/28].

Log when it runs correctly (first time):

03-15 03:34:48.181: I/System.out(2535): 9744 [bt-connect-8] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://86.14.244.99:35668/? [Ci|Ci|0]...
03-15 03:34:48.401: I/System.out(2535): 9962 [bt-connect-8] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Connected. Sending handshake to peer://86.14.244.99:35668/? [Ci|Ci|0]...
03-15 03:34:48.649: I/System.out(2535): 10209 [bt-connect-8] INFO com.turn.ttorrent.client.ConnectionHandler  - Handshaked with peer://86.14.244.99:35668/? [Ci|Ci|0], peer ID is 4d372d382d322d2d7c76537b4444a41088c0b420.
03-15 03:34:48.649: I/System.out(2535): 10210 [bt-connect-8] INFO com.turn.ttorrent.client.Client  - Handling new peer connection with peer://86.14.244.99:35668/c0b420...
03-15 03:34:48.649: I/System.out(2535): 10212 [bt-connect-8] DEBUG com.turn.ttorrent.client.Client  - Found peer (by host ID): peer://86.14.244.99:35668/c0b420 [Ci|Ci|0].
03-15 03:34:48.673: I/System.out(2535): 10236 [bt-connect-8] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Started peer exchange with peer://86.14.244.99:35668/c0b420 [Ci|Ci|0] for How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv].
03-15 03:34:48.685: I/System.out(2535): 10239 [bt-connect-8] DEBUG com.turn.ttorrent.client.Client  - New peer connection with peer://86.14.244.99:35668/c0b420 [Ci|Ci|0] [3/27].
03-15 03:34:50.525: I/System.out(2535): 12086 [bt-client(..376262)] DEBUG com.turn.ttorrent.client.Client  -   | peer://86.14.244.99:35668/c0b420 [ci|cI|730] (downloading piece#  14-)
03-15 03:34:53.545: I/System.out(2535): 15106 [bt-client(..376262)] DEBUG com.turn.ttorrent.client.Client  -   | peer://86.14.244.99:35668/c0b420 [ci|cI|730] (downloading piece#  14-)
03-15 03:34:56.561: I/System.out(2535): 18121 [bt-client(..376262)] DEBUG com.turn.ttorrent.client.Client  -   | peer://86.14.244.99:35668/c0b420 [ci|cI|730] (downloading piece#  14-)
03-15 03:34:59.573: I/System.out(2535): 21135 [bt-client(..376262)] DEBUG com.turn.ttorrent.client.Client  -   | peer://86.14.244.99:35668/c0b420 [ci|cI|730] (downloading piece#  14-)
03-15 03:35:02.593: I/System.out(2535): 24153 [bt-client(..376262)] DEBUG com.turn.ttorrent.client.Client  -   | peer://86.14.244.99:35668/c0b420 [ci|cI|730] (downloading piece#  14-)
03-15 03:35:02.605: I/System.out(2535): 24165 [bt-peer(..C0B420)-recv] DEBUG com.turn.ttorrent.client.Client  - Completed download of piece#  14+ from peer://86.14.244.99:35668/c0b420 [ci|cI|730]. We now have 1/730 pieces

Full log:

03-15 03:03:13.817: I/System.out(2303): 0 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  - Multi-file torrent information:
03-15 03:03:13.817: I/System.out(2303): 1 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -   Torrent name: How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv]
03-15 03:03:13.817: I/System.out(2303): 2 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -   Announced at:
03-15 03:03:13.821: I/System.out(2303): 5 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -      1. udp://tracker.publicbt.com:80/announce
03-15 03:03:13.829: I/System.out(2303): 8 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -      2. udp://tracker.openbittorrent.com:80/announce
03-15 03:03:13.829: I/System.out(2303): 12 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -      3. udp://tracker.istole.it:80/announce
03-15 03:03:13.833: I/System.out(2303): 16 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -      4. udp://9.rarbg.com:2710/announce
03-15 03:03:13.837: I/System.out(2303): 20 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -      5. udp://tracker.token.ro:80/announce
03-15 03:03:13.837: I/System.out(2303): 22 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -      6. udp://ipv4.tracker.harry.lu:80/announce
03-15 03:03:13.841: I/System.out(2303): 25 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -      7. udp://exodus.desync.com:6969/announce
03-15 03:03:13.841: I/System.out(2303): 26 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -      8. http://tracker.nwps.ws:6969/announce
03-15 03:03:13.845: I/System.out(2303): 28 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -      9. udp://tracker.secureboxes.net:80/announce
03-15 03:03:13.845: I/System.out(2303): 30 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -     10. udp://pow7.com:80/announce
03-15 03:03:13.849: I/System.out(2303): 34 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -   Created on..: Tue Feb 25 01:32:11 GMT+00:00 2014
03-15 03:03:13.849: I/System.out(2303): 34 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -   Comment.....: Torrent downloaded from torrent cache at http://torcache.net/
03-15 03:03:13.853: I/System.out(2303): 36 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -   Created by..: ruTorrent (PHP Class - Adrien Gibrat)
03-15 03:03:13.853: I/System.out(2303): 37 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -   Found 2 file(s) in multi-file torrent structure.
03-15 03:03:13.853: I/System.out(2303): 39 [AsyncTask #2] DEBUG com.turn.ttorrent.common.Torrent  -      1. How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv]/How.I.Met.Your.Mother.S09E18.HDTV.x264-EXCELLENCE.mp4 (191,253,275 byte(s))
03-15 03:03:13.857: I/System.out(2303): 40 [AsyncTask #2] DEBUG com.turn.ttorrent.common.Torrent  -      2. How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv]/Torrent Downloaded From ExtraTorrent.cc.txt (339 byte(s))
03-15 03:03:13.857: I/System.out(2303): 42 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -   Pieces......: 730 piece(s) (262144 byte(s)/piece)
03-15 03:03:13.861: I/System.out(2303): 44 [AsyncTask #2] INFO com.turn.ttorrent.common.Torrent  -   Total size..: 191,253,614 byte(s)
03-15 03:03:13.869: I/System.out(2303): 54 [AsyncTask #2] DEBUG com.turn.ttorrent.client.storage.FileStorage  - Partial download found at /mnt/shared/outros/torrent/How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv]/How.I.Met.Your.Mother.S09E18.HDTV.x264-EXCELLENCE.mp4.part. Continuing...
03-15 03:03:13.873: I/System.out(2303): 57 [AsyncTask #2] INFO com.turn.ttorrent.client.storage.FileStorage  - Initialized byte storage file at /mnt/shared/outros/torrent/How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv]/How.I.Met.Your.Mother.S09E18.HDTV.x264-EXCELLENCE.mp4.part (0+191253275 byte(s)).
03-15 03:03:13.881: I/System.out(2303): 66 [AsyncTask #2] DEBUG com.turn.ttorrent.client.storage.FileStorage  - Partial download found at /mnt/shared/outros/torrent/How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv]/Torrent Downloaded From ExtraTorrent.cc.txt.part. Continuing...
03-15 03:03:13.885: I/System.out(2303): 70 [AsyncTask #2] INFO com.turn.ttorrent.client.storage.FileStorage  - Initialized byte storage file at /mnt/shared/outros/torrent/How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv]/Torrent Downloaded From ExtraTorrent.cc.txt.part (191253275+339 byte(s)).
03-15 03:03:13.889: I/System.out(2303): 71 [AsyncTask #2] INFO com.turn.ttorrent.client.storage.FileCollectionStorage  - Initialized torrent byte storage on 2 file(s) (191253614 total byte(s)).
03-15 03:03:13.893: I/System.out(2303): 77 [AsyncTask #2] INFO com.turn.ttorrent.client.ConnectionHandler  - Listening for incoming connections on localhost/127.0.0.1:6881.
03-15 03:03:13.965: I/System.out(2303): 151 [AsyncTask #2] INFO com.turn.ttorrent.client.announce.Announce  - Initialized announce sub-system with 10 trackers on How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv].
03-15 03:03:13.973: I/System.out(2303): 156 [AsyncTask #2] INFO com.turn.ttorrent.client.Client  - BitTorrent client [..666232] for How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv] started and listening at 127.0.0.1:6881...
03-15 03:03:13.985: I/System.out(2303): 171 [bt-client(..666232)] INFO com.turn.ttorrent.client.SharedTorrent  - Analyzing local data for How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv] with 1 threads (730 pieces)...
03-15 03:03:14.941: I/System.out(2303): 1127 [bt-client(..666232)] INFO com.turn.ttorrent.client.SharedTorrent  -   ... 10% complete
03-15 03:03:15.853: I/System.out(2303): 2038 [bt-client(..666232)] INFO com.turn.ttorrent.client.SharedTorrent  -   ... 20% complete
03-15 03:03:16.753: I/System.out(2303): 2936 [bt-client(..666232)] INFO com.turn.ttorrent.client.SharedTorrent  -   ... 30% complete
03-15 03:03:17.609: I/System.out(2303): 3793 [bt-client(..666232)] INFO com.turn.ttorrent.client.SharedTorrent  -   ... 40% complete
03-15 03:03:18.449: I/System.out(2303): 4634 [bt-client(..666232)] INFO com.turn.ttorrent.client.SharedTorrent  -   ... 50% complete
03-15 03:03:19.273: I/System.out(2303): 5459 [bt-client(..666232)] INFO com.turn.ttorrent.client.SharedTorrent  -   ... 60% complete
03-15 03:03:20.125: I/System.out(2303): 6311 [bt-client(..666232)] INFO com.turn.ttorrent.client.SharedTorrent  -   ... 70% complete
03-15 03:03:20.965: I/System.out(2303): 7151 [bt-client(..666232)] INFO com.turn.ttorrent.client.SharedTorrent  -   ... 80% complete
03-15 03:03:21.801: I/System.out(2303): 7987 [bt-client(..666232)] INFO com.turn.ttorrent.client.SharedTorrent  -   ... 90% complete
03-15 03:03:22.629: I/System.out(2303): 8812 [bt-client(..666232)] DEBUG com.turn.ttorrent.client.SharedTorrent  - How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv]: we have 9175040/191253614 bytes (4.8%) [35/730 pieces].
03-15 03:03:22.629: I/System.out(2303): 8813 [bt-announce(..666232)] INFO com.turn.ttorrent.client.announce.Announce  - Starting announce loop...
03-15 03:03:22.629: I/System.out(2303): 8814 [bt-announce(..666232)] INFO com.turn.ttorrent.client.announce.UDPTrackerClient  - Announcing STARTED to tracker with 0U/0D/182078574L bytes...
03-15 03:03:22.641: I/System.out(2303): 8824 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/0 peers at 0.00/0.00 kB/s.
03-15 03:03:23.137: I/System.out(2303): 9320 [bt-announce(..666232)] INFO com.turn.ttorrent.client.announce.Announce  - Setting announce interval to 1855s per tracker request.
03-15 03:03:23.137: I/System.out(2303): 9320 [bt-announce(..666232)] INFO com.turn.ttorrent.client.Client  - Got 25 peer(s) in tracker response.
03-15 03:03:23.141: I/System.out(2303): 9324 [bt-connect-1] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://222.153.251.99:54076/? [Ci|Ci|0]...
03-15 03:03:23.141: I/System.out(2303): 9326 [bt-connect-2] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://69.80.37.46:62633/? [Ci|Ci|0]...
03-15 03:03:23.145: I/System.out(2303): 9329 [bt-connect-3] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://89.212.133.187:10263/? [Ci|Ci|0]...
03-15 03:03:23.145: I/System.out(2303): 9331 [bt-connect-4] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://84.248.16.199:19199/? [Ci|Ci|0]...
03-15 03:03:23.149: I/System.out(2303): 9334 [bt-connect-5] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://76.75.67.60:60857/? [Ci|Ci|0]...
03-15 03:03:23.153: I/System.out(2303): 9337 [bt-connect-6] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://72.27.31.105:33232/? [Ci|Ci|0]...
03-15 03:03:23.153: I/System.out(2303): 9339 [bt-connect-7] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://222.127.85.21:50878/? [Ci|Ci|0]...
03-15 03:03:23.157: I/System.out(2303): 9341 [bt-connect-8] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://179.179.240.50:63882/? [Ci|Ci|0]...
03-15 03:03:23.157: I/System.out(2303): 9343 [bt-connect-9] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://175.139.71.118:12500/? [Ci|Ci|0]...
03-15 03:03:23.161: I/System.out(2303): 9346 [bt-connect-10] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://95.154.67.108:60886/? [Ci|Ci|0]...
03-15 03:03:23.165: I/System.out(2303): 9348 [bt-connect-11] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://92.28.81.70:51189/? [Ci|Ci|0]...
03-15 03:03:23.165: I/System.out(2303): 9350 [bt-connect-12] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://84.28.244.146:61302/? [Ci|Ci|0]...
03-15 03:03:23.169: I/System.out(2303): 9353 [bt-connect-13] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://66.68.162.6:51413/? [Ci|Ci|0]...
03-15 03:03:23.173: I/System.out(2303): 9356 [bt-connect-14] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://201.231.141.45:18727/? [Ci|Ci|0]...
03-15 03:03:23.173: I/System.out(2303): 9358 [bt-connect-15] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://185.6.237.39:20376/? [Ci|Ci|0]...
03-15 03:03:23.177: I/System.out(2303): 9361 [bt-connect-16] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://179.234.49.162:30308/? [Ci|Ci|0]...
03-15 03:03:23.177: I/System.out(2303): 9363 [bt-connect-17] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://120.29.72.84:27311/? [Ci|Ci|0]...
03-15 03:03:23.181: I/System.out(2303): 9366 [bt-connect-18] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://84.250.46.60:35336/? [Ci|Ci|0]...
03-15 03:03:23.185: I/System.out(2303): 9368 [bt-connect-19] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://219.77.75.74:38470/? [Ci|Ci|0]...
03-15 03:03:23.185: I/System.out(2303): 9371 [bt-connect-20] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://175.144.147.52:47641/? [Ci|Ci|0]...
03-15 03:03:23.361: I/System.out(2303): 9547 [bt-connect-13] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Connected. Sending handshake to peer://66.68.162.6:51413/? [Ci|Ci|0]...
03-15 03:03:23.365: I/System.out(2303): 9548 [bt-connect-13] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Sent handshake (68 bytes), waiting for response...
03-15 03:03:23.453: I/System.out(2303): 9637 [bt-connect-15] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Connected. Sending handshake to peer://185.6.237.39:20376/? [Ci|Ci|0]...
03-15 03:03:23.453: I/System.out(2303): 9638 [bt-connect-15] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Sent handshake (68 bytes), waiting for response...
03-15 03:03:23.481: I/System.out(2303): 9665 [bt-connect-5] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Connected. Sending handshake to peer://76.75.67.60:60857/? [Ci|Ci|0]...
03-15 03:03:23.481: I/System.out(2303): 9666 [bt-connect-5] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Sent handshake (68 bytes), waiting for response...
03-15 03:03:23.521: I/System.out(2303): 9705 [bt-connect-8] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Connected. Sending handshake to peer://179.179.240.50:63882/? [Ci|Ci|0]...
03-15 03:03:23.521: I/System.out(2303): 9705 [bt-connect-8] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Sent handshake (68 bytes), waiting for response...
03-15 03:03:23.565: I/System.out(2303): 9749 [bt-connect-9] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Connected. Sending handshake to peer://175.139.71.118:12500/? [Ci|Ci|0]...
03-15 03:03:23.565: I/System.out(2303): 9750 [bt-connect-9] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Sent handshake (68 bytes), waiting for response...
03-15 03:03:23.729: I/System.out(2303): 9915 [bt-connect-15] INFO com.turn.ttorrent.client.ConnectionHandler  - Handshaked with peer://185.6.237.39:20376/? [Ci|Ci|0], peer ID is 2d5554333330302db973e8b2fbd0604a5e3ecbb3.
03-15 03:03:23.729: I/System.out(2303): 9915 [bt-connect-15] INFO com.turn.ttorrent.client.Client  - Handling new peer connection with peer://185.6.237.39:20376/3ecbb3...
03-15 03:03:23.733: I/System.out(2303): 9918 [bt-connect-15] DEBUG com.turn.ttorrent.client.Client  - Found peer (by host ID): peer://185.6.237.39:20376/3ecbb3 [Ci|Ci|0].
03-15 03:03:23.757: I/System.out(2303): 9940 [bt-connect-15] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Started peer exchange with peer://185.6.237.39:20376/3ecbb3 [Ci|Ci|0] for How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv].
03-15 03:03:23.761: I/System.out(2303): 9944 [bt-connect-15] DEBUG com.turn.ttorrent.client.Client  - New peer connection with peer://185.6.237.39:20376/3ecbb3 [Ci|Ci|0] [1/26].
03-15 03:03:23.761: I/System.out(2303): 9947 [bt-connect-15] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://173.212.71.199:25622/? [Ci|Ci|0]...
03-15 03:03:23.769: I/System.out(2303): 9951 [bt-connect-8] WARN com.turn.ttorrent.client.Client  - Could not connect to peer://179.179.240.50:63882/? [Ci|Ci|0]: Handshake size read underrrun.
03-15 03:03:23.769: I/System.out(2303): 9955 [bt-connect-8] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://116.124.69.139:21031/? [Ci|Ci|0]...
03-15 03:03:23.821: I/System.out(2303): 10004 [bt-connect-5] INFO com.turn.ttorrent.client.ConnectionHandler  - Handshaked with peer://76.75.67.60:60857/? [Ci|Ci|0], peer ID is 2d5554333332302d5f7655a2ad1746da3288a26e.
03-15 03:03:23.821: I/System.out(2303): 10005 [bt-connect-5] INFO com.turn.ttorrent.client.Client  - Handling new peer connection with peer://76.75.67.60:60857/88a26e...
03-15 03:03:23.821: I/System.out(2303): 10007 [bt-connect-5] DEBUG com.turn.ttorrent.client.Client  - Found peer (by host ID): peer://76.75.67.60:60857/88a26e [Ci|Ci|0].
03-15 03:03:23.845: I/System.out(2303): 10030 [bt-connect-5] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Started peer exchange with peer://76.75.67.60:60857/88a26e [Ci|Ci|0] for How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv].
03-15 03:03:23.849: I/System.out(2303): 10032 [bt-connect-5] DEBUG com.turn.ttorrent.client.Client  - New peer connection with peer://76.75.67.60:60857/88a26e [Ci|Ci|0] [2/26].
03-15 03:03:23.849: I/System.out(2303): 10034 [bt-connect-5] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://80.103.49.116:51413/? [Ci|Ci|0]...
03-15 03:03:23.985: I/System.out(2303): 10171 [bt-connect-9] INFO com.turn.ttorrent.client.ConnectionHandler  - Handshaked with peer://175.139.71.118:12500/? [Ci|Ci|0], peer ID is 2d5554333230302d3c6c6053a4b9940857ae2967.
03-15 03:03:23.989: I/System.out(2303): 10172 [bt-connect-9] INFO com.turn.ttorrent.client.Client  - Handling new peer connection with peer://175.139.71.118:12500/ae2967...
03-15 03:03:23.989: I/System.out(2303): 10174 [bt-connect-9] DEBUG com.turn.ttorrent.client.Client  - Found peer (by host ID): peer://175.139.71.118:12500/ae2967 [Ci|Ci|0].
03-15 03:03:24.013: I/System.out(2303): 10197 [bt-connect-9] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Started peer exchange with peer://175.139.71.118:12500/ae2967 [Ci|Ci|0] for How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv].
03-15 03:03:24.017: I/System.out(2303): 10199 [bt-connect-9] DEBUG com.turn.ttorrent.client.Client  - New peer connection with peer://175.139.71.118:12500/ae2967 [Ci|Ci|0] [3/27].
03-15 03:03:24.017: I/System.out(2303): 10202 [bt-connect-9] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://201.215.41.170:61940/? [Ci|Ci|0]...
03-15 03:03:24.101: I/System.out(2303): 10284 [bt-peer(..3ECBB3)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Could not read message from peer://185.6.237.39:20376/3ecbb3 [Ci|CI|730]: Unexpected end-of-stream while reading
03-15 03:03:24.101: I/System.out(2303): 10285 [bt-peer(..3ECBB3)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Peer exchange with peer://185.6.237.39:20376/3ecbb3 [Ci|CI|730] closed.
03-15 03:03:24.129: I/System.out(2303): 10316 [bt-peer(..3ECBB3)-recv] DEBUG com.turn.ttorrent.client.SharedTorrent  - Peer peer://185.6.237.39:20376/3ecbb3 [Ci|CI|730] went away with 730 piece(s) [completed=35; available=0/730]
03-15 03:03:24.133: I/System.out(2303): 10316 [bt-peer(..3ECBB3)-recv] DEBUG com.turn.ttorrent.client.Client  - Peer peer://185.6.237.39:20376/3ecbb3 [Ci|CI|730] disconnected, [2/27].
03-15 03:03:24.225: I/System.out(2303): 10411 [bt-peer(..88A26E)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Could not read message from peer://76.75.67.60:60857/88a26e [Ci|CI|730]: Unexpected end-of-stream while reading
03-15 03:03:24.225: I/System.out(2303): 10411 [bt-peer(..88A26E)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Peer exchange with peer://76.75.67.60:60857/88a26e [Ci|CI|730] closed.
03-15 03:03:24.241: I/System.out(2303): 10426 [bt-connect-13] INFO com.turn.ttorrent.client.ConnectionHandler  - Handshaked with peer://66.68.162.6:51413/? [Ci|Ci|0], peer ID is 2d5452323832302d61326f6e313530636d6b7030.
03-15 03:03:24.241: I/System.out(2303): 10427 [bt-connect-13] INFO com.turn.ttorrent.client.Client  - Handling new peer connection with peer://66.68.162.6:51413/6b7030...
03-15 03:03:24.245: I/System.out(2303): 10429 [bt-connect-13] DEBUG com.turn.ttorrent.client.Client  - Found peer (by host ID): peer://66.68.162.6:51413/6b7030 [Ci|Ci|0].
03-15 03:03:24.253: I/System.out(2303): 10437 [bt-peer(..88A26E)-recv] DEBUG com.turn.ttorrent.client.SharedTorrent  - Peer peer://76.75.67.60:60857/88a26e [Ci|CI|730] went away with 730 piece(s) [completed=35; available=0/730]
03-15 03:03:24.253: I/System.out(2303): 10438 [bt-peer(..88A26E)-recv] DEBUG com.turn.ttorrent.client.Client  - Peer peer://76.75.67.60:60857/88a26e [Ci|CI|730] disconnected, [1/28].
03-15 03:03:24.265: I/System.out(2303): 10449 [bt-connect-13] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Started peer exchange with peer://66.68.162.6:51413/6b7030 [Ci|Ci|0] for How I Met Your Mother S09E18 HDTV x264-EXCELLENCE[ettv].
03-15 03:03:24.269: I/System.out(2303): 10452 [bt-connect-13] DEBUG com.turn.ttorrent.client.Client  - New peer connection with peer://66.68.162.6:51413/6b7030 [Ci|Ci|0] [2/28].
03-15 03:03:24.269: I/System.out(2303): 10454 [bt-connect-13] INFO com.turn.ttorrent.client.ConnectionHandler  - Connecting to peer://177.36.10.249:41853/? [Ci|Ci|0]...
03-15 03:03:24.437: I/System.out(2303): 10621 [bt-peer(..AE2967)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Could not read message from peer://175.139.71.118:12500/ae2967 [Ci|CI|730]: Unexpected end-of-stream while reading
03-15 03:03:24.437: I/System.out(2303): 10621 [bt-peer(..AE2967)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Peer exchange with peer://175.139.71.118:12500/ae2967 [Ci|CI|730] closed.
03-15 03:03:24.449: I/System.out(2303): 10633 [bt-peer(..AE2967)-recv] DEBUG com.turn.ttorrent.client.SharedTorrent  - Peer peer://175.139.71.118:12500/ae2967 [Ci|CI|730] went away with 730 piece(s) [completed=35; available=0/730]
03-15 03:03:24.449: I/System.out(2303): 10634 [bt-peer(..AE2967)-recv] DEBUG com.turn.ttorrent.client.Client  - Peer peer://175.139.71.118:12500/ae2967 [Ci|CI|730] disconnected, [1/28].
03-15 03:03:24.761: I/System.out(2303): 10945 [bt-peer(..6B7030)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Could not read message from peer://66.68.162.6:51413/6b7030 [Ci|CI|730]: Unexpected end-of-stream while reading
03-15 03:03:24.761: I/System.out(2303): 10946 [bt-peer(..6B7030)-recv] DEBUG com.turn.ttorrent.client.peer.PeerExchange  - Peer exchange with peer://66.68.162.6:51413/6b7030 [Ci|CI|730] closed.
03-15 03:03:24.769: I/System.out(2303): 10954 [bt-peer(..6B7030)-recv] DEBUG com.turn.ttorrent.client.SharedTorrent  - Peer peer://66.68.162.6:51413/6b7030 [Ci|CI|730] went away with 730 piece(s) [completed=35; available=0/730]
03-15 03:03:24.769: I/System.out(2303): 10955 [bt-peer(..6B7030)-recv] DEBUG com.turn.ttorrent.client.Client  - Peer peer://66.68.162.6:51413/6b7030 [Ci|CI|730] disconnected, [0/28].
03-15 03:03:25.101: I/System.out(2303): 11286 [bt-connect-8] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Connected. Sending handshake to peer://116.124.69.139:21031/? [Ci|Ci|0]...
03-15 03:03:25.101: I/System.out(2303): 11286 [bt-connect-8] DEBUG com.turn.ttorrent.client.ConnectionHandler  - Sent handshake (68 bytes), waiting for response...
03-15 03:03:25.517: I/System.out(2303): 11700 [bt-connect-8] WARN com.turn.ttorrent.client.Client  - Could not connect to peer://116.124.69.139:21031/? [Ci|Ci|0]: Handshake size read underrrun.
03-15 03:03:25.641: I/System.out(2303): 11826 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:28.641: I/System.out(2303): 14827 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:31.645: I/System.out(2303): 17829 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:34.645: I/System.out(2303): 20830 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:37.645: I/System.out(2303): 23831 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:40.645: I/System.out(2303): 26831 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:43.649: I/System.out(2303): 29832 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:46.649: I/System.out(2303): 32833 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:49.653: I/System.out(2303): 35838 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:52.653: I/System.out(2303): 38838 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:55.657: I/System.out(2303): 41840 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:03:58.665: I/System.out(2303): 44847 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:04:01.665: I/System.out(2303): 47849 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:04:04.665: I/System.out(2303): 50850 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:04:07.665: I/System.out(2303): 53851 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:04:10.669: I/System.out(2303): 56853 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:04:13.669: I/System.out(2303): 59854 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
03-15 03:04:16.669: I/System.out(2303): 62855 [bt-client(..666232)] INFO com.turn.ttorrent.client.Client  - SHARING 35/730 pieces (4.79%) [0/0] with 0/27 peers at 0.00/0.00 kB/s.
sebastianpaz commented 10 years ago

I have the same issue. Do you have any solutions?

lalkmim commented 10 years ago

I had to stop the project where I was using ttorrent, but I believe you can workaround the problem by adding the same torrent file. It'll start as a new one, but won't lose the progress made previously. If you try to use the same torrent file already on disk, you get the problem.

nikkiii commented 10 years ago

I've spent some time working on this, and as far as I can tell it's something to do with the BitfieldMessage.

It only shows itself when there's a torrent that has at least some of the progress - and when it sends the piece list to other clients.

I've had it resume successfully when I replaced the call in PeerExchange.java with this:

for (int i = pieces.nextSetBit(0); i >= 0; i = pieces.nextSetBit(i+1)) {
    this.send(PeerMessage.HaveMessage.craft(i));
}
cjmalloy commented 10 years ago

Any more info on this? I can also reproduce the error.

I am also getting this exception: 

Thread [bt-serve] (Suspended (exception IllegalArgumentException))  
    ByteBuffer.allocate(int) line: 334  
    ConnectionHandler.validateHandshake(SocketChannel, byte[]) line: 381    
    ConnectionHandler.accept(SocketChannel) line: 301   
    ConnectionHandler.run() line: 248   
    Thread.run() line: 745

The ByteBuffer is trying to allocate a negative capacity.

philipphenkel commented 8 years ago

The bitfield payload in the bitfield message is truncated to the highest bit that is set. As a consequence the bitfield does not cover all pieces in most cases and therefore peers drop the connection. This prevents a successful resume of downloads.

mpetazzoni commented 8 years ago

Thanks @henkel for the patch! Closing this.