main event-loop spins consuming 100% of a CPU core running scheduler_set_channel_state
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