Peer does not respond with a "piece" message to a valid "request" message? (always the same block)

Challenges
1

I’m stuck on Stage #nd2

I can download the piece for the sample.torrent without problems, also the piece 0 and piece 2 can be downloaded for /tmp/torrents2881799268/congratulations.gif.torrent, but then the download eventually gets stuck on some other piece and block in /tmp/torrents578942357/codercat.gif.torrent (it is always the same block inside this piece - and this is somewhat suspicious): PieceBlock { piece: 11, begin: 163840, length: 16384 }

I see that my application tries to read the bytes from the connection opened with the peer after sending a specific “request” message (details below), but the peer does not send anything back, and also does not reset the connection, and becomes “stuck” => eventually the test times out

The peer fails to respond after I send the “request” message with the following bytes:

remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 2, 128, 0, 0, 0, 64, 0]

which as far as I can tell is following the Bittorrent protocol specification,

[0, 0, 0, 13] - message length prefix - 13
[6] - message id byte - 6 “request”

message payload:
[0, 0, 0, 11] - piece index - 11
[0, 2, 128, 0] - begin - 163840
[0, 0, 64, 0] - length - 16384

Here are my full logs (with the logs from my application code):

remote: [your_program] Downloading piece 11 from torrent “/tmp/torrents3692483886/codercat.gif.torrent” to file “/tmp/torrents3692483886/piece-11”
remote: [your_program] Piece length: 262144
remote: [your_program] Total number of pieces to download: 12
remote: [your_program] Piece blocks [PieceBlock { begin: 0, length: 16384 }, PieceBlock { begin: 16384, length: 16384 }, PieceBlock { begin: 32768, length: 16384 }, PieceBlock { begin: 49152, length: 16384 }, PieceBlock { begin: 65536, length: 16384 }, PieceBlock { begin: 81920, length: 16384 }, PieceBlock { begin: 98304, length: 16384 }, PieceBlock { begin: 114688, length: 16384 }, PieceBlock { begin: 131072, length: 16384 }, PieceBlock { begin: 147456, length: 16384 }, PieceBlock { begin: 163840, length: 16384 }, PieceBlock { begin: 180224, length: 16384 }, PieceBlock { begin: 196608, length: 16384 }, PieceBlock { begin: 212992, length: 16384 }, PieceBlock { begin: 229376, length: 16384 }, PieceBlock { begin: 245760, length: 16384 }]
remote: [your_program] Established connection to peer “2d524e302e302e302dc12e7e7a015e752af17f97” peer address PeerAddress { address: 178.62.82.89, port: 51431 }
remote: [your_program] Sent: ‘interested’ to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Received: ‘bitfield’ from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Received: ‘unchoke’ from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 0, 0, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 0, 0, 0, 0, 0, 64, 0]
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 0, 64, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 0, 64, 0, 0, 0, 64, 0]
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 0, 128, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 0, 128, 0, 0, 0, 64, 0]
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 0, 192, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 0, 192, 0, 0, 0, 64, 0]
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 1, 0, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 1, 0, 0, 0, 0, 64, 0]
remote: [your_program] Received: ‘piece’ from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Details about received ‘piece’: index=11 begin=0 length=16384 from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 1, 64, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 1, 64, 0, 0, 0, 64, 0]
remote: [your_program] Received: ‘piece’ from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Details about received ‘piece’: index=11 begin=16384 length=16384 from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 1, 128, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 1, 128, 0, 0, 0, 64, 0]
remote: [your_program] Received: ‘piece’ from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Details about received ‘piece’: index=11 begin=32768 length=16384 from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 1, 192, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 1, 192, 0, 0, 0, 64, 0]
remote: [your_program] Received: ‘piece’ from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Details about received ‘piece’: index=11 begin=49152 length=16384 from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 2, 0, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 2, 0, 0, 0, 0, 64, 0]
remote: [your_program] Received: ‘piece’ from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Details about received ‘piece’: index=11 begin=65536 length=16384 from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 2, 64, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 2, 64, 0, 0, 0, 64, 0]
remote: [your_program] Received: ‘piece’ from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Details about received ‘piece’: index=11 begin=81920 length=16384 from peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 11, 0, 2, 128, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302dc12e7e7a015e752af17f97”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 11, 0, 2, 128, 0, 0, 0, 64, 0]
remote: [tester::#ND2] timed out, test exceeded 10 seconds
remote: [tester::#ND2] Test failed

Would appreciate any hints why the download can be stuck and whether anybody encountered similar issues. The bug might well be in my code, but finding it without additional information about the execution is quite non-straightforward.

Did the peer respond with a “piece” message, but my code did not somehow read it properly or got into some sort of deadlock? Or the peer received some wrong message sent from my application and refuses to communicate after that? Is there any way to see the sequence of the messages sent and received by the peer?

2

Another timeout in the tests for another torrent "/tmp/torrents780314388/congratulations.gif.torrent" always happens on the block PieceBlock { begin: 81920, length: 16384 }

Logs (the last sent “request” message also seems to be correct and following the Bittorrent protocal specification), the peer however does not respond and hangs:

remote: [your_program] Downloading piece 3 from torrent “/tmp/torrents780314388/congratulations.gif.torrent” to file “/tmp/torrents780314388/piece-3”
remote: [your_program] Piece length: 262144
remote: [your_program] Total number of pieces to download: 4
remote: [your_program] Piece blocks [PieceBlock { begin: 0, length: 16384 }, PieceBlock { begin: 16384, length: 16384 }, PieceBlock { begin: 32768, length: 16384 }, PieceBlock { begin: 49152, length: 16384 }, PieceBlock { begin: 65536, length: 16384 }, PieceBlock { begin: 81920, length: 16384 }, PieceBlock { begin: 98304, length: 16384 }, PieceBlock { begin: 114688, length: 16384 }, PieceBlock { begin: 131072, length: 16384 }, PieceBlock { begin: 147456, length: 16384 }, PieceBlock { begin: 163840, length: 16384 }, PieceBlock { begin: 180224, length: 16384 }, PieceBlock { begin: 196608, length: 16384 }, PieceBlock { begin: 212992, length: 16384 }, PieceBlock { begin: 229376, length: 16384 }, PieceBlock { begin: 245760, length: 16384 }]
remote: [your_program] Established connection to peer “2d524e302e302e302d69f87eba9ba00df3f62193” peer address PeerAddress { address: 178.62.85.20, port: 51428 }
remote: [your_program] Sent: ‘interested’ to peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Received: ‘bitfield’ from peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Received: ‘unchoke’ from peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 3, 0, 0, 0, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 3, 0, 0, 0, 0, 0, 0, 64, 0]
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 3, 0, 0, 64, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 3, 0, 0, 64, 0, 0, 0, 64, 0]
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 3, 0, 0, 128, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 3, 0, 0, 128, 0, 0, 0, 64, 0]
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 3, 0, 0, 192, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 3, 0, 0, 192, 0, 0, 0, 64, 0]
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 3, 0, 1, 0, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 3, 0, 1, 0, 0, 0, 0, 64, 0]
remote: [your_program] Received: ‘piece’ from peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Details about received ‘piece’: index=3 begin=0 length=16384 from peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Sending: ‘request’ PeerMessage { message_id: Request, payload: [0, 0, 0, 3, 0, 1, 64, 0, 0, 0, 64, 0] } to peer “2d524e302e302e302d69f87eba9ba00df3f62193”
remote: [your_program] Request: [0, 0, 0, 13, 6, 0, 0, 0, 3, 0, 1, 64, 0, 0, 0, 64, 0]
remote: [tester::#ND2] timed out, test exceeded 10 seconds
remote: [tester::#ND2] Test failed

3

I found a bug in my code, fixed it and passed the stage:

The length of the last piece of the torrent file might be smaller than the piece_length as per the bittorent specification bep_0003.rst_post

piece length maps to the number of bytes in each piece the file is split into. For the purposes of transfer, files are split into fixed-size pieces which are all the same length except for possibly the last one which may be truncated. piece length is almost always a power of two, most commonly 2 18 = 256 K (BitTorrent prior to version 3.2 uses 2 20 = 1 M as default).

My original code (wrongly) assumed that the length of every piece of the torrent file is piece_length which led to requesting non-existing blocks for the last piece and the peer not responding to these requests

1 Like
4

This topic was automatically closed 5 days after the last reply. New replies are no longer allowed.