While experimenting with Tor v0.2.3.4-alpha's "optimistic data" and thus keeping an eye on the logs, I noticed that I get a lot of the following messages (with and without "optimistic data"):
Sep 20 13:47:57.428 [debug] {APP} connection_edge_process_relay_cell(): Now seen 8236 relay cells here (command 2, stream 49411). Sep 20 13:47:57.428 [debug] {APP} connection_edge_process_relay_cell(): circ deliver_window now 911. Sep 20 13:47:57.428 [info] {APP} connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 49411). Sep 20 13:47:57.431 [debug] {APP} connection_edge_process_relay_cell(): Now seen 8237 relay cells here (command 2, stream 49411). Sep 20 13:47:57.431 [debug] {APP} connection_edge_process_relay_cell(): circ deliver_window now 910. Sep 20 13:47:57.431 [info] {APP} connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 49411). Sep 20 13:47:57.432 [debug] {APP} connection_edge_process_relay_cell(): Now seen 8238 relay cells here (command 2, stream 49411). Sep 20 13:47:57.432 [debug] {APP} connection_edge_process_relay_cell(): circ deliver_window now 909. Sep 20 13:47:57.432 [info] {APP} connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 49411). Sep 20 13:47:57.432 [debug] {APP} connection_edge_process_relay_cell(): Now seen 8239 relay cells here (command 2, stream 49411). [...] Sep 20 13:48:01.479 [debug] {APP} connection_edge_process_relay_cell(): Now seen 8379 relay cells here (command 2, stream 49411). Sep 20 13:48:01.479 [debug] {APP} connection_edge_process_relay_cell(): circ deliver_window now 968. Sep 20 13:48:01.479 [info] {APP} connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 49411). Sep 20 13:48:01.479 [debug] {APP} relay_lookup_conn(): found conn for stream 49410.
Sometimes up to 400-500 dropped cells per unknown stream id. The deliver window seems to go down to 900 and then starts at 999 again.
It's my impression that it always happens after the client connection is closed prematurely, something my feed reader unfortunately does frequently:
Sep 20 13:47:56.608 [debug] {APP} connection_edge_process_relay_cell(): Now seen 8235 relay cells here (command 2, stream 49411). Sep 20 13:47:56.608 [debug] {APP} connection_edge_process_relay_cell(): circ deliver_window now 912. Sep 20 13:47:56.792 [debug] {APP} circuit_consider_stop_edge_reading(): considering layer_hint->package_window 995 Sep 20 13:47:56.792 [info] {EDGE} connection_edge_reached_eof(): conn (fd 14) reached eof. Closing.
I assume it can take several seconds for the exit relay to stop sending data and the Tor client has to continue reading from the stream to keep the circuit usable. Is that correct?
Is it intended behaviour for the Tor client to forget a stream id before the stream is actually closed on the remote end?
Fabian