Clients don't realize that a server has a different identity than stated in consensus
This problem came up when trying to access a hidden service on a "recent" trunk version (0.2.1.0-alpha-dev, exact revision number unknown). Log by killerchicken (times manually changed to GMT):
Apr 20 20:33:04.853 [Warning] Received NETINFO cell with skewed time from server at 195.24.77.135:80. It seems that our clock is ahead by 1 hours, 42 minutes, or that theirs is behind. Tor requires an accurate clock to work: please check your time and date settings. Apr 20 20:33:29.545 [Warning] Tried connecting to router at 91.89.159.76:9001, but identity key was not as expected: wanted CCFDBED5463B7F308C0EF909F00B25889F6A7EF8 but got FDD88040C0C98EE9EB573041A2C8824E9EFC4CE4. Apr 20 20:33:34.959 [Warning] Tried connecting to router at 91.89.159.76:9001, but identity key was not as expected: wanted CCFDBED5463B7F308C0EF909F00B25889F6A7EF8 but got FDD88040C0C98EE9EB573041A2C8824E9EFC4CE4. Apr 20 20:33:40.914 [Warning] Tried connecting to router at 91.89.159.76:9001, but identity key was not as expected: wanted CCFDBED5463B7F308C0EF909F00B25889F6A7EF8 but got FDD88040C0C98EE9EB573041A2C8824E9EFC4CE4. Apr 20 20:33:40.967 [Warning] Tried connecting to router at 91.89.159.76:9001, but identity key was not as expected: wanted CCFDBED5463B7F308C0EF909F00B25889F6A7EF8 but got FDD88040C0C98EE9EB573041A2C8824E9EFC4CE4. Apr 20 20:33:40.984 [Warning] Tried connecting to router at 91.89.159.76:9001, but identity key was not as expected: wanted CCFDBED5463B7F308C0EF909F00B25889F6A7EF8 but got FDD88040C0C98EE9EB573041A2C8824E9EFC4CE4. ... Apr 20 20:34:57.817 [Warning] Tried connecting to router at 91.89.159.76:9001, but identity key was not as expected: wanted CCFDBED5463B7F308C0EF909F00B25889F6A7EF8 but got FDD88040C0C98EE9EB573041A2C8824E9EFC4CE4. Apr 20 20:35:03.500 [Warning] Tried connecting to router at 91.89.159.76:9001, but identity key was not as expected: wanted CCFDBED5463B7F308C0EF909F00B25889F6A7EF8 but got FDD88040C0C98EE9EB573041A2C8824E9EFC4CE4. Apr 20 20:35:16.144 [Notice] Rend stream is 120 seconds late. Giving up on address '[scrubbed].onion'. Apr 20 20:37:16.783 [Notice] Rend stream is 120 seconds late. Giving up on address '[scrubbed].onion'.
The server with identity CCFDBED5463B7F308C0EF909F00B25889F6A7EF8 is HALLIGonALB which has changed identity keys just before the consensus was created. At 19:18:44 the server indeed had the identity CCFDBED5..., but it changed to FDD88040... at 19:50:57:
router HALLIGonALB 91.89.159.76 9001 0 0 platform Tor 0.2.0.23-rc (r14173) on Linux i686 opt protocols Link 1 Circuit 1 published 2008-04-20 19:18:44 opt fingerprint CCFD BED5 463B 7F30 8C0E F909 F00B 2588 9F6A 7EF8
router HALLIGonALB 91.89.159.76 9001 0 9030 platform Tor 0.2.0.23-rc (r14173) on Linux i686 opt protocols Link 1 Circuit 1 published 2008-04-20 19:50:57 opt fingerprint FDD8 8040 C0C9 8EE9 EB57 3041 A2C8 824E 9EFC 4CE4
The server is listed in the consensus as: r HALLIGonALB zP2+1UY7fzCMDvkJ8AsliJ9qfvg UcgjQHY3+4ftvO7CXn4DJ9v9TkY 2008-04-20 19:21:44 91.89.159.76 9001 9030
The bug here is that clients should stop creating connections to nodes that have "lied" about their identity before. The warning message comes from connection_or.c:789 in connection_or_check_valid_tls_handshake().
Attempts to reproduce this error by (1) always failing the condition in connection_or.c:782 or (2) failing after 2 attempts by introducing a static counter (rationale: the third connection attempt will be the first when actually trying to access a hidden service) failed. In all cases the "failing" nodes were correctly removed from the entry guards list and marked as down.
When this bug will be spotted again, an info-level or even debug-level log might help in understanding what happens in detail.
[Automatically added by flyspray2trac: Operating System: All]