[tor-bugs] #23751 [Core Tor/Tor]: [warn] tor_bug_occurred_: Bug: src/common/buffers.c, etc.

[Tor Bug Tracker & Wiki]

#23751: [warn] tor_bug_occurred_: Bug: src/common/buffers.c, etc.
------------------------------------------------+--------------------------
 Reporter:  Felixix                             |          Owner:  dgoulet
     Type:  defect                              |         Status:  accepted
 Priority:  High                                |      Milestone:  Tor:
                                                |  0.3.2.x-final
Component:  Core Tor/Tor                        |        Version:
 Severity:  Normal                              |     Resolution:
 Keywords:  tor-channel, tor-sched, tor-buffer  |  Actual Points:
Parent ID:  #23993                              |         Points:
 Reviewer:                                      |        Sponsor:  SponsorV
------------------------------------------------+--------------------------

Comment (by dgoulet):

 The above stracktrace again is not accurate. `scheduler_can_use_kist()`
 can *not* possibly call `channel_flush_some_cells()` so I'm not sure what
 to look at...

 However, again, these two warnings are real and seems the outbuf was full
 leading to this error.

 {{{
 Nov 07 15:32:50.000 [warn] write_to_buf failed on an orconn; notifying of
 error (fd 3936)
 Nov 07 15:32:50.000 [warn] Scheduler asked to release channel 4099239 but
 it wasn't in channels_pending
 }}}

 And here is what I think is happening:

 `channel_flush_some_cells()` is called inside the scheduler loop
 (`kist_scheduler_run()`) and if a connection write fails with the assert()
 we see in the stacktrace above, `connection_or_close_for_error()` is
 ultimately called leading to a `channel_change_state()` to put the channel
 in `CHANNEL_STATE_CLOSING` which will release the
 `scheduler_release_channel()` making KIST scheduler free its socket table
 entry.

 So when `channel_flush_some_cells()` returns, we try to update the socket
 info and this is triggered:

 `Bug: Non-fatal assertion !((!ent)) failed in update_socket_written`

 Now, we do check for a cell to be actually flushed before updating the
 socket table with `if (flush_result > 0) {` but in the case of a write
 error, how can that be? Good question, the answer is in
 `channel_flush_from_first_active_circuit()` which ignores the result of a
 write cell in the outbuf and always return that we did flush the cell:

 {{{
     /* Now send the cell */
     channel_write_packed_cell(chan, cell);
     cell = NULL;

     /*
      * Don't packed_cell_free_unchecked(cell) here because the channel
 will
      * do so when it gets out of the channel queue (probably already did,
 in
      * which case that was an immediate double-free bug).
      */

     /* Update the counter */
     ++n_flushed;
 }}}

 Ok so the good news is that this bug is benign but annoying due to the
 stacktrace.

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