Skip to content

GitLab

  • Projects
  • Groups
  • Snippets
  • Help
    • Loading...
  • Help
    • Help
    • Support
    • Community forum
    • Submit feedback
    • Contribute to GitLab
  • Sign in
T
Tor
  • Project overview
    • Project overview
    • Details
    • Activity
    • Releases
  • Repository
    • Repository
    • Files
    • Commits
    • Branches
    • Tags
    • Contributors
    • Graph
    • Compare
  • Issues 1,065
    • Issues 1,065
    • List
    • Boards
    • Labels
    • Service Desk
    • Milestones
  • Merge Requests 17
    • Merge Requests 17
  • CI / CD
    • CI / CD
    • Pipelines
    • Jobs
    • Schedules
  • Operations
    • Operations
    • Incidents
    • Environments
  • Analytics
    • Analytics
    • CI / CD
    • Repository
    • Value Stream
  • Members
    • Members
  • Activity
  • Graph
  • Create a new issue
  • Jobs
  • Commits
  • Issue Boards
Collapse sidebar

GitLab is used only for code review, issue tracking and project management. Canonical locations for source code are still https://gitweb.torproject.org/ https://git.torproject.org/ and git-rw.torproject.org.

  • The Tor Project
  • Core
  • Tor
  • Issues
  • #40242

Closed
Open
Opened Jan 14, 2021 by Roger Dingledine@armaReporter

Tor client stuck in a tight loop trying to send yet channel remains in state PENDING

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?

To upload designs, you'll need to enable LFS and have an admin enable hashed storage. More information
Assignee
Assign to
None
Milestone
None
Assign milestone
Time tracking
None
Due date
None
Reference: tpo/core/tor#40242