[intermittent] Server unavailable - Firewall modal displayed while changing locations

[data-sync-user]

Mozilla VPN affected versions:

• 2.11.1 (2.202211211212);

Platform tested:

• iOS 15.7;
• iOS 16;

Prerequisites:

• Have Mozilla VPN app installed and open;
• Have an account with subscription for Mozilla VPN;
• Be on Prod server;

Steps to reproduce:

1. Log in with the account from prerequisites;
2. Turn the VPN ON;
3. Access CI screen;
4. Navigate to the locations screen and back;
5. Switch a few locations;
6. Switch from single to multi-hop;
7. Observe the behavior;

Expected results:

• VPN is ON and works as expected.

Actual results:

• VPN stays in connecting mode and eventually displays the Server unavailable - Firewall blocked modal;

Notes:

• Attaching logs from 2 different devices;
• Not sure what triggered the modal;
• After reproducing once, it reproduces 3 of 5 times;
• Will confirm in a later message if it reproduces on 2.12 or 2.11;

┆Issue is synchronized with this Jira Bug ┆Reporter: Valentina Virlics

[data-sync-user]

➤ Valentina Virlics commented:

I am able to reproduce it on Mozilla VPN 2.12 and 2.11 as well.

[^2.12-MozillaVPN-logs (2).txt] [^2.11-MozillaVPN-logs (2).txt]

[data-sync-user]

➤ Sarah Bird commented:

I can reproduce this.

Specifically:

• On stage, haven’t tried prod.

• I’m 2.12.0 202211162005

• I used the sequence of servers that were noted in one of Valentina’s logs:

  • Skopje, Northern Macedonia
  • Montreal, Canada
  • Hong Kong, Hong Kong
  • Warsaw, Poland
  • Skopje, Northern Macedonia → Madrid, Spain

• It appeared that everything was working and I was actually writing up in here that I cannot reproduce but I looked down at my phone…maybe a minute or two had passed….and I first saw “connection unstable” and then “Server unavailable. The server has been blocked. Check your firewall settings.” popped.

After I got the message, I then tried changing to a different server. I switched to Belgrade and waited for < 30s. I then switched back to multi-hop and the skopje->madrid connection. All looked well. But then after ~1 minute I got connection unstable. And after ~1minute more I got the Server unavailable message again.

I pressed “pick a new location” and noticed the madrid server is what had been marked as unavailable. I switched my exit server to Zurich and waited 2min 30 and everything was fine. I switched to Sydney single-hop for 15s and then back to Skopje->Zurich and again waited and everything was fine. Finally I switched back to skopje → madrid and waited and again all was successful.

My guess as to what’s going on is that all the server hopping is confusing the connection reliability calculation. Owen Kirby I’d love your thoughts on this.

I want to note that the Madrid server was marked as unavailable immediately after the server unavailable failure but in subsequent loads of the locations page it was not. This might be a be a bug. Owen Kirby can you give me a brain dump (either here or we can do a short call) on the logic that exists for putting a server in the penalty box and taking it back out again.

Santiago Andrigo I don’t think this should be a high. I’m going to unassign myself for now. I think my action item was to investigate.

[data-sync-user]

➤ Sarah Bird commented:

update. after a very long wait i got the same error again and once again the madrid server is marked as unavailable.

[data-sync-user]

➤ Sarah Bird commented:

We should add glean events to try and capture this type of behaviour.

[data-sync-user]

➤ Sebastian Streich commented:

Sarah Bird - Was able to repro - this is not goood.

So.

[08.12.2022 13:55:14.414] Debug: (networking - ConnectionHealth) Stability changed: ConnectionHealth::Unstable [08.12.2022 13:55:14.415] Debug: (main - MozillaVPN) VPN tunnel silent server switch [08.12.2022 13:55:14.416] Debug: (main - TaskScheduler) Tasks: 0 [08.12.2022 13:55:14.417] Debug: (main|controller - TaskControllerAction) TaskControllerAction created for deactivation [08.12.2022 13:55:14.418] Debug: (main - TaskScheduler) Scheduling task: TaskControllerAction [08.12.2022 13:55:14.418] Debug: (main - TaskScheduler) Tasks: 1 [08.12.2022 13:55:14.419] Debug: (main|controller - TaskControllerAction) TaskControllerAction run [08.12.2022 13:55:14.419] Debug: (controller - Controller) Silently switch serversWe can see that connection health at some point marked the conneciton as “bad”… are we too sensitive if all of us can repro it with that server combo (?), but thats another topic.

[08.12.2022 13:56:44.398] Debug: (ios|controller - IOSController) IOSController activating es2-wireguard [08.12.2022 13:56:44.399] Debug: (ios - IOSSGlue) Swift log - tag: APP msg: Connecting [08.12.2022 13:56:44.417] Debug: (ios - IOSSGlue) Swift log - tag: APP msg: Activating includeAllNetworks [08.12.2022 13:56:44.448] Debug: (ios - IOSSGlue) Swift log - tag: APP msg: Saving the tunnel succeeded [08.12.2022 13:56:44.449] Debug: (ios - IOSSGlue) Swift log - tag: APP msg: Loading the tunnel succeeded [08.12.2022 13:56:59.387] Debug: (controller - Controller) Timeout while waiting for handshake [08.12.2022 13:56:59.388] Info: (main - Telemetry) Send a handshake failure eventThis causes a silent server switch, which does not seem to get confirmed. (which is wierd because on iOS that is a no-op).

This will cause the client to burn through the server list and put them on timeout.

Once no more servers are available, you get a prompot - since we were able to ping each server, you get a firewall message instead of the “server down” message >:c

Given that connection health is actively breaking the client, maybe we should bump that up again?

Also note, we have - glean for that error: https://dictionary.telemetry.mozilla.org/apps/mozilla_vpn/metrics/sample_connectivity_handshake_timeout ( https://dictionary.telemetry.mozilla.org/apps/mozilla_vpn/metrics/sample_connectivity_handshake_timeout|smart-link )

[data-sync-user]

➤ Bianca Hidecuti commented:

I am also able to reproduce this issue on the 2.12 version, on iOS 16.0.2, while following the next steps:

1. Go to Settings - Network settings and check the “Tunnel VPN through port 53/DNS” option;
2. Turn ON the VPN (any server, single-hop);
3. Access the CI screen;
4. Press the refresh button (one or 2 times), after the CI screen has loaded;

AR: “Unexpected error” screen is displayed. The VPN enters the “Connecting” state and after a few moments, the Server unavailable - Firewall blocked modal is displayed.

Attaching a video and logs as well.

Notes:

• if the refresh button from the CI screen is not pressed, I am not able to reproduce the issue while following the mentioned stepes;

• if the “Tunnel VPN through port 53/DNS” option is not checked, I am not able to reproduce the issue;

[^MozillaVPN-logs (1) (68fd5366-6041-4ce6-b0b4-ffca7c000dbe).txt]

!original-5765A6E1-0B9B-452D-A381-CC277EC728E0.mp4|width=444,height=960!

[data-sync-user]

➤ Santiago Andrigo commented:

FWIW:

• I can’t reproduce this on the 2.11 client for Android (neither with Sarah’s sequence of server connections, nor by repeating the CI screen)
• Owen Kirby and I discussed dedicating a Spike (not in the December sprint) towards investigating the impact of Silent Server switches: https://mozilla-hub.atlassian.net/browse/VPN-3277 ( https://mozilla-hub.atlassian.net/browse/VPN-3277|smart-link ).

[data-sync-user]

➤ Valentina Virlics commented:

Verified this on the latest 2.13 Mozilla VPN build, while on iOS 15.7.1.

The “server unavailable - firewall” modal was replaced with the “server unavailable“ classic modal.

I’ve triggered the modal after switching few locations, switching from single to multi hop and turning the VPN ON/OFF 2-3 times.

!1671623880299.JPEG|width=1559,height=2079!

I think that showing this modal is still an issue. and triggering it was pretty easy.

Reopening.

[data-sync-user]

➤ Sebastian Streich commented:

Oh no :c

Valentina Virlics , only if you have time , could you get new set of video and logs? I can no longer reproduce this, so i am assuming there is another issue that causes this. (or my fix never worked, who knows? 😄 )

[data-sync-user]

➤ Santiago Andrigo commented:

Moving to “Merged” as we don’t use “Needs QA” anymore.

[data-sync-user]

➤ Sebastian Streich commented:

Yikes! Moving this back to blocked then, i just wanted this to get QA attention, as it’s not done.

[data-sync-user]

➤ Valentina Virlics commented:

Verified this on iOS 15.7/16.5/16.6 while using the latest 2.21 Mozilla VPN build.

The server unavailable modal is no longer displayed after multiple single/multi hop locations changes.

Closing it.