[BUG] - Failing Healthchecks even with correct ProtonVPN IP address

Question

[BUG] - Failing Healthchecks even with correct ProtonVPN IP address

deploystudios opened this issue 3 years ago · 3 comments

deploystudios commented 3 years ago

Version of `protonvpn-docker`

latest

Credential & Plan

I have verified that my VPN credentials are valid
I am using OpenVPN credentials and not my proton account credentials.
I have verified that the servers I am trying to connect to are available under my plan.

System Architecture

x86_64

Running on a NAS?

Yes

Container Runtime

I don't know!

Version of Kubernetes

NA

Version of docker/podman runtime

NA

I have tried debugging with compose file provided as mentioned in TROUBLESHOOTING

Relevant log output

protonvpn_1  | 2021-11-28 19:58:00+0000  [ERROR   ] Your current public IP 185.156.46.42, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:58:00+00:00 [ERROR ] Healthcheck #7 Failed! 
protonvpn_1  | 2021-11-28 19:58:00+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:58:00+00:00 [ERROR ] Reconnecting! (3) 
protonvpn_1  | 2021-11-28 19:58:00+00:00 [WARN  ] Reconnecting... 
****************
more of the same and then
****************
protonvpn_1  | 2021-11-28 19:59:11+00:00 [OK    ] Reconnection successful 
protonvpn_1  | 2021-11-28 19:59:42+0000  [ERROR   ] Your current public IP 185.156.46.43, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:59:42+00:00 [ERROR ] Healthcheck #10 Failed! 
protonvpn_1  | 2021-11-28 19:59:42+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:59:42+00:00 [ERROR ] Reconnecting! (3) 
protonvpn_1  | 2021-11-28 19:59:42+00:00 [WARN  ] Reconnecting... 
protonvpn_1  | There is already a VPN connection running.
protonvpn_1  | Terminating previous connection...
protonvpn_1  | Connecting to US-VA#17 via UDP...
protonvpn_1  | Connected!
****************
running curl -vv https://ipinfo.io gave me this ip: 185.156.46.37
****************
protonvpn_1  | 2021-11-28 19:59:46+00:00 [OK    ] Reconnection successful 
protonvpn_1  | 2021-11-28 20:00:17+00:00 [OK    ] VPN is running and healthy 
protonvpn_1  | 2021-11-28 20:00:50+00:00 [OK    ] VPN is running and healthy 

FULL LOG BELOW TO REFERENCE OTHER IPS:

protonvpn_1  | 2021-11-28 19:55:14+0000  [ERROR   ] Your current public IP 185.156.46.42, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:55:14+00:00 [ERROR ] Healthcheck #2 Failed! 
protonvpn_1  | 2021-11-28 19:55:14+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:55:45+0000  [ERROR   ] Your current public IP 185.156.46.42, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:55:45+00:00 [ERROR ] Healthcheck #3 Failed! 
protonvpn_1  | 2021-11-28 19:55:45+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:56:15+0000  [ERROR   ] Your current public IP 185.156.46.42, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:56:15+00:00 [ERROR ] Healthcheck #4 Failed! 
protonvpn_1  | 2021-11-28 19:56:15+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:56:15+00:00 [ERROR ] Reconnecting! (3) 
protonvpn_1  | 2021-11-28 19:56:15+00:00 [WARN  ] Reconnecting... 
protonvpn_1  | There is already a VPN connection running.
protonvpn_1  | Terminating previous connection...
protonvpn_1  | Connecting to US-VA#17 via UDP...
protonvpn_1  | Connected!
protonvpn_1  | 2021-11-28 19:56:20+00:00 [OK    ] Reconnection successful 
protonvpn_1  | 2021-11-28 19:56:50+0000  [ERROR   ] Your current public IP 185.156.46.41, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:56:50+00:00 [ERROR ] Healthcheck #5 Failed! 
protonvpn_1  | 2021-11-28 19:56:50+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:56:50+00:00 [ERROR ] Reconnecting! (3) 
protonvpn_1  | 2021-11-28 19:56:50+00:00 [WARN  ] Reconnecting... 
protonvpn_1  | There is already a VPN connection running.
protonvpn_1  | Terminating previous connection...
protonvpn_1  | Connecting to US-VA#17 via UDP...
protonvpn_1  | Connected!
protonvpn_1  | 2021-11-28 19:56:53+00:00 [OK    ] Reconnection successful 
protonvpn_1  | 2021-11-28 19:57:24+0000  [ERROR   ] Your current public IP 185.156.46.44, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:57:24+00:00 [ERROR ] Healthcheck #6 Failed! 
protonvpn_1  | 2021-11-28 19:57:24+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:57:24+00:00 [ERROR ] Reconnecting! (3) 
protonvpn_1  | 2021-11-28 19:57:24+00:00 [WARN  ] Reconnecting... 
protonvpn_1  | There is already a VPN connection running.
protonvpn_1  | Terminating previous connection...
protonvpn_1  | Connecting to US-VA#17 via UDP...
protonvpn_1  | Connected!
protonvpn_1  | 2021-11-28 19:57:29+00:00 [OK    ] Reconnection successful 
protonvpn_1  | 2021-11-28 19:58:00+0000  [ERROR   ] Your current public IP 185.156.46.42, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:58:00+00:00 [ERROR ] Healthcheck #7 Failed! 
protonvpn_1  | 2021-11-28 19:58:00+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:58:00+00:00 [ERROR ] Reconnecting! (3) 
protonvpn_1  | 2021-11-28 19:58:00+00:00 [WARN  ] Reconnecting... 
protonvpn_1  | There is already a VPN connection running.
protonvpn_1  | Terminating previous connection...
protonvpn_1  | Connecting to US-VA#17 via UDP...
protonvpn_1  | Connected!
protonvpn_1  | 2021-11-28 19:58:03+00:00 [OK    ] Reconnection successful 
protonvpn_1  | 2021-11-28 19:58:34+0000  [ERROR   ] Your current public IP 185.156.46.38, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:58:34+00:00 [ERROR ] Healthcheck #8 Failed! 
protonvpn_1  | 2021-11-28 19:58:34+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:58:34+00:00 [ERROR ] Reconnecting! (3) 
protonvpn_1  | 2021-11-28 19:58:34+00:00 [WARN  ] Reconnecting... 
protonvpn_1  | There is already a VPN connection running.
protonvpn_1  | Terminating previous connection...
protonvpn_1  | Connecting to US-VA#17 via UDP...
protonvpn_1  | Connected!
protonvpn_1  | 2021-11-28 19:58:38+00:00 [OK    ] Reconnection successful 
protonvpn_1  | 2021-11-28 19:59:08+0000  [ERROR   ] Your current public IP 185.156.46.42, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:59:08+00:00 [ERROR ] Healthcheck #9 Failed! 
protonvpn_1  | 2021-11-28 19:59:08+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:59:08+00:00 [ERROR ] Reconnecting! (3) 
protonvpn_1  | 2021-11-28 19:59:08+00:00 [WARN  ] Reconnecting... 
protonvpn_1  | There is already a VPN connection running.
protonvpn_1  | Terminating previous connection...
protonvpn_1  | Connecting to US-VA#17 via UDP...
protonvpn_1  | Connected!
protonvpn_1  | 2021-11-28 19:59:11+00:00 [OK    ] Reconnection successful 
protonvpn_1  | 2021-11-28 19:59:42+0000  [ERROR   ] Your current public IP 185.156.46.43, does not match any IPs from server US-VA#17
protonvpn_1  | 2021-11-28 19:59:42+00:00 [ERROR ] Healthcheck #10 Failed! 
protonvpn_1  | 2021-11-28 19:59:42+00:00 [ERROR ] Connected to # instead of # 
protonvpn_1  | 2021-11-28 19:59:42+00:00 [ERROR ] Reconnecting! (3) 
protonvpn_1  | 2021-11-28 19:59:42+00:00 [WARN  ] Reconnecting... 
protonvpn_1  | There is already a VPN connection running.
protonvpn_1  | Terminating previous connection...
protonvpn_1  | Connecting to US-VA#17 via UDP...
protonvpn_1  | Connected!
protonvpn_1  | 2021-11-28 19:59:46+00:00 [OK    ] Reconnection successful 
protonvpn_1  | 2021-11-28 20:00:17+00:00 [OK    ] VPN is running and healthy 
protonvpn_1  | 2021-11-28 20:00:50+00:00 [OK    ] VPN is running and healthy 
protonvpn_1  | 2021-11-28 20:01:20+00:00 [OK    ] VPN is running and healthy 
protonvpn_1  | 2021-11-28 20:01:50+00:00 [OK    ] VPN is running and healthy 
protonvpn_1  | 2021-11-28 20:02:22+00:00 [OK    ] VPN is running and healthy 
protonvpn_1  | 2021-11-28 20:02:52+00:00 [OK    ] VPN is running and healthy 
protonvpn_1  | 2021-11-28 20:03:23+00:00 [OK    ] VPN is running and healthy 
protonvpn_1  | 2021-11-28 20:03:53+00:00 [OK    ] VPN is running and healthy 
protonvpn_1  | 2021-11-28 20:04:23+00:00 [OK    ] VPN is running and healthy 
protonvpn_1  | 2021-11-28 20:04:54+00:00 [OK    ] VPN is running and healthy

Any additional info

It seems like the lookup for the connected IP is not returning correct results. Mine cycled through several IPs until it seemed to work as noted above.

Code of Conduct & PII Redaction

I agree to follow this project's Code of Conduct
I have removed any sensitive personally identifying information(PII) and secrets from in this issue report.

Answer 1 · 2021-12-29T15:51:27.000Z

Hello. Same thing is happening to me.
It eventually gets to an IP that it likes.
I enabled DEBUG=1 to get some more info.
Attaching below what I could see.

It seems the serverinfo.json file does not have the correct information

How does that file refresh itself? Maybe we can test something running docker exec and see if it helps.

today at 12:46:43 PM2021-12-29 15:46:43+00:00 [DEBUG ] Is service disconnecting: 0 
today at 12:46:43 PM2021-12-29 15:46:43+0000  [DEBUG ] Detect IP of connected server from /root/.pvpn-cli/pvpn-cli.cfg
today at 12:46:43 PM2021-12-29 15:46:43+0000  [DEBUG ] Reading /root/.pvpn-cli/serverinfo.json
today at 12:46:43 PM2021-12-29 15:46:43+0000  [DEBUG ] Allowed IPs: ['162.12.206.11']
today at 12:46:43 PM2021-12-29 15:46:43+0000  [DEBUG ] Fetch Public IP from https://api.ipify.org
today at 12:46:44 PM2021-12-29 15:46:44+0000  [DEBUG ] Current IP is 162.12.206.10
today at 12:46:44 PM2021-12-29 15:46:44+0000  [ERROR ] Your current public IP 162.12.206.10, does not match any IPs from server AR#7
today at 12:46:44 PM2021-12-29 15:46:44+00:00 [ERROR ] Healthcheck #1 Failed! 
today at 12:46:44 PM2021-12-29 15:46:44+00:00 [ERROR ] Connected to # instead of # 
today at 12:46:59 PM2021-12-29 15:46:59+00:00 [DEBUG ] Is service disconnecting: 0 
today at 12:46:59 PM2021-12-29 15:46:59+0000  [DEBUG ] Detect IP of connected server from /root/.pvpn-cli/pvpn-cli.cfg
today at 12:46:59 PM2021-12-29 15:46:59+0000  [DEBUG ] Reading /root/.pvpn-cli/serverinfo.json
today at 12:46:59 PM2021-12-29 15:46:59+0000  [DEBUG ] Allowed IPs: ['162.12.206.11']
today at 12:46:59 PM2021-12-29 15:46:59+0000  [DEBUG ] Fetch Public IP from https://api.ipify.org
today at 12:47:00 PM2021-12-29 15:47:00+0000  [DEBUG ] Current IP is 162.12.206.10
today at 12:47:00 PM2021-12-29 15:47:00+0000  [ERROR ] Your current public IP 162.12.206.10, does not match any IPs from server AR#7
today at 12:47:00 PM2021-12-29 15:47:00+00:00 [ERROR ] Healthcheck #2 Failed! 
today at 12:47:00 PM2021-12-29 15:47:00+00:00 [ERROR ] Connected to # instead of # 
today at 12:47:15 PM2021-12-29 15:47:15+00:00 [DEBUG ] Is service disconnecting: 0 
today at 12:47:15 PM2021-12-29 15:47:15+0000  [DEBUG ] Detect IP of connected server from /root/.pvpn-cli/pvpn-cli.cfg
today at 12:47:15 PM2021-12-29 15:47:15+0000  [DEBUG ] Reading /root/.pvpn-cli/serverinfo.json
today at 12:47:15 PM2021-12-29 15:47:15+0000  [DEBUG ] Allowed IPs: ['162.12.206.11']
today at 12:47:15 PM2021-12-29 15:47:15+0000  [DEBUG ] Fetch Public IP from https://api.ipify.org
today at 12:47:15 PM2021-12-29 15:47:15+0000  [DEBUG ] Current IP is 162.12.206.10
today at 12:47:15 PM2021-12-29 15:47:15+0000  [ERROR ] Your current public IP 162.12.206.10, does not match any IPs from server AR#7
today at 12:47:16 PM2021-12-29 15:47:16+00:00 [ERROR ] Healthcheck #3 Failed! 
today at 12:47:16 PM2021-12-29 15:47:16+00:00 [ERROR ] Connected to # instead of # 
today at 12:47:31 PM2021-12-29 15:47:31+00:00 [DEBUG ] Is service disconnecting: 0 
today at 12:47:31 PM2021-12-29 15:47:31+0000  [DEBUG ] Detect IP of connected server from /root/.pvpn-cli/pvpn-cli.cfg
today at 12:47:31 PM2021-12-29 15:47:31+0000  [DEBUG ] Reading /root/.pvpn-cli/serverinfo.json
today at 12:47:31 PM2021-12-29 15:47:31+0000  [DEBUG ] Allowed IPs: ['162.12.206.11']
today at 12:47:31 PM2021-12-29 15:47:31+0000  [DEBUG ] Fetch Public IP from https://api.ipify.org
today at 12:47:31 PM2021-12-29 15:47:31+0000  [DEBUG ] Current IP is 162.12.206.10
today at 12:47:31 PM2021-12-29 15:47:31+0000  [ERROR ] Your current public IP 162.12.206.10, does not match any IPs from server AR#7
today at 12:47:31 PM2021-12-29 15:47:31+00:00 [ERROR ] Healthcheck #4 Failed!

Answer 2 · 2021-12-29T16:02:05.000Z

More info found... checking the code, I see that the serverinfo.json is downlaoded from https://api.protonvpn.ch/vpn/logicals. If you review the server info for AR#7 it shows the exit IP is the one that the container got correct 162.12.206.11. And the one that https://api.ipify.org shows, which is 162.12.206.10, actually belongs to AR#6. So maybe what is going on, is that the cli is informing the wrong connected server?

Answer 3 · 2021-12-29T17:50:02.000Z

I fixed it in the above PR, love to contribute to this project, use it all the time

Version of protonvpn-docker