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

[windows, bug] cannot connect to many provider #2394

Closed
cvl opened this issue Jun 18, 2020 · 8 comments
Closed

[windows, bug] cannot connect to many provider #2394

cvl opened this issue Jun 18, 2020 · 8 comments
Assignees
@tadaskay
Labels
bug component:desktop system:windows

Comments

@cvl
Copy link

cvl commented Jun 18, 2020

Can't connect to any provider, logs:

http://localhost:4050/healthcheck

{"uptime":"16m45.786519s","process":4936,"version":"0.34.1-1snapshot-20200618T0823-42eb3022","build_info":{"commit":"42eb3022","branch":"master","build_number":"157519540"}}

Electron console:

C:\Users\gordon\Desk…ports\console.js:91 13:54:35.921 › Server: ok: 0.34.1-1snapshot-20200618T0823-42eb3022
C:\Users\gordon\Desk…ports\console.js:91 13:54:35.922 › Running supervisor version: 0.34.1-1snapshot-20200618T0823-42eb3022
C:\Users\gordon\Desk…ports\console.js:91 13:54:35.924 › Running supervisor version is compatible, skipping the upgrade
C:\Users\gordon\Desk…ports\console.js:91 13:54:36.074 › myst process exited with code 1
C:\Users\gordon\Desk…ports\console.js:91 13:54:36.349 › [sudo-exec] 2020-06-18T13:54:35.000 INF Installing supervisor with options: install.Options{SupervisorPath:"C:\Users\gordon\Desktop\xx\desktop-vpn\static\bin\myst_supervisor.exe"}
2020-06-18T13:54:35.000 INF Checking previous installation
2020-06-18T13:54:35.000 INF Uninstalled previous service
2020-06-18T13:54:35.000 INF Supervisor installed
C:\Users\gordon\Desk…adapters\xhr.js:178 PUT http://127.0.0.1:4050/connection 500 (Internal Server Error)
C:\Users\gordon\Desk…ports\console.js:91 13:54:50.332 › Could not connect Request failed with status code 500 (path="connection")
C:\Users\gordon\Desk…adapters\xhr.js:178 PUT http://127.0.0.1:4050/connection 500 (Internal Server Error)
C:\Users\gordon\Desk…ports\console.js:91 13:54:57.198 › Could not connect Request failed with status code 500 (path="connection")
C:\Users\gordon\Desk…adapters\xhr.js:178 PUT http://127.0.0.1:4050/connection 500 (Internal Server Error)
C:\Users\gordon\Desk…ports\console.js:91 13:54:59.548 › Could not connect Request failed with status code 500 (path="connection")

renderer.logs
[2020-06-18 13:54:32.814] [error] Failed to connect to the supervisor, installing connect ENOENT \.\pipe\mystpipe
[2020-06-18 13:54:34.699] [info] Daemon is starting, suspending healthcheck
[2020-06-18 13:54:50.332] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:54:57.198] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:54:59.548] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:55:06.348] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:55:13.220] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:55:23.313] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:55:34.568] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:55:40.747] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:55:42.760] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:55:45.899] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:56:38.718] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:56:49.962] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:56:55.064] [error] Could not connect Request failed with status code 500 (path="connection")
[2020-06-18 13:56:58.336] [error] Could not connect Request failed with status code 500 (path="connection")

main.log
[2020-06-18 13:54:35.847] [info] Connected to: \.\pipe\mystpipe
[2020-06-18 13:54:35.909] [debug] Supervisor stdout: 0.34.1-1snapshot-20200618T0823-42eb3022

[2020-06-18 13:54:35.918] [info] Bundled supervisor version: 0.34.1-1snapshot-20200618T0823-42eb3022

[2020-06-18 13:54:35.921] [info] Server: ok: 0.34.1-1snapshot-20200618T0823-42eb3022

[2020-06-18 13:54:35.922] [info] Running supervisor version: 0.34.1-1snapshot-20200618T0823-42eb3022

[2020-06-18 13:54:35.924] [info] Running supervisor version is compatible, skipping the upgrade
[2020-06-18 13:54:36.074] [info] myst process exited with code 1
[2020-06-18 13:54:36.349] [info] [sudo-exec] 2020-06-18T13:54:35.000 INF Installing supervisor with options: install.Options{SupervisorPath:"C:\Users\gordon\Desktop\xx\desktop-vpn\static\bin\myst_supervisor.exe"}
2020-06-18T13:54:35.000 INF Checking previous installation
2020-06-18T13:54:35.000 INF Uninstalled previous service
2020-06-18T13:54:35.000 INF Supervisor installed
@cvl cvl added the bug label Jun 18, 2020
@cvl
Copy link
Author

cvl commented Jun 18, 2020 •
edited

mysterium-node.log:

2020-06-18T15:56:17.257 DBG source/logconfig/rollingwriter/rollingwriter.go:76 > Found 0 old log files in log directory, skipping cleanup
2020-06-18T15:56:17.257 INF source/cmd/di.go:174 > Starting Mysterium Node 0.34.2
2020-06-18T15:56:17.259 DBG source/config/config.go:186 > Returning default value outgoing-firewall:false
2020-06-18T15:56:17.259 DBG source/config/config.go:186 > Returning default value incoming-firewall:false
2020-06-18T15:56:17.259 INF source/firewall/incoming_firewall_noop.go:32 > Rules bootstrap was requested
2020-06-18T15:56:17.260 DBG source/config/config.go:177 > Returning CLI value usermode:true
2020-06-18T15:56:17.260 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL wss://goerli.infura.io/ws/v3/c2c7da73fcc84ec5885a7bb0eb3c3637 access
2020-06-18T15:56:17.260 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-api.mysterium.network/v1 access
2020-06-18T15:56:17.260 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-transactor.mysterium.network/api/v1 access
2020-06-18T15:56:17.260 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-accountant.mysterium.network/api/v2 access
2020-06-18T15:56:17.260 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL wss://goerli.infura.io/ws/v3/c2c7da73fcc84ec5885a7bb0eb3c3637 access
2020-06-18T15:56:17.260 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-api.mysterium.network/v1 access
2020-06-18T15:56:17.260 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-transactor.mysterium.network/api/v1 access
2020-06-18T15:56:17.260 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-accountant.mysterium.network/api/v2 access
2020-06-18T15:56:17.260 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-06-18T15:56:17.260 DBG source/communication/nats/connector.go:39 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222
2020-06-18T15:56:17.260 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-06-18T15:56:17.486 INF source/cmd/di.go:620 > Using Eth endpoint: wss://goerli.infura.io/ws/v3/c2c7da73fcc84ec5885a7bb0eb3c3637
2020-06-18T15:56:18.249 INF source/identity/registry/registry_contract.go:58 > Using registryAddress 0x3dD81545F3149538EdCb6691A4FfEE1898Bd2ef0 accountantAddress 0x0214281cf15C1a66b51990e2E65e1f7b7C363318
2020-06-18T15:56:18.249 DBG source/cmd/di.go:644 > Using lightweight keystore
2020-06-18T15:56:18.250 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-location.mysterium.network/api/v1/location access
2020-06-18T15:56:18.250 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-location.mysterium.network/api/v1/location access
2020-06-18T15:56:18.250 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-location.mysterium.network/api/v1/location access
2020-06-18T15:56:18.250 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-location.mysterium.network/api/v1/location access
2020-06-18T15:56:18.250 DBG source/cmd/di.go:772 > Experimental NAT punching enabled, creating a pinger
2020-06-18T15:56:18.250 DBG source/config/config.go:186 > Returning default value nat-port-mapping:true
2020-06-18T15:56:18.250 DBG source/cmd/di_desktop.go:58 > Skipping services bootstrap for consumer mode
2020-06-18T15:56:18.250 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://quality.mysterium.network/api/v1 access
2020-06-18T15:56:18.250 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://quality.mysterium.network/api/v1 access
2020-06-18T15:56:18.251 DBG source/cmd/di_desktop.go:181 > Skipping accountant promise settler for consumer mode
2020-06-18T15:56:18.251 DBG source/cmd/di_desktop.go:164 > Skipping provider registrar for consumer mode
2020-06-18T15:56:18.251 INF source/feedback/reporter.go:40 > Using feedback API at: https://feedback.mysterium.network
2020-06-18T15:56:18.251 DBG source/config/config.go:186 > Returning default value access-policy.address:https://testnet-trust.mysterium.network/api/v1/access-policies/
2020-06-18T15:56:18.251 DBG source/config/config.go:186 > Returning default value pprof.enable:false
2020-06-18T15:56:18.251 INF source/tequilapi/http_api_server.go:77 > API started on: 127.0.0.1:4050
2020-06-18T15:56:18.251 DBG source/eventbus/event_bus.go:81 > Published topic="Node" event={Status:Started}
2020-06-18T15:56:18.252 INF source/cmd/di.go:254 > Mysterium node started!
2020-06-18T15:56:18.252 DBG source/identity/registry/registry_contract.go:105 > event received {Started}
2020-06-18T15:56:18.252 DBG source/core/location/oracle_resolver.go:41 > Detecting with oracle resolver
2020-06-18T15:56:18.252 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP 239.255.255.250 access
2020-06-18T15:56:18.252 INF source/identity/registry/registry_contract.go:261 > Starting registry...
2020-06-18T15:56:18.252 DBG source/identity/registry/registry_contract.go:274 > Loading initial state
2020-06-18T15:56:18.848 DBG source/core/location/cache.go:112 > original location detected: LT (residential)
2020-06-18T15:56:18.887 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-06-18T15:56:19.058 DBG source/eventbus/event_bus.go:81 > Published topic="identity-created" event=0xc4dccf394e18e28ae707dddde4a9ce26a450280d
2020-06-18T15:56:19.350 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 312 supported: 303
2020-06-18T15:56:19.350 INF source/core/discovery/repository.go:91 > Returning 304 unique proposals
2020-06-18T15:56:19.550 DBG source/identity/manager.go:142 > Caching unlocked address: 0xc4dccf394e18e28ae707dddde4a9ce26a450280d
2020-06-18T15:56:19.550 DBG source/eventbus/event_bus.go:81 > Published topic="identity-unlocked" event=0xc4dccf394e18e28ae707dddde4a9ce26a450280d
2020-06-18T15:56:19.551 DBG source/identity/manager.go:129 > Unlocked identity found in cache, skipping keystore: 0xc4dccf394e18e28ae707dddde4a9ce26a450280d
2020-06-18T15:56:19.926 DBG source/eventbus/event_bus.go:81 > Published topic="transactor_identity_registration" event={RegistryAddress:0x3dD81545F3149538EdCb6691A4FfEE1898Bd2ef0 AccountantID:0x0214281cf15C1a66b51990e2E65e1f7b7C363318 Stake:0 Fee:10000000 Beneficiary:0x9de4a3900da15be1a1ede7caf002d7ff7eb631fb Signature:0xb76457720feb7a3277295fb851e41e10db4053bbe258da4a825f3015a0a9874f0a92b15b4bb482fc7774b39815e7c9903427ea7082b8ed8af1b7557047f3e0111c Identity:0xc4dccf394e18e28ae707dddde4a9ce26a450280d}
2020-06-18T15:56:19.926 DBG source/eventbus/event_bus.go:81 > Published topic="registration_event_topic" event={ID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} Status:InProgress}
2020-06-18T15:56:19.938 INF source/identity/registry/registry_contract.go:176 > Waiting on identities 0xc4DCcf394E18E28Ae707dddDE4a9ce26A450280d accountant 0x0214281cf15C1a66b51990e2E65e1f7b7C363318
2020-06-18T15:56:20.489 DBG source/nat/upnp/discover.go:90 > not a gateway device: map[deviceType:urn:dial-multiscreen-org:device:dialreceiver:1 friendlyName:[TV]Samsung LED48 manufacturer:Samsung Electronics modelName:UE48H6200 modelNo:1.0 server:SHP, UPnP/1.0, Samsung UPnP SDK/1.0]
2020-06-18T15:56:20.632 DBG source/nat/upnp/discover.go:90 > not a gateway device: map[deviceType:urn:schemas-upnp-org:device:MediaRenderer:1 friendlyName:[TV]Samsung LED48 manufacturer:Samsung Electronics modelName:UE48H6200 modelNo:AllShare1.0 server:SHP, UPnP/1.0, Samsung UPnP SDK/1.0]
2020-06-18T15:56:20.665 DBG source/session/pingpong/consumer_balance_tracker.go:308 > Loaded transactor state, current balance: 690000000 MYST
2020-06-18T15:56:20.665 DBG source/eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} Previous:0 Current:690000000}
2020-06-18T15:56:20.774 DBG source/nat/upnp/discover.go:90 > not a gateway device: map[deviceType:urn:samsung.com:device:RemoteControlReceiver:1 friendlyName:[TV]Samsung LED48 manufacturer:Samsung Electronics modelName:UE48H6200 modelNo:1.0 server:SHP, UPnP/1.0, Samsung UPnP SDK/1.0]
2020-06-18T15:56:20.876 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-06-18T15:56:20.913 DBG source/nat/upnp/discover.go:90 > not a gateway device: map[deviceType:urn:samsung.com:device:MainTVServer2:1 friendlyName:[TV]Samsung LED48 manufacturer:Samsung Electronics modelName:UE48H6200 modelNo:1.0 server:SHP, UPnP/1.0, Samsung UPnP SDK/1.0]
2020-06-18T15:56:20.914 INF source/nat/upnp/discover.go:58 > UPnP gateways detected: 1
2020-06-18T15:56:20.914 INF source/nat/upnp/discover.go:60 > UPnP gateway detected map[deviceType:urn:schemas-upnp-org:device:InternetGatewayDevice:1 friendlyName:TL-WR840N manufacturer:TP-Link modelName:TL-WR840N modelNo:6.0 server:Linux/2.6.36, UPnP/1.0, Portable SDK for UPnP devices/1.6.19]
2020-06-18T15:56:21.172 INF source/core/discovery/repository.go:91 > Returning 306 unique proposals
2020-06-18T15:56:21.941 DBG source/session/pingpong/consumer_balance_tracker.go:350 > Loaded accountant state: already promised: 0
2020-06-18T15:56:21.951 DBG source/eventbus/event_bus.go:81 > Published topic="consumer_grand_total_change" event={Current:0 AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d}}
2020-06-18T15:56:22.302 WRN github.com/mysteriumnetwork/payments@v0.0.13/client/retryable_client.go:95 > retry 2 of 3 error="could not get consumers channel: no contract code at given address"
2020-06-18T15:56:22.962 WRN github.com/mysteriumnetwork/payments@v0.0.13/client/retryable_client.go:95 > retry 3 of 3 error="could not get consumers channel: no contract code at given address"
2020-06-18T15:56:23.697 ERR source/session/pingpong/consumer_balance_tracker.go:199 > Could not get consumer channel error="could not get consumers channel: no contract code at given address"
2020-06-18T15:56:24.512 INF source/tequilapi/endpoints/connection.go:159 > identity "0xc4dccf394e18e28ae707dddde4a9ce26a450280d" registration is in progress, continuing...
2020-06-18T15:56:24.721 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 1 supported: 1
2020-06-18T15:56:24.721 INF source/core/connection/manager.go:545 > Connection state: NotConnected -> Connecting
2020-06-18T15:56:24.721 DBG source/communication/nats/connector.go:39 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222
2020-06-18T15:56:24.721 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-06-18T15:56:24.721 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Connecting SessionInfo:{StartedAt:2020-06-18 15:56:24.7210243 +0300 EEST m=+7.564708401 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} 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:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:24.721 INF source/core/state/state.go:359 > Session ID Connecting duration: 0s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:24.925 DBG source/p2p/dialer.go:144 > Consumer 0xc4dccf394e18e28ae707dddde4a9ce26a450280d sending public key 4992fff4d16de2c571cf4651b3b98feba6fb3aee0a5682c34c72f6045a3c2c61 to provider 0x3ec670f5063089fb04f7f4e003e88fd45e9228cc
2020-06-18T15:56:28.103 DBG source/p2p/dialer.go:171 > Consumer 0xc4dccf394e18e28ae707dddde4a9ce26a450280d received provider 0x3ec670f5063089fb04f7f4e003e88fd45e9228cc with config: publicIP:"zzz" ports:47418 ports:49189
2020-06-18T15:56:28.707 DBG source/core/ip/resolver.go:103 > IP detected: xxxx
2020-06-18T15:56:28.708 INF source/core/port/pool.go:68 > Supplying port 45560
2020-06-18T15:56:28.709 INF source/core/port/pool.go:68 > Supplying port 47138
2020-06-18T15:56:28.709 DBG source/p2p/dialer.go:194 > Consumer 0xc4dccf394e18e28ae707dddde4a9ce26a450280d sending ack with encrypted config to provider 0x3ec670f5063089fb04f7f4e003e88fd45e9228cc
2020-06-18T15:56:28.915 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP zzz access
2020-06-18T15:56:28.915 DBG source/p2p/dialer.go:99 > Skipping provider ping
2020-06-18T15:56:28.916 DBG source/p2p/dialer.go:121 > Received handlers ready message from provider
2020-06-18T15:56:28.918 DBG source/p2p/channel.go:200 > Creating p2p channel with local addr: 192.168.0.105:45560, UDP session addr: 127.0.0.1:53035, proxy addr: 127.0.0.1:53034, remote peer addr: x.x.x.x:47418
2020-06-18T15:56:28.918 DBG source/p2p/channel.go:519 > Will use service conn with local port: 47138, remote port: 49189
2020-06-18T15:56:28.919 WRN source/communication/nats/connection_wrap.go:86 > NATS: disconnected
2020-06-18T15:56:28.919 WRN source/communication/nats/connection_wrap.go:85 > NATS: connection closed
2020-06-18T15:56:28.919 INF source/firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://testnet-broker.mysterium.network:4222 removed
2020-06-18T15:56:28.920 DBG source/session/pingpong/invoice_payer.go:120 > Starting...
2020-06-18T15:56:28.920 DBG source/core/connection/manager.go:412 > Sending P2P message to "p2p-session-create": consumer:{id:"0xc4dccf394e18e28ae707dddde4a9ce26a450280d" accountantID:"0x0214281cf15C1a66b51990e2E65e1f7b7C363318" paymentVersion:"v3"} proposalID:1 config:"{"PublicKey":"/sMgNBXhCNWrLopc6AevgSXVJWLbkto9sW/4/PZZzBQ=","Ports":null}"
2020-06-18T15:56:30.165 DBG source/session/pingpong/factory.go:219 > Received P2P message for "p2p-payment-invoice": AgreementID:10267217042888759549 AgreementTotal:1 Hashlock:"0ce09c4d8bda91eb15c620f521270f07fdbfec06499a38924c7ce87f09831f03" Provider:"0x3ec670f5063089fb04f7f4e003e88fd45e9228cc"
2020-06-18T15:56:30.166 DBG source/session/pingpong/invoice_payer.go:139 > Invoice received: {10267217042888759549 1 0 0ce09c4d8bda91eb15c620f521270f07fdbfec06499a38924c7ce87f09831f03 0x3ec670f5063089fb04f7f4e003e88fd45e9228cc}
2020-06-18T15:56:30.166 DBG source/session/pingpong/price_calculator.go:67 > Calculated price 195521. Time component: 208, data component: 195313
2020-06-18T15:56:30.166 DBG source/session/pingpong/invoice_payer.go:180 > Estimated tolerance 1.721, upper bound 336585
2020-06-18T15:56:30.166 DBG source/session/pingpong/invoice_payer.go:229 > Loaded previous state: already promised: 0
2020-06-18T15:56:30.167 DBG source/session/pingpong/invoice_payer.go:230 > Incrementing promised amount by 1
2020-06-18T15:56:30.171 DBG source/session/pingpong/exchange_messaging.go:63 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"\x9d䣐\r\xa1[\xe1\xa1\xed\xe7\xca\xf0\x02\xd7\xff~\xb61\xfb" Amount:1 Hashlock:"\x0c\xe0\x9cM\x8bڑ\xeb\x15\xc6 \xf5!'\x0f\x07\xfd\xbf\xec\x06I\x9a8\x92L|\xe8�\t\x83\x1f\x03" Signature:"\x9a\xd7\x1b\x8dG\xa3,\x8d\xc1K-\x1d\xb4I\xce ǭJ\xa9j\x9f\x83r4\x1ebd\xaaR\xe9\x19E\xbc@\x1cw\xa9}\x9bC\xd5C*\xf6\x0be\x0fߣIt\x86\xd8�\xdc\xcb\xfa\xb1\xef�\xf0\x80:\x1b"} AgreementID:10267217042888759549 AgreementTotal:1 Provider:"0x3ec670f5063089fb04f7f4e003e88fd45e9228cc" Signature:"b25adf374846506d19811a42ec3dffc69988eafa63d60436a6100bb20bfe86110517fedc1fda2e7204ce694471339ddb049429cbde3e9cbf19a6da8098be5b651c"
2020-06-18T15:56:30.276 DBG source/eventbus/event_bus.go:81 > Published topic="invoice_paid" event={ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} SessionID: Invoice:{AgreementID:10267217042888759549 AgreementTotal:1 TransactorFee:0 Hashlock:0ce09c4d8bda91eb15c620f521270f07fdbfec06499a38924c7ce87f09831f03 Provider:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc}}
2020-06-18T15:56:30.277 WRN source/consumer/session/session_storage.go:119 > Received a unknown session update
2020-06-18T15:56:30.277 WRN source/core/quality/sender.go:158 > Can't recover session context error="unknown session: "
2020-06-18T15:56:30.285 DBG source/eventbus/event_bus.go:81 > Published topic="consumer_grand_total_change" event={Current:1 AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d}}
2020-06-18T15:56:30.285 DBG source/eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} Previous:690000000 Current:689999999}
2020-06-18T15:56:30.478 INF source/core/state/state.go:402 > Session ID Connecting duration: 5.757468s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:30.716 INF source/core/connection/manager.go:425 > Provider's session config: {"local_port":0,"remote_port":0,"ports":null,"provider":{"public_key":"ljP3Y2lCeN8YcgOY4ViJfZOCmNwKTT0jiTybMO4K5U8=","endpoint":"zzz:49189"},"consumer":{"ip_address":"10.182.0.2/24","dns_ips":"10.182.0.1"}}
2020-06-18T15:56:30.716 DBG source/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Created SessionInfo:{StartedAt:2020-06-18 15:56:24.7210243 +0300 EEST m=+7.564708401 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID:59294f5d-a5a6-4d5f-994f-48d4d969eb1e Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:30.725 DBG source/consumer/session/session_storage.go:178 > Session 59294f5d-a5a6-4d5f-994f-48d4d969eb1e saved
2020-06-18T15:56:30.726 DBG source/consumer/statistics/reporter.go:123 > Session statistics reporter started
2020-06-18T15:56:30.887 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-06-18T15:56:31.286 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 312 supported: 303
2020-06-18T15:56:31.287 INF source/core/discovery/repository.go:91 > Returning 320 unique proposals
2020-06-18T15:56:31.334 DBG source/core/ip/resolver.go:103 > IP detected: xxx
2020-06-18T15:56:31.334 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP zzz access
2020-06-18T15:56:31.334 INF source/services/wireguard/connection/connection.go:127 > Starting new connection
2020-06-18T15:56:31.334 DBG source/config/config.go:177 > Returning CLI value usermode:true
2020-06-18T15:56:31.335 DBG source/services/wireguard/endpoint/remoteclient/client.go:39 > Creating remote wg client
2020-06-18T15:56:31.335 INF source/services/wireguard/connection/connection.go:170 > Starting connection endpoint
2020-06-18T15:56:31.335 DBG source/services/wireguard/endpoint/endpoint.go:64 > Allocated interface: myst
2020-06-18T15:56:31.456 INF source/services/wireguard/connection/connection.go:200 > Stopping WireGuard connection
2020-06-18T15:56:31.456 INF source/firewall/outgoing_firewall_noop.go:50 > Rule for IP: zzz removed
2020-06-18T15:56:31.456 INF source/core/connection/manager.go:247 > Cancelling connection initiation: error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T15:56:31.456 INF source/core/connection/manager.go:545 > Connection state: Connecting -> Canceled
2020-06-18T15:56:31.456 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:ConnectionFailed SessionInfo:{StartedAt:2020-06-18 15:56:24.7210243 +0300 EEST m=+7.564708401 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID:59294f5d-a5a6-4d5f-994f-48d4d969eb1e Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:31.456 INF source/core/connection/manager.go:545 > Connection state: Canceled -> Disconnecting
2020-06-18T15:56:31.456 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Canceled SessionInfo:{StartedAt:2020-06-18 15:56:24.7210243 +0300 EEST m=+7.564708401 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Canceled SessionID:59294f5d-a5a6-4d5f-994f-48d4d969eb1e Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:31.456 INF source/core/state/state.go:359 > Session ID 59294f5d-a5a6-4d5f-994f-48d4d969eb1e Connecting duration: 6.7351489s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:31.456 DBG source/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Ended SessionInfo:{StartedAt:2020-06-18 15:56:24.7210243 +0300 EEST m=+7.564708401 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:59294f5d-a5a6-4d5f-994f-48d4d969eb1e Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:31.456 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Disconnecting SessionInfo:{StartedAt:2020-06-18 15:56:24.7210243 +0300 EEST m=+7.564708401 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:59294f5d-a5a6-4d5f-994f-48d4d969eb1e Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:31.456 INF source/core/state/state.go:359 > Session ID 59294f5d-a5a6-4d5f-994f-48d4d969eb1e Canceled duration: 6.7351489s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:31.465 DBG source/consumer/session/session_storage.go:154 > Session 59294f5d-a5a6-4d5f-994f-48d4d969eb1e updated with final data
2020-06-18T15:56:31.465 DBG source/consumer/statistics/reporter.go:137 > Session statistics reporter stopping
2020-06-18T15:56:31.465 DBG source/session/pingpong/invoice_payer.go:265 > Stopping...
2020-06-18T15:56:31.465 INF source/core/state/state.go:359 > Session ID 59294f5d-a5a6-4d5f-994f-48d4d969eb1e Disconnecting duration: 6.7442886s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:31.465 INF source/core/connection/manager.go:545 > Connection state: Disconnecting -> NotConnected
2020-06-18T15:56:31.465 DBG source/core/connection/manager.go:298 > Sending session status P2P message to "p2p-session-connectivity-status": ConsumerID:"0xc4dccf394e18e28ae707dddde4a9ce26a450280d" SessionID:"59294f5d-a5a6-4d5f-994f-48d4d969eb1e" Code:2003 Message:"could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T15:56:31.465 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:NotConnected SessionInfo:{StartedAt:2020-06-18 15:56:24.7210243 +0300 EEST m=+7.564708401 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:NotConnected SessionID:59294f5d-a5a6-4d5f-994f-48d4d969eb1e Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:31.465 INF source/core/state/state.go:359 > Session ID 59294f5d-a5a6-4d5f-994f-48d4d969eb1e NotConnected duration: 6.7442886s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:31.465 WRN source/core/connection/manager.go:357 > Cleanup error error="could not send p2p session status message: timeout waiting for reply to "p2p-session-connectivity-status": p2p send timeout"
2020-06-18T15:56:31.465 DBG source/core/location/oracle_resolver.go:41 > Detecting with oracle resolver
2020-06-18T15:56:31.465 DBG source/core/connection/manager.go:449 > Sending P2P message to "p2p-session-destroy": consumerID:"0xc4dccf394e18e28ae707dddde4a9ce26a450280d" sessionID:"59294f5d-a5a6-4d5f-994f-48d4d969eb1e"
2020-06-18T15:56:31.556 WRN source/p2p/channel.go:377 > Stream 3 not found, message data:
2020-06-18T15:56:31.557 ERR source/core/connection/manager.go:186 > Connect failed, disconnecting error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T15:56:31.558 ERR source/tequilapi/endpoints/connection.go:187 > error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T15:56:31.575 INF source/tequilapi/endpoints/connection.go:159 > identity "0xc4dccf394e18e28ae707dddde4a9ce26a450280d" registration is in progress, continuing...
2020-06-18T15:56:31.702 INF source/market/mysterium/mysterium_api.go:309 > Session stats sent: 59294f5d-a5a6-4d5f-994f-48d4d969eb1e
2020-06-18T15:56:31.702 DBG source/consumer/statistics/reporter.go:109 > Final stats sent
2020-06-18T15:56:31.838 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 1 supported: 1
2020-06-18T15:56:31.838 INF source/core/connection/manager.go:545 > Connection state: NotConnected -> Connecting
2020-06-18T15:56:31.838 DBG source/communication/nats/connector.go:39 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222
2020-06-18T15:56:31.838 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-06-18T15:56:31.838 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Connecting SessionInfo:{StartedAt:2020-06-18 15:56:31.8386484 +0300 EEST m=+14.682332501 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} 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:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x738933b77641a52e58ec2d7463b42fc230f661c4 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:31.838 INF source/core/state/state.go:359 > Session ID Connecting duration: 0s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:32.044 DBG source/p2p/dialer.go:144 > Consumer 0xc4dccf394e18e28ae707dddde4a9ce26a450280d sending public key 5471bd842cd23cf630dcfda5009b4a2cc5c3c6a6c468de2e233d758195660304 to provider 0x738933b77641a52e58ec2d7463b42fc230f661c4
2020-06-18T15:56:32.049 DBG source/core/location/cache.go:95 > Location update succeeded: {xxx wuha residential}
2020-06-18T15:56:33.196 DBG source/p2p/dialer.go:171 > Consumer 0xc4dccf394e18e28ae707dddde4a9ce26a450280d received provider 0x738933b77641a52e58ec2d7463b42fc230f661c4 with config: publicIP:"185.49.57.171" ports:40968 ports:45016
2020-06-18T15:56:33.761 DBG source/core/ip/resolver.go:103 > IP detected: xxx
2020-06-18T15:56:33.761 INF source/core/port/pool.go:68 > Supplying port 46198
2020-06-18T15:56:33.762 INF source/core/port/pool.go:68 > Supplying port 48766
2020-06-18T15:56:33.762 DBG source/p2p/dialer.go:194 > Consumer 0xc4dccf394e18e28ae707dddde4a9ce26a450280d sending ack with encrypted config to provider 0x738933b77641a52e58ec2d7463b42fc230f661c4
2020-06-18T15:56:33.969 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP 185.49.57.171 access
2020-06-18T15:56:33.969 DBG source/p2p/dialer.go:99 > Skipping provider ping
2020-06-18T15:56:33.970 DBG source/p2p/dialer.go:121 > Received handlers ready message from provider
2020-06-18T15:56:33.972 DBG source/p2p/channel.go:200 > Creating p2p channel with local addr: 192.168.0.105:46198, UDP session addr: 127.0.0.1:53039, proxy addr: 127.0.0.1:53038, remote peer addr: x.x.x.x:40968
2020-06-18T15:56:33.972 DBG source/p2p/channel.go:519 > Will use service conn with local port: 48766, remote port: 45016
2020-06-18T15:56:33.973 WRN source/communication/nats/connection_wrap.go:86 > NATS: disconnected
2020-06-18T15:56:33.973 WRN source/communication/nats/connection_wrap.go:85 > NATS: connection closed
2020-06-18T15:56:33.973 INF source/firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://testnet-broker.mysterium.network:4222 removed
2020-06-18T15:56:33.974 DBG source/session/pingpong/invoice_payer.go:120 > Starting...
2020-06-18T15:56:33.974 DBG source/core/connection/manager.go:412 > Sending P2P message to "p2p-session-create": consumer:{id:"0xc4dccf394e18e28ae707dddde4a9ce26a450280d" accountantID:"0x0214281cf15C1a66b51990e2E65e1f7b7C363318" paymentVersion:"v3"} proposalID:1 config:"{"PublicKey":"fJYU3y7H7xjCryLwNZqE4BQUnnAf7jEJnkazmYwcbWY=","Ports":null}"
2020-06-18T15:56:35.242 DBG source/session/pingpong/factory.go:219 > Received P2P message for "p2p-payment-invoice": AgreementID:3820831641963011533 AgreementTotal:1 Hashlock:"19c107c7a6573d703c68ea3a79d404da191c421bba68ebf02d866670746ec89a" Provider:"0x738933b77641a52e58ec2d7463b42fc230f661c4"
2020-06-18T15:56:35.243 DBG source/session/pingpong/invoice_payer.go:139 > Invoice received: {3820831641963011533 1 0 19c107c7a6573d703c68ea3a79d404da191c421bba68ebf02d866670746ec89a 0x738933b77641a52e58ec2d7463b42fc230f661c4}
2020-06-18T15:56:35.243 DBG source/session/pingpong/price_calculator.go:67 > Calculated price 195524. Time component: 211, data component: 195313
2020-06-18T15:56:35.243 DBG source/session/pingpong/invoice_payer.go:180 > Estimated tolerance 1.72, upper bound 336239
2020-06-18T15:56:35.244 DBG source/session/pingpong/invoice_payer.go:229 > Loaded previous state: already promised: 1
2020-06-18T15:56:35.244 DBG source/session/pingpong/invoice_payer.go:230 > Incrementing promised amount by 1
2020-06-18T15:56:35.248 DBG source/session/pingpong/exchange_messaging.go:63 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"\x9d䣐\r\xa1[\xe1\xa1\xed\xe7\xca\xf0\x02\xd7\xff~\xb61\xfb" Amount:2 Hashlock:"\x19\xc1\x07ǦW=p<h\xea:y\xd4\x04\xda\x19\x1cB\x1b\xbah\xeb\xf0-\x86fptnȚ" Signature:"\x0eU\x93CO\x83\x86\xd2dC9"\xc1Ӳ\x8aE^\xac:\xa5罛a\xd2?.\x1c\xef|\xba;B\x18e\x0el\xce\xcd\xe4\xaf \xf5\x07\xe5ݴڰ\xbc4>\xe6\x0f\xb9VpViN}\xa5$\x1c"} AgreementID:3820831641963011533 AgreementTotal:1 Provider:"0x738933b77641a52e58ec2d7463b42fc230f661c4" Signature:"30cb45bb025d2fb7240af48153bddd9b55c543dd223716cc6984f13045e586bc35a246e28088a4647e9ea6d1d569b809fbe8a4a917bf1c4841a05336839f8acc1c"
2020-06-18T15:56:35.336 DBG source/eventbus/event_bus.go:81 > Published topic="invoice_paid" event={ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} SessionID: Invoice:{AgreementID:3820831641963011533 AgreementTotal:1 TransactorFee:0 Hashlock:19c107c7a6573d703c68ea3a79d404da191c421bba68ebf02d866670746ec89a Provider:0x738933b77641a52e58ec2d7463b42fc230f661c4}}
2020-06-18T15:56:35.336 WRN source/consumer/session/session_storage.go:119 > Received a unknown session update
2020-06-18T15:56:35.336 WRN source/core/quality/sender.go:158 > Can't recover session context error="unknown session: "
2020-06-18T15:56:35.343 DBG source/eventbus/event_bus.go:81 > Published topic="consumer_grand_total_change" event={Current:2 AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d}}
2020-06-18T15:56:35.344 DBG source/eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} Previous:690000000 Current:689999998}
2020-06-18T15:56:35.536 INF source/core/state/state.go:402 > Session ID Connecting duration: 3.6981657s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:35.767 INF source/core/connection/manager.go:425 > Provider's session config: {"local_port":0,"remote_port":0,"ports":null,"provider":{"public_key":"lktmOIrTQMX2/J2AmZKT8gDSSsG6PplWH+dK4mHYcyE=","endpoint":"185.49.57.171:45016"},"consumer":{"ip_address":"10.182.1.2/24","dns_ips":"10.182.1.1"}}
2020-06-18T15:56:35.767 DBG source/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Created SessionInfo:{StartedAt:2020-06-18 15:56:31.8386484 +0300 EEST m=+14.682332501 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID:63b0af19-6133-4988-8a02-9114a3144ff4 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x738933b77641a52e58ec2d7463b42fc230f661c4 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:35.781 DBG source/consumer/session/session_storage.go:178 > Session 63b0af19-6133-4988-8a02-9114a3144ff4 saved
2020-06-18T15:56:35.781 DBG source/consumer/statistics/reporter.go:123 > Session statistics reporter started
2020-06-18T15:56:36.306 DBG source/core/ip/resolver.go:103 > IP detected: xxx
2020-06-18T15:56:36.307 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP 185.49.57.171 access
2020-06-18T15:56:36.307 INF source/services/wireguard/connection/connection.go:127 > Starting new connection
2020-06-18T15:56:36.307 DBG source/config/config.go:177 > Returning CLI value usermode:true
2020-06-18T15:56:36.307 DBG source/services/wireguard/endpoint/remoteclient/client.go:39 > Creating remote wg client
2020-06-18T15:56:36.308 INF source/services/wireguard/connection/connection.go:170 > Starting connection endpoint
2020-06-18T15:56:36.308 DBG source/services/wireguard/endpoint/endpoint.go:64 > Allocated interface: myst
2020-06-18T15:56:36.441 INF source/services/wireguard/connection/connection.go:200 > Stopping WireGuard connection
2020-06-18T15:56:36.441 INF source/firewall/outgoing_firewall_noop.go:50 > Rule for IP: 185.49.57.171 removed
2020-06-18T15:56:36.441 INF source/core/connection/manager.go:247 > Cancelling connection initiation: error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T15:56:36.441 INF source/core/connection/manager.go:545 > Connection state: Connecting -> Canceled
2020-06-18T15:56:36.441 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:ConnectionFailed SessionInfo:{StartedAt:2020-06-18 15:56:31.8386484 +0300 EEST m=+14.682332501 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID:63b0af19-6133-4988-8a02-9114a3144ff4 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x738933b77641a52e58ec2d7463b42fc230f661c4 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:36.441 INF source/core/connection/manager.go:545 > Connection state: Canceled -> Disconnecting
2020-06-18T15:56:36.441 INF source/core/state/state.go:359 > Session ID 63b0af19-6133-4988-8a02-9114a3144ff4 Connecting duration: 4.6027451s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:36.441 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Canceled SessionInfo:{StartedAt:2020-06-18 15:56:31.8386484 +0300 EEST m=+14.682332501 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Canceled SessionID:63b0af19-6133-4988-8a02-9114a3144ff4 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x738933b77641a52e58ec2d7463b42fc230f661c4 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:36.441 DBG source/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Ended SessionInfo:{StartedAt:2020-06-18 15:56:31.8386484 +0300 EEST m=+14.682332501 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:63b0af19-6133-4988-8a02-9114a3144ff4 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x738933b77641a52e58ec2d7463b42fc230f661c4 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:36.441 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Disconnecting SessionInfo:{StartedAt:2020-06-18 15:56:31.8386484 +0300 EEST m=+14.682332501 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:63b0af19-6133-4988-8a02-9114a3144ff4 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x738933b77641a52e58ec2d7463b42fc230f661c4 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:36.441 INF source/core/state/state.go:359 > Session ID 63b0af19-6133-4988-8a02-9114a3144ff4 Canceled duration: 4.6027451s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:36.448 DBG source/consumer/session/session_storage.go:154 > Session 63b0af19-6133-4988-8a02-9114a3144ff4 updated with final data
2020-06-18T15:56:36.448 DBG source/consumer/statistics/reporter.go:137 > Session statistics reporter stopping
2020-06-18T15:56:36.448 DBG source/session/pingpong/invoice_payer.go:265 > Stopping...
2020-06-18T15:56:36.448 INF source/core/state/state.go:359 > Session ID 63b0af19-6133-4988-8a02-9114a3144ff4 Disconnecting duration: 4.6097483s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:36.448 INF source/core/connection/manager.go:545 > Connection state: Disconnecting -> NotConnected
2020-06-18T15:56:36.448 DBG source/core/connection/manager.go:298 > Sending session status P2P message to "p2p-session-connectivity-status": ConsumerID:"0xc4dccf394e18e28ae707dddde4a9ce26a450280d" SessionID:"63b0af19-6133-4988-8a02-9114a3144ff4" Code:2003 Message:"could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T15:56:36.448 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:NotConnected SessionInfo:{StartedAt:2020-06-18 15:56:31.8386484 +0300 EEST m=+14.682332501 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:NotConnected SessionID:63b0af19-6133-4988-8a02-9114a3144ff4 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x738933b77641a52e58ec2d7463b42fc230f661c4 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:36.448 WRN source/core/connection/manager.go:357 > Cleanup error error="could not send p2p session status message: timeout waiting for reply to "p2p-session-connectivity-status": p2p send timeout"
2020-06-18T15:56:36.448 INF source/core/state/state.go:359 > Session ID 63b0af19-6133-4988-8a02-9114a3144ff4 NotConnected duration: 4.6097483s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:36.448 DBG source/core/connection/manager.go:449 > Sending P2P message to "p2p-session-destroy": consumerID:"0xc4dccf394e18e28ae707dddde4a9ce26a450280d" sessionID:"63b0af19-6133-4988-8a02-9114a3144ff4"
2020-06-18T15:56:36.448 DBG source/core/location/oracle_resolver.go:41 > Detecting with oracle resolver
2020-06-18T15:56:36.536 ERR source/core/connection/manager.go:186 > Connect failed, disconnecting error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T15:56:36.536 WRN source/p2p/channel.go:377 > Stream 3 not found, message data:
2020-06-18T15:56:36.536 ERR source/tequilapi/endpoints/connection.go:187 > error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T15:56:36.549 INF source/tequilapi/endpoints/connection.go:159 > identity "0xc4dccf394e18e28ae707dddde4a9ce26a450280d" registration is in progress, continuing...
2020-06-18T15:56:36.690 INF source/market/mysterium/mysterium_api.go:309 > Session stats sent: 63b0af19-6133-4988-8a02-9114a3144ff4
2020-06-18T15:56:36.690 DBG source/consumer/statistics/reporter.go:109 > Final stats sent
2020-06-18T15:56:36.767 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 1 supported: 1
2020-06-18T15:56:36.767 INF source/core/connection/manager.go:545 > Connection state: NotConnected -> Connecting
2020-06-18T15:56:36.768 DBG source/communication/nats/connector.go:39 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222
2020-06-18T15:56:36.768 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-06-18T15:56:36.768 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Connecting SessionInfo:{StartedAt:2020-06-18 15:56:36.7672179 +0300 EEST m=+19.610902001 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} 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:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x09f8218396a04820d82eaf76fda17c6c4aa1d881 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:36.768 INF source/core/state/state.go:359 > Session ID Connecting duration: 1.0022ms data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:36.971 DBG source/p2p/dialer.go:144 > Consumer 0xc4dccf394e18e28ae707dddde4a9ce26a450280d sending public key 73f8583ca2d9eeb8e31ed870aea6495052e5f458348fe2488076491de0b50b14 to provider 0x09f8218396a04820d82eaf76fda17c6c4aa1d881
2020-06-18T15:56:37.045 DBG source/core/location/cache.go:95 > Location update succeeded: {xxx wuha residential}
2020-06-18T15:56:38.116 DBG source/p2p/dialer.go:171 > Consumer 0xc4dccf394e18e28ae707dddde4a9ce26a450280d received provider 0x09f8218396a04820d82eaf76fda17c6c4aa1d881 with config: publicIP:"185.49.57.174" ports:44792 ports:43660
2020-06-18T15:56:38.715 DBG source/core/ip/resolver.go:103 > IP detected: xxx
2020-06-18T15:56:38.716 INF source/core/port/pool.go:68 > Supplying port 45974
2020-06-18T15:56:38.717 INF source/core/port/pool.go:68 > Supplying port 44496
2020-06-18T15:56:38.718 DBG source/p2p/dialer.go:194 > Consumer 0xc4dccf394e18e28ae707dddde4a9ce26a450280d sending ack with encrypted config to provider 0x09f8218396a04820d82eaf76fda17c6c4aa1d881
2020-06-18T15:56:38.728 INF source/core/connection/manager.go:545 > Connection state: Connecting -> Disconnecting
2020-06-18T15:56:38.728 INF source/core/connection/manager.go:545 > Connection state: Disconnecting -> NotConnected
2020-06-18T15:56:38.728 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Disconnecting SessionInfo:{StartedAt:2020-06-18 15:56:36.7672179 +0300 EEST m=+19.610902001 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID: Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x09f8218396a04820d82eaf76fda17c6c4aa1d881 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:38.728 WRN source/communication/nats/connection_wrap.go:86 > NATS: disconnected
2020-06-18T15:56:38.728 INF source/firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://testnet-broker.mysterium.network:4222 removed
2020-06-18T15:56:38.728 INF source/core/state/state.go:359 > Session ID Disconnecting duration: 1.9615675s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:38.728 WRN source/communication/nats/connection_wrap.go:85 > NATS: connection closed
2020-06-18T15:56:38.728 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:NotConnected SessionInfo:{StartedAt:2020-06-18 15:56:36.7672179 +0300 EEST m=+19.610902001 ConsumerID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:NotConnected SessionID: Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x09f8218396a04820d82eaf76fda17c6c4aa1d881 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T15:56:38.728 ERR source/core/connection/manager.go:186 > Connect failed, disconnecting error="could not create p2p channel: could not exchange config: could not send signed msg: could not send broker request to subject 0x09f8218396a04820d82eaf76fda17c6c4aa1d881.wireguard.p2p-config-exchange-ack: context canceled"
2020-06-18T15:56:38.728 ERR source/tequilapi/endpoints/connection.go:187 > error="could not create p2p channel: could not exchange config: could not send signed msg: could not send broker request to subject 0x09f8218396a04820d82eaf76fda17c6c4aa1d881.wireguard.p2p-config-exchange-ack: context canceled"
2020-06-18T15:56:38.728 DBG source/core/location/oracle_resolver.go:41 > Detecting with oracle resolver
2020-06-18T15:56:38.728 INF source/core/state/state.go:359 > Session ID NotConnected duration: 1.9615675s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T15:56:39.286 DBG source/core/location/cache.go:95 > Location update succeeded: {xxx wuha residential}
2020-06-18T15:56:40.898 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-06-18T15:56:41.298 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 312 supported: 303
2020-06-18T15:56:41.298 INF source/core/discovery/repository.go:91 > Returning 332 unique proposals
2020-06-18T15:56:51.114 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-06-18T15:56:51.454 INF source/core/discovery/repository.go:91 > Returning 349 unique proposals
2020-06-18T15:57:01.113 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-06-18T15:57:01.501 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 310 supported: 301
2020-06-18T15:57:01.502 INF source/core/discovery/repository.go:91 > Returning 361 unique proposals
2020-06-18T15:57:31.302 INF source/identity/registry/registry_contract.go:208 > Received registration event for {0xc4dccf394e18e28ae707dddde4a9ce26a450280d}
2020-06-18T15:57:31.302 DBG source/identity/registry/registry_contract.go:219 > Sending registration success event for {0xc4dccf394e18e28ae707dddde4a9ce26a450280d}
2020-06-18T15:57:31.302 DBG source/eventbus/event_bus.go:81 > Published topic="registration_event_topic" event={ID:{Address:0xc4dccf394e18e28ae707dddde4a9ce26a450280d} Status:RegisteredConsumer}
2020-06-18T15:57:31.711 WRN github.com/mysteriumnetwork/payments@v0.0.13/client/retryable_client.go:95 > retry 2 of 3 error="could not get consumers channel: no contract code at given address"

@cvl
Copy link
Author

cvl commented Jun 18, 2020

Some more node logs:

2020-06-18T17:43:07.966 DBG source/logconfig/rollingwriter/rollingwriter.go:76 > Found 0 old log files in log directory, skipping cleanup
2020-06-18T17:43:07.967 INF source/cmd/di.go:174 > Starting Mysterium Node 0.34.2-1snapshot-20200618T1118-7b15cdb2
2020-06-18T17:43:07.968 DBG source/config/config.go:186 > Returning default value outgoing-firewall:false
2020-06-18T17:43:07.969 DBG source/config/config.go:186 > Returning default value incoming-firewall:false
2020-06-18T17:43:07.969 INF source/firewall/incoming_firewall_noop.go:32 > Rules bootstrap was requested
2020-06-18T17:43:07.970 DBG source/config/config.go:177 > Returning CLI value usermode:true
2020-06-18T17:43:07.970 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL wss://goerli.infura.io/ws/v3/c2c7da73fcc84ec5885a7bb0eb3c3637 access
2020-06-18T17:43:07.970 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-api.mysterium.network/v1 access
2020-06-18T17:43:07.970 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-transactor.mysterium.network/api/v1 access
2020-06-18T17:43:07.970 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-accountant.mysterium.network/api/v2 access
2020-06-18T17:43:07.970 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL wss://goerli.infura.io/ws/v3/c2c7da73fcc84ec5885a7bb0eb3c3637 access
2020-06-18T17:43:07.970 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-api.mysterium.network/v1 access
2020-06-18T17:43:07.970 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-transactor.mysterium.network/api/v1 access
2020-06-18T17:43:07.970 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-accountant.mysterium.network/api/v2 access
2020-06-18T17:43:07.970 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-06-18T17:43:07.970 DBG source/communication/nats/connector.go:39 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222
2020-06-18T17:43:07.971 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-06-18T17:43:08.165 INF source/cmd/di.go:620 > Using Eth endpoint: wss://goerli.infura.io/ws/v3/c2c7da73fcc84ec5885a7bb0eb3c3637
2020-06-18T17:43:08.942 INF source/identity/registry/registry_contract.go:58 > Using registryAddress 0x3dD81545F3149538EdCb6691A4FfEE1898Bd2ef0 accountantAddress 0x0214281cf15C1a66b51990e2E65e1f7b7C363318
2020-06-18T17:43:08.942 DBG source/cmd/di.go:644 > Using lightweight keystore
2020-06-18T17:43:08.943 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-location.mysterium.network/api/v1/location access
2020-06-18T17:43:08.943 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-location.mysterium.network/api/v1/location access
2020-06-18T17:43:08.943 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-location.mysterium.network/api/v1/location access
2020-06-18T17:43:08.943 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-location.mysterium.network/api/v1/location access
2020-06-18T17:43:08.943 DBG source/cmd/di.go:773 > Experimental NAT punching enabled, creating a pinger
2020-06-18T17:43:08.943 DBG source/config/config.go:186 > Returning default value nat-port-mapping:true
2020-06-18T17:43:08.943 DBG source/cmd/di_desktop.go:58 > Skipping services bootstrap for consumer mode
2020-06-18T17:43:08.944 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL https://quality.mysterium.network/api/v1 access
2020-06-18T17:43:08.944 INF source/firewall/incoming_firewall_noop.go:53 > Allow URL https://quality.mysterium.network/api/v1 access
2020-06-18T17:43:08.944 DBG source/cmd/di_desktop.go:181 > Skipping accountant promise settler for consumer mode
2020-06-18T17:43:08.944 DBG source/cmd/di_desktop.go:164 > Skipping provider registrar for consumer mode
2020-06-18T17:43:08.944 INF source/feedback/reporter.go:40 > Using feedback API at: https://feedback.mysterium.network
2020-06-18T17:43:08.945 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP 239.255.255.250 access
2020-06-18T17:43:08.945 DBG source/config/config.go:186 > Returning default value access-policy.address:https://testnet-trust.mysterium.network/api/v1/access-policies/
2020-06-18T17:43:08.945 DBG source/config/config.go:186 > Returning default value pprof.enable:false
2020-06-18T17:43:08.945 INF source/tequilapi/http_api_server.go:77 > API started on: 127.0.0.1:4050
2020-06-18T17:43:08.945 DBG source/eventbus/event_bus.go:81 > Published topic="Node" event={Status:Started}
2020-06-18T17:43:08.945 INF source/cmd/di.go:254 > Mysterium node started!
2020-06-18T17:43:08.946 DBG source/identity/registry/registry_contract.go:105 > event received {Started}
2020-06-18T17:43:08.945 DBG source/core/location/oracle_resolver.go:41 > Detecting with oracle resolver
2020-06-18T17:43:08.946 INF source/identity/registry/registry_contract.go:261 > Starting registry...
2020-06-18T17:43:08.946 DBG source/identity/registry/registry_contract.go:274 > Loading initial state
2020-06-18T17:43:09.520 DBG source/core/location/cache.go:112 > original location detected: LT (residential)
2020-06-18T17:43:09.625 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-06-18T17:43:09.775 DBG source/identity/manager.go:142 > Caching unlocked address: 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d
2020-06-18T17:43:09.776 DBG source/identity/manager.go:129 > Unlocked identity found in cache, skipping keystore: 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d
2020-06-18T17:43:09.776 DBG source/eventbus/event_bus.go:81 > Published topic="identity-unlocked" event=0xf89a7d3ba3ab2d8c56181e58c17610f31617231d
2020-06-18T17:43:10.006 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 307 supported: 298
2020-06-18T17:43:10.007 INF source/core/discovery/repository.go:91 > Returning 298 unique proposals
2020-06-18T17:43:10.056 DBG source/session/pingpong/consumer_balance_tracker.go:350 > Loaded accountant state: already promised: 0
2020-06-18T17:43:10.078 DBG source/eventbus/event_bus.go:81 > Published topic="consumer_grand_total_change" event={Current:0 AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d}}
2020-06-18T17:43:10.451 DBG source/eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} Previous:0 Current:690000000}
2020-06-18T17:43:11.084 INF source/nat/upnp/discover.go:58 > UPnP gateways detected: 1
2020-06-18T17:43:11.084 INF source/nat/upnp/discover.go:60 > UPnP gateway detected map[deviceType:urn:schemas-upnp-org:device:InternetGatewayDevice:1 friendlyName:TL-WR840N manufacturer:TP-Link modelName:TL-WR840N modelNo:6.0 server:Linux/2.6.36, UPnP/1.0, Portable SDK for UPnP devices/1.6.19]
2020-06-18T17:43:15.595 INF source/tequilapi/endpoints/connection.go:161 > identity "0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" is registered, continuing...
2020-06-18T17:43:15.824 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 1 supported: 1
2020-06-18T17:43:15.824 INF source/core/connection/manager.go:574 > Connection state: NotConnected -> Connecting
2020-06-18T17:43:15.824 DBG source/communication/nats/connector.go:39 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222
2020-06-18T17:43:15.825 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-06-18T17:43:15.825 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Connecting SessionInfo:{StartedAt:2020-06-18 17:43:15.8241966 +0300 EEST m=+7.994325401 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} 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:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:15.825 INF source/core/state/state.go:359 > Session ID Connecting duration: 998.9µs data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:16.040 DBG source/p2p/dialer.go:144 > Consumer 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d sending public key 334b60da5a5f1a4c7180ee139b883bd646cc086784d3b1ba8ea3ecb576abba0a to provider 0x3ec670f5063089fb04f7f4e003e88fd45e9228cc
2020-06-18T17:43:17.230 DBG source/p2p/dialer.go:171 > Consumer 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d received provider 0x3ec670f5063089fb04f7f4e003e88fd45e9228cc with config: publicIP:"88.88.88.88" ports:42418 ports:42539
2020-06-18T17:43:17.231 DBG source/core/ip/cached_resolver.go:79 > Public IP cache is empty, fetching IP
2020-06-18T17:43:17.603 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-06-18T17:43:17.823 DBG source/core/ip/resolver.go:101 > IP detected: 99.99.99.99
2020-06-18T17:43:17.824 INF source/core/port/pool.go:68 > Supplying port 45725
2020-06-18T17:43:17.824 INF source/core/port/pool.go:68 > Supplying port 43016
2020-06-18T17:43:17.825 DBG source/p2p/dialer.go:194 > Consumer 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d sending ack with encrypted config to provider 0x3ec670f5063089fb04f7f4e003e88fd45e9228cc
2020-06-18T17:43:17.979 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 307 supported: 298
2020-06-18T17:43:17.980 INF source/core/discovery/repository.go:91 > Returning 310 unique proposals
2020-06-18T17:43:18.029 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP 88.88.88.88 access
2020-06-18T17:43:18.030 DBG source/p2p/dialer.go:99 > Skipping provider ping
2020-06-18T17:43:18.031 DBG source/p2p/dialer.go:121 > Received handlers ready message from provider
2020-06-18T17:43:18.033 DBG source/p2p/channel.go:200 > Creating p2p channel with local addr: 192.168.0.105:45725, UDP session addr: 127.0.0.1:50181, proxy addr: 127.0.0.1:50180, remote peer addr: x.x.x.x:42418
2020-06-18T17:43:18.033 DBG source/p2p/channel.go:519 > Will use service conn with local port: 43016, remote port: 42539
2020-06-18T17:43:18.034 WRN source/communication/nats/connection_wrap.go:86 > NATS: disconnected
2020-06-18T17:43:18.034 INF source/firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://testnet-broker.mysterium.network:4222 removed
2020-06-18T17:43:18.034 WRN source/communication/nats/connection_wrap.go:85 > NATS: connection closed
2020-06-18T17:43:18.034 DBG source/session/pingpong/invoice_payer.go:120 > Starting...
2020-06-18T17:43:18.035 DBG source/core/connection/manager.go:441 > Sending P2P message to "p2p-session-create": consumer:{id:"0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" accountantID:"0x0214281cf15C1a66b51990e2E65e1f7b7C363318" paymentVersion:"v3"} proposalID:1 config:"{"PublicKey":"vCTdAuT95/m1/ashOyk6yGFKzkXRFXluenAcab2+Rlc=","Ports":null}"
2020-06-18T17:43:19.258 DBG source/session/pingpong/factory.go:188 > Received P2P message for "p2p-payment-invoice": AgreementID:13328574660899196868 AgreementTotal:1 Hashlock:"6911faa995337e160ea80ffa383f34d333a85df253b7a16e733bdfb752bbcc60" Provider:"0x3ec670f5063089fb04f7f4e003e88fd45e9228cc"
2020-06-18T17:43:19.258 DBG source/session/pingpong/invoice_payer.go:139 > Invoice received: {13328574660899196868 1 0 6911faa995337e160ea80ffa383f34d333a85df253b7a16e733bdfb752bbcc60 0x3ec670f5063089fb04f7f4e003e88fd45e9228cc}
2020-06-18T17:43:19.259 DBG source/session/pingpong/price_calculator.go:67 > Calculated price 195517. Time component: 204, data component: 195313
2020-06-18T17:43:19.259 DBG source/session/pingpong/invoice_payer.go:180 > Estimated tolerance 1.723, upper bound 336911
2020-06-18T17:43:19.259 DBG source/session/pingpong/invoice_payer.go:229 > Loaded previous state: already promised: 0
2020-06-18T17:43:19.259 DBG source/session/pingpong/invoice_payer.go:230 > Incrementing promised amount by 1
2020-06-18T17:43:19.261 DBG source/session/pingpong/exchange_messaging.go:65 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"\xb0q\xa3G\xbeB\x96\x1dG\xd5C\xec\x0e\x002\x90\xa2\xbc\xb2\xd2" Amount:1 Hashlock:"i\x11\xfa\xa9\x953~\x16\x0e\xa8\x0f\xfa8?4\xd33\xa8]\xf2S\xb7\xa1ns;߷R\xbb\xcc" Signature:"\x80\xb0\x01c{\xa2\xad\xa3\x9e\x9a\xe4\xe5�\x01\xf6\xb5\xd79\xfa2\n\xa0;\xdfI\x82\x8d)\xeb\xc0\r\x1bP\xb4'\xce\x13\x95\x9a\xde\xc4e܉\xf3\x02\x8e\xc2&\xc1\xealS5}\xede\xfc�\x90\x15\x8c\x1b"} AgreementID:13328574660899196868 AgreementTotal:1 Provider:"0x3ec670f5063089fb04f7f4e003e88fd45e9228cc" Signature:"622e3a2097e6e88b83d1a4c52abca284449238a48895dc3b89cf05afc92ac53e067efb9b1c375c800e28b7dc95ed731ffea53d8ebb46547dab715a792c05aa901c" HermesID:"0x0214281cf15C1a66b51990e2E65e1f7b7C363318"
2020-06-18T17:43:19.358 DBG source/eventbus/event_bus.go:81 > Published topic="invoice_paid" event={ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} SessionID: Invoice:{AgreementID:13328574660899196868 AgreementTotal:1 TransactorFee:0 Hashlock:6911faa995337e160ea80ffa383f34d333a85df253b7a16e733bdfb752bbcc60 Provider:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc}}
2020-06-18T17:43:19.358 WRN source/consumer/session/session_storage.go:119 > Received a unknown session update
2020-06-18T17:43:19.358 WRN source/core/quality/sender.go:158 > Can't recover session context error="unknown session: "
2020-06-18T17:43:19.370 DBG source/eventbus/event_bus.go:81 > Published topic="consumer_grand_total_change" event={Current:1 AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d}}
2020-06-18T17:43:19.370 DBG source/eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} Previous:690000000 Current:689999999}
2020-06-18T17:43:19.560 INF source/core/state/state.go:402 > Session ID Connecting duration: 3.7359083s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:21.558 INF source/core/connection/manager.go:454 > Provider's session config: {"local_port":0,"remote_port":0,"ports":null,"provider":{"public_key":"tBLwAkNAuoeJwIvQhSbDrl19O7W1it+T9P15dR8VyRk=","endpoint":"88.88.88.88:42539"},"consumer":{"ip_address":"10.182.0.2/24","dns_ips":"10.182.0.1"}}
2020-06-18T17:43:21.558 DBG source/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Created SessionInfo:{StartedAt:2020-06-18 17:43:15.8241966 +0300 EEST m=+7.994325401 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID:ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:21.565 DBG source/consumer/session/session_storage.go:178 > Session ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 saved
2020-06-18T17:43:21.565 DBG source/consumer/statistics/reporter.go:123 > Session statistics reporter started
2020-06-18T17:43:21.565 DBG source/core/ip/cached_resolver.go:75 > Found cached public IP
2020-06-18T17:43:21.565 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP 88.88.88.88 access
2020-06-18T17:43:21.565 DBG source/core/connection/dns_option.go:85 > Selecting DNS servers using strategy: system
2020-06-18T17:43:21.565 INF source/services/wireguard/connection/connection.go:130 > Starting new connection
2020-06-18T17:43:21.565 DBG source/config/config.go:177 > Returning CLI value usermode:true
2020-06-18T17:43:21.565 DBG source/services/wireguard/endpoint/remoteclient/client.go:40 > Creating remote wg client
2020-06-18T17:43:21.565 INF source/services/wireguard/connection/connection.go:167 > Starting connection endpoint
2020-06-18T17:43:21.565 DBG source/services/wireguard/endpoint/endpoint.go:61 > Allocated interface: myst
2020-06-18T17:43:21.661 INF source/services/wireguard/connection/connection.go:197 > Stopping WireGuard connection
2020-06-18T17:43:21.661 INF source/firewall/outgoing_firewall_noop.go:50 > Rule for IP: 88.88.88.88 removed
2020-06-18T17:43:21.661 INF source/core/connection/manager.go:264 > Cancelling connection initiation: error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T17:43:21.661 INF source/core/connection/manager.go:574 > Connection state: Connecting -> Canceled
2020-06-18T17:43:21.661 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:ConnectionFailed SessionInfo:{StartedAt:2020-06-18 17:43:15.8241966 +0300 EEST m=+7.994325401 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID:ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:21.661 INF source/core/connection/manager.go:574 > Connection state: Canceled -> Disconnecting
2020-06-18T17:43:21.661 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Canceled SessionInfo:{StartedAt:2020-06-18 17:43:15.8241966 +0300 EEST m=+7.994325401 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Canceled SessionID:ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:21.661 DBG source/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Ended SessionInfo:{StartedAt:2020-06-18 17:43:15.8241966 +0300 EEST m=+7.994325401 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:21.661 INF source/core/state/state.go:359 > Session ID ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 Connecting duration: 5.8373087s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:21.661 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Disconnecting SessionInfo:{StartedAt:2020-06-18 17:43:15.8241966 +0300 EEST m=+7.994325401 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:21.662 INF source/core/state/state.go:359 > Session ID ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 Canceled duration: 5.8373087s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:21.667 DBG source/consumer/session/session_storage.go:154 > Session ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 updated with final data
2020-06-18T17:43:21.667 DBG source/consumer/statistics/reporter.go:137 > Session statistics reporter stopping
2020-06-18T17:43:21.667 DBG source/session/pingpong/invoice_payer.go:265 > Stopping...
2020-06-18T17:43:21.667 INF source/core/connection/manager.go:574 > Connection state: Disconnecting -> NotConnected
2020-06-18T17:43:21.667 DBG source/core/connection/manager.go:327 > Sending session status P2P message to "p2p-session-connectivity-status": ConsumerID:"0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" SessionID:"ca22afbd-27b3-4c6b-be0b-6aef7f6ff515" Code:2003 Message:"could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T17:43:21.667 WRN source/core/connection/manager.go:386 > Cleanup error error="could not send p2p session status message: timeout waiting for reply to "p2p-session-connectivity-status": p2p send timeout"
2020-06-18T17:43:21.668 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:NotConnected SessionInfo:{StartedAt:2020-06-18 17:43:15.8241966 +0300 EEST m=+7.994325401 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:NotConnected SessionID:ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x3ec670f5063089fb04f7f4e003e88fd45e9228cc ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:21.667 INF source/core/state/state.go:359 > Session ID ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 Disconnecting duration: 5.8435378s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:21.668 DBG source/core/connection/manager.go:478 > Sending P2P message to "p2p-session-destroy": consumerID:"0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" sessionID:"ca22afbd-27b3-4c6b-be0b-6aef7f6ff515"
2020-06-18T17:43:21.668 DBG source/core/location/oracle_resolver.go:41 > Detecting with oracle resolver
2020-06-18T17:43:21.668 INF source/core/state/state.go:359 > Session ID ca22afbd-27b3-4c6b-be0b-6aef7f6ff515 NotConnected duration: 5.8445315s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:21.779 WRN source/p2p/channel.go:377 > Stream 3 not found, message data:
2020-06-18T17:43:21.779 ERR source/core/connection/manager.go:196 > Connect failed, disconnecting error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T17:43:21.780 DBG source/core/connection/manager.go:177 > Consumer connection trace: "Whole Connect" took 5.9554933s, "P2P channel creation" took 2.2103475s, "Session creation" took 3.5313226s, "Start connection" took 95.6386ms
2020-06-18T17:43:21.780 ERR source/tequilapi/endpoints/connection.go:187 > error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T17:43:21.816 INF source/tequilapi/endpoints/connection.go:161 > identity "0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" is registered, continuing...
2020-06-18T17:43:21.928 INF source/market/mysterium/mysterium_api.go:309 > Session stats sent: ca22afbd-27b3-4c6b-be0b-6aef7f6ff515
2020-06-18T17:43:21.928 DBG source/consumer/statistics/reporter.go:109 > Final stats sent
2020-06-18T17:43:22.052 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 1 supported: 1
2020-06-18T17:43:22.053 INF source/core/connection/manager.go:574 > Connection state: NotConnected -> Connecting
2020-06-18T17:43:22.053 DBG source/communication/nats/connector.go:39 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222
2020-06-18T17:43:22.053 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Connecting SessionInfo:{StartedAt:2020-06-18 17:43:22.0532265 +0300 EEST m=+14.223355301 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} 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:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x09f8218396a04820d82eaf76fda17c6c4aa1d881 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:22.054 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-06-18T17:43:22.054 INF source/core/state/state.go:359 > Session ID Connecting duration: 1.0047ms data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:22.266 DBG source/p2p/dialer.go:144 > Consumer 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d sending public key 6492cd83bc8af54ed9b6132fc1f6ed9a68a3f75fef5ab1deed1d36ae6e1e5b7b to provider 0x09f8218396a04820d82eaf76fda17c6c4aa1d881
2020-06-18T17:43:22.266 DBG source/core/location/cache.go:95 > Location update succeeded: {99.99.99.99 15419 wuh residential}
2020-06-18T17:43:23.405 DBG source/p2p/dialer.go:171 > Consumer 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d received provider 0x09f8218396a04820d82eaf76fda17c6c4aa1d881 with config: publicIP:"77.77.77.77" ports:43602 ports:47517
2020-06-18T17:43:23.405 DBG source/core/ip/cached_resolver.go:75 > Found cached public IP
2020-06-18T17:43:23.406 INF source/core/port/pool.go:68 > Supplying port 48417
2020-06-18T17:43:23.406 INF source/core/port/pool.go:68 > Supplying port 40724
2020-06-18T17:43:23.406 DBG source/p2p/dialer.go:194 > Consumer 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d sending ack with encrypted config to provider 0x09f8218396a04820d82eaf76fda17c6c4aa1d881
2020-06-18T17:43:23.615 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP 77.77.77.77 access
2020-06-18T17:43:23.615 DBG source/p2p/dialer.go:99 > Skipping provider ping
2020-06-18T17:43:23.615 DBG source/p2p/dialer.go:121 > Received handlers ready message from provider
2020-06-18T17:43:23.617 DBG source/p2p/channel.go:200 > Creating p2p channel with local addr: 192.168.0.105:48417, UDP session addr: 127.0.0.1:50185, proxy addr: 127.0.0.1:50184, remote peer addr: x.x.x.x:43602
2020-06-18T17:43:23.617 DBG source/p2p/channel.go:519 > Will use service conn with local port: 40724, remote port: 47517
2020-06-18T17:43:23.617 WRN source/communication/nats/connection_wrap.go:86 > NATS: disconnected
2020-06-18T17:43:23.617 WRN source/communication/nats/connection_wrap.go:85 > NATS: connection closed
2020-06-18T17:43:23.618 INF source/firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://testnet-broker.mysterium.network:4222 removed
2020-06-18T17:43:23.618 DBG source/core/connection/manager.go:441 > Sending P2P message to "p2p-session-create": consumer:{id:"0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" accountantID:"0x0214281cf15C1a66b51990e2E65e1f7b7C363318" paymentVersion:"v3"} proposalID:1 config:"{"PublicKey":"ojKbN1DH0SR3kCTG9Pr8J3bcijVPNLXlXFtBWOFwq1k=","Ports":null}"
2020-06-18T17:43:23.619 DBG source/session/pingpong/invoice_payer.go:120 > Starting...
2020-06-18T17:43:24.849 DBG source/session/pingpong/factory.go:188 > Received P2P message for "p2p-payment-invoice": AgreementID:4484266179907871042 AgreementTotal:1 Hashlock:"8bd07d736aa3fda1d34b9c3b82f3705cecab9f977f014e73eab86b07c79e045a" Provider:"0x09f8218396a04820d82eaf76fda17c6c4aa1d881"
2020-06-18T17:43:24.849 DBG source/session/pingpong/invoice_payer.go:139 > Invoice received: {4484266179907871042 1 0 8bd07d736aa3fda1d34b9c3b82f3705cecab9f977f014e73eab86b07c79e045a 0x09f8218396a04820d82eaf76fda17c6c4aa1d881}
2020-06-18T17:43:24.850 DBG source/session/pingpong/price_calculator.go:67 > Calculated price 195518. Time component: 205, data component: 195313
2020-06-18T17:43:24.850 DBG source/session/pingpong/invoice_payer.go:180 > Estimated tolerance 1.723, upper bound 336805
2020-06-18T17:43:24.850 DBG source/session/pingpong/invoice_payer.go:229 > Loaded previous state: already promised: 1
2020-06-18T17:43:24.850 DBG source/session/pingpong/invoice_payer.go:230 > Incrementing promised amount by 1
2020-06-18T17:43:24.855 DBG source/session/pingpong/exchange_messaging.go:65 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"\xb0q\xa3G\xbeB\x96\x1dG\xd5C\xec\x0e\x002\x90\xa2\xbc\xb2\xd2" Amount:2 Hashlock:"\x8b\xd0}sj\xa3\xfd\xa1\xd3K\x9c;\x82\xf3p\쫟\x97�\x01Ns\xea\xb8k\x07Ǟ\x04Z" Signature:"\xb3\xe9\x16\xe0Sv\x0e\xa1t%\x8a\xe0\x1d\xab\xe5\xec\x97.$\x12~$\xe4˼\xc9m\xd61=9o`.D\xdab\xce\xcd\xf3\x949\xdce4\xc5p\xf8\xd7\xc8\xcd\x00\t\x1b\xae\x93\x05A\xc4\x06\x80\xc7G\xc6\x1c"} AgreementID:4484266179907871042 AgreementTotal:1 Provider:"0x09f8218396a04820d82eaf76fda17c6c4aa1d881" Signature:"17654c39de9084fbd7dd85665564992a52b05c6aa97f90e2930f689e7443a7206383d3fbe568d0280c6e2360dae080dca65246945a42c9a618f1b0bdbd2330b51b" HermesID:"0x0214281cf15C1a66b51990e2E65e1f7b7C363318"
2020-06-18T17:43:24.944 DBG source/eventbus/event_bus.go:81 > Published topic="invoice_paid" event={ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} SessionID: Invoice:{AgreementID:4484266179907871042 AgreementTotal:1 TransactorFee:0 Hashlock:8bd07d736aa3fda1d34b9c3b82f3705cecab9f977f014e73eab86b07c79e045a Provider:0x09f8218396a04820d82eaf76fda17c6c4aa1d881}}
2020-06-18T17:43:24.944 WRN source/consumer/session/session_storage.go:119 > Received a unknown session update
2020-06-18T17:43:24.944 WRN source/core/quality/sender.go:158 > Can't recover session context error="unknown session: "
2020-06-18T17:43:24.954 DBG source/eventbus/event_bus.go:81 > Published topic="consumer_grand_total_change" event={Current:2 AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d}}
2020-06-18T17:43:24.954 DBG source/eventbus/event_bus.go:81 > Published topic="balance_change" event={Identity:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} Previous:690000000 Current:689999998}
2020-06-18T17:43:25.145 INF source/core/state/state.go:402 > Session ID Connecting duration: 3.0919071s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:27.158 INF source/core/connection/manager.go:454 > Provider's session config: {"local_port":0,"remote_port":0,"ports":null,"provider":{"public_key":"HJU++RD/xmxiRRBtUiRS8dmwXXztyoy0SCR976YU/Rw=","endpoint":"77.77.77.77:47517"},"consumer":{"ip_address":"10.182.1.2/24","dns_ips":"10.182.1.1"}}
2020-06-18T17:43:27.158 DBG source/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Created SessionInfo:{StartedAt:2020-06-18 17:43:22.0532265 +0300 EEST m=+14.223355301 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID:73b2135d-9ed4-4975-b01e-c9d714ac593b Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x09f8218396a04820d82eaf76fda17c6c4aa1d881 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:27.165 DBG source/consumer/session/session_storage.go:178 > Session 73b2135d-9ed4-4975-b01e-c9d714ac593b saved
2020-06-18T17:43:27.165 DBG source/consumer/statistics/reporter.go:123 > Session statistics reporter started
2020-06-18T17:43:27.165 DBG source/core/ip/cached_resolver.go:75 > Found cached public IP
2020-06-18T17:43:27.166 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP 77.77.77.77 access
2020-06-18T17:43:27.166 DBG source/core/connection/dns_option.go:85 > Selecting DNS servers using strategy: system
2020-06-18T17:43:27.166 INF source/services/wireguard/connection/connection.go:130 > Starting new connection
2020-06-18T17:43:27.166 DBG source/config/config.go:177 > Returning CLI value usermode:true
2020-06-18T17:43:27.166 DBG source/services/wireguard/endpoint/remoteclient/client.go:40 > Creating remote wg client
2020-06-18T17:43:27.166 INF source/services/wireguard/connection/connection.go:167 > Starting connection endpoint
2020-06-18T17:43:27.166 DBG source/services/wireguard/endpoint/endpoint.go:61 > Allocated interface: myst
2020-06-18T17:43:27.273 INF source/services/wireguard/connection/connection.go:197 > Stopping WireGuard connection
2020-06-18T17:43:27.273 INF source/firewall/outgoing_firewall_noop.go:50 > Rule for IP: 77.77.77.77 removed
2020-06-18T17:43:27.273 INF source/core/connection/manager.go:264 > Cancelling connection initiation: error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T17:43:27.273 INF source/core/connection/manager.go:574 > Connection state: Connecting -> Canceled
2020-06-18T17:43:27.273 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:ConnectionFailed SessionInfo:{StartedAt:2020-06-18 17:43:22.0532265 +0300 EEST m=+14.223355301 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID:73b2135d-9ed4-4975-b01e-c9d714ac593b Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x09f8218396a04820d82eaf76fda17c6c4aa1d881 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:27.273 INF source/core/connection/manager.go:574 > Connection state: Canceled -> Disconnecting
2020-06-18T17:43:27.273 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Canceled SessionInfo:{StartedAt:2020-06-18 17:43:22.0532265 +0300 EEST m=+14.223355301 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Canceled SessionID:73b2135d-9ed4-4975-b01e-c9d714ac593b Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x09f8218396a04820d82eaf76fda17c6c4aa1d881 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:27.273 INF source/core/state/state.go:359 > Session ID 73b2135d-9ed4-4975-b01e-c9d714ac593b Connecting duration: 5.220032s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:27.273 DBG source/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Ended SessionInfo:{StartedAt:2020-06-18 17:43:22.0532265 +0300 EEST m=+14.223355301 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:73b2135d-9ed4-4975-b01e-c9d714ac593b Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x09f8218396a04820d82eaf76fda17c6c4aa1d881 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:27.273 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Disconnecting SessionInfo:{StartedAt:2020-06-18 17:43:22.0532265 +0300 EEST m=+14.223355301 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:73b2135d-9ed4-4975-b01e-c9d714ac593b Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x09f8218396a04820d82eaf76fda17c6c4aa1d881 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:27.274 INF source/core/state/state.go:359 > Session ID 73b2135d-9ed4-4975-b01e-c9d714ac593b Canceled duration: 5.220032s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:27.280 DBG source/consumer/session/session_storage.go:154 > Session 73b2135d-9ed4-4975-b01e-c9d714ac593b updated with final data
2020-06-18T17:43:27.280 DBG source/consumer/statistics/reporter.go:137 > Session statistics reporter stopping
2020-06-18T17:43:27.280 DBG source/session/pingpong/invoice_payer.go:265 > Stopping...
2020-06-18T17:43:27.281 INF source/core/connection/manager.go:574 > Connection state: Disconnecting -> NotConnected
2020-06-18T17:43:27.281 INF source/core/state/state.go:359 > Session ID 73b2135d-9ed4-4975-b01e-c9d714ac593b Disconnecting duration: 5.2271461s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:27.281 DBG source/core/connection/manager.go:327 > Sending session status P2P message to "p2p-session-connectivity-status": ConsumerID:"0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" SessionID:"73b2135d-9ed4-4975-b01e-c9d714ac593b" Code:2003 Message:"could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T17:43:27.281 WRN source/core/connection/manager.go:386 > Cleanup error error="could not send p2p session status message: timeout waiting for reply to "p2p-session-connectivity-status": p2p send timeout"
2020-06-18T17:43:27.281 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:NotConnected SessionInfo:{StartedAt:2020-06-18 17:43:22.0532265 +0300 EEST m=+14.223355301 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:NotConnected SessionID:73b2135d-9ed4-4975-b01e-c9d714ac593b Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x09f8218396a04820d82eaf76fda17c6c4aa1d881 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:27.281 DBG source/core/connection/manager.go:478 > Sending P2P message to "p2p-session-destroy": consumerID:"0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" sessionID:"73b2135d-9ed4-4975-b01e-c9d714ac593b"
2020-06-18T17:43:27.281 DBG source/core/location/oracle_resolver.go:41 > Detecting with oracle resolver
2020-06-18T17:43:27.281 INF source/core/state/state.go:359 > Session ID 73b2135d-9ed4-4975-b01e-c9d714ac593b NotConnected duration: 5.2281196s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:27.376 WRN source/p2p/channel.go:377 > Stream 3 not found, message data:
2020-06-18T17:43:27.376 ERR source/core/connection/manager.go:196 > Connect failed, disconnecting error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T17:43:27.376 DBG source/core/connection/manager.go:177 > Consumer connection trace: "Whole Connect" took 5.3234166s, "P2P channel creation" took 1.5651779s, "Session creation" took 3.5473035s, "Start connection" took 107.5506ms
2020-06-18T17:43:27.377 ERR source/tequilapi/endpoints/connection.go:187 > error="could not start new connection: failed to start connection endpoint: could not configure device: failed to create wg interface: could not create wintun: Error creating interface: No driver for device "Wintun" installed"
2020-06-18T17:43:27.406 INF source/tequilapi/endpoints/connection.go:161 > identity "0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" is registered, continuing...
2020-06-18T17:43:27.529 INF source/market/mysterium/mysterium_api.go:309 > Session stats sent: 73b2135d-9ed4-4975-b01e-c9d714ac593b
2020-06-18T17:43:27.529 DBG source/consumer/statistics/reporter.go:109 > Final stats sent
2020-06-18T17:43:27.591 DBG source/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-06-18T17:43:27.652 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 1 supported: 1
2020-06-18T17:43:27.652 INF source/core/connection/manager.go:574 > Connection state: NotConnected -> Connecting
2020-06-18T17:43:27.652 DBG source/communication/nats/connector.go:39 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222
2020-06-18T17:43:27.652 INF source/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-06-18T17:43:27.652 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Connecting SessionInfo:{StartedAt:2020-06-18 17:43:27.6529098 +0300 EEST m=+19.823038601 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} 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:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x6eaec9ae853bd8bb2cda083302c3af0bd4da70d9 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:27.652 INF source/core/state/state.go:359 > Session ID Connecting duration: 0s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:27.845 DBG source/p2p/dialer.go:144 > Consumer 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d sending public key 8317162f737554a9fa4c156df5c58652790eac495c1e18d65cb14a4e656afd6d to provider 0x6eaec9ae853bd8bb2cda083302c3af0bd4da70d9
2020-06-18T17:43:27.845 DBG source/core/location/cache.go:95 > Location update succeeded: {99.99.99.99 15419 wuh residential}
2020-06-18T17:43:27.958 DBG source/market/mysterium/mysterium_api.go:271 > Total proposals: 307 supported: 298
2020-06-18T17:43:27.959 INF source/core/discovery/repository.go:91 > Returning 321 unique proposals
2020-06-18T17:43:29.012 DBG source/p2p/dialer.go:171 > Consumer 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d received provider 0x6eaec9ae853bd8bb2cda083302c3af0bd4da70d9 with config: publicIP:"185.49.57.144" ports:48488 ports:42153
2020-06-18T17:43:29.012 DBG source/core/ip/cached_resolver.go:75 > Found cached public IP
2020-06-18T17:43:29.013 INF source/core/port/pool.go:68 > Supplying port 42711
2020-06-18T17:43:29.013 INF source/core/port/pool.go:68 > Supplying port 44129
2020-06-18T17:43:29.014 DBG source/p2p/dialer.go:194 > Consumer 0xf89a7d3ba3ab2d8c56181e58c17610f31617231d sending ack with encrypted config to provider 0x6eaec9ae853bd8bb2cda083302c3af0bd4da70d9
2020-06-18T17:43:29.224 INF source/firewall/outgoing_firewall_noop.go:48 > Allow IP 185.49.57.144 access
2020-06-18T17:43:29.224 DBG source/p2p/dialer.go:99 > Skipping provider ping
2020-06-18T17:43:29.225 DBG source/p2p/dialer.go:121 > Received handlers ready message from provider
2020-06-18T17:43:29.225 DBG source/p2p/channel.go:200 > Creating p2p channel with local addr: 192.168.0.105:42711, UDP session addr: 127.0.0.1:50189, proxy addr: 127.0.0.1:50188, remote peer addr: x.x.x.x:48488
2020-06-18T17:43:29.225 DBG source/p2p/channel.go:519 > Will use service conn with local port: 44129, remote port: 42153
2020-06-18T17:43:29.226 WRN source/communication/nats/connection_wrap.go:86 > NATS: disconnected
2020-06-18T17:43:29.226 WRN source/communication/nats/connection_wrap.go:85 > NATS: connection closed
2020-06-18T17:43:29.226 INF source/firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://testnet-broker.mysterium.network:4222 removed
2020-06-18T17:43:29.226 DBG source/session/pingpong/invoice_payer.go:120 > Starting...
2020-06-18T17:43:29.226 DBG source/core/connection/manager.go:441 > Sending P2P message to "p2p-session-create": consumer:{id:"0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" accountantID:"0x0214281cf15C1a66b51990e2E65e1f7b7C363318" paymentVersion:"v3"} proposalID:1 config:"{"PublicKey":"bBcFbuuQXa2ZM+vK97NpvD2gq/sJ4k8ff4jwAU+qgSQ=","Ports":null}"
2020-06-18T17:43:29.359 INF source/core/connection/manager.go:574 > Connection state: Connecting -> Disconnecting
2020-06-18T17:43:29.359 DBG source/session/pingpong/invoice_payer.go:265 > Stopping...
2020-06-18T17:43:29.359 INF source/core/connection/manager.go:574 > Connection state: Disconnecting -> NotConnected
2020-06-18T17:43:29.359 DBG source/core/connection/manager.go:327 > Sending session status P2P message to "p2p-session-connectivity-status": ConsumerID:"0xf89a7d3ba3ab2d8c56181e58c17610f31617231d" Code:2000 Message:"could not send p2p session create request: timeout waiting for reply to "p2p-session-create": p2p send timeout"
2020-06-18T17:43:29.359 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:Disconnecting SessionInfo:{StartedAt:2020-06-18 17:43:27.6529098 +0300 EEST m=+19.823038601 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID: Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x6eaec9ae853bd8bb2cda083302c3af0bd4da70d9 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:29.359 INF source/core/state/state.go:359 > Session ID Disconnecting duration: 1.7064154s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:29.359 DBG source/eventbus/event_bus.go:81 > Published topic="State" event={State:NotConnected SessionInfo:{StartedAt:2020-06-18 17:43:27.6529098 +0300 EEST m=+19.823038601 ConsumerID:{Address:0xf89a7d3ba3ab2d8c56181e58c17610f31617231d} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:NotConnected SessionID: Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:5m0s Bytes:5368709 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x6eaec9ae853bd8bb2cda083302c3af0bd4da70d9 ProviderContacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:}}}
2020-06-18T17:43:29.359 DBG source/core/location/oracle_resolver.go:41 > Detecting with oracle resolver
2020-06-18T17:43:29.359 INF source/core/state/state.go:359 > Session ID NotConnected duration: 1.7064154s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-06-18T17:43:29.359 ERR source/core/connection/manager.go:196 > Connect failed, disconnecting error="could not send p2p session create request: timeout waiting for reply to "p2p-session-create": p2p send timeout"
2020-06-18T17:43:29.359 DBG source/core/connection/manager.go:177 > Consumer connection trace: "Whole Connect" took 1.7064154s, "P2P channel creation" took 1.5738825s, "Session creation" took -2562047h47m16.854775808s
2020-06-18T17:43:29.360 ERR source/tequilapi/endpoints/connection.go:187 > error="could not send p2p session create request: timeout waiting for reply to "p2p-session-create": p2p send timeout"
2020-06-18T17:43:29.948 DBG source/core/location/cache.go:95 > Location update succeeded: {99.99.99.99 15419 wuh residential}
2020-06-18T17:43:33.839 INF source/tequilapi/endpoints/stop.go:44 > Application stop requested
2020-06-18T17:43:33.840 INF source/cmd/node.go:91 > No active connection - proceeding
2020-06-18T17:43:33.841 INF source/cmd/node.go:100 > API stopped
2020-06-18T17:43:33.841 DBG source/eventbus/event_bus.go:81 > Published topic="Node" event={Status:Stopped}
2020-06-18T17:43:33.841 INF source/cmd/node.go:103 > Web UI server stopped
2020-06-18T17:43:33.841 ERR source/cmd/commands/daemon/command.go:68 > Terminating application due to error: accept tcp 127.0.0.1:4050: use of closed network connection

2020-06-18T17:43:33.841 DBG source/identity/registry/registry_contract.go:105 > event received {Stopped}
2020-06-18T17:43:33.841 INF source/cmd/node.go:106 > NAT pinger stopped
2020-06-18T17:43:33.841 INF source/cmd/node.go:91 > No active connection - proceeding
2020-06-18T17:43:33.841 INF source/communication/nats/receiver.go:99 > Unsubscribed from *.proposal-ping
2020-06-18T17:43:33.842 INF source/communication/nats/receiver.go:99 > Unsubscribed from *.proposal-unregister
2020-06-18T17:43:33.842 INF source/cmd/node.go:100 > API stopped
2020-06-18T17:43:33.841 INF source/identity/registry/registry_contract.go:255 > Stopping registry...
2020-06-18T17:43:33.842 INF source/cmd/node.go:103 > Web UI server stopped
2020-06-18T17:43:33.842 INF source/communication/nats/receiver.go:99 > Unsubscribed from *.proposal-register
2020-06-18T17:43:33.842 INF source/cmd/node.go:106 > NAT pinger stopped
2020-06-18T17:43:33.842 WRN source/communication/nats/connection_wrap.go:86 > NATS: disconnected
2020-06-18T17:43:33.842 INF source/firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://testnet-broker.mysterium.network:4222 removed
2020-06-18T17:43:33.842 WRN source/communication/nats/connection_wrap.go:85 > NATS: connection closed
2020-06-18T17:43:33.842 INF source/firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://testnet-broker.mysterium.network:4222 removed

@cvl
Copy link
Author

cvl commented Jun 18, 2020

Looks like a problem with wintun installation?

@chompomonim chompomonim changed the title [windows, bug] cannot connect to any provider [windows, bug] cannot connect to many provider Jun 23, 2020
@chompomonim
Copy link
Contributor

chompomonim commented Jun 23, 2020 •
edited

Could you give windows version and app version?
Also if you would name 5-7 providers IDs to which you're trying to connect but it is failing, this would help us to debug.

@chompomonim chompomonim reopened this Jun 23, 2020
@chompomonim chompomonim mentioned this issue Jun 27, 2020
Closed
@tadaskay
Copy link
Member

No provider should work with this. Clearly, wintun driver hasn't been installed. Have you installed the app using the supplied installer?

Relevant error is:

Error creating interface: No driver for device "Wintun" installed

@tadaskay tadaskay self-assigned this Jun 29, 2020
@cvl
Copy link
Author

cvl commented Jun 29, 2020

I was doing yarn && yarn build && yarn dev on Windows.

@cvl
Copy link
Author

cvl commented Jun 29, 2020

It seems one needs to do the following to make it work:

  • yarn && yarn bundle -> then go to dist folder, install the built app, quit the built app.
  • go back to source folder and do yarn dev

Then it works.

@cvl cvl closed this as completed Jun 29, 2020
@cvl
Copy link
Author

cvl commented Jun 29, 2020

I'd suggest to update readme.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@tadaskay tadaskay

Labels
bug component:desktop system:windows
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@cvl @chompomonim @tadaskay