[tor-bugs] #14056 [Tor]: IPredator complains that we call time() too much when running over 500Mbps

[Tor Bug Tracker & Wiki]

#14056: IPredator complains that we call time() too much when running over 500Mbps
------------------------+-----------------------------------------
     Reporter:  teor    |      Owner:
         Type:  defect  |     Status:  new
     Priority:  normal  |  Milestone:  Tor: 0.2.6.x-final
    Component:  Tor     |    Version:  Tor: 0.2.5.10
   Resolution:          |   Keywords:  performance tor-relay lorax
Actual Points:          |  Parent ID:
       Points:          |
------------------------+-----------------------------------------

Comment (by teor):

 When I run 200MB through tor 0.2.6.2-alpha via the latest chutney, it
 takes approximately 45 seconds. (I have modified `chutney verify` to send
 larger chunks of random data.)

 I see the following call graph for `time` / `gettimeofday` (in the OS X C
 library, `time` calls `gettimeofday`):
 {{{
 Running Time       Samples      Symbol Name
 276.0ms  100.0%    276  100.0%  time
 114.0ms   41.3%    114   41.3%   channel_timestamp_active
  90.0ms   32.6%     90   32.6%   channel_timestamp_recv
  25.0ms    9.0%     25    9.0%   conn_read_callback
  14.0ms    5.0%     14    5.0%   conn_write_callback
  11.0ms    3.9%     11    3.9%   channel_timestamp_drained
  11.0ms    3.9%     11    3.9%   connection_or_process_inbuf
   6.0ms    2.1%      6    2.1%   channel_timestamp_xmit
   3.0ms    1.0%      3    1.0%   event_base_loop
   1.0ms    0.3%      1    0.3%   channel_write_cell_queue_entry
   1.0ms    0.3%      1    0.3%   connection_mark_for_close_internal_
 }}}

 This is approximately 4.5MB/s, and 3.6% of the samples are for `time`.
 If I understand the profiling tools I'm using, there are around 1 million
 calls to `time` during the data transmission, or around 20,000 calls per
 second (not shown it the table above).

 If we switched `channel_timestamp_active` and `channel_timestamp_recv`
 over to `approx_time`, the number of calls to time() could be reduced by
 around 75%, but this is still 5,000 calls per second.
 If we changed all of the functions above, we could see a reduction of
 99.4%, to 120 calls per second. Perhaps this would be enough to fix the
 performance issues - if not, we can re-do these tests and change another
 set of functions.

 mmcc, did you want to confirm the callers of `time` / `gettimeofday` on
 BSD, and make these fixes?
 The fixes should involve replacing commonly called instances (or simply
 every instance) of `time` in these functions with `approx_time`.

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