[tor-bugs] #25461 [Core Tor/Tor]: main event-loop spins consuming 100% of a CPU core at times

[Tor Bug Tracker & Wiki]

#25461: main event-loop spins consuming 100% of a CPU core at times
------------------------------+--------------------------------
     Reporter:  Dhalgren      |      Owner:  (none)
         Type:  defect        |     Status:  new
     Priority:  Medium        |  Milestone:
    Component:  Core Tor/Tor  |    Version:  Tor: 0.3.3.3-alpha
     Severity:  Normal        |   Keywords:
Actual Points:                |  Parent ID:
       Points:                |   Reviewer:
      Sponsor:                |
------------------------------+--------------------------------
 Lately have observed my exit hitting 100% cpu on the main even-loop
 thread, sometimes continuously, sometimes cyclically.  Captured full-debug
 of recent cyclical event where CPU started at 30% and rose to 100%, for
 about one cycle.  Chopped the 1G log into eight slices and took a simple
 function call-count histogram.  What's notable is not an increase of calls
 during saturation, but a reduction of several that seem to relate to
 connection close events (conn_close_if_marked, flush_chunk).  Left column
 is for the first slice where CPU was 30%, right column is for fourth slice
 where cpu was 100%.  Functions with less than 1000 calls not included
 below, but complete histograms attached.  Wrote about this on tor-relays:

 https://lists.torproject.org/pipermail/tor-relays/2018-March/014730.html

 This might be an attack of some kind, or perhaps a misbehavior related to
 the KIST scheduler.

 {{{
 append_cell_to_circuit_queue 6787
 append_cell_to_circuit_queue 7280
 channel_flush_from_first_active_circuit 6781
 channel_flush_from_first_active_circuit 7190
 channel_process_cell 11904                        channel_process_cell
 11813
 channel_write_packed_cell 120301
 channel_write_packed_cell 126330
 channel_write_to_kernel 8588                      channel_write_to_kernel
 10048
 circuit_consider_stop_edge_reading 146965
 circuit_consider_stop_edge_reading 152665
 circuit_get_by_circid_channel_impl 14128
 circuit_get_by_circid_channel_impl 13468
 circuit_receive_relay_cell 11483
 circuit_receive_relay_cell 11341
 circuit_resume_edge_reading 1203
 circuit_resume_edge_reading 1231
 conn_close_if_marked 39033                        conn_close_if_marked 779
 conn_read_callback 14743                          conn_read_callback 15645
 conn_write_callback 4531                          conn_write_callback 4447
 connection_add_impl 1023                          connection_add_impl 739
 connection_bucket_refill_helper 14787
 connection_bucket_refill_helper 15842
 connection_buf_read_from_socket 16196
 connection_buf_read_from_socket 17152
 connection_connect 1016                           connection_connect 732
 connection_connect_sockaddr 1016
 connection_connect_sockaddr 732
 connection_edge_package_raw_inbuf 237303
 connection_edge_package_raw_inbuf 255347
 connection_edge_process_relay_cell 22219
 connection_edge_process_relay_cell 22332
 connection_exit_begin_conn 3165
 connection_exit_begin_conn 2315
 connection_exit_connect 1050                      connection_exit_connect
 772
 connection_handle_write_impl 9240
 connection_handle_write_impl 10539
 connection_or_process_cells_from_inbuf 20042
 connection_or_process_cells_from_inbuf 20448
 flush_chunk 38192                                 flush_chunk 12
 flush_chunk_tls 22283                             flush_chunk_tls 24061
 free_outbuf_info_by_ent 8588                      free_outbuf_info_by_ent
 10047
 outbuf_table_add 8588                             outbuf_table_add 10014
 read_to_chunk 6856                                read_to_chunk 7254
 relay_lookup_conn 8459                            relay_lookup_conn 8525
 relay_send_command_from_edge_ 119963
 relay_send_command_from_edge_ 128738
 rep_hist_note_exit_bytes 13913                    rep_hist_note_exit_bytes
 14534
 scheduler_set_channel_state 126896
 scheduler_set_channel_state 133353
 update_socket_info 6719                           update_socket_info 7160
 update_socket_written 120297                      update_socket_written
 126327
 }}}

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