GitLab

I am seeing this stanza over and over and over in my Tor client logs:

Jan 14 13:05:45.842 [debug] scheduler_evt_callback(): Scheduler event callback called
Jan 14 13:05:45.842 [debug] update_socket_info(): chan=2 updated socket info, limit: 0, cwnd: 1, unacked: 1, notsent: 16290, mss: 1448
Jan 14 13:05:45.842 [debug] kist_scheduler_run(): Running the scheduler. 1 channels pending
Jan 14 13:05:45.842 [debug] outbuf_table_add(): scheduler init outbuf info for chan=2
Jan 14 13:05:45.842 [debug] channel_write_to_kernel(): Writing 0 bytes to kernel for chan 2
Jan 14 13:05:45.842 [debug] flush_chunk_tls(): flushed 0 bytes, 0 remain.
Jan 14 13:05:45.842 [debug] connection_handle_write_impl(): After TLS write of 0: 0 read, 0 written
Jan 14 13:05:45.842 [debug] free_outbuf_info_by_ent(): Freeing outbuf table entry from chan=2
Jan 14 13:05:45.843 [debug] kist_scheduler_run(): len pending=0, len to_readd=1
Jan 14 13:05:45.843 [debug] scheduler_set_channel_state(): chan 2 changed from scheduler state PENDING to PENDING

And by over and over, I mean

$ grep "Jan 14 13:04" tord-log |grep "changed from scheduler state PENDING to PENDING"|wc -l
4021
$ grep "Jan 14 13:05" tord-log |grep "changed from scheduler state PENDING to PENDING"|wc -l
14878
$ grep "Jan 14 13:06" tord-log |grep "changed from scheduler state PENDING to PENDING"|wc -l
14342

I.e. during this several-minute storm of attempts, I was spinning over this same loop 33241 times.

It finally left the loop with this stanza:

Jan 14 13:06:56.967 [debug] channel_write_packed_cell(): Writing 0x5635d0bf49a0 to channel 0x5635d13a95e0 with global ID 2
Jan 14 13:06:56.967 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() found placeholder for circ_id 2412249837, channel ID 2 (0x5635d13a95e0)
Jan 14 13:06:56.967 [debug] circuitmux_notify_xmit_destroy(): Cmux at 0x5635d0b87c90 sent a destroy, cmux counter is now 0, global counter is now 0
Jan 14 13:06:56.967 [debug] update_socket_written(): chan=2 wrote 543 bytes, old was 3801
Jan 14 13:06:56.967 [debug] scheduler_set_channel_state(): chan 2 changed from scheduler state PENDING to WAITING_FOR_CELLS

Shouldn't my Tor be...waiting for some state to change, rather than slamming its head against this socket over and over?

Is this a case where libevent says it's writeable but KIST says it isn't writeable so we listen to KIST but then we ask libevent again?