Link handshake fails with "Received unexpected cell command 10" on a bridge
If there is sufficient clock skew between a Tor client and its bridge, the client starts carrying out the link handshake protocol incorrectly, leading to (info-level) errors like this on the server side:
Aug 19 19:21:13.000 [info] channel_register(): Channel 0x7fcbd2927d00 (global ID 14) in state opening (1) registered with no identity digest
Aug 19 19:21:13.000 [info] channel_tls_process_versions_cell(): Negotiated version 4 with [scrubbed]:49733; Sending cells: VERSIONS CERTS NETINFO
Aug 19 19:21:13.000 [info] channel_tls_process_certs_cell(): Got some good certificates from [scrubbed]:49733: Waiting for AUTHENTICATE.
Aug 19 19:21:13.000 [info] channel_tls_handle_cell(): Received unexpected cell command 10 in chan state opening / conn state handshaking (Tor, v3 handshake); closing the connection.
From IRC (edited):
<nickm> Looks like the client is sending a CREATE2 cell before the handshake is done.
<nickm> It appears that the client isn't sending a NETINFO cell.
<nickm> If this is an unmodified Tor client and server, then that's a bug.
<zwol> 0.2.4.15-rc (git-f41c20b344fb7359) on the server.
<zwol> 0.2.4.15-rc (git-e7b435872cce464f) on the client.
<zwol> f41c20b344fb7359 corresponds to the tor 0.2.4.15-rc-1 package from current Debian unstable, and e7b435872cce464f is what was shipped with TBB 3.0a3.
I will attach two client-side info-level logs: one demonstrating the problem, one successful connection. The only configuration difference between the two is that in the problem case, the client's clock was 26 hours fast:
Aug 21 18:57:01.000 [info] connection_dir_client_reached_eof(): Received directory with skewed time (server '[scrubbed]:9002'): It seems that our clock is ahead by 1 days, 2 hours, 32 minutes, or that theirs is behind. Tor requires an accurate clock to work: please check your time, timezone, and date settings.