AFAICT, Transmission has never (back to 2.4?) successfully retried a handshake using plaintext after encrypted handshake fails. An attempt is made but it gets messed up, possibly by holding onto the existing crypto state from the MSE?
More specifically, if the DH keys are exchanged but torrent is not found (or is not running) then the connection is dropped but Transmission will retry with plaintext (aka in-the-clear) because it cannot tell the difference between a connection that is deliberately dropped and a failed MSE (encryption) handshake. What's bizarre is that the retry appears to be encrypted-but-not-encrypted.
[2024-06-24 12:41:52.544] trc session.cc:397 new incoming connection 24 (65.###.###.###:58657) (session.cc:397)
[2024-06-24 12:41:52.544] trc 65.###.###.###:58657 socket (tcp) is 24 (peer-socket.cc:43)
[2024-06-24 12:41:52.544] trc 65.###.###.###:58657 enabling ready-to-read polling (peer-io.cc:513)
[2024-06-24 12:41:52.544] trc handshake 65.###.###.###:58657 handling can_read; state is [awaiting ya] (handshake.cc:582)
[2024-06-24 12:41:52.544] trc handshake 65.###.###.###:58657 in read_ya... need 96, have 436 (handshake.cc:366)
[2024-06-24 12:41:52.544] trc handshake 65.###.###.###:58657 sending B->A: Diffie Hellman Yb, PadB (handshake.cc:381)
[2024-06-24 12:41:52.544] trc handshake 65.###.###.###:58657 len(PadB) is 54 (handshake.cc:384)
[2024-06-24 12:41:52.544] trc 65.###.###.###:58657 enabling ready-to-write polling (peer-io.cc:525)
[2024-06-24 12:41:52.544] trc 65.###.###.###:58657 libevent says this peer socket is ready for writing (peer-io.cc:357)
[2024-06-24 12:41:53.543] trc 65.###.###.###:58657 libevent says this peer socket is ready for reading (peer-io.cc:488)
[2024-06-24 12:41:53.543] trc 65.###.###.###:58657 enabling ready-to-read polling (peer-io.cc:513)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 handling can_read; state is [awaiting pad a] (handshake.cc:582)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 found HASH('req1', S)! (handshake.cc:413)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 len(PadA) is 340 (handshake.cc:416)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 handling can_read; state is [awaiting crypto provide] (handshake.cc:582)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 reading obfuscated torrent hash... (handshake.cc:444)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 got INCOMING connection's MSE handshake for torrent [39] (handshake.cc:456)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 crypto_provide is 2 (handshake.cc:479)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 len(PadC) is 0 (handshake.cc:482)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 handling can_read; state is [awaiting pad c] (handshake.cc:582)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 len(IA) is 68 (handshake.cc:505)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 handling can_read; state is [awaiting ia] (handshake.cc:582)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 reading IA... have 68, need 68 (handshake.cc:514)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 sending vc (handshake.cc:530)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 selecting crypto mode '2' (handshake.cc:537)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 sending pad d (handshake.cc:546)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 handling can_read; state is [awaiting handshake] (handshake.cc:582)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 read_handshake: need 48, got 68 (handshake.cc:238)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 sending handshake in reply (handshake.cc:312)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 handling can_read; state is [awaiting peer id] (handshake.cc:582)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 read_peer_id: need 20, got 20 (handshake.cc:328)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:58657 peer-id is 'Transmission 4.0.6 (Dev)' ... isIncoming is true (handshake.cc:338)
[2024-06-24 12:41:53.543] trc 65.###.###.###:58657 in tr_peerIo destructor (peer-io.cc:202)
[2024-06-24 12:41:53.543] trc 65.###.###.###:58657 disabling ready-to-read polling (peer-io.cc:544)
...
[2024-06-24 12:41:53.543] trc session.cc:397 new incoming connection 20 (65.###.###.###:33639) (session.cc:397)
[2024-06-24 12:41:53.543] trc 65.###.###.###:33639 socket (tcp) is 20 (peer-socket.cc:43)
[2024-06-24 12:41:53.543] trc 65.###.###.###:33639 enabling ready-to-read polling (peer-io.cc:513)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:33639 handling can_read; state is [awaiting ya] (handshake.cc:582)
[2024-06-24 12:41:53.543] trc handshake 65.###.###.###:33639 in read_ya... need 96, have 68 (handshake.cc:366)
[2024-06-24 12:41:53.543] trc 65.###.###.###:33639 enabling ready-to-write polling (peer-io.cc:525)
[2024-06-24 12:41:53.543] trc 65.###.###.###:33639 libevent says this peer socket is ready for writing (peer-io.cc:357)
...
[2024-06-24 12:42:22.544] trc 65.###.###.###:33639 libevent says this peer socket is ready for reading (peer-io.cc:488)
[2024-06-24 12:42:22.544] trc 65.###.###.###:33639 try_read err: n_read:0 errno:107 (Transport endpoint is not connected) (peer-io.cc:465)
[2024-06-24 12:42:22.544] WRN 65.###.###.###:33639 try_read err: drain final 68 (peer-io.cc:469)
[2024-06-24 12:42:22.544] trc handshake 65.###.###.###:33639 handling can_read; state is [awaiting ya] (handshake.cc:582)
[2024-06-24 12:42:22.544] trc handshake 65.###.###.###:33639 in read_ya... need 96, have 68 (handshake.cc:366)
[2024-06-24 12:42:22.544] trc handshake 65.###.###.###:33639 handshake failed, not trying plaintext (handshake.cc:666)
[2024-06-24 12:42:22.544] trc handshake 65.###.###.###:33639 handshake socket err: Transport endpoint is not connected (107) (handshake.cc:625)
[2024-06-24 12:42:22.544] trc peer-mgr.cc:1314 on_handshake_done 65.###.###.###:33639, result.is_connected false, no swarm (peer-mgr.cc:1314)
[2024-06-24 12:42:22.544] trc 65.###.###.###:33639 in tr_peerIo destructor (peer-io.cc:202)
This inbound connection using port 58657 is looking for a torrent that client has but in this case is not running. You'll see that the MSE handshake works but connection is dropped. This is immediately followed by a new connection using port 33639. Notice the 68-byte packet that arrives. That is an in-the-clear handshake which got garbled (presumably encrypted, based on a dump of the packet).
I noticed a TON of these phantom 68-byte handshakes in my logs, but in every case they are generated by some version of Transmission, all the way back to 2.92. In my logs, there are plenty of successful encryption-fails-but-then-plaintext-succeeds by other peers; conversely in every case Transmission peers fail to retry properly.
tearfur
commented
1 month ago
What is the issue?
Discovered while testing PR #6913
AFAICT, Transmission has never (back to 2.4?) successfully retried a handshake using plaintext after encrypted handshake fails. An attempt is made but it gets messed up, possibly by holding onto the existing crypto state from the MSE?
More specifically, if the DH keys are exchanged but torrent is not found (or is not running) then the connection is dropped but Transmission will retry with plaintext (aka in-the-clear) because it cannot tell the difference between a connection that is deliberately dropped and a failed MSE (encryption) handshake. What's bizarre is that the retry appears to be encrypted-but-not-encrypted.
This inbound connection using port 58657 is looking for a torrent that client has but in this case is not running. You'll see that the MSE handshake works but connection is dropped. This is immediately followed by a new connection using port 33639. Notice the 68-byte packet that arrives. That is an in-the-clear handshake which got garbled (presumably encrypted, based on a dump of the packet).
I noticed a TON of these phantom 68-byte handshakes in my logs, but in every case they are generated by some version of Transmission, all the way back to 2.92. In my logs, there are plenty of successful encryption-fails-but-then-plaintext-succeeds by other peers; conversely in every case Transmission peers fail to retry properly.
Which application of Transmission?
transmission-daemon
Which version of Transmission?
Tr2.9+