Opened 4 months ago

Last modified 2 weeks ago

#31971 needs_information defect

Snowflake is *consistently* extremely slow when using the Windows build

Reported by: cypherpunks Owned by: cohosh
Priority: Medium Milestone:
Component: Circumvention/Snowflake Version:
Severity: Normal Keywords:
Cc: arlolra, cohosh, phw, dcf Actual Points: .5
Parent ID: Points: 3
Reviewer: Sponsor: Sponsor28

Description

Snowflake is *consistently* extremely slow when using the Windows build, I tried 5 times by restarting the browser and I always get 20kb/s max. In my Linux machine it works normally.

Child Tickets

TicketStatusOwnerSummaryComponent
#32870needs_reviewcohoshBump version of pion webrtc in Tor BrowserApplications/Tor Browser

Attachments (11)

tbb-windows.png (125.5 KB) - added by cohosh 3 months ago.
iperf.png (24.3 KB) - added by cohosh 2 months ago.
windows-torrc (491 bytes) - added by cohosh 6 weeks ago.
windows_script.bat (954 bytes) - added by cohosh 6 weeks ago.
windows-download.csv (458 bytes) - added by cohosh 6 weeks ago.
windows-bootstrap.csv (17.1 KB) - added by cohosh 6 weeks ago.
bootstrap.png (33.5 KB) - added by cohosh 6 weeks ago.
throughput.png (34.3 KB) - added by cohosh 6 weeks ago.
recompiled-throughput.png (40.4 KB) - added by cohosh 3 weeks ago.
recompiled-bootstrap.png (34.2 KB) - added by cohosh 3 weeks ago.
reproducible-throughput.png (40.9 KB) - added by cohosh 3 weeks ago.

Download all attachments as: .zip

Change History (48)

comment:1 Changed 4 months ago by dcf

20 Kb/s is also what I remember getting when I briefly tested in comment:59:ticket:28942.

comment:2 Changed 3 months ago by cohosh

Points: 3

Just estimating this to be 3 points for now since we need to do some investigation into what is happening here.

comment:3 Changed 3 months ago by gaba

Sponsor: Sponsor28

comment:4 Changed 3 months ago by cohosh

Owner: set to cohosh
Status: newassigned

Changed 3 months ago by cohosh

Attachment: tbb-windows.png added

comment:5 Changed 3 months ago by cohosh

I just got a VM up and running. I was able to reproduce these results. It's bootstrapping noticeably slowly.

This doesn't seem to be related to the latency, but the first thing I noticed was this warning message that pops up the first time you try to use snowflake.


Last edited 3 months ago by dcf (previous) (diff)

comment:6 Changed 3 months ago by cohosh

Alright I'm going to amend my previous statement. I just did some tests to compare Tor Browser with Snowflake in a Windows VM vs. Tor Browser with Snowflake on Linux. I loaded the University of Waterloo homepage 5 times in each environment and used the snowflake log output to determine the maximum throughput. I also used the logs to determine how long it took the page to load and found load time to be consistently between 2-3 minutes in each environment. The maximum throughput results are:

Windows VM
159 kbps
209 kbps
156 kbps
182 kbps
149 kbps

Linux
161 kbps
274 kbps
154 kbps
243 kbps
125 kbps

This matches what I measured using the Task Manager in Windows as well. So I'm getting well over the 20 kbps reported in this ticket, and the results between Linux and Windows look comparable.

I was originally tricked into thinking I'd reproduced this after a single load because as you can see Snowflake is still quite slow. Getting a bad snowflake with no throughput will halt the bootstrap process all-together and ask you to reconfigure the browser on both systems.

The corresponding log messages used to calculate the above measurements are:

Windows VM
2019/11/04 15:46:58 Traffic Bytes (in|out): 99140 | 10715 -- (23 OnMessages, 15 Sends)

2019/11/04 15:54:31 Traffic Bytes (in|out): 130928 | 16688 -- (35 OnMessages, 25 Sends)

2019/11/04 16:01:14 Traffic Bytes (in|out): 97325 | 2715 -- (17 OnMessages, 5 Sends)

2019/11/04 16:05:53 Traffic Bytes (in|out): 113624 | 12228 -- (27 OnMessages, 14 Sends)

2019/11/04 16:24:29 Traffic Bytes (in|out): 93302 | 2715 -- (15 OnMessages, 5 Sends)

Linux
2019/11/04 16:55:05 Traffic Bytes (in|out): 100678 | 3801 -- (7 OnMessages, 7 Sends)

2019/11/04 16:59:14 Traffic Bytes (in|out): 171348 | 6487 -- (11 OnMessages, 11 Sends)

2019/11/04 17:02:26 Traffic Bytes (in|out): 96317 | 2657 -- (30 OnMessages, 3 Sends)

2019/11/04 17:06:15 Traffic Bytes (in|out): 152011 | 3801 -- (44 OnMessages, 7 Sends)

2019/11/04 17:20:05 Traffic Bytes (in|out): 78095 | 2715 -- (22 OnMessages, 5 Sends)

comment:7 Changed 3 months ago by cohosh

Status: assignedneeds_information

I'll leave this open for a bit to see if anyone else can reproduce it, but after that I'll close it because it seems to working okay on Windows now.

comment:8 Changed 3 months ago by cohosh

Actual Points: .5

comment:9 in reply to:  6 ; Changed 2 months ago by cypherpunks

Replying to cohosh:

This matches what I measured using the Task Manager in Windows as well. So I'm getting well over the 20 kbps reported in this ticket, and the results between Linux and Windows look comparable.

Could it be that this is a result of the recent change regarding handing proxy-go instances more often than browser snowflakes? I will retest and keep you informed about whether I'm seeing any improvement on Windows, but I'm curious how this could have fixed itself and whether browser proxies work as fast as proxy-go instances.

Last edited 2 months ago by cypherpunks (previous) (diff)

comment:10 in reply to:  9 Changed 2 months ago by cohosh

Replying to cypherpunks:

Could it be that this is a result of the recent change regarding handing proxy-go instances more often than browser snowflakes? I will retest and keep you informed about whether I'm seeing any improvement on Windows, but I'm curious how this could have fixed itself and whether browser proxies work as fast as proxy-go instances.

I don't think this is just due to getting more proxy-go instances. Even with the change, it's still more likely to get a browser snowflake than a proxy-go instance. I should definitely have gotten a browser proxy in one of the 5 bootstraps and I got well over 20kbps for each one. I am also puzzled as to why I wasn't able to reproduce this. Perhaps something in a recent Windows update? Or a firewall setting? It would be really helpful if you could check on your setup again and confirm. Thanks cypherpunks!

comment:11 Changed 2 months ago by cypherpunks

Unfortunately the same problem happened to me, I still got 20 kbps. I'll try to see if applying Windows updates will yield any improvement.

comment:12 in reply to:  11 ; Changed 2 months ago by cohosh

Replying to cypherpunks:

Unfortunately the same problem happened to me, I still got 20 kbps. I'll try to see if applying Windows updates will yield any improvement.

Hmm, thanks for the update! I'm going to ask a few questions so I can try to reproduce this:

  • How are you measuring your throughput?
  • Which version of Windows are you using?
  • Which version of Tor Browser are you using?

comment:13 in reply to:  12 ; Changed 2 months ago by cypherpunks

Replying to cohosh:

Hmm, thanks for the update! I'm going to ask a few questions so I can try to reproduce this:

  • How are you measuring your throughput?

Downloading a test file (could be Tor Browser, Debian ISO, ... doesn't matter).

  • Which version of Windows are you using?

Windows 10: 18362.476

  • Which version of Tor Browser are you using?

Latest alpha.

comment:14 in reply to:  13 ; Changed 2 months ago by cohosh

Replying to cypherpunks:

Replying to cohosh:

Hmm, thanks for the update! I'm going to ask a few questions so I can try to reproduce this:

  • How are you measuring your throughput?

Downloading a test file (could be Tor Browser, Debian ISO, ... doesn't matter).

Are you using Task manager or some other tool to measure the how many kbps you get when you download the file? Or are you timing the download yourself?

comment:15 in reply to:  14 Changed 2 months ago by cypherpunks

Replying to cohosh:

Are you using Task manager or some other tool to measure the how many kbps you get when you download the file? Or are you timing the download yourself?

No, just from the download speed at about:downloads.

comment:18 in reply to:  17 Changed 2 months ago by cypherpunks

Replying to cypherpunks:

I don't think there's any problem with my connection, I can get decent speeds.

by UDP?

(https://superuser.com/questions/1242830/online-udp-speed-test (https://iperf.fr/iperf-servers.php))

Changed 2 months ago by cohosh

Attachment: iperf.png added

comment:19 Changed 2 months ago by cohosh

Okay I was able to reproduce the 10-20KB/s download speed by looking at the transfer rate in about:downloads.

I also ran a speed test using iperf -u and found the performance to be fine:

I tried a download on linux and found that I'm getting the same 10-20KB/s in about:downloads when I use snowflake. I'm starting to doubt this is a windows-specific problem. In any case, 20KB/s is very slow. I'll look into whether there are good reasons why it's so slow on all platforms.

comment:20 in reply to:  19 Changed 2 months ago by cypherpunks

Replying to cohosh:

I tried a download on linux and found that I'm getting the same 10-20KB/s in about:downloads when I use snowflake. I'm starting to doubt this is a windows-specific problem. In any case, 20KB/s is very slow. I'll look into whether there are good reasons why it's so slow on all platforms.

I think the problem is from where you were downloading, I just tested again I get less than 20 KB/s in Windows and more than 500 KB/s on Linux with the same donwload link.

Edit: Tested again on a friend's laptop with Windows 10 and again I get unusable speeds of less than 20KB/s. Also the bootstrap was unusually slow.

Last edited 2 months ago by cypherpunks (previous) (diff)

comment:21 Changed 2 months ago by cypherpunks

cypherpunks,

Windows Registry Editor Version 5.00

[HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\services\AFD\Parameters]
"DefaultReceiveWindow"=dword:00200000
"DefaultSendWindow"=dword:00200000

Can you check this registry tweak? (for test purpose only, not sure about DefaultSendWindow and values)

https://docs.microsoft.com/en-us/previous-versions//bb726981(v=technet.10)

Default: 4096/8192/8192

Linux

net.core.rmem_max > 128K

Changed 6 weeks ago by cohosh

Attachment: windows-torrc added

comment:23 Changed 6 weeks ago by cohosh

I'm running some throughput tests using the attached windows_script.bat and windows-torrc files. After 20 runs, I was getting a maximum throughput of about 20 KB/s. I'm going to try this on a windows box instead of a VM to see if anything changes.

comment:24 in reply to:  23 Changed 6 weeks ago by cypherpunks

Replying to cohosh:

I'm running some throughput tests using the attached windows_script.bat and windows-torrc files. After 20 runs, I was getting a maximum throughput of about 20 KB/s. I'm going to try this on a windows box instead of a VM to see if anything changes.

FWIW I was testing out things with a Windows box and not a VM. By the way I just retested again and I still get 20Kb/s.

Changed 6 weeks ago by cohosh

Attachment: windows_script.bat added

Changed 6 weeks ago by cohosh

Attachment: windows-download.csv added

Changed 6 weeks ago by cohosh

Attachment: windows-bootstrap.csv added

Changed 6 weeks ago by cohosh

Attachment: bootstrap.png added

Changed 6 weeks ago by cohosh

Attachment: throughput.png added

comment:25 Changed 6 weeks ago by cohosh

There is definitely something slowing down snowflake connections.

I've uploaded the results of 30 snowflake runs. I got an average throughput of 5 KB/s and a maximum throughput of 15 KB/s.

There was a circuit timeout of 3 minutes set and still only about half of the connections bootstrapped to 100% (despite the fact that only 1 snowflake was faulty).

This is pretty much unusable, and it's not due to something in Tor browser because I ran these with the tor binary directly and connected with curl to the SOCKS port to download a file.

comment:26 Changed 6 weeks ago by cohosh

I did some speed tests at https://test.webrtc.org

On Chrome:

[ OK ] Transmitting at 1305.853 kbps.
[ OK ] Transmitting at 1335.296 kbps.
[ OK ] Transmitting at 1222.687 kbps.
[ OK ] Transmitting at 1376.256 kbps.
[ OK ] Transmitting at 1388.475 kbps.
[ OK ] Total transmitted: 6676.48 kilo-bits in 5.032 seconds

That's 163 KB/s, 167KB/s, 153 KB/s, 172 KB/s, 174 KB/s.

On Firefox:

[ OK ] Transmitting at 449.757 kbps.
[ OK ] Transmitting at 445.658 kbps.
[ OK ] Transmitting at 261.606 kbps.
[ OK ] Transmitting at 74.813 kbps.
[ OK ] Total transmitted: 1433.6 kilo-bits in 5.039 seconds.

That's 56 KB/s, 57 KB/s, 32 KB/s, 9 KB/s.

I performed a few tests to check if these results are representative and they seem to be.

So even the Firefox version of WebRTC is much slower than the Chrome version. I wonder if there's something special Chrome has figured out and is doing to get around an issue with Windows.

comment:27 Changed 6 weeks ago by cohosh

To contrast with what it's like on linux, I get the following results for a Firefox speed test:

[ OK ] Transmitting at 1531.904 kbps.
[ OK ] Transmitting at 1509.482 kbps.
[ OK ] Transmitting at 1507.328 kbps.
[ OK ] Transmitting at 1543.657 kbps.
[ OK ] Transmitting at 1539.545 kbps.
[ OK ] Total transmitted: 7692.288 kilo-bits in 5.029 seconds.

comment:28 Changed 6 weeks ago by cypherpunks

comment:29 in reply to:  26 Changed 6 weeks ago by phw

Replying to cohosh:

So even the Firefox version of WebRTC is much slower than the Chrome version. I wonder if there's something special Chrome has figured out and is doing to get around an issue with Windows.


Huh, this is unexpected. I tried to reproduce this on a Windows 10 (not a VM), using an up-to-date Chrome v79 and an up-to-date Firefox v71. On Chrome:

[ OK ] Transmitting at 1476.845 kbps.
[ OK ] Transmitting at 1449.984 kbps.
[ OK ] Transmitting at 1479.792 kbps.
[ OK ] Transmitting at 1471.617 kbps.
[ OK ] Transmitting at 1476.845 kbps.
[ OK ] Total transmitted: 7405.568 kilo-bits in 5.037 seconds.

On Firefox:

[ OK ] Transmitting at 1466.619 kbps.
[ OK ] Transmitting at 1504.319 kbps.
[ OK ] Transmitting at 1490.944 kbps.
[ OK ] Transmitting at 1499.829 kbps.
[ OK ] Transmitting at 1561.93 kbps.
[ OK ] Total transmitted: 7593.984 kilo-bits in 5.036 seconds.

My Firefox v71 on Debian (on a separate physical machine) is somewhat faster:

[ OK ] Transmitting at 1622.016 kbps.
[ OK ] Transmitting at 1662.976 kbps.
[ OK ] Transmitting at 1690.672 kbps.
[ OK ] Transmitting at 1687.552 kbps.
[ OK ] Transmitting at 1695.744 kbps.
[ OK ] Total transmitted: 8421.376 kilo-bits in 5.04 seconds.

comment:31 in reply to:  30 Changed 6 weeks ago by cohosh

Replying to cypherpunks:

this is unexpected

https://dxr.mozilla.org/mozilla-central/source/media/mtransport/nr_socket_prsock.cpp#585

https://bugzilla.mozilla.org/show_bug.cgi?id=1252769

Thanks cypherpunks, this is a good find. I looked at netstat statistics for UDP sockets on my windows machine and wasn't seeing any packet loss at the socket level (as suggested by the comment above on AFD Parameters). However, there might be a different buffer that's overflowing somewhere in the pion library.

I just recompiled snowflake to log more messages from the pion libraries and my plan is to see if we're getting a large amount of unusual errors that might point to the problem.

comment:32 Changed 6 weeks ago by cypherpunks

I looked at netstat statistics for UDP sockets on my windows machine and wasn't seeing any packet loss at the socket level (as suggested by the comment above on AFD Parameters)

https://social.technet.microsoft.com/Forums/windowsserver/en-US/35f79821-7ab5-4335-89d5-cec58fa31d33/detecting-the-amount-of-udp-packet-loss

(2008 year):

Netstat displays the statistics from the transport layer. Winsock layer sits on top of the transport layer. Datagrams may be dropped at various layers within the networking stack. The netstat statistics do not account for datagram drops happening at Winsock layer due to exceeding the socket receive buffer limit.

Unfortunately, there’s no tool currently that shows Winsock layer datagram drop statistics. The closest thing on Vista and later is Winsock ETW tracing which would log a trace entry for each drop. Disadvantage of the ETW tracing that only the support personal can convert it to readable format (and this is for internal use only).

Changed 3 weeks ago by cohosh

Attachment: recompiled-throughput.png added

Changed 3 weeks ago by cohosh

Attachment: recompiled-bootstrap.png added

comment:33 Changed 3 weeks ago by cohosh

This is interesting. I recompiled the snowflake client binary with an up-to-date pull of the pion library using the command
GOOS=windows GOARCH=amd64 go build
and then ran the tests above with this snowflake executable (note: this was not built using the Tor Browser reproducible build system).

The results were much higher throughput:

"Number of failed downloads: 0"
"Average throughput (KB/s): 107.038550791267"
"Maximum throughput (KB/s): 401.498996655518"
"Standard deviation: 97.169504273772"

resulting in more completed bootstraps:

So, either there were changes made to the pion webrtc library since version v2.1.3, or there is something about the reproducible build process that slows things down. I'm going to attempt an upgrade of the pion library in the tor browser build to see if that fixes things.

Changed 3 weeks ago by cohosh

Attachment: reproducible-throughput.png added

comment:34 Changed 3 weeks ago by cohosh

Cool, I built snowflake reproducibly using this branch: https://gitweb.torproject.org/user/cohosh/tor-browser-build.git/log/?h=pion-update

and it's still performing well:

[1] "Average throughput (KB/s): 91.8818429737581"
[1] "Maximum throughput (KB/s): 425.16961130742"
[1] "Standard deviation: 86.1295446322453"


I think this will solve the problem, I've put #32870 in needs_review. Might spend some time later looking at the changes to figure out why.

comment:35 Changed 3 weeks ago by cypherpunks

Hooooray!! Finally!! :-D

Please make sure this makes it in the next alpha TB release.

comment:36 Changed 3 weeks ago by cypherpunks

comment:37 Changed 2 weeks ago by cohosh

Noting here that after talking to Sean, it seems reasonable that https://github.com/pion/sctp/issues/62 is at least one of the reasons this issue has been fixed. I tried running a test on the version of SCTP before this fix and it was indeed much slower. However, I suspect there were multiple changes that led to increased performance.

Note: See TracTickets for help on using tickets.