[tor-bugs] #29437 [Core Tor/Stem]: test-stem times out intermittently

[Tor Bug Tracker & Wiki]

#29437: test-stem times out intermittently
-----------------------------------+-----------------------------------
 Reporter:  rl1987                 |          Owner:  atagar
     Type:  defect                 |         Status:  needs_information
 Priority:  Medium                 |      Milestone:
Component:  Core Tor/Stem          |        Version:
 Severity:  Normal                 |     Resolution:
 Keywords:  tor-ci-fail-sometimes  |  Actual Points:  0.2
Parent ID:                         |         Points:  0.2
 Reviewer:                         |        Sponsor:
-----------------------------------+-----------------------------------

Comment (by nickm):

 I've investigated this for a while; here's what I found.

 I investigated the stall in `test.integ.client.connection`, which I see
 with Python >= 3.6 but not Python <= 3.5.  I used a hacked up version of
 stem and  a hacked up version of tor that logged a bunch of extra
 information.  I found that the buggy behavior, from Stem's point of view,
 is that Tor accepted a VERSIONS cell but never replied.

 From Tor's point of view, however, Stem negotiated a v1 link connection
 with it, and so there is no such thing as a variable-length cell or a
 VERSIONS cell.

 Why does Tor think that stem negotiated a v1 link connection?  It decides
 this in `tor_tls_server_info_callback()`, when it first calls
 `tor_tls_client_is_using_v2_ciphers()`. For some reason,
 `SSL_get_client_ciphers()` returns null at this point, meaning "the client
 has declared no ciphers" and convincing tor that the v1 link protocol is
 in use.  This result of scanning the ciphers is cached through subsequent
 calls.  If I remove the code in Tor that caches this result, then the stem
 test passes, since later calls to `SSL_get_client_ciphers()` do in fact
 return non-NULL.

 Why does `SSL_get_client_ciphers()` return NULL for python3.6, but not
 python3.5?

 When Python 3.5 is in use, the session_secret_cb function is invoked
 before the tor_tls_server_info_callback() function triggers cipher
 classification, and at that point, the ciphers are set.  When Python 3.6
 is in use, the tor_tls_server_info_callback() function is hit twice early
 on to hit cipher classification: once with the ciphers not set, and then
 later with the ciphers set.

--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/29437#comment:15>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online