mysteriumnetwork / node

Mysterium Network Node - official implementation of distributed VPN network (dVPN) protocol
https://mysterium.network
GNU General Public License v3.0
1.11k stars 313 forks source link

[Android, Mac] After some time app disconnects and doesn't let connect #1743

Closed cvl closed 4 years ago

cvl commented 4 years ago

After some time app disconnects and doesn't let connect, shows the message "Disconnecting..."

I cannot do anything else, as it says "disconnect first to connect".

anjmao commented 4 years ago

Hi @cvl . Could you sent feedback from the app which will include logs? Is it OpenVPN only or both OpenVPN and WireGuard?

cvl commented 4 years ago

Could you advise how to access the logs? This happens in production app.

anjmao commented 4 years ago

You could debug app locally and use logcat to fetch logs or implement some feedback service so users can send feedback with attached logs to your service.

cvl commented 4 years ago

This is hard to reproduce bug, happened couple times after node upgrade.

Perhaps this will fix with that udp/tcp parsing issue (when lowercases only are expected)...

Let me see if this repeats after that one is fixed.

cvl commented 4 years ago

Still happening. The notification says "Connected", the app says it's disconnected. And it is actually disconnected.

cvl commented 4 years ago

Runs network.mysterium:mobile-node:0.21.0 Would be good to have some kind of location for prod app error logs.

cvl commented 4 years ago

@anjmao I literally get this every time I leave VPN open on my phone. Sometimes the notification says it's disconnected, sometimes it says it's connected, but it disconnects by itself. Provider node used (might help to reproduce): 0x5626c78981154c31a100dcdabf183dc0f8f18ff5

anjmao commented 4 years ago

@cvl I connected to node you gave for about 6 minutes, didn't saw any problem. One improvement we need to do is to expose more errors (maybe via events) so app can show why it was disconnected. One reason it may disconnect is because of payments.

As I mentioned you can simply plug your phone into PC via USB and run debug version of the app. When you will see node library logs. Regarding prod app error logs you can create some backend api endpoint and send logs there, logs location on android in known and configurable.

cvl commented 4 years ago

USB debugging doesn't work on my computer for some reason, so it's not an option. It takes more than 6 minutes, 10-15 or so.

cvl commented 4 years ago

Occurred once again with 0x7130a37577709041d6576c4c2d4a6e096405ab9d (Belgium): I connect, the app says it's not connected, yet the taskbar notification says it's connected.

In reality, it's not connected.

cvl commented 4 years ago

Actually, after upgrading from 0.22.5 to 0.30.0-rc1 the app behaves very strangely (in terms of connecting, connection state updates etc).

Was there some considerable changes in node regarding conn handling?

anjmao commented 4 years ago

Hi @cvl , can you try to update to new 0.31.0-rc2 version. It should fix some issues.

anjmao commented 4 years ago

@cvl The initial bug you register should be fixed in 0.31.0-rc2. If it works for you let's close this issue. One issue I noticed is that If I turn off WIFI, app will disconnect after some time and show red message "Not internet connection" which is expected, but If I turn internet back I still see this message and notification saying Connected to ..., will try to fix this, it's quite annoying.

cvl commented 4 years ago

Hi @anjmao

Now it says "Connected" in the app & in the notification, but it's actually not connected.

Also, when I click disconnect, it says "failed to disconnect" (probably because it's not connected really).

Tried with 5+ proposals, all fail in the same way.

cvl commented 4 years ago

After further testing:

This bug is likely related to https://github.com/mysteriumnetwork/node/issues/2051

cvl commented 4 years ago

Doesn't occur anymore, I think we can close this and reopen if I encounter this again.

cvl commented 4 years ago

Still occurred :(

Good news, I managed to reproduce it on emulator as well (with logs).

Steps to reproduce:

Logs from emulator: E/GoLog: 2020-04-29T12:10:30.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/market/mysterium/mysterium_api.go:268 > Total proposals: 1 supported: 1 E/GoLog: 2020-04-29T12:10:30.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/manager.go:624 > Connection state: NotConnected -> Connecting E/GoLog: 2020-04-29T12:10:30.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/eventbus/event_bus.go:81 > Published topic="State" event={State:Connecting SessionInfo:{StartedAt:2020-04-29 12:10:30.614573 +0000 UTC m=+21.430019001 ConsumerID:{Address:0x60ddda3db5e89bd8340f18bfa69c43cbb2988790} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID: Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:MD City:Chișinău Municipality ASN:31252 ISP:SC StarNet SRL NodeType:residential} LocationOriginate:{Continent:EU Country:MD City:Chișinău Municipality ASN:31252 ISP:SC StarNet SRL NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:1m0s Bytes:7669584 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8 ProviderContacts:[{Type:nats/v1 Definition:{Topic:0x5e375a2a467400fd9eaa9 b8ada4e721f1834f5e8.wireguard BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}} 2020-04-29T12:10:30.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/manager.go:206 > Provider 0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8 doesn't support p2p, will fallback to dialog E/GoLog: 2020-04-29T12:10:30.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/dialog/dialog_establisher.go:53 > Establishing dialog to: market.Contact{Type:"nats/v1", Definition:discovery.ContactNATSV1{Topic:"0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8.wireguard", BrokerAddresses:[]string{"nats://testnet-broker.mysterium.network:4222"}}} 2020-04-29T12:10:30.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/connector.go:45 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222 2020-04-29T12:10:30.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/state/state.go:359 > Session ID Connecting duration: 2.84ms data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST 2020-04-29T12:10:30.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access E/GoLog: 2020-04-29T12:10:30.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/sender.go:76 > Request "0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8.wireguard.dialog-create" sending: {"payload":{"peer_id":"0x60ddda3db5e89bd8340f18bfa69c43cbb2988790","version":"v1"},"signature":"iZr45UDi/ZaPhKKGoL6fC4H/pEP+ZJ/SpHiF9PEfyw8RtAfrqf+zOl+YiiRuJWo5m7KE8WCCQDsb7ISMyhhaLAA="} E/GoLog: 2020-04-29T12:10:30.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/sender.go:83 > Received response for "0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8.wireguard.dialog-create": {"payload":{"reason":200,"reasonMessage":"OK","topic":"b9792a90-9099-40f7-bc65-cc0527db848b"},"signature":"kNXs+/3+I4vw73i2qy2YRQMh7jHz9WzuoiwpnjVqvWg0V6Xh7xGI8dDw6LOeLPAovky9POeM5CRx7N0SYh37ugE="} E/GoLog: 2020-04-29T12:10:30.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/dialog/dialog_establisher.go:72 > Dialog established with: market.Contact{Type:"nats/v1", Definition:discovery.ContactNATSV1{Topic:"0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8.wireguard", BrokerAddresses:[]string{"nats://testnet-broker.mysterium.network:4222"}}} E/GoLog: 2020-04-29T12:10:31.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/ip/resolver.go:103 > IP detected: 86.38.130.251 2020-04-29T12:10:31.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/port/pool.go:68 > Supplying port 40036 2020-04-29T12:10:31.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/port/pool.go:68 > Supplying port 49083 E/GoLog: 2020-04-29T12:10:31.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/port/pool.go:68 > Supplying port 46169 E/GoLog: 2020-04-29T12:10:31.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/port/pool.go:68 > Supplying port 46223 2020-04-29T12:10:31.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/port/pool.go:68 > Supplying port 41076 2020-04-29T12:10:31.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/port/pool.go:68 > Supplying port 42201 E/GoLog: 2020-04-29T12:10:31.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/port/pool.go:68 > Supplying port 44248 2020-04-29T12:10:31.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/port/pool.go:68 > Supplying port 42134 E/GoLog: 2020-04-29T12:10:31.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/port/pool.go:68 > Supplying port 48783 E/GoLog: 2020-04-29T12:10:31.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/port/pool.go:68 > Supplying port 47206 E/GoLog: 2020-04-29T12:10:31.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/sender.go:76 > Request "b9792a90-9099-40f7-bc65-cc0527db848b.session-create" sending: {"payload":{"proposal_id":1,"config":{"PublicKey":"KsAg4cvvPnGz5WWtybtpS9KEDAJg9DZ2oGFe9XF+5SY=","IP":"86.38.130.251","Ports":[40036,49083,46169,46223,41076,42201,44248,42134,48783,47206]},"consumer_info":{"issuerID":{"address":"0x60ddda3db5e89bd8340f18bfa69c43cbb2988790"},"accountantID":{"address":"0x0214281cf15c1a66b51990e2e65e1f7b7c363318"},"paymentVersion":"v3"}},"signature":"UAMn0FReF8bnrBlb2UJRaRaqc1sStnSJjdanq6hgktU2jdGAM4afyphCMDjNWOGoZLOesY/BjRU2kuBFbnZnLAA="} E/GoLog: 2020-04-29T12:10:35.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/sender.go:83 > Received response for "b9792a90-9099-40f7-bc65-cc0527db848b.session-create": {"payload":{"success":true,"message":"","session":{"id":"4205bedc-f38d-449a-aaf5-e2caccee3e4a","config":{"local_port":0,"remote_port":0,"ports":null,"provider":{"public_key":"oJUI+ZwZfEGTP9BXP+KDb9gzf1FnWvL+zVCQ7EGFHHM=","endpoint":"89.28.106.145:48788"},"consumer":{"ip_address":"10.182.0.2/24","dns_ips":"10.182.0.1","connect_delay":2000}}},"paymentInfo":{"supported":"v3"}},"signature":"LSxJTysa1RzP2QwhiR91st8xMRW0+UEHyA4K8iAXeKAohvOVwVblfvL4RINgrqIXYXFsn5+NpBKpfG1Rt4ciCAE="} E/GoLog: 2020-04-29T12:10:35.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Created SessionInfo:{StartedAt:2020-04-29 12:10:30.614573 +0000 UTC m=+21.430019001 ConsumerID:{Address:0x60ddda3db5e89bd8340f18bfa69c43cbb2988790} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID:4205bedc-f38d-449a-aaf5-e2caccee3e4a Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:MD City:Chișinău Municipality ASN:31252 ISP:SC StarNet SRL NodeType:residential} LocationOriginate:{Continent:EU Country:MD City:Chișinău Municipality ASN:31252 ISP:SC StarNet SRL NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:1m0s Bytes:7669584 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8 ProviderContacts:[{Type:nats/v1 Defin ition:{Topic:0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8.wireguard BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}} E/GoLog: 2020-04-29T12:10:35.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/consumer/session/session_storage.go:178 > Session 4205bedc-f38d-449a-aaf5-e2caccee3e4a saved E/GoLog: 2020-04-29T12:10:35.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/consumer/statistics/reporter.go:123 > Session statistics reporter started 2020-04-29T12:10:35.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/factory.go:217 > Using new payments E/GoLog: 2020-04-29T12:10:35.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/invoice_payer.go:120 > Starting... E/GoLog: 2020-04-29T12:10:36.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/ip/resolver.go:103 > IP detected: 86.38.130.251 E/GoLog: 2020-04-29T12:10:36.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/wireguard_connection_setup.go:233 > Creating tunnel device E/GoLog: 2020-04-29T12:10:36.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/dns_option.go:86 > Selecting DNS servers using strategy: auto E/GoLog: 2020-04-29T12:10:36.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/dns_option.go:96 > Attempting to use provider DNS E/GoLog: 2020-04-29T12:10:36.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/wireguard_connection_setup.go:338 > Delaying tunnel creation for 2000 milliseconds E/GoLog: 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/receiver.go:54 > Message "b9792a90-9099-40f7-bc65-cc0527db848b.session-invoice" received: {"payload":{"invoice":{"AgreementID":2323732120932154078,"AgreementTotal":1048,"TransactorFee":0,"Hashlock":"13b1a146e2bf92beb280b7f8d9d47a12ccb47195dc6d16f2d1a3f2c6f3829a23","Provider":"0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8"}},"signature":"L4B0Jaq3tncb1AVdxqJH8p9RhSdq2AJgGw3AjCPzmp9fiJv7ZEDW8cpy/VADE+my0EK4vNJWhcEcEJ0VvK+IQgE="} E/GoLog: 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/invoice_payer.go:139 > Invoice received: {2323732120932154078 1048 0 13b1a146e2bf92beb280b7f8d9d47a12ccb47195dc6d16f2d1a3f2c6f3829a23 0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8} E/GoLog: 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/price_calculator.go:67 > Calculated price 1384. Time component: 1384, data component: 0 E/GoLog: 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/invoice_payer.go:180 > Estimated tolerance 1.611, upper bound 2229 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/invoice_payer.go:229 > Loaded previous state: already promised: 3718 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/session/pingpong/invoice_payer.go:230 > Incrementing promised amount by 1048 E/GoLog: 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/sender.go:56 > Message "b9792a90-9099-40f7-bc65-cc0527db848b.session-exchange" sending: {"payload":{"exchangeMessage":{"Promise":{"ChannelID":"SGRfersXdqQIZvII9YXulibeB1A=","Amount":4766,"Fee":0,"Hashlock":"E7GhRuK/kr6ygLf42dR6Esy0cZXcbRby0aPyxvOCmiM=","R":null,"Signature":"J0tWy+l37E3200YpzchVIh+734e9RXQF9uFjDUk139A65n/nJ8a7i5WNZ9wbczV2WQToNxdJZKlOYlbhMLx+SRw="},"AgreementID":2323732120932154078,"AgreementTotal":1048,"Provider":"0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8","Signature":"f18d0a0d31e62186bdb1ce1b76758f2ce2378020d667741eedd697f43477b4c45c3a85ad735376a092b53f621d6c3895d2c593bd71d631f24d4602b134cd4e081c"}},"signature":"OTP1MSPHFQC8dCapBeiXsz9Hru1ljVDixVaDNYZOhYR41dbyzjvRVq4tqSAqY2mZBMdkQHhVKkhXvCsBaz6y1gE="} E/GoLog: 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/eventbus/event_bus.go:81 > Published topic="invoice_paid" event={ConsumerID:{Address:0x60ddda3db5e89bd8340f18bfa69c43cbb2988790} SessionID:4205bedc-f38d-449a-aaf5-e2caccee3e4a Invoice:{AgreementID:2323732120932154078 AgreementTotal:1048 TransactorFee:0 Hashlock:13b1a146e2bf92beb280b7f8d9d47a12ccb47195dc6d16f2d1a3f2c6f3829a23 Provider:0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8}} E/GoLog: 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/consumer/session/session_storage.go:132 > Session 4205bedc-f38d-449a-aaf5-e2caccee3e4a updated E/GoLog: 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/eventbus/event_bus.go:81 > Published topic="consumer_grand_total_change" event={Current:4766 AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] ConsumerID:{Address:0x60ddda3db5e89bd8340f18bfa69c43cbb2988790}} E/GoLog: 2020-04-29T12:10:37.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0x60ddda3db5e89bd8340f18bfa69c43cbb2988790} Previous:689996282 Current:689995234} E/GoLog: 2020-04-29T12:10:37.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/state/state.go:402 > Session ID Connecting duration: 7.030985s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000010MYST E/GoLog: 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/wireguard_connection_setup.go:346 > Tun value is: 100 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/wireguard_connection_setup.go:351 > Name value: tun0 I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: event worker - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: decryption worker - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: encryption worker - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: encryption worker - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: handshake worker - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: handshake worker - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: encryption worker - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: encryption worker - started I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: decryption worker - started I/chatty: uid=10140(network.portals.vpn) identical 1 line I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: decryption worker - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: handshake worker - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: handshake worker - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: TUN reader - started I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 UAPI: Updating private key DEBUG: [userspace-wg]2020/04/29 12:10:38 UAPI: Updating listen port I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 UAPI: Transition to peer configuration DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - UAPI: Created DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - UAPI: Updating persistent keepalive interval I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - UAPI: Updating endpoint DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - UAPI: Adding allowedip DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - UAPI: Adding allowedip DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: receive incoming IPv6 - started DEBUG: [userspace-wg]2020/04/29 12:10:38 Routine: receive incoming IPv4 - started I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 UDP bind has been updated DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - Starting... I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - Routine: sequential receiver - started DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - Routine: sequential sender - started DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - Routine: nonce worker - started I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - Sending keepalive packet I/[Wg tun setup]: Protecting: 99 Success: true I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - Sending handshake initiation I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - Awaiting keypair I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - Received handshake response I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:38 peer(oJUI…FHHM) - Obtained awaited keypair E/GoLog: 2020-04-29T12:10:38.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/mobile/mysterium/wireguard_connection_setup.go:154 > Connected successfully 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/firewall/outgoing_firewall_noop.go:40 > Outgoing traffic block requested E/GoLog: 2020-04-29T12:10:38.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/manager.go:724 > waiting for connected state 2020-04-29T12:10:38.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/manager.go:759 > Connection state received: Connecting E/GoLog: 2020-04-29T12:10:38.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/manager.go:734 > Connected started event received E/GoLog: 2020-04-29T12:10:38.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/manager.go:759 > Connection state received: Connected E/GoLog: 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/manager.go:624 > Connection state: Connecting -> Connected 2020-04-29T12:10:38.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/sender.go:56 > Message "b9792a90-9099-40f7-bc65-cc0527db848b.session-aknowledge" sending: {"payload":{"acknowledgeMessage":{"sessionId":"4205bedc-f38d-449a-aaf5-e2caccee3e4a"}},"signature":"wXOF5WATTD2B6FV3/J9Pr8OAanYj74gx5PMdgKsd3Zxa970TuQ2rbSz9E8sHRaPnmcx2wOUYsUJ5F+hRHAiH/wE="} E/GoLog: 2020-04-29T12:10:38.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/eventbus/event_bus.go:81 > Published topic="State" event={State:Connected SessionInfo:{StartedAt:2020-04-29 12:10:30.614573 +0000 UTC m=+21.430019001 ConsumerID:{Address:0x60ddda3db5e89bd8340f18bfa69c43cbb2988790} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connected SessionID:4205bedc-f38d-449a-aaf5-e2caccee3e4a Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:MD City:Chișinău Municipality ASN:31252 ISP:SC StarNet SRL NodeType:residential} LocationOriginate:{Continent:EU Country:MD City:Chișinău Municipality ASN:31252 ISP:SC StarNet SRL NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:1m0s Bytes:7669584 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8 ProviderContacts:[{Type:nats/v1 Definit ion:{Topic:0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8.wireguard BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}} E/GoLog: 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/cmd/di.go:852 > Reconnecting HTTP clients due to VPN connection state change 2020-04-29T12:10:38.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/core/location/oracle_resolver.go:41 > Detecting with oracle resolver 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/connector.go:85 > Attempting to reconnect to broker (2 connections) 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/connector.go:91 > Re-establishing broker connection c9ba17d8-c8b8-45a7-b7ca-bf3dfb8bc57b E/GoLog: 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/connector.go:91 > Re-establishing broker connection 607356f7-23b2-402a-8853-28e72f7a816c 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/connector.go:95 > Re-establishing broker connection c9ba17d8-c8b8-45a7-b7ca-bf3dfb8bc57b DONE 2020-04-29T12:10:38.000 WRN ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/connection_wrap.go:86 > NATS: disconnected 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/state/state.go:359 > Session ID 4205bedc-f38d-449a-aaf5-e2caccee3e4a Connected duration: 7.834113s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000010MYST E/GoLog: 2020-04-29T12:10:38.000 WRN ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/connection_wrap.go:86 > NATS: disconnected E/GoLog: 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/connector.go:95 > Re-establishing broker connection 607356f7-23b2-402a-8853-28e72f7a816c DONE E/GoLog: 2020-04-29T12:10:38.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/communication/nats/connector.go:100 > All broker connections re-established I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:10:51 peer(oJUI…FHHM) - Receiving keepalive packet E/GoLog: 2020-04-29T12:10:58.000 ERR ext-go/1/src/github.com/mysteriumnetwork/node/core/location/cache.go:91 > Location update failed error="failed to execute request: Get https://testnet-location.mysterium.network/api/v1/location: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)" E/GoLog: 2020-04-29T12:11:00.000 ERR ext-go/1/src/github.com/mysteriumnetwork/node/core/quality/mysterium_morqa.go:98 > Failed to sent batch metrics request error="Post https://quality.mysterium.network/api/v1/batch: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)" I/GoLog: DEBUG: [userspace-wg]2020/04/29 12:11:02 peer(oJUI…FHHM) - Receiving keepalive packet E/GoLog: 2020-04-29T12:11:06.000 INF ext-go/1/src/github.com/mysteriumnetwork/node/core/connection/manager.go:624 > Connection state: Connected -> Disconnecting E/GoLog: 2020-04-29T12:11:06.000 DBG ext-go/1/src/github.com/mysteriumnetwork/node/eventbus/event_bus.go:81 > Published topic="State" event={State:Disconnecting SessionInfo:{StartedAt:2020-04-29 12:10:30.614573 +0000 UTC m=+21.430019001 ConsumerID:{Address:0x60ddda3db5e89bd8340f18bfa69c43cbb2988790} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:4205bedc-f38d-449a-aaf5-e2caccee3e4a Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:MD City:Chișinău Municipality ASN:31252 ISP:SC StarNet SRL NodeType:residential} LocationOriginate:{Continent:EU Country:MD City:Chișinău Municipality ASN:31252 ISP:SC StarNet SRL NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:1m0s Bytes:7669584 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8 ProviderContacts:[{Type:nats/v1 E/GoLog: Definition:{Topic:0x5e375a2a467400fd9eaa9b8ada4e721f1834f5e8.wireguard BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}

cvl commented 4 years ago

Extra clue: After this happens, the app cannot connect to any other provider (stuck in connecting). Although disconnect works when in connecting state (though sometimes throws message "disconnect failed".

After app relaunch - it works again.

cvl commented 4 years ago

On MacOs similar thing happens: stuck in connecting, and after 3rd click it crashes the app (the app refreshes browser window I guess).

Also, after quitting app, it still stuck in this intermediary state:

Logs (in dev mode): Browser console: react_devtools_backend.js:6 Failed to disconnect timeout of 5000ms exceeded (path="connection") r @ react_devtools_backend.js:6 disconnect @ store.ts?ea21:228 async function (async) disconnect @ store.ts?ea21:226 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:908 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895 onClickPowerButton @ vpn-main-view.tsx?6df9:104 callCallback @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:188 invokeGuardedCallbackDev @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:237 invokeGuardedCallback @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:292 invokeGuardedCallbackAndCatchFirstError @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:306 executeDispatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:389 executeDispatchesInOrder @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:414 executeDispatchesAndRelease @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3278 executeDispatchesAndReleaseTopLevel @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3287 forEachAccumulated @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3259 runEventsInBatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3304 runExtractedPluginEventsInBatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3514 handleTopLevel @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3558 batchedEventUpdates$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:21871 batchedEventUpdates @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:795 dispatchEventForLegacyPluginEventSystem @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3568 attemptToDispatchEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4267 dispatchEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4189 unstable_runWithPriority @ /Users/xxx/dev/app/desktop-vpn/node_modules/scheduler/cjs/scheduler.development.js:653 runWithPriority$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:11039 discreteUpdates$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:21887 discreteUpdates @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:806 dispatchDiscreteEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4168 react_devtools_backend.js:6 TequilapiError: timeout of 5000ms exceeded (path="proposals") at new TequilapiError (/Users/xxx/dev/app/desktop-vpn/node_modules/mysterium-vpn-js/lib/tequilapi-error.js:35:28) at /Users/xxx/dev/app/desktop-vpn/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:60:27 at step (/Users/xxx/dev/app/desktop-vpn/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:39:23) at Object.throw (/Users/xxx/dev/app/desktop-vpn/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:20:53) at rejected (/Users/xxx/dev/app/desktop-vpn/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:12:65) r @ react_devtools_backend.js:6 eval @ countries-store.ts?2d95:87 Promise.catch (async) fetchCountries @ countries-store.ts?2d95:87 eval @ countries-store.ts?2d95:49 3react_devtools_backend.js:6 Failed to disconnect timeout of 5000ms exceeded (path="connection") r @ react_devtools_backend.js:6 disconnect @ store.ts?ea21:228 async function (async) disconnect @ store.ts?ea21:226 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:908 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895 onClickPowerButton @ vpn-main-view.tsx?6df9:104 callCallback @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:188 invokeGuardedCallbackDev @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:237 invokeGuardedCallback @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:292 invokeGuardedCallbackAndCatchFirstError @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:306 executeDispatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:389 executeDispatchesInOrder @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:414 executeDispatchesAndRelease @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3278 executeDispatchesAndReleaseTopLevel @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3287 forEachAccumulated @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3259 runEventsInBatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3304 runExtractedPluginEventsInBatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3514 handleTopLevel @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3558 batchedEventUpdates$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:21871 batchedEventUpdates @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:795 dispatchEventForLegacyPluginEventSystem @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3568 attemptToDispatchEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4267 dispatchEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4189 unstable_runWithPriority @ /Users/xxx/dev/app/desktop-vpn/node_modules/scheduler/cjs/scheduler.development.js:653 runWithPriority$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:11039 discreteUpdates$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:21887 discreteUpdates @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:806 dispatchDiscreteEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4168 react_devtools_backend.js:6 Healthcheck failed: timeout of 500ms exceeded (path="healthcheck") r @ react_devtools_backend.js:6 healthcheck @ store.ts?6747:73 async function (async) healthcheck @ store.ts?6747:70 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:908 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895 eval @ store.ts?6747:37 react_devtools_backend.js:6 Failed to disconnect timeout of 5000ms exceeded (path="connection") r @ react_devtools_backend.js:6 disconnect @ store.ts?ea21:228 async function (async) disconnect @ store.ts?ea21:226 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:908 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895 onClickPowerButton @ vpn-main-view.tsx?6df9:104 callCallback @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:188 invokeGuardedCallbackDev @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:237 invokeGuardedCallback @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:292 invokeGuardedCallbackAndCatchFirstError @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:306 executeDispatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:389 executeDispatchesInOrder @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:414 executeDispatchesAndRelease @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3278 executeDispatchesAndReleaseTopLevel @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3287 forEachAccumulated @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3259 runEventsInBatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3304 runExtractedPluginEventsInBatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3514 handleTopLevel @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3558 batchedEventUpdates$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:21871 batchedEventUpdates @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:795 dispatchEventForLegacyPluginEventSystem @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3568 attemptToDispatchEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4267 dispatchEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4189 unstable_runWithPriority @ /Users/xxx/dev/app/desktop-vpn/node_modules/scheduler/cjs/scheduler.development.js:653 runWithPriority$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:11039 discreteUpdates$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:21887 discreteUpdates @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:806 dispatchDiscreteEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4168 react_devtools_backend.js:6 Healthcheck failed: timeout of 500ms exceeded (path="healthcheck") r @ react_devtools_backend.js:6 healthcheck @ store.ts?6747:73 async function (async) healthcheck @ store.ts?6747:70 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:908 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895 eval @ store.ts?6747:37 3react_devtools_backend.js:6 Failed to disconnect timeout of 5000ms exceeded (path="connection")

react_devtools_backend.js:6 Failed to disconnect timeout of 5000ms exceeded (path="connection") r @ react_devtools_backend.js:6 disconnect @ store.ts?ea21:228 async function (async) disconnect @ store.ts?ea21:226 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:908 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895 onClickPowerButton @ vpn-main-view.tsx?6df9:104 callCallback @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:188 invokeGuardedCallbackDev @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:237 invokeGuardedCallback @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:292 invokeGuardedCallbackAndCatchFirstError @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:306 executeDispatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:389 executeDispatchesInOrder @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:414 executeDispatchesAndRelease @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3278 executeDispatchesAndReleaseTopLevel @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3287 forEachAccumulated @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3259 runEventsInBatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3304 runExtractedPluginEventsInBatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3514 handleTopLevel @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3558 batchedEventUpdates$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:21871 batchedEventUpdates @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:795 dispatchEventForLegacyPluginEventSystem @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:3568 attemptToDispatchEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4267 dispatchEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4189 unstable_runWithPriority @ /Users/xxx/dev/app/desktop-vpn/node_modules/scheduler/cjs/scheduler.development.js:653 runWithPriority$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:11039 discreteUpdates$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:21887 discreteUpdates @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:806 dispatchDiscreteEvent @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:4168 react_devtools_backend.js:6 TequilapiError: timeout of 5000ms exceeded (path="proposals") at new TequilapiError (/Users/xxx/dev/app/desktop-vpn/node_modules/mysterium-vpn-js/lib/tequilapi-error.js:35:28) at /Users/xxx/dev/app/desktop-vpn/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:60:27 at step (/Users/xxx/dev/app/desktop-vpn/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:39:23) at Object.throw (/Users/xxx/dev/app/desktop-vpn/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:20:53) at rejected (/Users/xxx/dev/app/desktop-vpn/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:12:65) r @ react_devtools_backend.js:6 eval @ countries-store.ts?2d95:87 Promise.catch (async) fetchCountries @ countries-store.ts?2d95:87 eval @ countries-store.ts?2d95:49 react_devtools_backend.js:6 Error while checking if activation expired Error: Network Error at createError (createError.js?2d83:16) at XMLHttpRequest.handleError (xhr.js?b50d:83) r @ react_devtools_backend.js:6 checkIfActivationExpired @ activation-store.ts?d133:64 async function (async) checkIfActivationExpired @ activation-store.ts?d133:55 eval @ activation-store.ts?d133:45 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:908 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895 reactionRunner @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:2137 (anonymous) @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:2117 Reaction.runReaction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1752 runReactionsHelper @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1889 reactionScheduler @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1867 (anonymous) @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1896 batchedUpdates$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:21856 reactionScheduler @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1896 runReactions @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1872 endBatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1572 _endAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:961 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:915 runInAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:2040 ConfigStore.fetchConfig @ store.ts?42d9:50 async function (async) ConfigStore.fetchConfig @ store.ts?42d9:49 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:908 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895 eval @ store.ts?42d9:40 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:908 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895 reactionRunner @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:2137 (anonymous) @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:2117 Reaction.runReaction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1752 runReactionsHelper @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1889 reactionScheduler @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1867 (anonymous) @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1896 batchedUpdates$1 @ /Users/xxx/dev/app/desktop-vpn/node_modules/react-dom/cjs/react-dom.development.js:21856 reactionScheduler @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1896 runReactions @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1872 endBatch @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:1572 _endAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:961 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:915 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895 healthcheck @ store.ts?6747:71 async function (async) healthcheck @ store.ts?6747:70 executeAction @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:908 healthcheck @ /Users/xxx/dev/app/desktop-vpn/node_modules/mobx/lib/mobx.js:895

Electron console: ┏ Electron -------------------

Connected to: /var/run/myst.sock

┗ ---------------------------- ┏ Electron -------------------

Server: FAIL

┗ ----------------------------

Supervisor logs (outputs only if I click disconnect multiple times):

2020/04/29 15:52:11 Waiting for connections... 2020/04/29 15:52:11 Client connected: unix 2020/04/29 15:52:11 myst output [err=exit status 1]: 2020-04-29T15:52:11.490 DBG Users/tadas/mygo/node/config/config.go:73 > Loading user configuration: /Users/xxx/dev/app/desktop-vpn/static/config/config.toml 2020-04-29T15:52:11.491 INF Users/tadas/mygo/node/config/config.go:83 > User configuration loaded: 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value data-dir:/Users/xxx/.mysterium 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value config-dir:/Users/xxx/dev/app/desktop-vpn/static/config 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value runtime-dir:/Users/xxx/dev/app/desktop-vpn/static 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value tequilapi.address:127.0.0.1 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value tequilapi.port:4050 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value bind.address:0.0.0.0 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:172 > Returning CLI value ui.enable:false 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value ui.port:4449 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value feedback.url:https://feedback.mysterium.network 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value keystore.lightweight:false 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value log-dir:/Users/xxx/.mysterium/logs 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value log-level:debug 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value log.http:false 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value testnet:false 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value localnet:false 2020-04-29T15:52:11.493 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value experiment-natpunching:true 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value api.address:https://testnet-api.mysterium.network/v1 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value broker-address:nats://testnet-broker.mysterium.network 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value ether.client.rpc:wss://goerli.infura.io/ws/v3/c2c7da73fcc84ec5885a7bb0eb3c3637 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value discovery.type:[api broker] 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value discovery.ping:3m0s 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value discovery.fetch:3m0s 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value mymysterium.url:https://my.mysterium.network/api/v1 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:172 > Returning CLI value mymysterium.enabled:false 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value quality.type:morqa 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value quality.address:https://quality.mysterium.network/api/v1 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value ip-detector:https://testnet-location.mysterium.network/api/v1/location 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value location.type:oracle 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value location.address:https://testnet-location.mysterium.network/api/v1/location 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value location.country: 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value location.city: 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value location.node-type: 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value transactor.address:https://testnet-transactor.mysterium.network/api/v1 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value transactor.registry-address:0x3dD81545F3149538EdCb6691A4FfEE1898Bd2ef0 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value transactor.channel-implementation:0x3026eB9622e2C5bdC157C6b117F7f4aC2C2Db3b5 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value transactor.provider.max-registration-attempts:10 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value transactor.provider.registration-retry-delay:3m0s 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value transactor.provider.registration-stake:6200000000 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.accountant.max.fee:1500 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.bc.timeout:30s 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.accountant.promise.threshold:0.1 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.accountant.promise.timeout:2h0m0s 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.mystscaddress:0x7753cfAD258eFbC52A9A1452e42fFbce9bE486cb 2020-04-29T15:52:11.494 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.consumer.price-pergib-max:7000000 2020-04-29T15:52:11.495 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.consumer.price-pergib-min:0 2020-04-29T15:52:11.495 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.consumer.price-perminute-max:50000 2020-04-29T15:52:11.495 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.consumer.price-perminute-min:0 2020-04-29T15:52:11.495 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.consumer.data-leeway-megabytes:20 2020-04-29T15:52:11.495 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value payments.provider.invoice-frequency:1m0s 2020-04-29T15:52:11.495 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value accountant.accountant-id:0x0214281cf15C1a66b51990e2E65e1f7b7C363318 2020-04-29T15:52:11.495 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value accountant.address:https://testnet-accountant.mysterium.network/api/v2 2020-04-29T15:52:11.495 DBG Users/tadas/mygo/node/config/config.go:172 > Returning CLI value openvpn.binary:/Users/xxx/dev/app/desktop-vpn/static/openvpn 2020-04-29T15:52:11.495 DBG Users/tadas/mygo/node/config/config.go:181 > Returning default value firewall.killSwitch.always:false 2020-04-29T15:52:11.495 INF Users/tadas/mygo/node/logconfig/config.go:65 > Log level: debug 2020-04-29T15:52:11.495 INF Users/tadas/mygo/node/logconfig/config.go:67 > Log file path: /Users/xxx/.mysterium/logs/mysterium-node 2020-04-29T15:52:11.495 DBG Users/tadas/mygo/node/logconfig/config_rollingwriter.go:70 > Found 0 old log files in log directory, skipping cleanup 2020-04-29T15:52:11.495 INF Users/tadas/mygo/node/cmd/di.go:172  > Starting Mysterium Node source.dev-build 2020-04-29T15:52:11.496 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:35 > Rules reset was requested 2020-04-29T15:52:11.496 ERR Users/tadas/mygo/node/cmd/mysterium_node/mysterium_node.go:58 > Failed to execute command: error="the port 4050 seems to be taken. Either you're already running a node or it is already used by another application: listen tcp 127.0.0.1:4050: bind: address already in use"

2020/04/29 15:52:11 Could not run myst: exit status 1

anjmao commented 4 years ago

Hi, I think this issue is fixes in node, but not released yet. I will check and let you know when it’s released.

cvl commented 4 years ago

Thanks!

cvl commented 4 years ago

Doesn't reoccur anymore.