<div dir="ltr"><div>Hi George, <br></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Wed, Jul 10, 2019 at 8:21 AM George Kadianakis <<a href="mailto:desnacked@riseup.net" target="_blank">desnacked@riseup.net</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Dennis Jackson <<a href="mailto:djackson@mozilla.com" target="_blank">djackson@mozilla.com</a>> writes:<br>
<br>
> Hi all,<br>
><br>
> I've spent a week or so digging into some latency measurements of the Tor<br>
> network. I've put together some graphs and my observations in a PDF here<br>
> <<a href="https://drive.google.com/file/d/1e7yngIW9JkZiO8uwt6W6QrzOdg9nohGj/view?usp=sharing" rel="noreferrer" target="_blank">https://drive.google.com/file/d/1e7yngIW9JkZiO8uwt6W6QrzOdg9nohGj/view?usp=sharing</a>>,<br>
> which is created from a Google Slides Presentation (comments enabled) here<br>
> <<a href="https://docs.google.com/presentation/d/1vUqx7-fkNfy2xwtJXS9PCwQvTuVUwI7JwodNc-tJLTw/edit?usp=sharing" rel="noreferrer" target="_blank">https://docs.google.com/presentation/d/1vUqx7-fkNfy2xwtJXS9PCwQvTuVUwI7JwodNc-tJLTw/edit?usp=sharing</a>>.<br>
> My cleaned up data sets and the source code for the graphs are also linked<br>
> at the end of the PDF in case anyone wants to play with it.<br>
><br>
<br>
Hello Denis,<br>
<br>
this is really great and well-thought-out material! Thanks!<br>
<br></blockquote><div><br></div><div>Thanks! :) <br></div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
> The takeaways:<br>
><br>
> - Lots of graphs.<br>
> - The Jan 2015 inflection point in the metrics data is due to 'siv'<br>
> changing ISPs. Tor still has a bad phase followed by a good phase, but the<br>
> change is more gradual and begins earlier.<br>
<br>
Good catch. That seems about right!<br>
<br>
I also liked the token bucket refill explanation for the per-second horizontal<br>
bands. Seems like the fix there was proposal 183 (ticket #3630), which got<br>
merged upstream in September 2011, but the effects only started showing in mid<br>
2013 (...)<br>
<br>
> - There are still significant deviations between measurement servers in<br>
> recent torperf data which are greater than can be explained by random<br>
> chance.<br>
> - There are some exit nodes running behind a VPN which doubles or<br>
> triples round trip time and worsens UX. However, current client/consensus<br>
> code does not (directly) punish this.<br>
<br>
How do we know that these exit nodes are running behind a VPN?<br>
<br></blockquote><div><br></div><div>Sorry, this was speculation and is presented as speculation in the slides, but looks like a claim here. <br></div><div>Running behind a VPN is my candidate explanation, because these nodes have solid bandwidth and <br></div><div>their fastest latency measurement is still >1 second. As a relays fastest measurements should coincide <br></div><div>with minimal delay on the relay itself, the only other source is on the link into the relay. A VPN would <br></div><div>induce 1 extra round trip between the true relay and its VPN endpoint into every measurement. <br></div><div>However, this isn't certain. It might be that the routes between the fixed guard and some exits are</div><div> particularly bad or some other strange behavior. <br></div><div><br></div><div>I guess we could gather more evidence by pulling out these relays and checking whether their IP</div><div> addresses correspond to commercial VPN providers or by reaching out to the operators directly. <br></div><div><br></div><div><br></div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
> - *A non-negligible fraction of relays, get into a 'broken' state where<br>
> round trip time is either normal for the relay, or delayed for 6 seconds. I<br>
> can't find any explanation for this behavior. It seems to be consistent<br>
> across Tor versions, host OS's and exit weighting. *<br>
> - This is just an exploratory analysis. The dataset and analysis should<br>
> be carefully examined before using it in any decision making.<br>
><br>
> If anyone can shed any light on the '6 second mystery', I'd be quite<br>
> interested! It also impacts nearly 1% of the requests in one dataset,<br>
> suggesting it might be having a real impact on UX.<br>
><br>
<br>
Yes this '6 second mystery' seems really interesting and potentially<br>
buggylicious! It's particularly fun that latencies seem to cluster up into<br>
distinct horizontal bands, which might hint into some sort of inefficient<br>
callback behavior that runs every second or every N miliseconds (like the new<br>
token bucket refill behavior) either on the client-side or the relay-side.<br>
<br>
I took a look at some of our per-second callbacks like<br>
second_elapsed_callback() but I could not find anything particularly related<br>
(apart from pseudo-interesting things like accounting_run_housekeeping() where<br>
relays apply bandwidth rate limiting, etc.).<br>
<br>
Is this '6 second' behavior exhibited at all by onionperf nowadays? Or is this<br>
mainly seen in Arthur's experiment?<br>
<br></blockquote><div> </div>It's funny you ask! Because I did the analysis on Arthur's dataset first, then torperf, I never actually looked at a histogram of torperf's measurements. I've just generated the histograms and you can find them as pngs <a href="https://drive.google.com/drive/folders/1yUxyGGHXLcGKCFCP91MrGSY7N-VoUZ8q?usp=sharing">here</a>. <br></div><div class="gmail_quote">Each histogram corresponds to all successful measurements (10 seconds or less) for each measurement server. I've split them into pre-2014 ('early') and 2014 or later ('late'). Unfortunately, there's not enough samples to confirm or refute the 6 second peak. There is a suggestion of a peak around 5 seconds for some of the later
relays. That could be noise (very sparse samples remember) or it could
be the 6 second peak varies on RTT significantly. Remember Arthur's
dataset used a fixed guard, so the peak may vary based on the selected
guard node. More measurements are needed! However, there are still some interesting observations to be made. The early-late distinction is huge. In particular, we see the peaks corresponding to the 1-second buckets and that they disappear between samples. There is also a clear peak around 100ms intervals, which I think
is the new value for the bucket refilling and probably not a problem. <br></div><div class="gmail_quote"><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
I originally suspected that this is some sort of issue on the client-side<br>
(i.e. Arthur's latency collecting tor) but the graph on page 59 seems to imply<br>
that it's specific relays that demonstrate this 6 second behavior. I was also<br>
thinking that perhaps this was due to KIST, but it seems like there is a<br>
reasonable amount of 0.2.x relays exhibiting this issue (page 62), and KIST got<br>
introduced in 0.3.2.<br></blockquote><div><br></div><div>This was my thought as well initially, however we only see it on a subset of relays (rather than all) and there's a clear change over time in specific relays which seems uncorrelated with each other. For example, page 77, 79, and 82 all show some relays changing between 'bad' and 'good' states. It seems hard to explain that as a client side issue, but its also hard to rule out without checking further. <br></div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
I haven't had the time to look at Arthur's script to see how latency gets<br>
calculated and how it handles errors, for example, in cases where a circuit or<br>
a stream expires (see circuit_expire_building() or<br>
connection_ap_expire_beginning() which are again called on a per-second basis).<br>
<br></blockquote><div>I threw away all failed measurements. Everything in that slide deck is only considering successful measurements that finished within 10 seconds. Looking at the failures might be even more interesting of course! <br></div><div> <br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
If the issue is not on the client-side, then according to the graphs this has<br>
to be some pretty ancient inefficient Tor behavior which runs even before<br>
0.2.9. Seems like worth digging into more, while keeping in mind the bigger picture.<br>
<br>
---<br>
<br>
Thanks for the great analysis! That was a fun presentation.<br></blockquote><div><br></div><div>Great to hear! Hope you all have a good week! :) <br></div><div><br></div><div>Best,</div><div>Dennis <br></div></div></div>