Opened 9 years ago

Closed 2 years ago

#1298 closed defect (fixed)

Tor does not treat multiple streams fairly

Reported by: mikeperry Owned by: nickm
Priority: Medium Milestone: Tor: unspecified
Component: Core Tor/Tor Version: 0.2.1.24
Severity: Normal Keywords: performance scheduling tor-client
Cc: mikeperry, Sebastian, nickm Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description (last modified by nickm)

Camilo Viecco noticed that Tor seems to have problems multiplexing streams onto the same circuit, and I have been able to reproduce this. In a simple test setup, I had 6 streams running on the same fast 2 hop circuit, and one stream would get 100-200K/s and the rest would only get 1K/s. He also ran the following experiments:

"The tests that I made seem to show that the problem was on multiplexing multiple streams on the same circuit. I ran tests on a private Tor network and the problem seem to be limited to a per circuit limit . (I tried multiple clients on the same host, using the same circuit path, and the problem seems to be related to the a circuit case, that is the 4th stream on each circuit ). The private network was using a high speed low latency network (at most one router between hosts, with at least 1GBs paths between nodes, switches and routers).

Therefore my guess is that the problem lies on the client or exit node socks code."

Neither of us have yet tested the same client with different circuits, as this is difficult to pin down due to circuit performance variance.

Child Tickets:

#1653
exit relays don't consider local cell queue when hearing sendme
#1937
circuit_resume_edge_reading_helper is highly unfair
#2210
Stream starvation due to activation order in circuit_resume_edge_reading_helper()


Child Tickets

TicketStatusOwnerSummaryComponent
#1653closedexit relays don't consider local cell queue when hearing sendmeCore Tor/Tor
#1937closednickmcircuit_resume_edge_reading_helper is highly unfairCore Tor/Tor
#2210closednickmStream starvation due to activation order in circuit_resume_edge_reading_helper()Core Tor/Tor

Change History (33)

comment:1 Changed 9 years ago by nickm

Make sure you can reproduce this with a recent Libevent 1.4.x? The older Libevents had some fairness issues on
some platforms.

comment:2 Changed 9 years ago by mikeperry

When I tested this it was libevent-1.4.12 on my client. That doesn't mean I have any idea what libevent the exit was
using, though... So it's either still a problem in 1.4.x, or it's server side.

comment:3 Changed 9 years ago by nickm

One way to rule explanation out or in would be to see how much it occurs on Windows exits specifically. This would
be interesting because

  • The fairness issues will always show up with Windows before Libevent 1.4.12-stable, whereas they only show up on other platforms depending on the backend.
  • For the most part, Windows people are running with the binaries we ship, with known Libevent versions.

comment:4 Changed 9 years ago by mikeperry

The test scripts Camilo used are at:

svn checkout http://tdor.googlecode.com/svn/trunk/testing/

comment:5 Changed 9 years ago by nickm

Description: modified (diff)
Milestone: Tor: 0.2.2.x-final

comment:6 Changed 9 years ago by nickm

I wonder if some aspect of cell queues could be at fault here. We might be filling up the queue with cells from one stream, then not having any space for cells from the other streams. Or it could be more complex and involve connection buffers somehow.

I think our next step is to run your 6-stream test again (assuming you can do so easily) with a Tor modified to log the state of the cell queue and the connection buffers in a pretty verbose way.

comment:7 Changed 9 years ago by mwenge

I ran Camilo's script a few times and got the following. The downloads didn't complete after the first few goes but the distribution of bandwidth per stream seemed fair in many cases. Very often the same circuit exhibited fairness in one test run and unfairness in the next.

torserversnet3:
thread[0] 1281558283.093650 : 1285568 30.207178 981 18 60 128 64 96 47 15 23 7 1 0 0 0 0
thread[1] 1281558282.870243 : 1347348 30.086063 1047 17 69 117 63 104 39 21 22 8 1 0 0 0 0
thread[2] 1281558283.164881 : 1351818 30.034449 1050 34 70 114 59 103 47 16 16 9 2 0 0 0 0

thread[0] 1281558351.993494 : 987252 31.524040 767 23 39 99 30 76 23 14 8 8 0 4 0 0 0
thread[1] 1281558351.931896 : 1046024 33.589523 820 12 43 87 41 98 25 10 9 3 1 3 1 0 0
thread[2] 1281558351.993529 : 1064330 30.523550 842 16 47 92 24 91 20 14 9 6 2 3 0 0 0

st0nehenger:
thread[0] 1281558443.629197 : 16572 34.059772 10 0 0 0 0 0 0 0 0 7 0 1 2 1 0
thread[1] 1281558443.629208 : 54512 30.051977 43 0 0 0 0 0 0 0 0 19 2 2 0 0 0
thread[2] 1281558444.629184 : 1024 68.100372 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

thread[0] 1281558590.505162 : 72414 37.407928 67 0 0 0 0 1 0 0 0 7 2 0 3 1 0
thread[1] 1281558590.278249 : 172360 30.623142 157 6 2 0 2 2 1 1 0 21 2 0 1 0 0
thread[2] 1281558590.675638 : 36266 30.225664 30 0 0 0 0 1 0 0 0 4 0 0 3 1 0

fejk:
thread[0] 1281558644.945076 : 1024 32.056534 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
thread[1] 1281558643.945112 : 210936 30.044186 191 1 1 0 0 0 0 0 0 28 1 0 0 0 0
thread[2] 1281558645.945276 : 1024 39.067944 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

blutmagie4:
thread[0] 1281558834.182062 : 99504 30.231522 87 1 0 0 0 0 1 1 2 9 3 2 1 0 0
thread[1] 1281558834.060585 : 127728 30.352617 113 1 0 0 0 1 3 0 1 15 1 2 1 0 0
thread[2] 1281558834.322487 : 64736 34.095009 56 0 1 0 0 0 1 0 0 7 1 2 2 1 0

thread[0] 1281558924.900739 : 173336 31.688431 154 0 0 4 0 2 1 2 1 19 1 0 2 0 0
thread[1] 1281558925.027798 : 18400 37.569653 14 0 0 0 0 1 0 0 0 2 0 0 3 1 0
thread[2] 1281558925.087045 : 109188 30.502056 97 0 0 1 0 1 0 0 0 12 1 1 2 0 0

31173services:
thread[0] 1281559028.220014 : 102384 36.569477 94 1 0 0 0 2 0 1 1 10 1 1 2 1 0
thread[1] 1281559028.219999 : 87452 30.561298 78 0 1 0 0 1 0 1 1 11 1 1 2 0 0
thread[2] 1281559028.166624 : 105280 31.614664 93 2 1 2 1 2 0 2 0 12 1 1 2 0 0

comment:8 Changed 9 years ago by mikeperry

14:11 < mwenge> mikeperry: i'm interested in testing bug 1298 more. i tried

camilo's script but didn't get the same results as the bug report

14:21 < mikeperry> mwenge: nickm was suspecting it was possibly due to bad

libevents on certain OSes

14:22 < mikeperry> did you notice anything like that?
14:22 < mwenge> mikeperry: no, the results were consistently inconsistent across

a bunch of exits of varying versions

14:22 < mikeperry> am I reading this right? is torserversdotnet the most fair in

this list in the bug?

14:23 < mwenge> it's also the first one i tried
14:27 < mikeperry> so they get less fair the more you try?
14:28 < mwenge> my impression is they get less fair the more you try on the same

exit

14:31 < mikeperry> in the same circuit, or different circuits?
14:31 < mwenge> on the same circuit
14:31 < mwenge> i'm running it again here on different circuits and the results

are very mixed

14:33 < mwenge> on the whole a small minority of tests exhibit really unfair

balancing

14:33 < mikeperry> if its the same circuit, it could be our SENDME windows

killing the later ones

comment:9 Changed 9 years ago by mwenge

[22:45] <mwenge> there is something odd though - tor is still reporting incoming bw even when the streams are closed
[22:45] <mwenge> it then dies off after twenty seconds or so
[22:46] <mwenge> so it looks like the circuit is still pumping cells something through to the client

comment:10 Changed 9 years ago by nickm

Can somebody explain how to interpret the big tables of numbers?

comment:11 in reply to:  7 Changed 9 years ago by mwenge

time taken (nsec) bytes time periodic latency

thread[0] 1281558283.093650 : 1285568 30.207178 981 18 60 128 64 96 ..

The test program cuts off the downloads after roughly 30 seconds.

comment:12 Changed 9 years ago by mwenge

I've done quite a bit more random testing with Camilo's test-case and have encountered only quite rare unfairness in the bandwidth distributed across streams. Can anyone recreate the problem with Camilo's test utility?

comment:13 Changed 9 years ago by nickm

This could be related to an issue mentioned in the discussion of bug #1653 , and fixed in my public bug1653 branch in commit 8782dcf6a291b4. If a cell queue is full and draining, it won't unblock until it is under a low-water mark. But any new streams that are created will (erroneously) not know that they should be blocked. So if the new stream adds cells at exactly the right rate (i.e., not so fast that the queue fills up again, but not so slow that it ever gets under its high-water mark), the old streams will never unblock.

As I said, I think 8782dcf6a291b4 might fix this. It's not a perfect fix, but I am pretty sure it won't miss any cases.

comment:14 Changed 9 years ago by yetonetime

trap.

comment:15 Changed 9 years ago by nickm

"trap" ?

comment:16 Changed 9 years ago by yetonetime

It's impossible to prevent appenditition to a queue with at least 1 cell per each relay_begin request, with a such or another patch. Slowdos is guaranted. All situation looks like the trap.

The second BUG msg could happen for an every middle relay while a queue have been grown for a some reasons for more than the high-water mark. Any investigates after a such msgs about question "why" is only the time-trap.

comment:17 Changed 9 years ago by arma

Priority: minormajor

Triage: we think this bug is caused by #1653, which needs to get fixed for 0.2.2.x. Once #1653 is fixed, we should revisit whether this bug is resolved or is something else, and re-triage it if it's something else.

comment:18 Changed 9 years ago by nickm

Owner: changed from mikeperry to nickm
Status: newassigned

Stealing the bug assignment on this one. See comments on updated bug1653 branch at bug #1653 discussion.

comment:19 Changed 9 years ago by arma

It seems clear that fixing #1653 will make this problem less bad.

But I bet there are still some fairness problems that could be relevant.

For example, notice how circuit_resume_edge_reading_helper() always walks the stream list in the same order, and stops when it's exhausted the circuit's package window. Whenever that "stop when package window is empty" case gets triggered, we're being unfair to the streams later in the linked list.

comment:20 Changed 9 years ago by nickm

That issue is also relevant, and worth fixing. Here are a couple of ways we could do it:

  • We could only package a limited number of cells per stream at a time, and loop until all input data is packaged, or the queue is full.
  • We could start at a different position in the list of streams each time.
  • Some combination of the above.

I think the answer is "some combination of the above", since the first one still technically favors older streams, and the second one (though technically fair) can produce "fairness" of a really choppy type.

Thoughts?

comment:21 Changed 9 years ago by nickm

Description: modified (diff)

comment:22 Changed 9 years ago by nickm

Added a #1937 to cover the case discussed in the last two comments. Added a child ticket list to the description here.

comment:23 Changed 9 years ago by nickm

Merged #1937 fix. Roger notes another issue there:

I wonder if there are other cases where we call connection_edge_package_raw_inbuf() without constraining how many cells it can package, and it gobbles up more than it should.

comment:24 Changed 9 years ago by nickm

Grepping: We call connection_edge_package_raw_inbuf() in 4 places. One is the case in relay.c that we fixed in #1937. The other three cases have no constraint on how much we process from the stream. They are:

  • In relay.c:
    • (A) connection_edge_process_relay_cell_not_open(), upon receiving a RELAY_COMMAND_CONNECTED
    • (B) connection_edge_process_relay_cell(), upon receiving a RELAY_COMMAND_SENDME.
    • (C) The case in relay.c that we fixed with #1937
  • In connection_edge.c
    • (D) connection_edge_process_inbuf(), upon receiving data on an edge connection.

Case (C) is fixed. Case (D) is fair, since we'll just package data as it arrives, and we consider connections that we can read from in pseuodrandom or first-come-first-served order.

Case (A) and case (B) can lead to hogging the circuit temporarily, though I think it happens in a more-or-less fair way. It would be neat to make those cases less hoggish, but we have a bit of an architectural problem in the way. Right now (as you can see above) there are two circumstances when we package edge data into relay cells:

  • (1) Data arrives on an edge conn, so we package as much as we can immediately.
  • (2) An edge-conn becomes non-blocked (either it was blocked on its own, or its whole circuit was blocked), so we package as much data as we can (from the connection if just one was blocked, or from all the connections on a circuit if a whole circuit was blocked).

Thus, if we leave data on an edge conn inbuf temporarily without blocking the edge conn, there's currently no mechanism to make sure that it will get pulled off unless more data arrives, or unless the edge conn becomes blocked then unblocked.

We could add such a mechanism, I guess, but I'm not currently clear on how it would look. I think it can wait for 0.2.3.x, though?

comment:25 Changed 9 years ago by nickm

Milestone: Tor: 0.2.2.x-final

comment:26 Changed 9 years ago by nickm

Milestone: Tor: 0.2.3.x-final

We fixed the cases we know about of this one; I've made bug #2179 to summarize the "lumpy traffic" cases I noted two comments above.

I've also added #2180 to note that we should do more testing for all fairness types.

If you find a new stream unfairness bug, please add or reopen a new child ticket, rather than adding more comments here; it's getting pretty confusing.

comment:27 Changed 9 years ago by nickm

Keywords: fairness added
Priority: majornormal

comment:28 Changed 8 years ago by arma

Keywords: performance scheduling added; fairness removed

comment:29 Changed 8 years ago by nickm

Milestone: Tor: 0.2.3.x-finalTor: 0.2.4.x-final

comment:30 Changed 7 years ago by nickm

Keywords: tor-client added

comment:31 Changed 7 years ago by nickm

Component: Tor ClientTor

comment:32 Changed 7 years ago by nickm

Milestone: Tor: 0.2.4.x-finalTor: unspecified

Moving this into unspecified, given that we haven't gotten a new report here since 2010.

comment:33 Changed 2 years ago by nickm

Cc: mikeperry,Sebastian,nickmmikeperry, Sebastian, nickm
Resolution: Nonefixed
Severity: Normal
Status: assignedclosed

Closed because known cases were fixed back in 2010

Note: See TracTickets for help on using tickets.