Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Mobile OpenVPN is not working when provider uses UPNP #2199

Closed
anjmao opened this issue May 11, 2020 · 2 comments
Closed

Mobile OpenVPN is not working when provider uses UPNP #2199

anjmao opened this issue May 11, 2020 · 2 comments
Labels
bug

Comments

@anjmao
Copy link
Contributor

anjmao commented May 11, 2020

Android on mobile network could not connect to provider with upnp enabled. Looks that udp nat proxy is not working and may not be needed in such case. See https://github.com/mysteriumnetwork/node/blob/master/mobile/mysterium/openvpn_connection_setup.go#L159

2020-05-11 18:34:11.313 23600-23663/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:106 > Start copying stream from consumer natProxy to remote remoteConn
2020-05-11 18:34:11.314 23600-23663/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:214 > Openvpn client configuration data={"VpnConfig":{"CACertificate":"-----BEGIN CERTIFICATE-----\nMIIBxjCCAWygAwIBAgICBFcwCgYIKoZIzj0EAwIwQjELMAkGA1UEBhMCTFQxGjAY\nBgNVBAoTEU15c3Rlcml1bSBOZXR3b3JrMRcwFQYDVQQLEw5NeXN0ZXJpdW0gVGVh\nbTAeFw0yMDA1MTExNTI0MjJaFw0zMDA1MTExNTI0MjJaMEIxCzAJBgNVBAYTAkxU\nMRowGAYDVQQKExFNeXN0ZXJpdW0gTmV0d29yazEXMBUGA1UECxMOTXlzdGVyaXVt\nIFRlYW0wWTATBgcqhkjOPQIBBggqhkjOPQMBBwNCAASeWtZSqt96EauiIYgzZN1h\nZalldediIVwjLo9kO7zR6NIJt7I0x8BB3GQnUjDGJZ9bNf9qq0aadNOm6Wwrociv\no1IwUDAOBgNVHQ8BAf8EBAMCAoQwHQYDVR0lBBYwFAYIKwYBBQUHAwIGCCsGAQUF\nBwMBMA8GA1UdEwEB/wQFMAMBAf8wDgYDVR0OBAcEBQECAwQFMAoGCCqGSM49BAMC\nA0gAMEUCIQDNUdh6wetokL1GufHIC4UORqLynIHfoZZUhWUd7qHU3wIgKDNdjRjP\nmwc81RV/vjl7i19PYUxhifnqV9ju9YesCZ8=\n-----END CERTIFICATE-----\n","TLSPresharedKey":"-----BEGIN OpenVPN Static key V1-----\nafdd3e6640711297af85acb88bbd59806e4e550c0f
2020-05-11 18:34:11.314 23600-23663/network.mysterium.vpn E/GoLog: 2b03a96de3d5e6abdf613a\ne12cc194fea451cfdd02aa5da2bafa74f1316766b485516aae5919861fff9fea\nef19dbb0fd7ee3bc3e509767d052342e0a6243692ff734b2d4bcfb50e5863144\n5cdee62cc7eefb7c4d3ff4709141bf7bb075b96f905599b5afe441c5c73f9ab9\nc1afb9aa4426b8d88a5cc509031767189e6ffe9bce0b79d563169b0cce473250\n8b8ffbe4d059be1592a82d12979b2650da0f3fe3e3aa79ba488f6edd13d6169e\ne97fec53c2aa15c9b4f5661eb5ec9282f93a2a823ed88321fea8f2177e00f8f1\n3229ac86571d1f6a6c4a53db780a7697f5168f37f47deb6b5b454f78b8a5abf8\n-----END OpenVPN Static key V1-----\n","dns_ips":"10.8.0.1","lport":40378,"port":40378,"ports":null,"protocol":"udp","remote":"127.0.0.1"}}
2020-05-11 18:34:11.316 23600-23668/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/firewall/outgoing_firewall_noop.go:40 > Outgoing traffic block requested
2020-05-11 18:34:11.317 23600-23668/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/manager.go:724 > waiting for connected state
2020-05-11 18:34:11.329 23600-23668/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:139 > Openvpn log: Frame=512/2048/512 mssfix-ctrl=1250
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:139 > Openvpn log: UNUSED OPTIONS
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 2 [verb] [3] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 3 [tls-cipher] [TLS-ECDHE-ECDSA-WITH-AES-256-GCM-SHA384] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 5 [ping-timer-rem] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 6 [persist-key] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 9 [resolv-retry] [infinite] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 11 [up] [update-resolv-conf] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 12 [down] [update-resolv-conf] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 14 [single-session] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 15 [tls-exit] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 16 [connect-retry-max] [2] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 17 [remap-usr1] [SIGTERM] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 19 [script-security] [2] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 20 [auth-nocache] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 23 [lport] [40378] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 27 [management-query-passwords] 
2020-05-11 18:34:11.330 23600-23668/network.mysterium.vpn E/GoLog: 28 [explicit-exit-notify] 
2020-05-11 18:34:11.331 23600-23668/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:124 > Unhandled event: {Fatal:false Error:false Name:RESOLVE Info:}
2020-05-11 18:34:11.333 23600-23668/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:139 > Openvpn log: Contacting 127.0.0.1:40378 via UDP
2020-05-11 18:34:11.333 23600-23668/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:124 > Unhandled event: {Fatal:false Error:false Name:WAIT Info:}
2020-05-11 18:34:11.337 23600-23663/network.mysterium.vpn I/Openvpn3 setup bridge: Protecting socket: 99  res: true
2020-05-11 18:34:11.340 23600-23658/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:139 > Openvpn log: Connecting to [127.0.0.1]:40378 (127.0.0.1) via UDPv4
2020-05-11 18:34:11.382 23600-23658/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:11.000 ERR ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:146 > Failed to read remote peer: 10.61.86.138:49033 error="read udp4 10.61.86.138:49033->78.31.184.122:43111: read: connection refused"
2020-05-11 18:34:12.097 23600-23662/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/factory.go:258 > Received P2P message for "p2p-payment-invoice": AgreementID:16196067082990985078 AgreementTotal:154 Hashlock:"191b2d3b856e6f1bff9d380abe6b4e979694288b40e821e2b81397541a96caaf" Provider:"0x1a95ef8027e0dda6b91e7bc8efe68cefc39492a9"
2020-05-11 18:34:12.099 23600-23666/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/invoice_payer.go:144 > Invoice received: {16196067082990985078 154 0 191b2d3b856e6f1bff9d380abe6b4e979694288b40e821e2b81397541a96caaf 0x1a95ef8027e0dda6b91e7bc8efe68cefc39492a9}
2020-05-11 18:34:12.099 23600-23666/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/price_calculator.go:67 > Calculated price 164. Time component: 164, data component: 0 
2020-05-11 18:34:12.100 23600-23666/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/invoice_payer.go:185 > Estimated tolerance 3, upper bound 492
2020-05-11 18:34:12.100 23600-23666/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/invoice_payer.go:234 > Loaded previous state: already promised: 21487
2020-05-11 18:34:12.101 23600-23666/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/invoice_payer.go:235 > Incrementing promised amount by 154
2020-05-11 18:34:12.106 23600-23666/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/exchange_messaging.go:72 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"*\x9b\xa3\xa7\xb8\x89\xf7\x02\xbcm)8.0\xf8lˮ\x00\xba" Amount:21641 Hashlock:"\x19\x1b-;\x85no\x1b\xff\x9d8\n\xbekN\x97\x96\x94(\x8b@\xe8!\xe2\xb8\x13\x97T\x1a\x96ʯ" Signature:"\xb8\x99b\xf0߉\x99Ec\xf6#Ǽ!\xfd\xf7FP.ot_\xbe\xe9\x00\x89\x1dG\x14'>j~8\x0c\xd1\xe0t0\xb9{\x04lq\xfdD\xf3\xaeF\x02a\x0e\xe6\x1c\x00:Z\x82\xb8\xa6LRL~\x1c"} AgreementID:16196067082990985078 AgreementTotal:154 Provider:"0x1a95ef8027e0dda6b91e7bc8efe68cefc39492a9" Signature:"3fcf541b54f64e640b5c73a4d64e3d5b47122d3c7272143989bb62954f4d17a3230bf18aa2735f50a492089673e459bde7f9ab81ae44c4f6ebc8c2e36433fb311b"
2020-05-11 18:34:12.166 23600-23662/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/eventbus/event_bus.go:81 > Published topic="invoice_paid" event={ConsumerID:{Address:0x67faef1b4af5dd0423085c02703613d93ffd15d5} SessionID:fe67a38f-026e-4d88-8834-a07fa75c52b2 Invoice:{AgreementID:16196067082990985078 AgreementTotal:154 TransactorFee:0 Hashlock:191b2d3b856e6f1bff9d380abe6b4e979694288b40e821e2b81397541a96caaf Provider:0x1a95ef8027e0dda6b91e7bc8efe68cefc39492a9}}
2020-05-11 18:34:12.179 23600-23662/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/consumer/session/session_storage.go:132 > Session fe67a38f-026e-4d88-8834-a07fa75c52b2 updated
2020-05-11 18:34:12.186 23600-23662/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/eventbus/event_bus.go:81 > Published topic="consumer_grand_total_change" event={Current:21641 AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] ConsumerID:{Address:0x67faef1b4af5dd0423085c02703613d93ffd15d5}}
2020-05-11 18:34:12.192 23600-23662/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0x67faef1b4af5dd0423085c02703613d93ffd15d5} Previous:689978513 Current:689978359}
2020-05-11 18:34:12.382 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:12.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/state/state.go:402 > Session ID  Connecting duration: 5.780010311s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000002MYST
2020-05-11 18:34:13.338 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:13.000 ERR ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:123 > Failed to write remote peer: 78.31.184.122:43111 error="write udp4 10.61.86.138:49033->78.31.184.122:43111: write: connection refused"
2020-05-11 18:34:13.338 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:13.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:80 > Waiting connect from client
2020-05-11 18:34:13.338 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:13.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:106 > Start copying stream from consumer natProxy to remote remoteConn
2020-05-11 18:34:15.340 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:15.000 ERR ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:123 > Failed to write remote peer: 78.31.184.122:43111 error="write udp4 10.61.86.138:49033->78.31.184.122:43111: write: connection refused"
2020-05-11 18:34:15.341 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:15.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:80 > Waiting connect from client
2020-05-11 18:34:15.341 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:15.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:106 > Start copying stream from consumer natProxy to remote remoteConn
2020-05-11 18:34:17.344 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:17.000 ERR ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:123 > Failed to write remote peer: 78.31.184.122:43111 error="write udp4 10.61.86.138:49033->78.31.184.122:43111: write: connection refused"
2020-05-11 18:34:17.344 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:17.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:80 > Waiting connect from client
2020-05-11 18:34:17.344 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:17.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:106 > Start copying stream from consumer natProxy to remote remoteConn
2020-05-11 18:34:19.350 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:19.000 ERR ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:123 > Failed to write remote peer: 78.31.184.122:43111 error="write udp4 10.61.86.138:49033->78.31.184.122:43111: write: connection refused"
2020-05-11 18:34:19.350 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:19.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:80 > Waiting connect from client
2020-05-11 18:34:19.350 23600-23664/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:19.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/nat/traversal/nat_proxy.go:106 > Start copying stream from consumer natProxy to remote remoteConn
2020-05-11 18:34:21.335 23600-23683/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:21.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:139 > Openvpn log: Server poll timeout, trying next remote entry...
2020-05-11 18:34:21.337 23600-23683/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:21.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:124 > Unhandled event: {Fatal:false Error:false Name:RECONNECTING Info:}
2020-05-11 18:34:21.338 23600-23683/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:21.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:139 > Openvpn log: Contacting 127.0.0.1:40378 via UDP
2020-05-11 18:34:21.339 23600-23683/network.mysterium.vpn E/GoLog: 2020-05-11T15:34:21.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/openvpn_connection_setup.go:124 > Unhandled event: {Fatal:false Error:false Name:WAIT Info:}
2020-05-11 18:34:21.341 23600-23663/network.mysterium.vpn I/Openvpn3 setup bridge: Protecting socket: 96  res: true
@anjmao anjmao added the bug label May 11, 2020
@anjmao
Copy link
Contributor Author

anjmao commented May 12, 2020

Can be solved with #2192

@soffokl
Copy link
Member

soffokl commented Jun 23, 2020

Resolved by #2192

@soffokl soffokl closed this as completed Jun 23, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@anjmao @soffokl