Closed NinoSkopac closed 4 months ago
Starts successfully on MacOS Ventura 13.3
mysteriumnetwork-workshop % yarn fleet-start
yarn run v1.22.19
$ docker-compose up fleet
[+] Running 10/10
⠿ Network mysteriumnetwork-workshop_default Created 0.0s
⠿ Container mysteriumnetwork-workshop-ca-node-1 Created 0.2s
⠿ Container mysteriumnetwork-workshop-uk-node-1 Created 0.2s
⠿ Container mysteriumnetwork-workshop-ua-node-1 Created 0.2s
⠿ Container mysteriumnetwork-workshop-plain-node-1 Created 0.2s
⠿ Container mysteriumnetwork-workshop-us-node-1 Created 0.2s
⠿ Container mysteriumnetwork-workshop-de-node-1 Created 0.2s
⠿ Container mysteriumnetwork-workshop-lt-node-1 Created 0.2s
⠿ Container mysteriumnetwork-workshop-jp-node-1 Created 0.2s
⠿ Container mysteriumnetwork-workshop-fleet-1 Created 0.1s
Attaching to mysteriumnetwork-workshop-fleet-1
mysteriumnetwork-workshop-fleet-1 exited with code 0
✨ Done in 2.97s.
yarn fleet-connect
still crashes:
mysteriumnetwork-workshop % yarn fleet-connect
yarn run v1.22.19
$ ts-node src/fleet/connect.ts
/Users/nino/PhpstormProjects/mysteriumnetwork-workshop/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:12
function rejected(value) { try { step(generator["throw"](value)); } catch (e) { reject(e); } }
^
TequilapiError: Request failed with status code 401 (path="auth/authenticate")
at /Users/nino/PhpstormProjects/mysteriumnetwork-workshop/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:34:19
at Generator.throw (<anonymous>)
at rejected (/Users/nino/PhpstormProjects/mysteriumnetwork-workshop/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:12:65)
at processTicksAndRejections (node:internal/process/task_queues:95:5) {
_originalError: Error: Request failed with status code 401
at createError (/Users/nino/PhpstormProjects/mysteriumnetwork-workshop/node_modules/axios/lib/core/createError.js:16:15)
at settle (/Users/nino/PhpstormProjects/mysteriumnetwork-workshop/node_modules/axios/lib/core/settle.js:17:12)
at IncomingMessage.handleStreamEnd (/Users/nino/PhpstormProjects/mysteriumnetwork-workshop/node_modules/axios/lib/adapters/http.js:322:11)
at IncomingMessage.emit (node:events:524:35)
at IncomingMessage.emit (node:domain:489:12)
at endReadableNT (node:internal/streams/readable:1359:12)
at processTicksAndRejections (node:internal/process/task_queues:82:21) {
config: {
transitional: [Object],
adapter: [Function: httpAdapter],
transformRequest: [Array],
transformResponse: [Array],
timeout: 40000,
xsrfCookieName: 'XSRF-TOKEN',
xsrfHeaderName: 'X-XSRF-TOKEN',
maxContentLength: -1,
maxBodyLength: -1,
validateStatus: [Function: validateStatus],
headers: [Object],
baseURL: 'http://localhost:20001/tequilapi',
method: 'post',
url: 'auth/authenticate',
data: '{"username":"myst","password":"qwerty123456"}'
},
request: ClientRequest {
_events: [Object: null prototype],
_eventsCount: 7,
_maxListeners: undefined,
outputData: [],
outputSize: 0,
writable: true,
destroyed: true,
_last: false,
chunkedEncoding: false,
shouldKeepAlive: true,
maxRequestsOnConnectionReached: false,
_defaultKeepAlive: true,
useChunkedEncodingByDefault: true,
sendDate: false,
_removedConnection: false,
_removedContLen: false,
_removedTE: false,
strictContentLength: false,
_contentLength: 45,
_hasBody: true,
_trailer: '',
finished: true,
_headerSent: true,
_closed: true,
socket: [Socket],
_header: 'POST /tequilapi/auth/authenticate HTTP/1.1\r\n' +
'Accept: application/json, text/plain, */*\r\n' +
'Content-Type: application/json\r\n' +
'Cache-Control: no-cache, no-store\r\n' +
'User-Agent: axios/0.26.1\r\n' +
'Content-Length: 45\r\n' +
'Host: localhost:20001\r\n' +
'Connection: keep-alive\r\n' +
'\r\n',
_keepAliveTimeout: 0,
_onPendingData: [Function: nop],
agent: [Agent],
socketPath: undefined,
method: 'POST',
maxHeaderSize: undefined,
insecureHTTPParser: undefined,
joinDuplicateHeaders: undefined,
path: '/tequilapi/auth/authenticate',
_ended: true,
res: [IncomingMessage],
aborted: false,
timeoutCb: null,
upgradeOrConnect: false,
parser: null,
maxHeadersCount: null,
reusedSocket: false,
host: 'localhost',
protocol: 'http:',
_redirectable: [Writable],
[Symbol(kCapture)]: false,
[Symbol(kBytesWritten)]: 0,
[Symbol(kNeedDrain)]: false,
[Symbol(corked)]: 0,
[Symbol(kOutHeaders)]: [Object: null prototype],
[Symbol(errored)]: null,
[Symbol(kUniqueHeaders)]: null
},
response: {
status: 401,
statusText: 'Unauthorized',
headers: [Object],
config: [Object],
request: [ClientRequest],
data: [Object]
},
isAxiosError: true,
toJSON: [Function: toJSON]
}
}
error Command failed with exit code 1.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.
@NinoSkopac have you manually connected to each node on port 4449 (this port exposes a UI) and completed onboarding?
Also readme notes
Make sure to set your password to qwerty123456 - all scripts will expect this
By default script expects all node API passwords to be set to qwerty123456
, you can however change this if you wish. HTTP response status 401 along with
baseURL: 'http://localhost:20001/tequilapi',
method: 'post',
url: 'auth/authenticate',
data: '{"username":"myst","password":"qwerty123456"}'
suggests that password is incorrect.
You are right on both counts 👍
I've done that.
Now there's another error:
mysteriumnetwork-workshop % yarn fleet-connect
yarn run v1.22.19
$ ts-node src/fleet/connect.ts
connecting to LT... (proxyPort: 10002)
connecting to JP... (proxyPort: 10005)
connecting to UA... (proxyPort: 10003)
connecting to CA... (proxyPort: 10007)
connecting to GB... (proxyPort: 10004)
connecting to DE... (proxyPort: 10001)
connecting to US... (proxyPort: 10006)
failed to connect JP, retries left: 2
connecting to JP... (proxyPort: 10005)
failed to connect GB, retries left: 2
connecting to GB... (proxyPort: 10004)
failed to connect DE, retries left: 2
connecting to DE... (proxyPort: 10001)
failed to connect LT, retries left: 2
connecting to LT... (proxyPort: 10002)
failed to connect CA, retries left: 2
connecting to CA... (proxyPort: 10007)
failed to connect UA, retries left: 2
connecting to UA... (proxyPort: 10003)
failed to connect US, retries left: 2
connecting to US... (proxyPort: 10006)
failed to connect DE, retries left: 1
connecting to DE... (proxyPort: 10001)
failed to connect JP, retries left: 1
connecting to JP... (proxyPort: 10005)
failed to connect GB, retries left: 1
connecting to GB... (proxyPort: 10004)
failed to connect LT, retries left: 1
connecting to LT... (proxyPort: 10002)
failed to connect US, retries left: 1
connecting to US... (proxyPort: 10006)
failed to connect CA, retries left: 1
connecting to CA... (proxyPort: 10007)
failed to connect UA, retries left: 1
connecting to UA... (proxyPort: 10003)
✨ Done in 9.38s.
Looking at logs, it's because of insufficient balance?
2023-03-30 02:33:28 2023-03-29T19:33:28.434 DBG ../../market/mysterium/mysterium_api.go:66 > Total proposals: 1 supported: 1
2023-03-30 02:33:28 2023-03-29T19:33:28.434 DBG ../../core/discovery/repository.go:94 > Returning 1 unique proposals
2023-03-30 02:33:28 2023-03-29T19:33:28.839 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer whole Connect Duration:404.762021ms}
2023-03-30 02:33:28 2023-03-29T19:33:28.839 DBG ../../core/connection/manager.go:232 > Consumer connection trace: "Consumer whole Connect" took 404.762021ms
2023-03-30 02:33:28 2023-03-29T19:33:28.839 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x32fe395f9214870e2dee09e61c15558dc42addf8 ConsumerID:0x49fca9f3649e72e6820776aa642e7cd1093702ac HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error:insufficient balance Stage:connection_unknown_error}
2023-03-30 02:33:28 2023-03-29T19:33:28.839 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30 02:33:28 2023-03-29T19:33:28.840 ERR ../../tequilapi/endpoints/connection.go:216 > Failed to connect error="insufficient balance"
I thought that the $1 I paid via Paypal to open the account/wallet was credited as some MYST. Should i just top up on every node?
Can you please run:
yarn fleet-info
It's likely I will get back to you tomorrow.
yarn fleet-info
yarn run v1.22.19
$ ts-node src/fleet/info.ts
DE - balance: 0
LT - balance: 0
UA - balance: 0
GB - balance: 0
JP - balance: 0
US - balance: 0
CA - balance: 0
It definitely seems like insufficient balance on all, even though I just opened the accounts with $1.
Should I top up on each node separately, that's the way to go about it, if I want to use 7 exit nodes simultaneously?
What if I want to use only 1 node in the same time, what's the way to go about that?
We used to transfer left over myst after registration to balance. I need to reach out to payments team on this matter. What you could do is list me identities of all the nodes here (they are in NodeUI -> Settings first tab). I will get back to you tomorrow, payments team is off hours ATM.
It's worth noting my UI port was not 4449 like you mentioned earlier, it was in the 20,000 range (eg 20001, 20002 for each next node)
The 20000 range is for the fleet. If you registered only the 4449 port node then you can try to just run:
yarn booking - will run a scraping using single node (slow but simple setup)
The fleet mode means it will run 7 nodes at once, each node connected to different country. Non fleet mode means it will use single node to jump from country to country.
Thank you for your information. I really appreciate it.
May I ask, what is the port in the 10,000 range for?
For http proxy. Script uses chromium browser with configured http proxy for scraping.
@NinoSkopac could you go to each node NodeUI (on the respective port) Go to Settings page (cog wheel) and copy and paste all of the identities here?
yes sir!
0x49fca9f3649e72e6820776aa642e7cd1093702ac 0x9db4fd24a72d80d4b84177585ed3475205bdcca4 0x32387535a5efe12ecdadf473e21dee1cceb18dc5 0x7465027f18442536710f73545d5f3c406050bb99 0x39d508e4e62e0873e2b164d096bfb98dd96ee145 0x679acd518e4964f4c197079f7e23e2418de5df9c 0x51b6b405ea522b8815d60326115b8034f15380f5
@NinoSkopac try to check you balance by running:
yarn fleet-info
% yarn fleet-info
yarn run v1.22.19
$ ts-node src/fleet/info.ts
DE - balance: 0
LT - balance: 0
UA - balance: 0
GB - balance: 0
JP - balance: 0
US - balance: 0
CA - balance: 0
✨ Done in 8.78s.
And if you just try to run the example ?
yarn fleet-connect
% yarn fleet-connect
yarn run v1.22.19
$ ts-node src/fleet/connect.ts
connecting to UA... (proxyPort: 10003)
connecting to JP... (proxyPort: 10005)
connecting to CA... (proxyPort: 10007)
connecting to LT... (proxyPort: 10002)
connecting to DE... (proxyPort: 10001)
connecting to GB... (proxyPort: 10004)
connecting to US... (proxyPort: 10006)
failed to connect UA, retries left: 2
connecting to UA... (proxyPort: 10003)
failed to connect JP, retries left: 2
connecting to JP... (proxyPort: 10005)
failed to connect CA, retries left: 2
connecting to CA... (proxyPort: 10007)
failed to connect LT, retries left: 2
connecting to LT... (proxyPort: 10002)
failed to connect DE, retries left: 2
connecting to DE... (proxyPort: 10001)
failed to connect GB, retries left: 2
connecting to GB... (proxyPort: 10004)
failed to connect JP, retries left: 1
connecting to JP... (proxyPort: 10005)
failed to connect UA, retries left: 1
connecting to UA... (proxyPort: 10003)
failed to connect US, retries left: 2
connecting to US... (proxyPort: 10006)
failed to connect CA, retries left: 1
connecting to CA... (proxyPort: 10007)
failed to connect LT, retries left: 1
connecting to LT... (proxyPort: 10002)
failed to connect DE, retries left: 1
connecting to DE... (proxyPort: 10001)
failed to connect GB, retries left: 1
connecting to GB... (proxyPort: 10004)
failed to connect US, retries left: 1
connecting to US... (proxyPort: 10006)
✨ Done in 10.90s.
The funds are coming:
% yarn fleet-info
yarn run v1.22.19
$ ts-node src/fleet/info.ts
DE - balance: 0.399984
LT - balance: 0.4
UA - balance: 0.399983
GB - balance: 0
JP - balance: 0.399999
US - balance: 0.399996
CA - balance: 0.4
✨ Done in 4.70s.
Connect still doesn't work (funds have arrived on every account).
% yarn fleet-connect
yarn run v1.22.19
$ ts-node src/fleet/connect.ts
connecting to JP... (proxyPort: 10005)
connecting to LT... (proxyPort: 10002)
connecting to UA... (proxyPort: 10003)
connecting to CA... (proxyPort: 10007)
connecting to GB... (proxyPort: 10004)
connecting to DE... (proxyPort: 10001)
connecting to US... (proxyPort: 10006)
connected to: DE! (0xcc07d2e067f724686ea8aae3582e8e57625394e9)
failed to connect JP, retries left: 2
connecting to JP... (proxyPort: 10005)
failed to connect LT, retries left: 2
connecting to LT... (proxyPort: 10002)
failed to connect UA, retries left: 2
connecting to UA... (proxyPort: 10003)
failed to connect CA, retries left: 2
connecting to CA... (proxyPort: 10007)
failed to connect GB, retries left: 2
connecting to GB... (proxyPort: 10004)
failed to connect LT, retries left: 1
connecting to LT... (proxyPort: 10002)
failed to connect UA, retries left: 1
connecting to UA... (proxyPort: 10003)
failed to connect JP, retries left: 1
connecting to JP... (proxyPort: 10005)
failed to connect CA, retries left: 1
connecting to CA... (proxyPort: 10007)
failed to connect US, retries left: 2
connecting to US... (proxyPort: 10006)
failed to connect GB, retries left: 1
connecting to GB... (proxyPort: 10004)
failed to connect US, retries left: 1
connecting to US... (proxyPort: 10006)
✨ Done in 9.51s.
US-node logs:
2023-03-30 14:56:38 iptables basepath detected: /sbin
2023-03-30 14:56:38 2023-03-30T07:56:38.486 DBG ../../config/config.go:81 > Loading user configuration: /var/lib/mysterium-node/config-mainnet.toml
2023-03-30 14:56:38 2023-03-30T07:56:38.489 INF ../../config/config.go:93 > User configuration loaded:
2023-03-30 14:56:38 {"mmn":{"api-key":"fsXWFA5KlhNs3VmSNyr7btwC1vzGKJZ2u14JXaxi"},"terms":{"provider-agreed":true,"version":"0.0.50"}}
2023-03-30 14:56:38 2023-03-30T07:56:38.495 DBG ../../config/config.go:216 > Returning CLI value data-dir:/var/lib/mysterium-node
2023-03-30 14:56:38 2023-03-30T07:56:38.495 DBG ../../config/config.go:216 > Returning CLI value data-dir:/var/lib/mysterium-node
2023-03-30 14:56:38 2023-03-30T07:56:38.495 DBG ../../config/config.go:216 > Returning CLI value script-dir:/etc/mysterium-node
2023-03-30 14:56:38 2023-03-30T07:56:38.495 DBG ../../config/config.go:216 > Returning CLI value runtime-dir:/var/run/mysterium-node
2023-03-30 14:56:38 2023-03-30T07:56:38.495 DBG ../../config/config.go:216 > Returning CLI value ui.port:20006
2023-03-30 14:56:38 2023-03-30T07:56:38.495 INF ../../logconfig/config.go:74 > Log level: debug
2023-03-30 14:56:38 2023-03-30T07:56:38.495 INF ../../logconfig/config.go:76 > Log file path: /root/.mysterium/logs/mysterium-node
2023-03-30 14:56:38 2023-03-30T07:56:38.495 DBG ../../logconfig/rollingwriter/rollingwriter.go:76 > Found 0 old log files in log directory, skipping cleanup
2023-03-30 14:56:38 2023-03-30T07:56:38.496 INF ../../cmd/di.go:218 > Starting Mysterium Node 1.19.21
2023-03-30 14:56:38 2023-03-30T07:56:38.498 INF ../../firewall/incoming_firewall_noop.go:32 > Rules bootstrap was requested
2023-03-30 14:56:38 2023-03-30T07:56:38.507 INF ../../cmd/di.go:701 > Using local DNS: location.mysterium.network -> [51.158.129.204]
2023-03-30 14:56:38 2023-03-30T07:56:38.507 INF ../../cmd/di.go:701 > Using local DNS: badupnp.benjojo.co.uk -> [104.22.70.70 104.22.71.70 172.67.25.154]
2023-03-30 14:56:38 2023-03-30T07:56:38.507 INF ../../cmd/di.go:701 > Using local DNS: trust.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30 14:56:38 2023-03-30T07:56:38.507 INF ../../cmd/di.go:701 > Using local DNS: pilvytis.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30 14:56:38 2023-03-30T07:56:38.507 INF ../../cmd/di.go:701 > Using local DNS: affiliator.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30 14:56:38 2023-03-30T07:56:38.507 INF ../../cmd/di.go:701 > Using local DNS: observer.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30 14:56:38 2023-03-30T07:56:38.507 INF ../../cmd/di.go:701 > Using local DNS: quality.mysterium.network -> [51.158.129.204]
2023-03-30 14:56:38 2023-03-30T07:56:38.507 INF ../../cmd/di.go:701 > Using local DNS: feedback.mysterium.network -> [116.203.17.150]
2023-03-30 14:56:38 2023-03-30T07:56:38.508 INF ../../cmd/di.go:701 > Using local DNS: api.ipify.org -> [54.204.14.42 54.225.153.147 54.235.83.248 54.243.161.145 23.21.109.69 23.21.126.66 50.19.252.36 174.129.214.20]
2023-03-30 14:56:38 2023-03-30T07:56:38.508 INF ../../cmd/di.go:701 > Using local DNS: discovery.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30 14:56:38 2023-03-30T07:56:38.508 INF ../../cmd/di.go:701 > Using local DNS: broker.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30 14:56:38 2023-03-30T07:56:38.508 INF ../../cmd/di.go:701 > Using local DNS: transactor.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30 14:56:38 2023-03-30T07:56:38.508 DBG ../../communication/nats/connector.go:79 > Connecting to NATS servers: [nats://broker.mysterium.network:4222]
2023-03-30 14:56:38 2023-03-30T07:56:38.508 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30 14:56:38 2023-03-30T07:56:38.508 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30 14:56:38 2023-03-30T07:56:38.508 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.22.197:4222 access
2023-03-30 14:56:38 2023-03-30T07:56:38.508 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.12:4222 access
2023-03-30 14:56:38 2023-03-30T07:56:38.508 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.14:4222 access
2023-03-30 14:56:38 2023-03-30T07:56:38.508 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.16:4222 access
2023-03-30 14:56:40 2023-03-30T07:56:40.621 INF ../../cmd/di.go:730 > Using L1 Eth endpoints: [https://ethereum1.mysterium.network/ https://cloudflare-eth.com/]
2023-03-30 14:56:40 2023-03-30T07:56:40.621 INF ../../cmd/di.go:731 > Using L2 Eth endpoints: [https://polygon1.mysterium.network/ https://polygon-rpc.com/]
2023-03-30 14:56:41 2023-03-30T07:56:41.539 INF ../../cmd/di.go:513 > Node chain id 137
2023-03-30 14:56:42 2023-03-30T07:56:42.389 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://discovery.mysterium.network/api/v4 access
2023-03-30 14:56:42 2023-03-30T07:56:42.390 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://transactor.mysterium.network/api/v1 access
2023-03-30 14:56:42 2023-03-30T07:56:42.390 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://affiliator.mysterium.network/api/v1 access
2023-03-30 14:56:42 2023-03-30T07:56:42.390 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://hermes3.mysterium.network/api/v2 access
2023-03-30 14:56:42 2023-03-30T07:56:42.390 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://pilvytis.mysterium.network access
2023-03-30 14:56:42 2023-03-30T07:56:42.391 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://ethereum1.mysterium.network/ access
2023-03-30 14:56:42 2023-03-30T07:56:42.391 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://cloudflare-eth.com/ access
2023-03-30 14:56:42 2023-03-30T07:56:42.391 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://polygon1.mysterium.network/ access
2023-03-30 14:56:42 2023-03-30T07:56:42.391 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://polygon-rpc.com/ access
2023-03-30 14:56:42 2023-03-30T07:56:42.391 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://discovery.mysterium.network/api/v4 access
2023-03-30 14:56:42 2023-03-30T07:56:42.392 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://transactor.mysterium.network/api/v1 access
2023-03-30 14:56:42 2023-03-30T07:56:42.392 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://affiliator.mysterium.network/api/v1 access
2023-03-30 14:56:42 2023-03-30T07:56:42.392 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://hermes3.mysterium.network/api/v2 access
2023-03-30 14:56:42 2023-03-30T07:56:42.392 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://pilvytis.mysterium.network access
2023-03-30 14:56:42 2023-03-30T07:56:42.392 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://ethereum1.mysterium.network/ access
2023-03-30 14:56:42 2023-03-30T07:56:42.392 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://cloudflare-eth.com/ access
2023-03-30 14:56:42 2023-03-30T07:56:42.392 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://polygon1.mysterium.network/ access
2023-03-30 14:56:42 2023-03-30T07:56:42.393 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://polygon-rpc.com/ access
2023-03-30 14:56:42 2023-03-30T07:56:42.393 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://location.mysterium.network/api/v1/location access
2023-03-30 14:56:42 2023-03-30T07:56:42.393 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://location.mysterium.network/api/v1/location access
2023-03-30 14:56:42 2023-03-30T07:56:42.393 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://location.mysterium.network/api/v1/location access
2023-03-30 14:56:42 2023-03-30T07:56:42.393 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://location.mysterium.network/api/v1/location access
2023-03-30 14:56:42 2023-03-30T07:56:42.394 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30 14:56:42 2023-03-30T07:56:42.394 DBG ../../cmd/di.go:852 > Using lightweight keystore
2023-03-30 14:56:42 2023-03-30T07:56:42.449 DBG ../../config/config.go:216 > Returning CLI value data-dir:/var/lib/mysterium-node
2023-03-30 14:56:42 2023-03-30T07:56:42.449 DBG ../../core/ip/cached_resolver.go:59 > Outbound IP cache is empty, fetching IP
2023-03-30 14:56:42 2023-03-30T07:56:42.450 WRN ../../ui/server.go:96 > could not read node ui version config, falling back to bundled version
2023-03-30 14:56:42 2023-03-30T07:56:42.451 DBG ../../config/config.go:216 > Returning CLI value local-service-discovery:false
2023-03-30 14:56:42 2023-03-30T07:56:42.474 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables --new MYST --table nat" output:
2023-03-30 14:56:42
2023-03-30 14:56:42 2023-03-30T07:56:42.491 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A MYST --destination 10.0.0.0/8 --jump DNAT --to-destination 240.0.0.1 --table nat" output:
2023-03-30 14:56:42
2023-03-30 14:56:42 2023-03-30T07:56:42.507 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A MYST --destination 172.16.0.0/12 --jump DNAT --to-destination 240.0.0.1 --table nat" output:
2023-03-30 14:56:42
2023-03-30 14:56:42 2023-03-30T07:56:42.516 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A MYST --destination 192.168.0.0/16 --jump DNAT --to-destination 240.0.0.1 --table nat" output:
2023-03-30 14:56:42
2023-03-30 14:56:42 2023-03-30T07:56:42.539 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A MYST --destination 127.0.0.0/8 --jump DNAT --to-destination 240.0.0.1 --table nat" output:
2023-03-30 14:56:42
2023-03-30 14:56:42 2023-03-30T07:56:42.543 INF ../../nat/service_ipforward.go:46 > IP forwarding already enabled
2023-03-30 14:56:42 2023-03-30T07:56:42.544 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://quality.mysterium.network/api/v3 access
2023-03-30 14:56:42 2023-03-30T07:56:42.546 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://quality.mysterium.network/api/v3 access
2023-03-30 14:56:42 2023-03-30T07:56:42.548 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2023-03-30 14:56:42 2023-03-30T07:56:42.549 INF ../../feedback/reporter.go:46 > Using feedback API at: https://feedback.mysterium.network
2023-03-30 14:56:42 2023-03-30T07:56:42.552 INF ../../tequilapi/http_api_server.go:122 > API started on: 127.0.0.1:4050
2023-03-30 14:56:42 2023-03-30T07:56:42.552 DBG ../../sleep/sleep_noop.go:28 > Register for noop sleep events
2023-03-30 14:56:42 2023-03-30T07:56:42.553 INF ../../ui/discovery/discovery.go:66 > LAN discovery disabled. Starting noop local service discovery.
2023-03-30 14:56:42 2023-03-30T07:56:42.553 DBG ../../eventbus/event_bus.go:101 > Published topic="Node" event={Status:Started}
2023-03-30 14:56:42 2023-03-30T07:56:42.554 DBG ../../core/ip/cached_resolver.go:55 > Found cached outbound IP
2023-03-30 14:56:42 2023-03-30T07:56:42.554 DBG ../../core/location/oracle_resolver.go:67 > Detecting with oracle resolver
2023-03-30 14:56:42 2023-03-30T07:56:42.554 INF ../../ui/server.go:160 > UI starting on: 127.0.0.1:20006
2023-03-30 14:56:42 2023-03-30T07:56:42.555 DBG ../../identity/registry/registry_contract.go:158 > event received {Started}
2023-03-30 14:56:42 2023-03-30T07:56:42.560 INF ../../identity/registry/registry_contract.go:316 > Starting registry...
2023-03-30 14:56:42 2023-03-30T07:56:42.560 DBG ../../identity/registry/registry_contract.go:327 > Loading initial state
2023-03-30 14:56:42 2023-03-30T07:56:42.559 DBG ../../core/ip/cached_resolver.go:79 > Public IP cache is empty, fetching IP
2023-03-30 14:56:42 2023-03-30T07:56:42.559 DBG ../../core/ip/cached_resolver.go:55 > Found cached outbound IP
2023-03-30 14:56:42 2023-03-30T07:56:42.557 INF ../../session/pingpong/hermes_promise_settler.go:382 > Listening for settlement events
2023-03-30 14:56:42 2023-03-30T07:56:42.565 DBG ../../identity/registry/registry_contract.go:342 > Identity {"0x679acd518e4964f4c197079f7e23e2418de5df9c"} already registered, skipping
2023-03-30 14:56:42 2023-03-30T07:56:42.567 INF ../../ui/server.go:160 > UI starting on: 172.21.0.8:20006
2023-03-30 14:56:42 2023-03-30T07:56:42.774 INF ../../session/pingpong/hermes_promise_settler.go:511 > no inactive hermeses found for chain: 137
2023-03-30 14:56:43 2023-03-30T07:56:43.373 INF ../../cmd/di.go:305 > Mysterium node started!
2023-03-30 14:56:43 2023-03-30T07:56:43.381 DBG ../../core/location/cache.go:131 > original location detected: TH (residential)
2023-03-30 14:56:43 2023-03-30T07:56:43.439 INF ../../session/pingpong/pricing.go:208 > pricing info loaded. expires @ 2023-03-30 08:00:27.325982707 +0000 UTC
2023-03-30 14:56:44 2023-03-30T07:56:44.197 DBG ../../session/pingpong/hermes_promise_handler.go:231 > hermes promise handler started
2023-03-30 14:56:44 2023-03-30T07:56:44.649 INF ../../nat/upnp/discover.go:58 > UPnP gateways detected: 0
2023-03-30 14:57:07 2023-03-30T07:57:07.297 DBG ../../identity/manager.go:166 > Caching unlocked address: 0x679acd518e4964f4c197079f7e23e2418de5df9c
2023-03-30 14:57:07 2023-03-30T07:57:07.297 DBG ../../eventbus/event_bus.go:101 > Published topic="identity-unlocked" event={ChainID:137 ID:{Address:0x679acd518e4964f4c197079f7e23e2418de5df9c}}
2023-03-30 14:57:07 2023-03-30T07:57:07.297 DBG ../../eventbus/event_bus.go:101 > Published topic="resident-country" event={ID:0x679acd518e4964f4c197079f7e23e2418de5df9c Country:TH}
2023-03-30 14:57:07 2023-03-30T07:57:07.935 DBG ../../session/pingpong/consumer_balance_tracker.go:656 > Loaded hermes state: already promised: 3107184637520
2023-03-30 14:57:07 2023-03-30T07:57:07.936 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+3107184637520 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0x679acd518e4964f4c197079f7e23e2418de5df9c}}
2023-03-30 14:57:08 2023-03-30T07:57:08.553 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0x679acd518e4964f4c197079f7e23e2418de5df9c} Previous:+0 Current:+399996892815362480}
2023-03-30 14:58:02 2023-03-30T07:58:02.911 DBG ../../identity/manager.go:153 > Unlocked identity found in cache, skipping keystore: 0x679acd518e4964f4c197079f7e23e2418de5df9c
2023-03-30 14:58:29 2023-03-30T07:58:29.235 DBG ../../identity/manager.go:153 > Unlocked identity found in cache, skipping keystore: 0x679acd518e4964f4c197079f7e23e2418de5df9c
2023-03-30 14:58:29 2023-03-30T07:58:29.317 DBG ../../core/discovery/repository.go:64 > Retrieving proposals from 1 repositories filter={"AccessPolicy":"","AccessPolicySource":"","BandwidthMin":0,"CompatibilityMax":0,"CompatibilityMin":2,"ExcludeUnsupported":true,"IPType":"residential","IncludeMonitoringFailed":false,"LocationCountry":"US","NATCompatibility":"","PresetID":0,"ProviderID":"","ProviderIDs":null,"QualityMin":1,"ServiceType":""}
2023-03-30 14:58:30 2023-03-30T07:58:30.802 DBG ../../market/mysterium/mysterium_api.go:66 > Total proposals: 2706 supported: 2706
2023-03-30 14:58:30 2023-03-30T07:58:30.807 DBG ../../core/discovery/repository.go:94 > Returning 2706 unique proposals
2023-03-30 14:58:30 2023-03-30T07:58:30.906 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x6174e40b65d97915ea2059a52ece3e6d67023f00 ConsumerID:0x679acd518e4964f4c197079f7e23e2418de5df9c HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error: Stage:registration_registered}
2023-03-30 14:58:30 2023-03-30T07:58:30.906 INF ../../tequilapi/endpoints/connection.go:183 > identity "0x679acd518e4964f4c197079f7e23e2418de5df9c" is registered, continuing...
2023-03-30 14:58:30 2023-03-30T07:58:30.906 DBG ../../core/discovery/repository.go:64 > Retrieving proposals from 1 repositories filter={"AccessPolicy":"all","AccessPolicySource":"","BandwidthMin":0,"CompatibilityMax":0,"CompatibilityMin":0,"ExcludeUnsupported":false,"IPType":"","IncludeMonitoringFailed":false,"LocationCountry":"","NATCompatibility":"","PresetID":0,"ProviderID":"","ProviderIDs":["0x6174e40b65d97915ea2059a52ece3e6d67023f00"],"QualityMin":0,"ServiceType":"wireguard"}
2023-03-30 14:58:31 2023-03-30T07:58:31.567 DBG ../../market/mysterium/mysterium_api.go:66 > Total proposals: 1 supported: 1
2023-03-30 14:58:31 2023-03-30T07:58:31.567 DBG ../../core/discovery/repository.go:94 > Returning 1 unique proposals
2023-03-30 14:58:31 2023-03-30T07:58:31.568 INF ../../core/connection/manager.go:744 > Connection state: NotConnected -> Connecting
2023-03-30 14:58:31 2023-03-30T07:58:31.568 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:e4a8e5d6-654d-4abd-a4d9-037551b24b3c State:Connecting SessionInfo:{StartedAt:2023-03-30 07:58:31.568023285 +0000 UTC m=+113.136611452 ConsumerID:{Address:0x679acd518e4964f4c197079f7e23e2418de5df9c} ConsumerLocation:{IP: ASN:133481 ISP:Advanced Info Service Public Company Limited Continent:AS Country:TH Region:Surat Thani City:Surat Thani IPType:residential} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:Connecting SessionID: Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x6174e40b65d97915ea2059a52ece3e6d67023f00 ServiceType:wireguard Location:{Continent:NA Country:US Region:Washington City:Seattle ASN:21743 ISP:Atlas Networks Corporation IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.15.22.197:4222 nats://51.15.23.12:4222 nats://51.15.23.14:4222 nats://51.15.23.16:4222]}}] AccessPolicies:<nil> Quality:{Quality:2.0250000000000004 Latency:219.164918 Bandwidth:39.839048 Uptime:23.833333}} Price:896674413933603/h, 215201859344064704/GiB }}}
2023-03-30 14:58:31 2023-03-30T07:58:31.568 DBG ../../communication/nats/connector.go:79 > Connecting to NATS servers: [nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.15.22.197:4222 nats://51.15.23.12:4222 nats://51.15.23.14:4222 nats://51.15.23.16:4222]
2023-03-30 14:58:31 2023-03-30T07:58:31.568 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.568 INF ../../core/state/state.go:399 > Session ID: , state: Connecting, duration: 623.412µs data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2023-03-30 14:58:31 2023-03-30T07:58:31.569 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.569 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.22.197:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.569 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30 14:58:31 2023-03-30T07:58:31.569 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.12:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.569 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.14:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.569 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.16:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.569 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.569 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.22.197:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.569 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.12:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.569 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.14:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.569 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.16:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.570 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.570 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.22.197:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.570 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.12:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.570 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.14:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.570 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.16:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.570 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.22.197:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.570 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.12:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.570 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.14:4222 access
2023-03-30 14:58:31 2023-03-30T07:58:31.571 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.16:4222 access
2023-03-30 14:58:33 2023-03-30T07:58:33.673 DBG ../../p2p/dialer.go:200 > Consumer 0x679acd518e4964f4c197079f7e23e2418de5df9c sending public key 71e5b5d57c092ea8e66e3afc248f634a3391ef01df4c647c25856672f256fa49 to provider 0x6174e40b65d97915ea2059a52ece3e6d67023f00
2023-03-30 14:58:35 2023-03-30T07:58:35.908 ??? ../../usr/local/go/src/log/log.go:195 > http: proxy error: context canceled
2023-03-30 14:58:35 2023-03-30T07:58:35.911 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x7118baf4c54138a6f06aa199d5a51b0cf341d767 ConsumerID:0x679acd518e4964f4c197079f7e23e2418de5df9c HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error: Stage:registration_registered}
2023-03-30 14:58:35 2023-03-30T07:58:35.911 INF ../../tequilapi/endpoints/connection.go:183 > identity "0x679acd518e4964f4c197079f7e23e2418de5df9c" is registered, continuing...
2023-03-30 14:58:35 2023-03-30T07:58:35.911 DBG ../../core/discovery/repository.go:64 > Retrieving proposals from 1 repositories filter={"AccessPolicy":"all","AccessPolicySource":"","BandwidthMin":0,"CompatibilityMax":0,"CompatibilityMin":0,"ExcludeUnsupported":false,"IPType":"","IncludeMonitoringFailed":false,"LocationCountry":"","NATCompatibility":"","PresetID":0,"ProviderID":"","ProviderIDs":["0x7118baf4c54138a6f06aa199d5a51b0cf341d767"],"QualityMin":0,"ServiceType":"wireguard"}
2023-03-30 14:58:36 2023-03-30T07:58:36.551 DBG ../../market/mysterium/mysterium_api.go:66 > Total proposals: 1 supported: 1
2023-03-30 14:58:36 2023-03-30T07:58:36.551 DBG ../../core/discovery/repository.go:94 > Returning 1 unique proposals
2023-03-30 14:58:36 2023-03-30T07:58:36.551 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer whole Connect Duration:3.009µs}
2023-03-30 14:58:36 2023-03-30T07:58:36.551 DBG ../../core/connection/manager.go:232 > Consumer connection trace: "Consumer whole Connect" took 3.009µs
2023-03-30 14:58:36 2023-03-30T07:58:36.552 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x7118baf4c54138a6f06aa199d5a51b0cf341d767 ConsumerID:0x679acd518e4964f4c197079f7e23e2418de5df9c HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error:connection already exists Stage:connection_already_exists}
2023-03-30 14:58:36 2023-03-30T07:58:36.552 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30 14:58:36 2023-03-30T07:58:36.556 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x1c0fa48e1a6b71f9ede276e9cf9f25d2c5a656ba ConsumerID:0x679acd518e4964f4c197079f7e23e2418de5df9c HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error: Stage:registration_registered}
2023-03-30 14:58:36 2023-03-30T07:58:36.556 INF ../../tequilapi/endpoints/connection.go:183 > identity "0x679acd518e4964f4c197079f7e23e2418de5df9c" is registered, continuing...
2023-03-30 14:58:36 2023-03-30T07:58:36.556 DBG ../../core/discovery/repository.go:64 > Retrieving proposals from 1 repositories filter={"AccessPolicy":"all","AccessPolicySource":"","BandwidthMin":0,"CompatibilityMax":0,"CompatibilityMin":0,"ExcludeUnsupported":false,"IPType":"","IncludeMonitoringFailed":false,"LocationCountry":"","NATCompatibility":"","PresetID":0,"ProviderID":"","ProviderIDs":["0x1c0fa48e1a6b71f9ede276e9cf9f25d2c5a656ba"],"QualityMin":0,"ServiceType":"wireguard"}
2023-03-30 14:58:37 2023-03-30T07:58:37.186 DBG ../../market/mysterium/mysterium_api.go:66 > Total proposals: 1 supported: 1
2023-03-30 14:58:37 2023-03-30T07:58:37.186 DBG ../../core/discovery/repository.go:94 > Returning 1 unique proposals
2023-03-30 14:58:37 2023-03-30T07:58:37.186 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer whole Connect Duration:3.482µs}
2023-03-30 14:58:37 2023-03-30T07:58:37.187 DBG ../../core/connection/manager.go:232 > Consumer connection trace: "Consumer whole Connect" took 3.482µs
2023-03-30 14:58:37 2023-03-30T07:58:37.187 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x1c0fa48e1a6b71f9ede276e9cf9f25d2c5a656ba ConsumerID:0x679acd518e4964f4c197079f7e23e2418de5df9c HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error:connection already exists Stage:connection_already_exists}
2023-03-30 14:58:37 2023-03-30T07:58:37.187 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30 14:58:38 2023-03-30T07:58:38.822 INF ../../router/router_desktop.go:226 > Default gateway changed to 172.21.0.1, reconfiguring routes.
2023-03-30 14:58:38 2023-03-30T07:58:38.828 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2023-03-30 14:58:38 2023-03-30T07:58:38.828 DBG ../../core/ip/cached_resolver.go:75 > Found cached public IP
2023-03-30 14:58:38 2023-03-30T07:58:38.828 INF ../../core/port/pool.go:54 > Supplying port 31731
2023-03-30 14:58:38 2023-03-30T07:58:38.829 INF ../../core/port/pool.go:54 > Supplying port 30134
2023-03-30 14:58:38 2023-03-30T07:58:38.829 INF ../../core/port/pool.go:54 > Supplying port 59693
2023-03-30 14:58:38 2023-03-30T07:58:38.829 INF ../../core/port/pool.go:54 > Supplying port 17395
2023-03-30 14:58:38 2023-03-30T07:58:38.829 INF ../../core/port/pool.go:54 > Supplying port 25702
2023-03-30 14:58:38 2023-03-30T07:58:38.829 INF ../../core/port/pool.go:54 > Supplying port 44456
2023-03-30 14:58:38 2023-03-30T07:58:38.830 INF ../../core/port/pool.go:54 > Supplying port 39574
2023-03-30 14:58:38 2023-03-30T07:58:38.830 INF ../../core/port/pool.go:54 > Supplying port 27981
2023-03-30 14:58:38 2023-03-30T07:58:38.830 INF ../../core/port/pool.go:54 > Supplying port 15925
2023-03-30 14:58:38 2023-03-30T07:58:38.830 INF ../../core/port/pool.go:54 > Supplying port 33437
2023-03-30 14:58:38 2023-03-30T07:58:38.833 INF ../../core/port/pool.go:54 > Supplying port 12778
2023-03-30 14:58:38 2023-03-30T07:58:38.834 INF ../../core/port/pool.go:54 > Supplying port 10351
2023-03-30 14:58:38 2023-03-30T07:58:38.834 INF ../../core/port/pool.go:54 > Supplying port 58894
2023-03-30 14:58:38 2023-03-30T07:58:38.835 INF ../../core/port/pool.go:54 > Supplying port 46524
2023-03-30 14:58:38 2023-03-30T07:58:38.835 INF ../../core/port/pool.go:54 > Supplying port 49745
2023-03-30 14:58:38 2023-03-30T07:58:38.836 INF ../../core/port/pool.go:54 > Supplying port 58562
2023-03-30 14:58:38 2023-03-30T07:58:38.836 INF ../../core/port/pool.go:54 > Supplying port 10312
2023-03-30 14:58:38 2023-03-30T07:58:38.836 INF ../../core/port/pool.go:54 > Supplying port 36448
2023-03-30 14:58:38 2023-03-30T07:58:38.837 INF ../../core/port/pool.go:54 > Supplying port 21536
2023-03-30 14:58:38 2023-03-30T07:58:38.837 INF ../../core/port/pool.go:54 > Supplying port 53577
2023-03-30 14:58:38 2023-03-30T07:58:38.988 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:38 2023-03-30T07:58:38.994 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:38 2023-03-30T07:58:38.999 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.000 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.002 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.006 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.012 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.030 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.037 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.038 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.039 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.039 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.047 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.047 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.050 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.052 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.053 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.056 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.060 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.061 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x679acd518e4964f4c197079f7e23e2418de5df9c NATType:fail}
2023-03-30 14:58:39 2023-03-30T07:58:39.061 DBG ../../p2p/dialer.go:254 > Consumer 0x679acd518e4964f4c197079f7e23e2418de5df9c sending ack with encrypted config to provider 0x6174e40b65d97915ea2059a52ece3e6d67023f00
2023-03-30 14:58:39 2023-03-30T07:58:39.467 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2023-03-30 14:58:39 2023-03-30T07:58:39.467 DBG ../../p2p/dialer.go:327 > Pinging provider 0x6174e40b65d97915ea2059a52ece3e6d67023f00 using ports [21536 53577 31731 30134 33437 12778 10351 36448 59693 39574 15925 58894 58562 25702 44456 10312 17395 27981 46524 49745]:[48581 15002 30644 56669 10890 53200 24059 28099 27817 53945 16872 57018 23436 50861 36903 49932 22902 24565 13559 20603]
2023-03-30 14:58:39 2023-03-30T07:58:39.467 INF ../../nat/traversal/pinger.go:190 > NAT pinging to remote peer
2023-03-30 14:58:39 2023-03-30T07:58:39.467 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:21536
2023-03-30 14:58:39 2023-03-30T07:58:39.467 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:53577
2023-03-30 14:58:39 2023-03-30T07:58:39.467 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:31731
2023-03-30 14:58:39 2023-03-30T07:58:39.468 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:30134
2023-03-30 14:58:39 2023-03-30T07:58:39.468 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:33437
2023-03-30 14:58:39 2023-03-30T07:58:39.468 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:12778
2023-03-30 14:58:39 2023-03-30T07:58:39.468 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:10351
2023-03-30 14:58:39 2023-03-30T07:58:39.468 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:36448
2023-03-30 14:58:39 2023-03-30T07:58:39.468 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:59693
2023-03-30 14:58:39 2023-03-30T07:58:39.468 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:39574
2023-03-30 14:58:39 2023-03-30T07:58:39.469 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:15925
2023-03-30 14:58:39 2023-03-30T07:58:39.469 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:58894
2023-03-30 14:58:39 2023-03-30T07:58:39.469 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:58562
2023-03-30 14:58:39 2023-03-30T07:58:39.469 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:25702
2023-03-30 14:58:39 2023-03-30T07:58:39.469 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:44456
2023-03-30 14:58:39 2023-03-30T07:58:39.469 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:10312
2023-03-30 14:58:39 2023-03-30T07:58:39.471 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:27981
2023-03-30 14:58:39 2023-03-30T07:58:39.471 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:46524
2023-03-30 14:58:39 2023-03-30T07:58:39.471 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:49745
2023-03-30 14:58:39 2023-03-30T07:58:39.471 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:17395
2023-03-30 14:58:49 2023-03-30T07:58:49.468 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.468 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.469 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.469 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.469 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.469 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.469 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.469 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.469 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.469 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.469 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.469 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.470 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.470 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.470 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.470 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.470 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.470 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.470 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.470 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30 14:58:49 2023-03-30T07:58:49.470 WRN ../../communication/nats/connection_wrap.go:105 > NATS: disconnected
2023-03-30 14:58:49 2023-03-30T07:58:49.470 WRN ../../communication/nats/connection_wrap.go:104 > NATS: connection closed
2023-03-30 14:58:49 2023-03-30T07:58:49.470 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.471 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.472 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.472 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.472 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.472 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.472 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.472 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.472 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-03-30 14:58:49 2023-03-30T07:58:49.472 ERR ../../core/connection/manager.go:260 > Connect failed, disconnecting error="could not create p2p channel during connect: p2p dialer failed: could not dial p2p channel: could not ping peer: too few connections were built"
2023-03-30 14:58:49 2023-03-30T07:58:49.472 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30 14:58:49 2023-03-30T07:58:49.472 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30 14:58:49 2023-03-30T07:58:49.472 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30 14:58:49 2023-03-30T07:58:49.473 INF ../../core/connection/manager.go:744 > Connection state: Connecting -> NotConnected
2023-03-30 14:58:49 2023-03-30T07:58:49.473 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:e4a8e5d6-654d-4abd-a4d9-037551b24b3c State:NotConnected SessionInfo:{StartedAt:2023-03-30 07:58:31.568023285 +0000 UTC m=+113.136611452 ConsumerID:{Address:0x679acd518e4964f4c197079f7e23e2418de5df9c} ConsumerLocation:{IP: ASN:133481 ISP:Advanced Info Service Public Company Limited Continent:AS Country:TH Region:Surat Thani City:Surat Thani IPType:residential} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:NotConnected SessionID: Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x6174e40b65d97915ea2059a52ece3e6d67023f00 ServiceType:wireguard Location:{Continent:NA Country:US Region:Washington City:Seattle ASN:21743 ISP:Atlas Networks Corporation IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.15.22.197:4222 nats://51.15.23.12:4222 nats://51.15.23.14:4222 nats://51.15.23.16:4222]}}] AccessPolicies:<nil> Quality:{Quality:2.0250000000000004 Latency:219.164918 Bandwidth:39.839048 Uptime:23.833333}} Price:896674413933603/h, 215201859344064704/GiB }}}
2023-03-30 14:58:49 2023-03-30T07:58:49.473 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer whole Connect Duration:17.905476956s}
2023-03-30 14:58:49 2023-03-30T07:58:49.473 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P channel creation Duration:17.904024101s}
2023-03-30 14:58:49 2023-03-30T07:58:49.473 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30 14:58:49 2023-03-30T07:58:49.473 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P connect Duration:2.104951963s}
2023-03-30 14:58:49 2023-03-30T07:58:49.473 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30 14:58:49 2023-03-30T07:58:49.474 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P exchange Duration:5.149016851s}
2023-03-30 14:58:49 2023-03-30T07:58:49.474 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P exchange (ports) Duration:8.980889ms}
2023-03-30 14:58:49 2023-03-30T07:58:49.474 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30 14:58:49 2023-03-30T07:58:49.474 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30 14:58:49 2023-03-30T07:58:49.474 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P exchange ack Duration:405.695358ms}
2023-03-30 14:58:49 2023-03-30T07:58:49.474 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30 14:58:49 2023-03-30T07:58:49.474 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P dial (pinger) Duration:10.003374712s}
2023-03-30 14:58:49 2023-03-30T07:58:49.474 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30 14:58:49 2023-03-30T07:58:49.474 DBG ../../core/connection/manager.go:232 > Consumer connection trace: "Consumer whole Connect" took 17.905476956s, "Consumer P2P channel creation" took 17.904024101s, "Consumer P2P connect" took 2.104951963s, "Consumer P2P exchange" took 5.149016851s, "Consumer P2P exchange (ports)" took 8.980889ms, "Consumer P2P exchange ack" took 405.695358ms, "Consumer P2P dial (pinger)" took 10.003374712s
2023-03-30 14:58:49 2023-03-30T07:58:49.474 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x6174e40b65d97915ea2059a52ece3e6d67023f00 ConsumerID:0x679acd518e4964f4c197079f7e23e2418de5df9c HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error:could not create p2p channel during connect: p2p dialer failed: could not dial p2p channel: could not ping peer: too few connections were built Stage:connection_unknown_error}
2023-03-30 14:58:49 2023-03-30T07:58:49.474 ERR ../../tequilapi/endpoints/connection.go:216 > Failed to connect error="could not create p2p channel during connect: p2p dialer failed: could not dial p2p channel: could not ping peer: too few connections were built"
2023-03-30 14:58:49 2023-03-30T07:58:49.474 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30 14:58:49 2023-03-30T07:58:49.474 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
Just tried again
% yarn fleet-connect
yarn run v1.22.19
$ ts-node src/fleet/connect.ts
connecting to UA... (proxyPort: 10003)
connecting to JP... (proxyPort: 10005)
connecting to LT... (proxyPort: 10002)
connecting to CA... (proxyPort: 10007)
connecting to GB... (proxyPort: 10004)
connecting to DE... (proxyPort: 10001)
connecting to US... (proxyPort: 10006)
connected to: UA! (0x83646437be6e085985b419b27586f4941d53ae93)
failed to connect JP, retries left: 2
connecting to JP... (proxyPort: 10005)
failed to connect LT, retries left: 2
connecting to LT... (proxyPort: 10002)
connected to: DE! (0x991989fbfd381dbfd9c0740829255a1f59b7f954)
failed to connect CA, retries left: 2
connecting to CA... (proxyPort: 10007)
failed to connect GB, retries left: 2
connecting to GB... (proxyPort: 10004)
failed to connect LT, retries left: 1
connecting to LT... (proxyPort: 10002)
failed to connect JP, retries left: 1
connecting to JP... (proxyPort: 10005)
failed to connect US, retries left: 2
connecting to US... (proxyPort: 10006)
failed to connect CA, retries left: 1
connecting to CA... (proxyPort: 10007)
failed to connect GB, retries left: 1
connecting to GB... (proxyPort: 10004)
failed to connect US, retries left: 1
connecting to US... (proxyPort: 10006)
Connects to Ukraine and Germany.
While tethered to my phone as opposed to WiFI:
% yarn fleet-connect
yarn run v1.22.19
$ ts-node src/fleet/connect.ts
connecting to LT... (proxyPort: 10002)
connecting to JP... (proxyPort: 10005)
connecting to UA... (proxyPort: 10003)
connecting to CA... (proxyPort: 10007)
connecting to DE... (proxyPort: 10001)
connecting to GB... (proxyPort: 10004)
connecting to US... (proxyPort: 10006)
failed to connect LT, retries left: 2
connecting to LT... (proxyPort: 10002)
failed to connect JP, retries left: 2
connecting to JP... (proxyPort: 10005)
failed to connect UA, retries left: 2
connecting to UA... (proxyPort: 10003)
failed to connect CA, retries left: 2
connecting to CA... (proxyPort: 10007)
failed to connect DE, retries left: 2
connecting to DE... (proxyPort: 10001)
connected to: GB! (0xf29d0511e87d93e9288e2c28d63fbaca91114048)
failed to connect JP, retries left: 1
connecting to JP... (proxyPort: 10005)
failed to connect LT, retries left: 1
connecting to LT... (proxyPort: 10002)
failed to connect UA, retries left: 1
connecting to UA... (proxyPort: 10003)
failed to connect US, retries left: 2
connecting to US... (proxyPort: 10006)
failed to connect CA, retries left: 1
connecting to CA... (proxyPort: 10007)
failed to connect DE, retries left: 1
connecting to DE... (proxyPort: 10001)
failed to connect US, retries left: 1
connecting to US... (proxyPort: 10006)
✨ Done in 11.07s.
Seems random.
Well, it seems to be working tho in all respects this project is year old and by this point is a bit out-dated. Also connectivity is dependent on your router, ISP and the provider on the other end. You could check your NAT settings and avoid "Symmetric" NAT since this is a p2p VPN connection - we heavily rely on it.
I suggest you play around with TS script and "mysterium-vpn-js": "^19.3.0"
to improve your experience. Also there is more up to date version of mysterium-vpn-js
here https://www.npmjs.com/package/mysterium-vpn-js
Also I've updated README.MD of this project, the main takeaway is that you should not use "PayPal" or "Credit Card" in registering your node in the future for this USE CASE and instead use Direct transfer of MYST. Direct transfer of MYST will yield you balance in the end.
Awesome
Thanks a lot for your guidance.
I'll try running it on AWS instead locally. I also suspect NAT
@NinoSkopac be wary about traffic usage, we have several issue regarding excessive traffic even if the node is not doing anything which are still not solved. Just launching a node might run you up ~300mb of traffic. AFAIK cloud charges heavily for it.
Thanks for pointing that out.
Could you put a ballpark on how much wasted traffic are we talking?
A few gigabytes per month per node is okay for me, just not hundreds of gigabytes per node per month.
IMO traffic on AWS is cheap.
I don't have a clear picture ATM since we only ran into this issue around this month when we started experimenting with idea of mobile provider (running node on android device) but initial test drive suggested node will fetch some data of up to ~300mb when launched.
I would recommend you do your own experiment. Maybe if you are only using it as a consumer (meaning you will not be enabling services: "public"/"b2b") this won't cause you any problems.
I will put a reminder to reply to this issue once we have more data on it.
Can't connect on AWS either.
On AWS Ubuntu 22 LTS, after migrating the data folders from local machine (where I was running the fleet when I did onboarding for each node) to EC2:
ubuntu@ip-172-31-93-187:~/workshop$ yarn fleet-info
yarn run v1.22.19
$ ts-node src/fleet/info.ts
DE - balance: 0
LT - balance: 0.399974
UA - balance: 0.399802
GB - balance: 0.399982
JP - balance: 0.399935
US - balance: 0
CA - balance: 0.39984
Done in 4.44s.
ubuntu@ip-172-31-93-187:~/workshop$ yarn fleet-connect
yarn run v1.22.19
$ ts-node src/fleet/connect.ts
connecting to JP... (proxyPort: 10005)
connecting to UA... (proxyPort: 10003)
connecting to LT... (proxyPort: 10002)
connecting to CA... (proxyPort: 10007)
connecting to DE... (proxyPort: 10001)
connecting to GB... (proxyPort: 10004)
connecting to US... (proxyPort: 10006)
failed to connect DE, retries left: 2
connecting to DE... (proxyPort: 10001)
failed to connect DE, retries left: 1
connecting to DE... (proxyPort: 10001)
failed to connect US, retries left: 2
connecting to US... (proxyPort: 10006)
failed to connect US, retries left: 1
connecting to US... (proxyPort: 10006)
failed to connect JP, retries left: 2
connecting to JP... (proxyPort: 10005)
failed to connect UA, retries left: 2
connecting to UA... (proxyPort: 10003)
failed to connect LT, retries left: 2
connecting to LT... (proxyPort: 10002)
failed to connect CA, retries left: 2
connecting to CA... (proxyPort: 10007)
failed to connect GB, retries left: 2
connecting to GB... (proxyPort: 10004)
failed to connect UA, retries left: 1
connecting to UA... (proxyPort: 10003)
failed to connect JP, retries left: 1
connecting to JP... (proxyPort: 10005)
failed to connect CA, retries left: 1
connecting to CA... (proxyPort: 10007)
failed to connect LT, retries left: 1
connecting to LT... (proxyPort: 10002)
failed to connect GB, retries left: 1
connecting to GB... (proxyPort: 10004)
Done in 9.35s.
ubuntu@ip-172-31-93-187:~/workshop$
Seems like the issue is still NAT
iptables basepath detected: /sbin
2023-03-30T10:19:40.268 DBG ../../config/config.go:81 > Loading user configuration: /var/lib/mysterium-node/config-mainnet.toml
2023-03-30T10:19:40.268 INF ../../config/config.go:93 > User configuration loaded:
{"mmn":{"api-key":"fsXWFA5KlhNs3VmSNyr7btwC1vzGKJZ2u14JXaxi"},"terms":{"provider-agreed":true,"version":"0.0.50"}}
2023-03-30T10:19:40.276 DBG ../../config/config.go:216 > Returning CLI value data-dir:/var/lib/mysterium-node
2023-03-30T10:19:40.277 DBG ../../config/config.go:216 > Returning CLI value data-dir:/var/lib/mysterium-node
2023-03-30T10:19:40.277 DBG ../../config/config.go:216 > Returning CLI value script-dir:/etc/mysterium-node
2023-03-30T10:19:40.277 DBG ../../config/config.go:216 > Returning CLI value runtime-dir:/var/run/mysterium-node
2023-03-30T10:19:40.277 DBG ../../config/config.go:216 > Returning CLI value ui.port:20004
2023-03-30T10:19:40.277 INF ../../logconfig/config.go:74 > Log level: debug
2023-03-30T10:19:40.277 INF ../../logconfig/config.go:76 > Log file path: /root/.mysterium/logs/mysterium-node
2023-03-30T10:19:40.278 DBG ../../logconfig/rollingwriter/rollingwriter.go:76 > Found 0 old log files in log directory, skipping cleanup
2023-03-30T10:19:40.278 INF ../../cmd/di.go:218 > Starting Mysterium Node 1.19.21
2023-03-30T10:19:40.279 INF ../../firewall/incoming_firewall_noop.go:32 > Rules bootstrap was requested
2023-03-30T10:19:40.279 INF ../../cmd/di.go:701 > Using local DNS: location.mysterium.network -> [51.158.129.204]
2023-03-30T10:19:40.279 INF ../../cmd/di.go:701 > Using local DNS: observer.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30T10:19:40.279 INF ../../cmd/di.go:701 > Using local DNS: trust.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30T10:19:40.280 INF ../../cmd/di.go:701 > Using local DNS: pilvytis.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30T10:19:40.280 INF ../../cmd/di.go:701 > Using local DNS: affiliator.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30T10:19:40.280 INF ../../cmd/di.go:701 > Using local DNS: quality.mysterium.network -> [51.158.129.204]
2023-03-30T10:19:40.280 INF ../../cmd/di.go:701 > Using local DNS: feedback.mysterium.network -> [116.203.17.150]
2023-03-30T10:19:40.280 INF ../../cmd/di.go:701 > Using local DNS: api.ipify.org -> [54.204.14.42 54.225.153.147 54.235.83.248 54.243.161.145 23.21.109.69 23.21.126.66 50.19.252.36 174.129.214.20]
2023-03-30T10:19:40.281 INF ../../cmd/di.go:701 > Using local DNS: badupnp.benjojo.co.uk -> [104.22.70.70 104.22.71.70 172.67.25.154]
2023-03-30T10:19:40.281 INF ../../cmd/di.go:701 > Using local DNS: discovery.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30T10:19:40.281 INF ../../cmd/di.go:701 > Using local DNS: broker.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30T10:19:40.281 INF ../../cmd/di.go:701 > Using local DNS: transactor.mysterium.network -> [51.15.22.197 51.15.23.12 51.15.23.14 51.15.23.16]
2023-03-30T10:19:40.281 DBG ../../communication/nats/connector.go:79 > Connecting to NATS servers: [nats://broker.mysterium.network:4222]
2023-03-30T10:19:40.282 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30T10:19:40.282 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30T10:19:40.284 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.22.197:4222 access
2023-03-30T10:19:40.284 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.12:4222 access
2023-03-30T10:19:40.284 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.14:4222 access
2023-03-30T10:19:40.284 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.16:4222 access
2023-03-30T10:19:42.055 INF ../../cmd/di.go:730 > Using L1 Eth endpoints: [https://ethereum1.mysterium.network/ https://cloudflare-eth.com/]
2023-03-30T10:19:42.055 INF ../../cmd/di.go:731 > Using L2 Eth endpoints: [https://polygon1.mysterium.network/ https://polygon-rpc.com/]
2023-03-30T10:19:42.417 INF ../../cmd/di.go:513 > Node chain id 137
2023-03-30T10:19:42.789 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://discovery.mysterium.network/api/v4 access
2023-03-30T10:19:42.790 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://transactor.mysterium.network/api/v1 access
2023-03-30T10:19:42.790 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://affiliator.mysterium.network/api/v1 access
2023-03-30T10:19:42.790 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://hermes3.mysterium.network/api/v2 access
2023-03-30T10:19:42.790 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://pilvytis.mysterium.network access
2023-03-30T10:19:42.790 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://ethereum1.mysterium.network/ access
2023-03-30T10:19:42.790 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://cloudflare-eth.com/ access
2023-03-30T10:19:42.790 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://polygon1.mysterium.network/ access
2023-03-30T10:19:42.790 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://polygon-rpc.com/ access
2023-03-30T10:19:42.790 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://discovery.mysterium.network/api/v4 access
2023-03-30T10:19:42.791 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://transactor.mysterium.network/api/v1 access
2023-03-30T10:19:42.791 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://affiliator.mysterium.network/api/v1 access
2023-03-30T10:19:42.791 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://hermes3.mysterium.network/api/v2 access
2023-03-30T10:19:42.791 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://pilvytis.mysterium.network access
2023-03-30T10:19:42.791 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://ethereum1.mysterium.network/ access
2023-03-30T10:19:42.791 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://cloudflare-eth.com/ access
2023-03-30T10:19:42.791 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://polygon1.mysterium.network/ access
2023-03-30T10:19:42.791 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://polygon-rpc.com/ access
2023-03-30T10:19:42.791 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://location.mysterium.network/api/v1/location access
2023-03-30T10:19:42.791 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://location.mysterium.network/api/v1/location access
2023-03-30T10:19:42.791 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://location.mysterium.network/api/v1/location access
2023-03-30T10:19:42.791 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://location.mysterium.network/api/v1/location access
2023-03-30T10:19:42.792 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30T10:19:42.792 DBG ../../cmd/di.go:852 > Using lightweight keystore
2023-03-30T10:19:42.792 DBG ../../config/config.go:216 > Returning CLI value data-dir:/var/lib/mysterium-node
2023-03-30T10:19:42.792 DBG ../../core/ip/cached_resolver.go:59 > Outbound IP cache is empty, fetching IP
2023-03-30T10:19:42.792 WRN ../../ui/server.go:96 > could not read node ui version config, falling back to bundled version
2023-03-30T10:19:42.793 DBG ../../config/config.go:216 > Returning CLI value local-service-discovery:false
2023-03-30T10:19:42.796 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables --new MYST --table nat" output:
2023-03-30T10:19:42.799 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A MYST --destination 10.0.0.0/8 --jump DNAT --to-destination 240.0.0.1 --table nat" output:
2023-03-30T10:19:42.802 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A MYST --destination 172.16.0.0/12 --jump DNAT --to-destination 240.0.0.1 --table nat" output:
2023-03-30T10:19:42.804 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A MYST --destination 192.168.0.0/16 --jump DNAT --to-destination 240.0.0.1 --table nat" output:
2023-03-30T10:19:42.807 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A MYST --destination 127.0.0.0/8 --jump DNAT --to-destination 240.0.0.1 --table nat" output:
2023-03-30T10:19:42.808 INF ../../nat/service_ipforward.go:46 > IP forwarding already enabled
2023-03-30T10:19:42.808 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://quality.mysterium.network/api/v3 access
2023-03-30T10:19:42.808 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://quality.mysterium.network/api/v3 access
2023-03-30T10:19:42.809 INF ../../feedback/reporter.go:46 > Using feedback API at: https://feedback.mysterium.network
2023-03-30T10:19:42.809 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2023-03-30T10:19:42.809 INF ../../tequilapi/http_api_server.go:122 > API started on: 127.0.0.1:4050
2023-03-30T10:19:42.809 DBG ../../eventbus/event_bus.go:101 > Published topic="Node" event={Status:Started}
2023-03-30T10:19:42.809 DBG ../../core/ip/cached_resolver.go:55 > Found cached outbound IP
2023-03-30T10:19:42.809 DBG ../../core/ip/cached_resolver.go:79 > Public IP cache is empty, fetching IP
2023-03-30T10:19:42.809 INF ../../ui/server.go:160 > UI starting on: 172.21.0.9:20004
2023-03-30T10:19:42.809 INF ../../ui/discovery/discovery.go:66 > LAN discovery disabled. Starting noop local service discovery.
2023-03-30T10:19:42.810 INF ../../ui/server.go:160 > UI starting on: 127.0.0.1:20004
2023-03-30T10:19:42.810 DBG ../../core/location/oracle_resolver.go:67 > Detecting with oracle resolver
2023-03-30T10:19:42.810 DBG ../../core/ip/cached_resolver.go:55 > Found cached outbound IP
2023-03-30T10:19:42.810 DBG ../../identity/registry/registry_contract.go:158 > event received {Started}
2023-03-30T10:19:42.810 INF ../../identity/registry/registry_contract.go:316 > Starting registry...
2023-03-30T10:19:42.810 DBG ../../identity/registry/registry_contract.go:327 > Loading initial state
2023-03-30T10:19:42.811 INF ../../session/pingpong/hermes_promise_settler.go:382 > Listening for settlement events
2023-03-30T10:19:42.811 DBG ../../identity/registry/registry_contract.go:342 > Identity {"0x7465027f18442536710f73545d5f3c406050bb99"} already registered, skipping
2023-03-30T10:19:42.812 DBG ../../sleep/sleep_noop.go:28 > Register for noop sleep events
2023-03-30T10:19:42.903 INF ../../session/pingpong/hermes_promise_settler.go:511 > no inactive hermeses found for chain: 137
2023-03-30T10:19:43.173 INF ../../cmd/di.go:305 > Mysterium node started!
2023-03-30T10:19:43.277 INF ../../session/pingpong/pricing.go:208 > pricing info loaded. expires @ 2023-03-30 10:20:29.209537832 +0000 UTC
2023-03-30T10:19:43.361 DBG ../../session/pingpong/hermes_promise_handler.go:231 > hermes promise handler started
2023-03-30T10:19:43.368 DBG ../../core/location/cache.go:131 > original location detected: US (hosting)
2023-03-30T10:19:44.910 INF ../../nat/upnp/discover.go:58 > UPnP gateways detected: 0
2023-03-30T10:19:54.802 DBG ../../identity/manager.go:166 > Caching unlocked address: 0x7465027f18442536710f73545d5f3c406050bb99
2023-03-30T10:19:54.802 DBG ../../eventbus/event_bus.go:101 > Published topic="identity-unlocked" event={ChainID:137 ID:{Address:0x7465027f18442536710f73545d5f3c406050bb99}}
2023-03-30T10:19:54.803 DBG ../../eventbus/event_bus.go:101 > Published topic="resident-country" event={ID:0x7465027f18442536710f73545d5f3c406050bb99 Country:US}
2023-03-30T10:19:55.094 DBG ../../session/pingpong/consumer_balance_tracker.go:656 > Loaded hermes state: already promised: 17510698969485
2023-03-30T10:19:55.094 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+17510698969485 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0x7465027f18442536710f73545d5f3c406050bb99}}
2023-03-30T10:19:55.279 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0x7465027f18442536710f73545d5f3c406050bb99} Previous:+0 Current:+399982489301030515}
2023-03-30T10:20:05.407 DBG ../../identity/manager.go:153 > Unlocked identity found in cache, skipping keystore: 0x7465027f18442536710f73545d5f3c406050bb99
2023-03-30T10:20:05.690 DBG ../../core/discovery/repository.go:64 > Retrieving proposals from 1 repositories filter={"AccessPolicy":"","AccessPolicySource":"","BandwidthMin":0,"CompatibilityMax":0,"CompatibilityMin":2,"ExcludeUnsupported":true,"IPType":"residential","IncludeMonitoringFailed":false,"LocationCountry":"GB","NATCompatibility":"","PresetID":0,"ProviderID":"","ProviderIDs":null,"QualityMin":1,"ServiceType":""}
2023-03-30T10:20:06.304 DBG ../../market/mysterium/mysterium_api.go:66 > Total proposals: 831 supported: 831
2023-03-30T10:20:06.306 DBG ../../core/discovery/repository.go:94 > Returning 831 unique proposals
2023-03-30T10:20:06.361 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x27ade9c2296d10e62d295b726444600cec257fad ConsumerID:0x7465027f18442536710f73545d5f3c406050bb99 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error: Stage:registration_registered}
2023-03-30T10:20:06.362 INF ../../tequilapi/endpoints/connection.go:183 > identity "0x7465027f18442536710f73545d5f3c406050bb99" is registered, continuing...
2023-03-30T10:20:06.362 DBG ../../core/discovery/repository.go:64 > Retrieving proposals from 1 repositories filter={"AccessPolicy":"all","AccessPolicySource":"","BandwidthMin":0,"CompatibilityMax":0,"CompatibilityMin":0,"ExcludeUnsupported":false,"IPType":"","IncludeMonitoringFailed":false,"LocationCountry":"","NATCompatibility":"","PresetID":0,"ProviderID":"","ProviderIDs":["0x27ade9c2296d10e62d295b726444600cec257fad"],"QualityMin":0,"ServiceType":"wireguard"}
2023-03-30T10:20:06.642 DBG ../../market/mysterium/mysterium_api.go:66 > Total proposals: 1 supported: 1
2023-03-30T10:20:06.642 DBG ../../core/discovery/repository.go:94 > Returning 1 unique proposals
2023-03-30T10:20:06.642 INF ../../core/connection/manager.go:744 > Connection state: NotConnected -> Connecting
2023-03-30T10:20:06.643 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:bd0e6f48-9f45-4ba7-8390-5d20c1a09423 State:Connecting SessionInfo:{StartedAt:2023-03-30 10:20:06.6429145 +0000 UTC m=+26.435472012 ConsumerID:{Address:0x7465027f18442536710f73545d5f3c406050bb99} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:Connecting SessionID: Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x27ade9c2296d10e62d295b726444600cec257fad ServiceType:wireguard Location:{Continent:EU Country:GB Region:England City:Adel ASN:205570 ISP:Super Link Communications Co. Ltd IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.15.22.197:4222 nats://51.15.23.12:4222 nats://51.15.23.14:4222 nats://51.15.23.16:4222]}}] AccessPolicies:<nil> Quality:{Quality:2.4749999999999996 Latency:0 Bandwidth:23.01142 Uptime:23.808333}} Price:944925936705081/h, 226782224809219456/GiB }}}
2023-03-30T10:20:06.643 INF ../../core/state/state.go:399 > Session ID: , state: Connecting, duration: 393.285µs data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2023-03-30T10:20:06.643 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30T10:20:06.643 DBG ../../communication/nats/connector.go:79 > Connecting to NATS servers: [nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.15.22.197:4222 nats://51.15.23.12:4222 nats://51.15.23.14:4222 nats://51.15.23.16:4222]
2023-03-30T10:20:06.643 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30T10:20:06.643 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30T10:20:06.643 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.22.197:4222 access
2023-03-30T10:20:06.643 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.12:4222 access
2023-03-30T10:20:06.643 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.14:4222 access
2023-03-30T10:20:06.644 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.16:4222 access
2023-03-30T10:20:06.644 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30T10:20:06.644 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.22.197:4222 access
2023-03-30T10:20:06.644 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.12:4222 access
2023-03-30T10:20:06.644 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.14:4222 access
2023-03-30T10:20:06.645 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.16:4222 access
2023-03-30T10:20:06.645 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2023-03-30T10:20:06.645 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.22.197:4222 access
2023-03-30T10:20:06.645 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.12:4222 access
2023-03-30T10:20:06.645 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.14:4222 access
2023-03-30T10:20:06.645 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.16:4222 access
2023-03-30T10:20:06.646 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.22.197:4222 access
2023-03-30T10:20:06.646 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.12:4222 access
2023-03-30T10:20:06.646 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.14:4222 access
2023-03-30T10:20:06.646 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.15.23.16:4222 access
2023-03-30T10:20:08.513 DBG ../../p2p/dialer.go:200 > Consumer 0x7465027f18442536710f73545d5f3c406050bb99 sending public key 99cf97574dd34b88fcd819bc0a18f5b14386b42db4cd811e58ffca01ab8d7b0d to provider 0x27ade9c2296d10e62d295b726444600cec257fad
2023-03-30T10:20:11.361 ??? ../../usr/local/go/src/log/log.go:195 > http: proxy error: context canceled
2023-03-30T10:20:11.364 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x6bc942fccbde402f743daac5ca382353d787df47 ConsumerID:0x7465027f18442536710f73545d5f3c406050bb99 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error: Stage:registration_registered}
2023-03-30T10:20:11.364 INF ../../tequilapi/endpoints/connection.go:183 > identity "0x7465027f18442536710f73545d5f3c406050bb99" is registered, continuing...
2023-03-30T10:20:11.364 DBG ../../core/discovery/repository.go:64 > Retrieving proposals from 1 repositories filter={"AccessPolicy":"all","AccessPolicySource":"","BandwidthMin":0,"CompatibilityMax":0,"CompatibilityMin":0,"ExcludeUnsupported":false,"IPType":"","IncludeMonitoringFailed":false,"LocationCountry":"","NATCompatibility":"","PresetID":0,"ProviderID":"","ProviderIDs":["0x6bc942fccbde402f743daac5ca382353d787df47"],"QualityMin":0,"ServiceType":"wireguard"}
2023-03-30T10:20:11.849 DBG ../../market/mysterium/mysterium_api.go:66 > Total proposals: 1 supported: 1
2023-03-30T10:20:11.849 DBG ../../core/discovery/repository.go:94 > Returning 1 unique proposals
2023-03-30T10:20:11.849 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer whole Connect Duration:3.085µs}
2023-03-30T10:20:11.849 DBG ../../core/connection/manager.go:232 > Consumer connection trace: "Consumer whole Connect" took 3.085µs
2023-03-30T10:20:11.849 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x6bc942fccbde402f743daac5ca382353d787df47 ConsumerID:0x7465027f18442536710f73545d5f3c406050bb99 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error:connection already exists Stage:connection_already_exists}
2023-03-30T10:20:11.849 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30T10:20:11.851 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x5e83e37b1a00ed60da19d88deeba2e0a4e090647 ConsumerID:0x7465027f18442536710f73545d5f3c406050bb99 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error: Stage:registration_registered}
2023-03-30T10:20:11.851 INF ../../tequilapi/endpoints/connection.go:183 > identity "0x7465027f18442536710f73545d5f3c406050bb99" is registered, continuing...
2023-03-30T10:20:11.852 DBG ../../core/discovery/repository.go:64 > Retrieving proposals from 1 repositories filter={"AccessPolicy":"all","AccessPolicySource":"","BandwidthMin":0,"CompatibilityMax":0,"CompatibilityMin":0,"ExcludeUnsupported":false,"IPType":"","IncludeMonitoringFailed":false,"LocationCountry":"","NATCompatibility":"","PresetID":0,"ProviderID":"","ProviderIDs":["0x5e83e37b1a00ed60da19d88deeba2e0a4e090647"],"QualityMin":0,"ServiceType":"wireguard"}
2023-03-30T10:20:12.153 DBG ../../market/mysterium/mysterium_api.go:66 > Total proposals: 1 supported: 1
2023-03-30T10:20:12.153 DBG ../../core/discovery/repository.go:94 > Returning 1 unique proposals
2023-03-30T10:20:12.153 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer whole Connect Duration:3.659µs}
2023-03-30T10:20:12.153 DBG ../../core/connection/manager.go:232 > Consumer connection trace: "Consumer whole Connect" took 3.659µs
2023-03-30T10:20:12.153 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x5e83e37b1a00ed60da19d88deeba2e0a4e090647 ConsumerID:0x7465027f18442536710f73545d5f3c406050bb99 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error:connection already exists Stage:connection_already_exists}
2023-03-30T10:20:12.154 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30T10:20:18.321 INF ../../router/router_desktop.go:226 > Default gateway changed to 172.21.0.1, reconfiguring routes.
2023-03-30T10:20:18.324 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2023-03-30T10:20:18.324 DBG ../../core/ip/cached_resolver.go:75 > Found cached public IP
2023-03-30T10:20:18.324 INF ../../core/port/pool.go:54 > Supplying port 13031
2023-03-30T10:20:18.324 INF ../../core/port/pool.go:54 > Supplying port 29055
2023-03-30T10:20:18.324 INF ../../core/port/pool.go:54 > Supplying port 18054
2023-03-30T10:20:18.324 INF ../../core/port/pool.go:54 > Supplying port 26967
2023-03-30T10:20:18.324 INF ../../core/port/pool.go:54 > Supplying port 33734
2023-03-30T10:20:18.324 INF ../../core/port/pool.go:54 > Supplying port 22463
2023-03-30T10:20:18.324 INF ../../core/port/pool.go:54 > Supplying port 57621
2023-03-30T10:20:18.324 INF ../../core/port/pool.go:54 > Supplying port 59603
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 57927
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 58670
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 50547
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 32318
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 46721
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 44646
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 52482
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 11722
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 27830
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 11662
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 52059
2023-03-30T10:20:18.325 INF ../../core/port/pool.go:54 > Supplying port 42999
2023-03-30T10:20:18.441 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.441 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.441 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.441 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.441 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.441 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.441 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.441 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.442 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.442 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.442 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.442 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.443 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.443 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.443 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.443 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.443 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.443 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.444 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.444 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x7465027f18442536710f73545d5f3c406050bb99 NATType:full}
2023-03-30T10:20:18.444 DBG ../../p2p/dialer.go:254 > Consumer 0x7465027f18442536710f73545d5f3c406050bb99 sending ack with encrypted config to provider 0x27ade9c2296d10e62d295b726444600cec257fad
2023-03-30T10:20:18.899 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2023-03-30T10:20:18.899 DBG ../../p2p/dialer.go:327 > Pinging provider 0x27ade9c2296d10e62d295b726444600cec257fad using ports [57621 57927 11662 27830 52059 26967 22463 32318 46721 52482 13031 33734 50547 42999 11722 29055 18054 59603 58670 44646]:[13600 22972 23861 12881 29435 35577 27962 44797 14603 50925 38871 23624 35932 30835 16015 29153 16167 55128 27856 12420]
2023-03-30T10:20:18.899 INF ../../nat/traversal/pinger.go:190 > NAT pinging to remote peer
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:57621
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:13031
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:33734
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:50547
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:57927
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:42999
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:11722
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:11662
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:29055
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:27830
2023-03-30T10:20:18.899 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:18054
2023-03-30T10:20:18.900 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:52059
2023-03-30T10:20:18.900 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:59603
2023-03-30T10:20:18.900 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:26967
2023-03-30T10:20:18.900 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:58670
2023-03-30T10:20:18.900 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:44646
2023-03-30T10:20:18.900 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:22463
2023-03-30T10:20:18.900 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:46721
2023-03-30T10:20:18.900 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:32318
2023-03-30T10:20:18.900 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:52482
2023-03-30T10:20:19.203 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2023-03-30T10:20:28.899 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.899 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.900 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.900 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.900 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.900 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.900 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.900 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.900 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.900 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.900 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.901 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.901 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.901 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.901 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.901 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.901 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.901 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.901 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-03-30T10:20:28.901 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-03-30T10:20:28.902 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-03-30T10:20:28.903 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-03-30T10:20:28.903 ERR ../../core/connection/manager.go:260 > Connect failed, disconnecting error="could not create p2p channel during connect: p2p dialer failed: could not dial p2p channel: could not ping peer: too few connections were built"
2023-03-30T10:20:28.903 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30T10:20:28.903 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30T10:20:28.903 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30T10:20:28.903 INF ../../core/connection/manager.go:744 > Connection state: Connecting -> NotConnected
2023-03-30T10:20:28.901 WRN ../../communication/nats/connection_wrap.go:105 > NATS: disconnected
2023-03-30T10:20:28.903 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:bd0e6f48-9f45-4ba7-8390-5d20c1a09423 State:NotConnected SessionInfo:{StartedAt:2023-03-30 10:20:06.6429145 +0000 UTC m=+26.435472012 ConsumerID:{Address:0x7465027f18442536710f73545d5f3c406050bb99} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:NotConnected SessionID: Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x27ade9c2296d10e62d295b726444600cec257fad ServiceType:wireguard Location:{Continent:EU Country:GB Region:England City:Adel ASN:205570 ISP:Super Link Communications Co. Ltd IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.15.22.197:4222 nats://51.15.23.12:4222 nats://51.15.23.14:4222 nats://51.15.23.16:4222]}}] AccessPolicies:<nil> Quality:{Quality:2.4749999999999996 Latency:0 Bandwidth:23.01142 Uptime:23.808333}} Price:944925936705081/h, 226782224809219456/GiB }}}
2023-03-30T10:20:28.903 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer whole Connect Duration:22.260798481s}
2023-03-30T10:20:28.903 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P channel creation Duration:22.259530001s}
2023-03-30T10:20:28.903 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P connect Duration:1.869491071s}
2023-03-30T10:20:28.903 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-03-30T10:20:28.904 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30T10:20:28.903 WRN ../../communication/nats/connection_wrap.go:104 > NATS: connection closed
2023-03-30T10:20:28.904 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P exchange Duration:9.80793413s}
2023-03-30T10:20:28.904 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30T10:20:28.904 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30T10:20:28.904 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P exchange (ports) Duration:1.922105ms}
2023-03-30T10:20:28.904 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30T10:20:28.904 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P exchange ack Duration:454.835103ms}
2023-03-30T10:20:28.904 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30T10:20:28.904 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P dial (pinger) Duration:10.002796876s}
2023-03-30T10:20:28.905 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30T10:20:28.905 DBG ../../core/connection/manager.go:232 > Consumer connection trace: "Consumer whole Connect" took 22.260798481s, "Consumer P2P channel creation" took 22.259530001s, "Consumer P2P connect" took 1.869491071s, "Consumer P2P exchange" took 9.80793413s, "Consumer P2P exchange (ports)" took 1.922105ms, "Consumer P2P exchange ack" took 454.835103ms, "Consumer P2P dial (pinger)" took 10.002796876s
2023-03-30T10:20:28.905 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-03-30T10:20:28.905 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x27ade9c2296d10e62d295b726444600cec257fad ConsumerID:0x7465027f18442536710f73545d5f3c406050bb99 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error:could not create p2p channel during connect: p2p dialer failed: could not dial p2p channel: could not ping peer: too few connections were built Stage:connection_unknown_error}
2023-03-30T10:20:28.905 ERR ../../tequilapi/endpoints/connection.go:216 > Failed to connect error="could not create p2p channel during connect: p2p dialer failed: could not dial p2p channel: could not ping peer: too few connections were built"
The Mysterium VPN desktop app works perfectly on my local computer, MacOS.
But the Docker fleet doesn't want to connect, on that same local computer.
Identities with positive balances are set up.
How come?
How do I actually start the server for the single-node booking use-case?
% yarn booking
yarn run v1.22.19
$ ts-node src/booking.ts
/Users/ninoskopac/PhpstormProjects/mysteriumnetwork-workshop/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:12
function rejected(value) { try { step(generator["throw"](value)); } catch (e) { reject(e); } }
^
TequilapiError: connect ECONNREFUSED ::1:44449 (path="auth/authenticate")
at /Users/ninoskopac/PhpstormProjects/mysteriumnetwork-workshop/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:34:19
at Generator.throw (<anonymous>)
at rejected (/Users/ninoskopac/PhpstormProjects/mysteriumnetwork-workshop/node_modules/mysterium-vpn-js/lib/http/axios-adapter.js:12:65)
at processTicksAndRejections (node:internal/process/task_queues:95:5) {
_originalError: Error: connect ECONNREFUSED ::1:44449
at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1532:16) {
I'm guessing by using systemctl
as described here.
I got those services started but I can't top up:
ubuntu@ip-172-31-93-187:~$ myst account topup --amount 100 --currency BTC --gateway coingate
W0330 13:28:36.081587 31644 native_arm64.go:188] Could not read /proc/self/auxv: open /proc/self/auxv: permission denied
[ERROR] Failed to create a top-up request, make sure your requested amount is equal or more than 0.0001 BTC
ubuntu@ip-172-31-93-187:~$ myst account topup
W0330 13:28:51.548343 31651 native_arm64.go:188] Could not read /proc/self/auxv: open /proc/self/auxv: permission denied
[ERROR] Can't continue, no such gateway:
ubuntu@ip-172-31-93-187:~$ myst account topup --gateway coingate
W0330 13:29:01.594384 31657 native_arm64.go:188] Could not read /proc/self/auxv: open /proc/self/auxv: permission denied
[WARNING] Top-up amount is required and must be greater than 0
ubuntu@ip-172-31-93-187:~$ myst account topup --amount 1 --gateway coingate
W0330 13:29:10.040008 31664 native_arm64.go:188] Could not read /proc/self/auxv: open /proc/self/auxv: permission denied
[ERROR] Top-up amount must be greater than 10.4
ubuntu@ip-172-31-93-187:~$ myst account topup --amount 100 --gateway coingate
W0330 13:29:15.252735 31670 native_arm64.go:188] Could not read /proc/self/auxv: open /proc/self/auxv: permission denied
[WARNING] Given currency cannot be used
[INFO] Supported currencies are:BTC, BCH, DAI, ETH, LTC, USDT, MYST, DOGE
ubuntu@ip-172-31-93-187:~$ myst account topup --amount 100 --currency MYST --gateway coingate
W0330 13:29:32.160065 31677 native_arm64.go:188] Could not read /proc/self/auxv: open /proc/self/auxv: permission denied
[ERROR] Failed to create a top-up request, make sure your requested amount is equal or more than 0.0001 BTC
ubuntu@ip-172-31-93-187:~$ myst account topup --amount 0.0001 --currency BTC --gateway coingate
W0330 13:29:52.646097 31684 native_arm64.go:188] Could not read /proc/self/auxv: open /proc/self/auxv: permission denied
[ERROR] Top-up amount must be greater than 10.4
~$ myst cli orders create 0x58d554c8627f3e8675870e9f4fd122e8d0fc251 100 BTC coingate Croatia
W0330 14:17:14.145945 32332 native_arm64.go:188] Could not read /proc/self/auxv: open /proc/self/auxv: permission denied
[ERROR] Gateway data wrong, example: lightning_network=true,custom_id="123 11"
just cant get it working
From the first glance, it seems that consumer is behind the symmetric NAT (in symmetric NAT, the NAT's mapping associated with the connection to the well known STUN server is restricted to receiving data from the well-known server, and therefore the NAT mapping the well-known server sees is not useful information to the endpoint.).
There are situations in which NAT/UDP hole punching (used in node) will not work with some providers (and failing pings are clearly present in your log output) , most notably when one of the peers is behind a symmetric NAT. In such cases, peers can instead explicitly add port mappings, either manually or by allocating them automatically, using UPnP feature supported by most home/soho routers and single-NAT implementations.
a) How to port forward b) To enable or disable UPnP, login to your router's dashboard and navigate to the Advanced Settings > UPnP (the actual location might differ with each router model). c) Checking your "NAT settings/NAT type" of the Router is also a way to go; Anyway, making it more open will guarantee better connection results.
Another thing is if you are using the standard bridged connection and docker, so docker adds an extra layer of NAT which adds complexity for the connection and might impact the success of connections.
I would suggest to test with hosting providers first and then switch to residential ones.
Thank you @etherunit , I'll do what you said and report back.
What remains an unanswered question in my mind is how the Mysterium VPN desktop app works perfectly on my local computer, MacOS. Can connect to both residential and datacenter.
But the Docker fleet doesn't want to connect, on that same local computer, same network.
Would it be possible for Mysterium to use tunnels instead of NAT?
In terms of AWS, it could be a matter of not whitelisting ports for ingress.
Which ports should I allow? Udp 10000:60000?
For example, on AWS EC2, if I want to run a Web server on port 80, I have to allow that port first before the server starts allowing connections on that port.
It might be that Docker adds NAT complexity overhead there. The only way to find out is to run nat behavior probing test inside docker.
Use some utility to conduct tests.
E.g. docker run -it --rm yarmak/natdisco
Range of ports to forward: 30000-60000/udp
Hello.
Well, I've added my local computer to a DMZ which should alleviate NAT issues, and it still couldn't connect:
% yarn fleet-connect
yarn run v1.22.19
$ ts-node src/fleet/connect.ts
connecting to JP... (proxyPort: 10005)
connecting to UA... (proxyPort: 10003)
connecting to LT... (proxyPort: 10002)
connecting to DE... (proxyPort: 10001)
connecting to GB... (proxyPort: 10004)
connecting to US... (proxyPort: 10006)
connecting to CA... (proxyPort: 10007)
failed to connect JP, retries left: 2
connecting to JP... (proxyPort: 10005)
failed to connect UA, retries left: 2
connecting to UA... (proxyPort: 10003)
connected to: DE! (0xec511e6501719c8f760c3e630cfc9ae212654b2e)
failed to connect LT, retries left: 2
connecting to LT... (proxyPort: 10002)
failed to connect GB, retries left: 2
connecting to GB... (proxyPort: 10004)
failed to connect JP, retries left: 1
connecting to JP... (proxyPort: 10005)
failed to connect UA, retries left: 1
connecting to UA... (proxyPort: 10003)
failed to connect LT, retries left: 1
connecting to LT... (proxyPort: 10002)
failed to connect GB, retries left: 1
connecting to GB... (proxyPort: 10004)
failed to connect US, retries left: 2
connecting to US... (proxyPort: 10006)
failed to connect CA, retries left: 2
connecting to CA... (proxyPort: 10007)
failed to connect CA, retries left: 1
connecting to CA... (proxyPort: 10007)
failed to connect US, retries left: 1
connecting to US... (proxyPort: 10006)
✨ Done in 12.29s.
From GPT4, about DMZ:
Prompst: Will putting my host in a DMZ make it immune to NAT issues?
Placing your host in a DMZ (Demilitarized Zone) can help alleviate some NAT (Network Address Translation) issues, particularly when it comes to inbound connections. However, it doesn't make the host entirely immune to NAT issues, and there are other potential security implications to consider.
DMZ is a separate network segment, isolated from your internal network, that is designed to host public-facing services. When you place a host in a DMZ, it typically gets a public IP address, and traffic from the internet is allowed to directly reach the host without passing through NAT. This can help resolve issues related to port forwarding and inbound connections, as well as improve compatibility with some protocols that may not work well with NAT.
However, placing a host in a DMZ doesn't guarantee immunity to all NAT-related issues. If there are other devices or networks involved in the communication that use NAT, you might still encounter problems. Furthermore, NAT can still affect outbound connections, depending on how the DMZ and the rest of your network are configured.
It's essential to understand that placing a host in a DMZ also exposes it to potential attacks from the internet. When you move a host into a DMZ, you should implement additional security measures, such as firewalls, intrusion prevention systems, and regular security updates, to minimize the risk of a security breach. It's also a good practice to harden the host by disabling unnecessary services, implementing strong authentication mechanisms, and regularly monitoring for signs of compromise.
In summary, placing a host in a DMZ can help resolve some NAT issues, particularly for inbound connections, but it doesn't make the host completely immune to NAT problems. Additionally, placing a host in a DMZ exposes it to potential security risks, so it's crucial to implement proper security measures to protect the host.
I still can't get it running on EC2 either, even though I've allowed ingress for udp 10000:30000
as mentioned above.
Ok I figured it out 🎉 (well, you two did)
You need to allow udp 30000-60000 ingress on ec2.
containers work fine then but yarn fleet-connect
is buggy - it keeps telling me:
$ yarn fleet-connect
yarn run v1.22.19
$ ts-node src/fleet/connect.ts
connecting to LT... (proxyPort: 10002)
connecting to UA... (proxyPort: 10003)
connecting to JP... (proxyPort: 10005)
connecting to CA... (proxyPort: 10007)
connecting to GB... (proxyPort: 10004)
connecting to DE... (proxyPort: 10001)
connecting to US... (proxyPort: 10006)
failed to connect DE, retries left: 2
connecting to DE... (proxyPort: 10001)
failed to connect DE, retries left: 1
connecting to DE... (proxyPort: 10001)
failed to connect US, retries left: 2
connecting to US... (proxyPort: 10006)
failed to connect US, retries left: 1
connecting to US... (proxyPort: 10006)
failed to connect LT, retries left: 2
connecting to LT... (proxyPort: 10002)
failed to connect UA, retries left: 2
connecting to UA... (proxyPort: 10003)
failed to connect JP, retries left: 2
connecting to JP... (proxyPort: 10005)
failed to connect CA, retries left: 2
connecting to CA... (proxyPort: 10007)
failed to connect GB, retries left: 2
connecting to GB... (proxyPort: 10004)
failed to connect JP, retries left: 1
connecting to JP... (proxyPort: 10005)
failed to connect LT, retries left: 1
connecting to LT... (proxyPort: 10002)
failed to connect UA, retries left: 1
connecting to UA... (proxyPort: 10003)
failed to connect GB, retries left: 1
connecting to GB... (proxyPort: 10004)
failed to connect CA, retries left: 1
connecting to CA... (proxyPort: 10007)
Done in 9.22s.
even though the connections succeed and the proxies works
An update on this.
Unfortunately, it still doesn't properly work. It connects sometimes, about every fifth time. It sporadically works.
2023-04-27T09:38:19.517 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x2d643aa2f3297b0eb1c32649b1e1d36d46ded888 ConsumerID:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error:connection already exists Stage:connection_already_exists}
2023-04-27T09:38:19.517 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-04-27T09:38:20.232 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2023-04-27T09:38:20.233 DBG ../../core/ip/cached_resolver.go:79 > Public IP cache is empty, fetching IP
2023-04-27T09:38:20.610 INF ../../core/port/pool.go:54 > Supplying port 50307
2023-04-27T09:38:20.610 INF ../../core/port/pool.go:54 > Supplying port 12854
2023-04-27T09:38:20.610 INF ../../core/port/pool.go:54 > Supplying port 24922
2023-04-27T09:38:20.610 INF ../../core/port/pool.go:54 > Supplying port 52228
2023-04-27T09:38:20.610 INF ../../core/port/pool.go:54 > Supplying port 31050
2023-04-27T09:38:20.610 INF ../../core/port/pool.go:54 > Supplying port 48458
2023-04-27T09:38:20.610 INF ../../core/port/pool.go:54 > Supplying port 51668
2023-04-27T09:38:20.610 INF ../../core/port/pool.go:54 > Supplying port 50799
2023-04-27T09:38:20.610 INF ../../core/port/pool.go:54 > Supplying port 27544
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 47116
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 46814
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 12910
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 54945
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 34090
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 47971
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 41916
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 54890
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 53626
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 34727
2023-04-27T09:38:20.611 INF ../../core/port/pool.go:54 > Supplying port 48363
2023-04-27T09:38:20.727 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.727 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.728 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.728 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.728 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.728 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.729 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.729 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.729 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.729 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.729 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.729 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.729 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.730 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.730 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.730 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.730 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.730 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.730 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.730 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b NATType:fail}
2023-04-27T09:38:20.730 DBG ../../p2p/dialer.go:254 > Consumer 0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b sending ack with encrypted config to provider 0x1cf415cf4e78d4d067fb96709f0bab9da77d8e9c
2023-04-27T09:38:30.434 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2023-04-27T09:38:30.434 DBG ../../p2p/dialer.go:327 > Pinging provider 0x1cf415cf4e78d4d067fb96709f0bab9da77d8e9c using ports [47116 12910 34090 54890 12854 52228 31050 51668 53626 48363 48458 50799 47971 41916 50307 24922 54945 27544 46814 34727]:[11099 29946 25788 57854 49337 37783 48332 28097 44194 34145 24839 56093 32623 27371 35720 45576 38612 43295 53180 44995]
2023-04-27T09:38:30.434 INF ../../nat/traversal/pinger.go:190 > NAT pinging to remote peer
2023-04-27T09:38:30.434 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:53626
2023-04-27T09:38:30.434 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:47116
2023-04-27T09:38:30.434 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:48363
2023-04-27T09:38:30.434 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:12910
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:48458
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:34090
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:50799
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:54890
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:41916
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:12854
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:50307
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:52228
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:24922
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:31050
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:47971
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:54945
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:27544
2023-04-27T09:38:30.436 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:34727
2023-04-27T09:38:30.435 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:46814
2023-04-27T09:38:30.434 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:51668
2023-04-27T09:38:40.435 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.435 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.435 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.435 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.435 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.435 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.435 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.435 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.435 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.435 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 WRN ../../nat/traversal/pinger.go:204 > One of the pings has error error="ping receiver error: context deadline exceeded"
2023-04-27T09:38:40.436 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-04-27T09:38:40.436 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-04-27T09:38:40.436 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-04-27T09:38:40.437 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-04-27T09:38:40.437 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-04-27T09:38:40.437 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-04-27T09:38:40.437 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-04-27T09:38:40.437 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-04-27T09:38:40.437 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-04-27T09:38:40.437 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-04-27T09:38:40.437 WRN ../../communication/nats/connection_wrap.go:105 > NATS: disconnected
2023-04-27T09:38:40.437 WRN ../../communication/nats/connection_wrap.go:104 > NATS: connection closed
2023-04-27T09:38:40.437 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-04-27T09:38:40.438 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2023-04-27T09:38:40.438 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-04-27T09:38:40.438 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-04-27T09:38:40.438 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-04-27T09:38:40.438 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-04-27T09:38:40.439 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.22.197:4222 removed
2023-04-27T09:38:40.439 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.12:4222 removed
2023-04-27T09:38:40.439 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.14:4222 removed
2023-04-27T09:38:40.439 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.15.23.16:4222 removed
2023-04-27T09:38:40.439 ERR ../../core/connection/manager.go:260 > Connect failed, disconnecting error="could not create p2p channel during connect: p2p dialer failed: could not dial p2p channel: could not ping peer: too few connections were built"
2023-04-27T09:38:40.439 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-04-27T09:38:40.439 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-04-27T09:38:40.439 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-04-27T09:38:40.439 INF ../../core/connection/manager.go:744 > Connection state: Connecting -> NotConnected
2023-04-27T09:38:40.439 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:4b1faf7a-fa19-43be-970e-2bd2c360b695 State:NotConnected SessionInfo:{StartedAt:2023-04-27 09:38:13.299264975 +0000 UTC m=+141652.185452124 ConsumerID:{Address:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Technologies Inc. Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:NotConnected SessionID: Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x1cf415cf4e78d4d067fb96709f0bab9da77d8e9c ServiceType:wireguard Location:{Continent:NA Country:US Region:Virginia City:Ashburn ASN:206119 ISP:Turkcell Iletisim Hizmetleri A.S. IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.15.22.197:4222 nats://51.15.23.12:4222 nats://51.15.23.14:4222 nats://51.15.23.16:4222]}}] AccessPolicies:<nil> Quality:{Quality:2.4000000000000004 Latency:28601.395684 Bandwidth:15.85888 Uptime:24}} Price:935061826287954/h, 224414838309108992/GiB }}}
2023-04-27T09:38:40.439 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer whole Connect Duration:27.140645039s}
2023-04-27T09:38:40.439 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P channel creation Duration:27.139714352s}
2023-04-27T09:38:40.440 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P connect Duration:1.878462188s}
2023-04-27T09:38:40.440 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P exchange Duration:5.052514323s}
2023-04-27T09:38:40.440 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P exchange (ports) Duration:378.955374ms}
2023-04-27T09:38:40.440 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P exchange ack Duration:9.703391316s}
2023-04-27T09:38:40.440 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID: Key:Consumer P2P dial (pinger) Duration:10.002552927s}
2023-04-27T09:38:40.440 DBG ../../core/connection/manager.go:232 > Consumer connection trace: "Consumer whole Connect" took 27.140645039s, "Consumer P2P channel creation" took 27.139714352s, "Consumer P2P connect" took 1.878462188s, "Consumer P2P exchange" took 5.052514323s, "Consumer P2P exchange (ports)" took 378.955374ms, "Consumer P2P exchange ack" took 9.703391316s, "Consumer P2P dial (pinger)" took 10.002552927s
2023-04-27T09:38:40.440 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-04-27T09:38:40.440 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-04-27T09:38:40.440 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID:0x1cf415cf4e78d4d067fb96709f0bab9da77d8e9c ConsumerID:0x60a73e07e3f849b02ef37a20dd1c00ed13d6389b HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab Error:could not create p2p channel during connect: p2p dialer failed: could not dial p2p channel: could not ping peer: too few connections were built Stage:connection_unknown_error}
2023-04-27T09:38:40.440 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-04-27T09:38:40.440 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-04-27T09:38:40.440 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-04-27T09:38:40.440 ERR ../../tequilapi/endpoints/connection.go:216 > Failed to connect error="could not create p2p channel during connect: p2p dialer failed: could not dial p2p channel: could not ping peer: too few connections were built"
2023-04-27T09:38:40.441 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
2023-04-27T09:38:40.441 DBG ../../config/config.go:216 > Returning CLI value proxymode:true
2023-04-27T09:38:40.440 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: "
Running this containerized on EC2 with ingress udp/30000:60000 whitelisted.
Question
From the container logs, doesn't this imply ports 10k-60k are used, not 30k-60k ?
Pinging provider 0x1e620df35955abaad6186fd608a79264d4ddac4a using ports [21689 52155 49128 13730 38605 11558 50295 31258 31628 59656 47681 58182 54603 28444 10707 47281 42846 51378 46715 51996]:[24889 48294 23078 17535 38527 53482 12722 52416 56014 46609 47560 43762 10476 10810 19393 54598 56653 59714 42599 39033]
Yeah, this did help
Following the video:
Ubuntu 22.04.2 LTS (GNU/Linux 5.19.0-1022-aws aarch64)