Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Starting a Myst connection in Docker crashes host OS (Ubuntu, Alpine and Amazon Linux 2) #6063

Open
NinoSkopac opened this issue Jul 20, 2024 · 4 comments

Comments

@NinoSkopac
Copy link

I run the default docker run from the README:

docker run \
  --cap-add NET_ADMIN \
  --net host \
  --name myst -d \
  mysteriumnetwork/myst service --agreed-terms-and-conditions

I shell into the container, register and top up.

Then, I run myst connection up and I can't reach the server anymore until I reboot it.
Same thing on Ubuntu 24, Alpine and AL2. Running on EC2.

This doesn't happen if I remove --net host but then ofc p2p doesn't properly work. I'm guessing a faulty iptables rule.

@NinoSkopac NinoSkopac added the bug label Jul 20, 2024
@NinoSkopac
Copy link
Author

IDEALLY there would be NO NEED for --net host due to security concerns.

@NinoSkopac
Copy link
Author

Oh I noticed these OSes aren't officially supported, so I spun it up in Ubuntu 22, which is officially supported. Same thing.

@NinoSkopac NinoSkopac changed the title myst connection up in Docker crashes OS (Ubuntu, Alpine and Amazon Linux 2) Starting a connection in Docker crashes OS (Ubuntu, Alpine and Amazon Linux 2) Jul 20, 2024
@NinoSkopac NinoSkopac changed the title Starting a connection in Docker crashes OS (Ubuntu, Alpine and Amazon Linux 2) Starting a connection in Docker crashes host OS (Ubuntu, Alpine and Amazon Linux 2) Jul 20, 2024
@NinoSkopac NinoSkopac changed the title Starting a connection in Docker crashes host OS (Ubuntu, Alpine and Amazon Linux 2) Starting a Myst connection in Docker crashes host OS (Ubuntu, Alpine and Amazon Linux 2) Jul 20, 2024
@NinoSkopac
Copy link
Author

This is where it dies:

2024-07-20T16:37:41.880 DBG ../../consumer/session/session_storage.go:337 > Session 4eae89f0-f36d-4b97-a505-f2fa42995ec1 saved
2024-07-20T16:37:41.880 DBG ../../core/ip/cached_resolver.go:75 > Found cached public IP
2024-07-20T16:37:41.881 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2024-07-20T16:37:41.881 DBG ../../core/connection/dns_option.go:85 > Selecting DNS servers using strategy: auto
2024-07-20T16:37:41.881 DBG ../../core/connection/dns_option.go:95 > Attempting to use provider DNS
2024-07-20T16:37:41.881 INF ../../services/wireguard/connection/connection.go:145 > Starting new connection
2024-07-20T16:37:41.943 DBG ../../services/wireguard/endpoint/wg_client.go:93 > "ip link add iswgsupported type wireguard" output:

2024-07-20T16:37:42.043 DBG ../../services/wireguard/endpoint/wg_client.go:98 > "ip link del iswgsupported" output:

Apparently, it keeps going after I can no longer interact with the server:
(direct continuation)

2024-07-20T16:34:29.354 INF ../../services/wireguard/connection/connection.go:183 > Starting connection endpoint
2024-07-20T16:34:29.354 DBG ../../services/wireguard/endpoint/endpoint.go:72 > Allocated interface: myst0
2024-07-20T16:34:29.362 DBG ../../services/wireguard/endpoint/kernelspace/client.go:192 > "ip link add dev myst0 type wireguard" output:

2024-07-20T16:34:29.372 DBG ../../services/wireguard/endpoint/kernelspace/client.go:200 > "ip link set dev myst0 up" output:

2024-07-20T16:34:29.379 DBG ../../utils/netutil/network_linux.go:48 > "ip route add 0.0.0.0/1 dev myst0" output:

2024-07-20T16:34:29.391 DBG ../../utils/netutil/network_linux.go:52 > "ip route add 128.0.0.0/1 dev myst0" output:

2024-07-20T16:34:29.393 DBG ../../utils/netutil/network_linux.go:77 > "sysctl net.ipv6.conf.all.disable_ipv6" output:
net.ipv6.conf.all.disable_ipv6 = 0

2024-07-20T16:34:29.398 DBG ../../utils/netutil/network_linux.go:57 > "ip -6 route add ::/1 dev myst0" output:

2024-07-20T16:34:29.416 DBG ../../utils/netutil/network_linux.go:61 > "ip -6 route add 8000::/1 dev myst0" output:

2024-07-20T16:34:29.422 DBG ../../services/wireguard/endpoint/kernelspace/client.go:93 > "ip address replace dev myst0 10.182.1.2/24" output:

2024-07-20T16:34:29.476 INF ../../services/wireguard/connection/connection.go:168 > Waiting for initial handshake
2024-07-20T16:34:29.678 DBG ../../core/ip/cached_resolver.go:55 > Found cached outbound IP
2024-07-20T16:34:29.678 INF ../../firewall/outgoing_firewall_noop.go:40 > Outgoing traffic block requested
2024-07-20T16:34:29.679 DBG ../../core/ip/cached_resolver.go:101 > Clearing ip resolver cache
2024-07-20T16:34:29.679 DBG ../../core/connection/manager.go:841 > waiting for connected state
2024-07-20T16:34:29.679 DBG ../../core/connection/manager.go:873 > Connection state received: Connecting
2024-07-20T16:34:29.679 DBG ../../core/connection/manager.go:851 > Connected started event received
2024-07-20T16:34:29.679 DBG ../../core/connection/manager.go:873 > Connection state received: Connected
2024-07-20T16:34:29.679 INF ../../core/connection/manager.go:744 > Connection state: Connecting -> Connected
2024-07-20T16:34:29.679 DBG ../../core/connection/manager.go:634 > Sending P2P message to "p2p-session-acknowledge": consumerID:"0xeed77101df82afde19dddfa2a58cd94ae1818696" sessionID:"6fd63ee6-25dc-4dfe-9894-ae9c26f16edf"
2024-07-20T16:34:29.679 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:3137070e-0fee-481a-add8-e03e74da5087 State:Connected SessionInfo:{StartedAt:2024-07-20 16:34:22.199801766 +0000 UTC m=+76.741473644 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:Connected SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x01781972ad4a5b662c49aacec2162a1f91701b29 ServiceType:wireguard Location:{Continent:EU Country:NL Region:Limburg City:Kerkrade ASN:44592 ISP:Skylink Data Center BV IPType:hosting} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] AccessPolicies: Quality:{Quality:2.9 Latency:14.77 Bandwidth:333.06 Uptime:24}} Price:326671414291221/h, 588008545724197806/GiB }}}
2024-07-20T16:34:29.680 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer whole Connect Duration:7.480315255s}
2024-07-20T16:34:29.680 INF ../../cmd/di.go:1082 > Reconnecting HTTP clients due to VPN connection state change
2024-07-20T16:34:29.680 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer P2P channel creation Duration:6.473142899s}
2024-07-20T16:34:29.680 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer P2P connect Duration:1.772879238s}
2024-07-20T16:34:29.680 DBG ../../core/location/oracle_resolver.go:67 > Detecting with oracle resolver
2024-07-20T16:34:29.680 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer P2P exchange Duration:4.235194234s}
2024-07-20T16:34:29.680 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer P2P exchange (ports) Duration:6.048382ms}
2024-07-20T16:34:29.681 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer P2P exchange ack Duration:149.657433ms}
2024-07-20T16:34:29.681 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer P2P dial (pinger) Duration:192.934918ms}
2024-07-20T16:34:29.681 INF ../../core/state/state.go:399 > Session ID: 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf, state: Connected, duration: 7.48135596s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2024-07-20T16:34:29.681 DBG ../../core/ip/cached_resolver.go:79 > Public IP cache is empty, fetching IP
2024-07-20T16:34:29.681 DBG ../../eventbus/event_bus.go:101 > Published topic="ether-client-reconnect" event={}
2024-07-20T16:34:29.681 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer P2P dial ack Duration:96.414012ms}
2024-07-20T16:34:29.681 DBG ../../identity/registry/registry_contract.go:329 > Loading initial state
2024-07-20T16:34:29.682 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer session creation Duration:529.703946ms}
2024-07-20T16:34:29.682 DBG ../../identity/registry/registry_contract.go:347 > Identity {"0xeed77101df82afde19dddfa2a58cd94ae1818696"} already registered, skipping
2024-07-20T16:34:29.682 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer session creation (start) Duration:2.330998ms}
2024-07-20T16:34:29.682 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Key:Consumer start connection Duration:473.352388ms}
2024-07-20T16:34:29.683 DBG ../../core/connection/manager.go:232 > Consumer connection trace: "Consumer whole Connect" took 7.480315255s, "Consumer P2P channel creation" took 6.473142899s, "Consumer P2P connect" took 1.772879238s, "Consumer P2P exchange" took 4.235194234s, "Consumer P2P exchange (ports)" took 6.048382ms, "Consumer P2P exchange ack" took 149.657433ms, "Consumer P2P dial (pinger)" took 192.934918ms, "Consumer P2P dial ack" took 96.414012ms, "Consumer session creation" took 529.703946ms, "Consumer session creation (start)" took 2.330998ms, "Consumer start connection" took 473.352388ms
2024-07-20T16:34:29.683 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID: ConsumerID:0xeed77101df82afde19dddfa2a58cd94ae1818696 HermesID:0x80ed28d84792d8b153bf2f25f0c4b7a1381de4ab Error: Stage:connection_ok}
2024-07-20T16:34:30.038 DBG ../../core/connection/manager.go:465 > Sending session status P2P message to "p2p-session-connectivity-status": ConsumerID:"0xeed77101df82afde19dddfa2a58cd94ae1818696" SessionID:"6fd63ee6-25dc-4dfe-9894-ae9c26f16edf" Code:1000
2024-07-20T16:34:30.043 DBG ../../eventbus/event_bus.go:101 > Published topic="location-update-event" event={IP: ASN:44592 ISP:Skylink Data Center BV Continent:EU Country:NL Region:Limburg City:Kerkrade IPType:hosting}
2024-07-20T16:34:34.015 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"55555522086490428779957235803780915081507070472437764806044096533651856579229" AgreementTotal:"9024531458892" TransactorFee:"0" Hashlock:"f3fde3ce813d9d93d1902994442fdd223352f95392ffec45eff50dd09782a27e" Provider:"0x01781972ad4a5b662c49aacec2162a1f91701b29" ChainID:137
2024-07-20T16:34:34.018 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {55555522086490428779957235803780915081507070472437764806044096533651856579229 9024531458892 0 f3fde3ce813d9d93d1902994442fdd223352f95392ffec45eff50dd09782a27e 0x01781972ad4a5b662c49aacec2162a1f91701b29 137}
2024-07-20T16:34:34.018 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 11493587268892296. Time component: 4.8487632619519990695e+11, data component: 1.1493102392566101097e+16. Transferred: 20987152, duration: 5.343457364. Price 326671414291221/h, 588008545724197806/GiB
2024-07-20T16:34:34.019 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.638, upper bound 18831430356712164
2024-07-20T16:34:34.019 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 1
2024-07-20T16:34:34.019 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 9024531458891
2024-07-20T16:34:34.020 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"9024531458892" Fee:"0" Hashlock:"\xf3\xfd\xe3΁=\x9d\x93ѐ)\x94D/\xdd"3R\xf9S\x92\xff\xecE\xef\xf5\rЗ\x82\xa2~" ChainID:137 Signature:"\x84dF\xaa\x15N\xbdT_\xae\xa4\xc2\x18fC\xda\xf8\x90:\x06\xe7\xfe\x9e\nw\x12\x19+\xf2\xa7\x1d\x1f\xbf\x91'\xb4{\x9c8\oԷ\xc1k\r\xf7j;$\xb0\xe3#aP\xf6\x15\x05\x92߂\xeb\x1c"} AgreementID:"55555522086490428779957235803780915081507070472437764806044096533651856579229" AgreementTotal:"9024531458892" Provider:"0x01781972ad4a5b662c49aacec2162a1f91701b29" Signature:"61e936885e0ccd62e308c7e5324ef1cdede3dd358756b4fc7f6adfa44cd41599546a86e59b3e3fece250a090961f84259f498f14a172a451de5fa7475ec9496a1c" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:34:34.103 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:3137070e-0fee-481a-add8-e03e74da5087 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Invoice:{AgreementID:+55555522086490428779957235803780915081507070472437764806044096533651856579229 AgreementTotal:+9024531458892 TransactorFee:+0 Hashlock:f3fde3ce813d9d93d1902994442fdd223352f95392ffec45eff50dd09782a27e Provider:0x01781972ad4a5b662c49aacec2162a1f91701b29 ChainID:137}}
2024-07-20T16:34:34.112 DBG ../../consumer/session/session_storage.go:294 > Session 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf updated
2024-07-20T16:34:34.112 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+9024531458892 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:34:34.113 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+42009731169891758}
2024-07-20T16:34:34.291 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Duration:87.361145ms}
2024-07-20T16:34:34.313 INF ../../core/state/state.go:450 > Session ID: 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf, state: Connected, duration: 12.113352774s data: 9.9KiB/5.3KiB, throughput: 0bs/0bs, spent: 0.000009MYST
2024-07-20T16:34:39.373 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Duration:80.87878ms}
2024-07-20T16:34:41.030 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"55555522086490428779957235803780915081507070472437764806044096533651856579229" AgreementTotal:"17395630095536" TransactorFee:"0" Hashlock:"d87042a92df98d796c7fb4422995dccabbac2b93dc2bcd6e4ad896b8ef000092" Provider:"0x01781972ad4a5b662c49aacec2162a1f91701b29" ChainID:137
2024-07-20T16:34:41.030 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {55555522086490428779957235803780915081507070472437764806044096533651856579229 17395630095536 0 d87042a92df98d796c7fb4422995dccabbac2b93dc2bcd6e4ad896b8ef000092 0x01781972ad4a5b662c49aacec2162a1f91701b29 137}
2024-07-20T16:34:41.031 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 11502072151184168. Time component: 1.1211880502144777769e+12, data component: 1.1500950963133954104e+16. Transferred: 21001484, duration: 12.355770368. Price 326671414291221/h, 588008545724197806/GiB
2024-07-20T16:34:41.031 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.623, upper bound 18662173729023836
2024-07-20T16:34:41.031 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 9024531458892
2024-07-20T16:34:41.031 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 8371098636644
2024-07-20T16:34:41.031 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"17395630095536" Fee:"0" Hashlock:"\xd8pB\xa9-\xf9\x8dyl\x7f\xb4B)\x95\xdcʻ\xac+\x93\xdc+\xcdnJؖ\xb8\xef\x00\x00\x92" ChainID:137 Signature:"\xaa*\x95\r\xfbi\xd2z\xf9m\xcbƤ\x8aK\x16\xd1s\xb8)\xda\xe4\xd5r\x8c\xc1\x02\xedD\xad\xb1Ta\x9f\x97\xf3r\x8c\x10T\xfaZ\xdf\x08\xc3\xe6R+t\x92Lo\x06!\xcfH"\xb9w\xfc:\xb6#\x9a\x1b"} AgreementID:"55555522086490428779957235803780915081507070472437764806044096533651856579229" AgreementTotal:"17395630095536" Provider:"0x01781972ad4a5b662c49aacec2162a1f91701b29" Signature:"d308ba0e568010bb6535631b2c3b00e0f5391d050bbb6e3074089070a9f3d1f4437cbc6efea62ecef5323b54c5d4078871617897e5cbea38cc6125cbfa00c8fd1b" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:34:41.130 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:3137070e-0fee-481a-add8-e03e74da5087 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Invoice:{AgreementID:+55555522086490428779957235803780915081507070472437764806044096533651856579229 AgreementTotal:+17395630095536 TransactorFee:+0 Hashlock:d87042a92df98d796c7fb4422995dccabbac2b93dc2bcd6e4ad896b8ef000092 Provider:0x01781972ad4a5b662c49aacec2162a1f91701b29 ChainID:137}}
2024-07-20T16:34:41.132 DBG ../../consumer/session/session_storage.go:294 > Session 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf updated
2024-07-20T16:34:41.132 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+17395630095536 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:34:41.132 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+42001360071255114}
2024-07-20T16:34:41.333 INF ../../core/state/state.go:450 > Session ID: 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf, state: Connected, duration: 19.133614417s data: 14.9KiB/14.4KiB, throughput: 0bs/0bs, spent: 0.000017MYST
2024-07-20T16:34:42.901 DBG ../../core/connection/manager.go:953 > Received p2p keepalive ping with SessionID=6fd63ee6-25dc-4dfe-9894-ae9c26f16edf from 0x01781972ad4A5b662C49Aacec2162a1f91701b29
2024-07-20T16:34:44.460 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Duration:84.018161ms}
2024-07-20T16:34:49.543 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Duration:80.937678ms}
2024-07-20T16:34:50.041 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"55555522086490428779957235803780915081507070472437764806044096533651856579229" AgreementTotal:"23107003448062" TransactorFee:"0" Hashlock:"b91e6b23ad9afeb24d92f94f667e06858442abc392324811667386b14ed36225" Provider:"0x01781972ad4a5b662c49aacec2162a1f91701b29" ChainID:137
2024-07-20T16:34:50.041 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {55555522086490428779957235803780915081507070472437764806044096533651856579229 23107003448062 0 b91e6b23ad9afeb24d92f94f667e06858442abc392324811667386b14ed36225 0x01781972ad4a5b662c49aacec2162a1f91701b29 137}
2024-07-20T16:34:50.041 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 11507669498379935. Time component: 1.9388587237782669071e+12, data component: 1.1505730639656157637e+16. Transferred: 21010212, duration: 21.366703973. Price 326671414291221/h, 588008545724197806/GiB
2024-07-20T16:34:50.042 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.617, upper bound 18611042204161545
2024-07-20T16:34:50.042 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 17395630095536
2024-07-20T16:34:50.042 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 5711373352526
2024-07-20T16:34:50.042 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"23107003448062" Fee:"0" Hashlock:"\xb9\x1ek#\xad\x9a\xfe\xb2M\x92\xf9Of~\x06\x85\x84B\xabÒ2H\x11fs\x86\xb1N\xd3b%" ChainID:137 Signature:"9\xf1\xa6\xe5_mR\xf0\x9e\xad\x1c\xf6\x16H䈕\xf2\x904U\xbd\x8c\x9c@ӺN.ƶ \x19\x1b\xf6\xc49\x97\x92\xc9[\xd3\xc9p\x894\x99YqT\n\xc1\xbaϖ\xb0\x97%\xe5\xb2\xd4+\x87\x90\x1c"} AgreementID:"55555522086490428779957235803780915081507070472437764806044096533651856579229" AgreementTotal:"23107003448062" Provider:"0x01781972ad4a5b662c49aacec2162a1f91701b29" Signature:"86eeab5666f3a150579b4931c0ce7ffa9478221a827a65e00887665d742ac6af41f902326b75496f29bbd52126e162e8030449f7f6cc01f72db7a55e43b6fc341b" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:34:50.126 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:3137070e-0fee-481a-add8-e03e74da5087 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Invoice:{AgreementID:+55555522086490428779957235803780915081507070472437764806044096533651856579229 AgreementTotal:+23107003448062 TransactorFee:+0 Hashlock:b91e6b23ad9afeb24d92f94f667e06858442abc392324811667386b14ed36225 Provider:0x01781972ad4a5b662c49aacec2162a1f91701b29 ChainID:137}}
2024-07-20T16:34:50.128 DBG ../../consumer/session/session_storage.go:294 > Session 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf updated
2024-07-20T16:34:50.128 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+23107003448062 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:34:50.128 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+41995648697902588}
2024-07-20T16:34:50.330 INF ../../core/state/state.go:450 > Session ID: 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf, state: Connected, duration: 28.130756882s data: 20.4KiB/17.4KiB, throughput: 0bs/0bs, spent: 0.000023MYST
2024-07-20T16:34:54.625 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Duration:81.30441ms}
2024-07-20T16:34:56.986 DBG ../../core/connection/manager.go:953 > Received p2p keepalive ping with SessionID=6fd63ee6-25dc-4dfe-9894-ae9c26f16edf from 0x01781972ad4A5b662C49Aacec2162a1f91701b29
2024-07-20T16:34:57.419 WRN ../../communication/nats/connection_wrap.go:105 > NATS: disconnected error="nats: stale connection"
2024-07-20T16:34:59.196 WRN ../../communication/nats/connection_wrap.go:106 > NATS: reconnected
2024-07-20T16:34:59.706 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Duration:80.563322ms}
2024-07-20T16:35:02.054 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"55555522086490428779957235803780915081507070472437764806044096533651856579229" AgreementTotal:"26834482057289" TransactorFee:"0" Hashlock:"f1c90132c554843861863b35d14ec4dae355a990b448fe5dd31696f274905213" Provider:"0x01781972ad4a5b662c49aacec2162a1f91701b29" ChainID:137
2024-07-20T16:35:02.054 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {55555522086490428779957235803780915081507070472437764806044096533651856579229 26834482057289 0 f1c90132c554843861863b35d14ec4dae355a990b448fe5dd31696f274905213 0x01781972ad4a5b662c49aacec2162a1f91701b29 137}
2024-07-20T16:35:02.054 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 11511607215226075. Time component: 3.0289222798797264836e+12, data component: 1.1508578292946196406e+16. Transferred: 21015412, duration: 33.379474697. Price 326671414291221/h, 588008545724197806/GiB
2024-07-20T16:35:02.055 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.615, upper bound 18587433630600133
2024-07-20T16:35:02.055 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 23107003448062
2024-07-20T16:35:02.055 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 3727478609227
2024-07-20T16:35:02.056 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"26834482057289" Fee:"0" Hashlock:"\xf1\xc9\x012\xc5T\x848a\x86;5\xd1N\xc4\xda\xe3U\xa9\x90\xb4H\xfe]\xd3\x16\x96\xf2t\x90R\x13" ChainID:137 Signature:"\xaa21k\xffO\x086\xed\xafn\xa1\xcao;n\xd6\xd1&Ũ\xe9\x1d\x88\xb1\x90\xe4LQV\xe3\xd8\x1doү\x19\xfa&\x0f\xe3\xa4\xf2q\x03u\xa0䅦\xdf,\xf2T\xe7!\xb7$\xc6\xec\x84\xc2\xd4D\x1c"} AgreementID:"55555522086490428779957235803780915081507070472437764806044096533651856579229" AgreementTotal:"26834482057289" Provider:"0x01781972ad4a5b662c49aacec2162a1f91701b29" Signature:"75ea1226ae4496e6d7ee2933a658f3b6a8fa69cb651925eff5222e6ed5ab2efd4f864c386f25fe60a8a4ac35146c686be9a10fd843ba75e32a94789456f636bd1c" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:35:02.141 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:3137070e-0fee-481a-add8-e03e74da5087 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Invoice:{AgreementID:+55555522086490428779957235803780915081507070472437764806044096533651856579229 AgreementTotal:+26834482057289 TransactorFee:+0 Hashlock:f1c90132c554843861863b35d14ec4dae355a990b448fe5dd31696f274905213 Provider:0x01781972ad4a5b662c49aacec2162a1f91701b29 ChainID:137}}
2024-07-20T16:35:02.144 DBG ../../consumer/session/session_storage.go:294 > Session 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf updated
2024-07-20T16:35:02.144 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+26834482057289 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:35:02.144 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+41991921219293361}
2024-07-20T16:35:02.345 INF ../../core/state/state.go:450 > Session ID: 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf, state: Connected, duration: 40.145953497s data: 21.7KiB/21.1KiB, throughput: 0bs/0bs, spent: 0.000027MYST
2024-07-20T16:35:04.788 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Duration:80.735304ms}
2024-07-20T16:35:09.870 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Duration:81.22789ms}
2024-07-20T16:35:10.382 INF ../../cmd/commands/service/command.go:103 > Stopping application
2024-07-20T16:35:10.382 INF ../../core/connection/manager.go:744 > Connection state: Connected -> Disconnecting
2024-07-20T16:35:10.382 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:3137070e-0fee-481a-add8-e03e74da5087 State:Disconnecting SessionInfo:{StartedAt:2024-07-20 16:34:22.199801766 +0000 UTC m=+76.741473644 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:Disconnecting SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x01781972ad4a5b662c49aacec2162a1f91701b29 ServiceType:wireguard Location:{Continent:EU Country:NL Region:Limburg City:Kerkrade ASN:44592 ISP:Skylink Data Center BV IPType:hosting} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] AccessPolicies: Quality:{Quality:2.9 Latency:14.77 Bandwidth:333.06 Uptime:24}} Price:326671414291221/h, 588008545724197806/GiB }}}
2024-07-20T16:35:10.382 INF ../../firewall/outgoing_firewall_noop.go:42 > Outgoing traffic block removed
2024-07-20T16:35:10.383 INF ../../services/wireguard/connection/connection.go:226 > Stopping WireGuard connection
2024-07-20T16:35:10.383 INF ../../firewall/outgoing_firewall_noop.go:50 > Rule for IP removed
2024-07-20T16:35:10.383 INF ../../core/state/state.go:399 > Session ID: 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf, state: Disconnecting, duration: 48.183626399s data: 32.7KiB/30.4KiB, throughput: 0bs/0bs, spent: 0.000027MYST
2024-07-20T16:35:10.383 DBG ../../core/connection/manager.go:962 > Stopping p2p keepalive: context canceled
2024-07-20T16:35:10.383 INF ../../core/connection/stats_publisher.go:72 > Stopped publishing connection statistics
2024-07-20T16:35:10.383 DBG ../../core/connection/manager.go:873 > Connection state received: Disconnecting
2024-07-20T16:35:10.498 DBG ../../services/wireguard/endpoint/kernelspace/client.go:186 > "ip link del dev myst0" output:

2024-07-20T16:35:10.546 DBG ../../eventbus/event_bus.go:101 > Published topic="Session" event={Status:Ended SessionInfo:{StartedAt:2024-07-20 16:34:22.199801766 +0000 UTC m=+76.741473644 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:Disconnecting SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x01781972ad4a5b662c49aacec2162a1f91701b29 ServiceType:wireguard Location:{Continent:EU Country:NL Region:Limburg City:Kerkrade ASN:44592 ISP:Skylink Data Center BV IPType:hosting} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] AccessPolicies: Quality:{Quality:2.9 Latency:14.77 Bandwidth:333.06 Uptime:24}} Price:326671414291221/h, 588008545724197806/GiB }}}
2024-07-20T16:35:10.546 DBG ../../core/connection/manager.go:873 > Connection state received: NotConnected
2024-07-20T16:35:10.550 DBG ../../consumer/session/session_storage.go:316 > Session 6fd63ee6-25dc-4dfe-9894-ae9c26f16edf updated with final data
2024-07-20T16:35:10.551 DBG ../../session/pingpong/invoice_payer.go:295 > Stopping...
2024-07-20T16:35:10.551 DBG ../../core/ip/cached_resolver.go:101 > Clearing ip resolver cache
2024-07-20T16:35:10.551 INF ../../core/connection/manager.go:744 > Connection state: Disconnecting -> NotConnected
2024-07-20T16:35:10.552 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:3137070e-0fee-481a-add8-e03e74da5087 State:NotConnected SessionInfo:{StartedAt:2024-07-20 16:34:22.199801766 +0000 UTC m=+76.741473644 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:NotConnected SessionID:6fd63ee6-25dc-4dfe-9894-ae9c26f16edf Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x01781972ad4a5b662c49aacec2162a1f91701b29 ServiceType:wireguard Location:{Continent:EU Country:NL Region:Limburg City:Kerkrade ASN:44592 ISP:Skylink Data Center BV IPType:hosting} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] AccessPolicies: Quality:{Quality:2.9 Latency:14.77 Bandwidth:333.06 Uptime:24}} Price:326671414291221/h, 588008545724197806/GiB }}}
2024-07-20T16:35:10.552 DBG ../../core/connection/manager.go:651 > Sending P2P message to "p2p-session-destroy": consumerID:"0xeed77101df82afde19dddfa2a58cd94ae1818696" sessionID:"6fd63ee6-25dc-4dfe-9894-ae9c26f16edf"
2024-07-20T16:35:10.552 DBG ../../core/location/oracle_resolver.go:67 > Detecting with oracle resolver
2024-07-20T16:35:10.552 INF ../../cmd/di.go:1082 > Reconnecting HTTP clients due to VPN connection state change
2024-07-20T16:35:10.556 DBG ../../eventbus/event_bus.go:101 > Published topic="ether-client-reconnect" event={}
2024-07-20T16:35:10.557 DBG ../../identity/registry/registry_contract.go:329 > Loading initial state
2024-07-20T16:35:10.558 DBG ../../identity/registry/registry_contract.go:347 > Identity {"0xeed77101df82afde19dddfa2a58cd94ae1818696"} already registered, skipping
2024-07-20T16:35:10.657 INF ../../cmd/node.go:92 > Connection closed
2024-07-20T16:35:10.657 INF ../../cmd/node.go:96 > API stopped
2024-07-20T16:35:10.657 DBG ../../eventbus/event_bus.go:101 > Published topic="Node" event={Status:Stopped}
2024-07-20T16:35:10.657 INF ../../ui/discovery/discovery.go:71 > LAN discovery disabled. Stopping noop local service discovery.
2024-07-20T16:35:10.657 DBG ../../session/pingpong/hermes_promise_handler.go:236 > hermes promise handler stopped
2024-07-20T16:35:10.658 INF ../../session/pingpong/hermes_promise_settler.go:390 > Stopped listening for settlement events
2024-07-20T16:35:10.657 INF ../../identity/registry/registry_contract.go:315 > Stopping registry...
2024-07-20T16:35:10.658 INF ../../ui/server.go:177 > Server stopped
2024-07-20T16:35:10.658 INF ../../ui/server.go:177 > Server stopped
2024-07-20T16:35:10.658 INF ../../cmd/node.go:99 > Web UI server stopped
2024-07-20T16:35:10.658 DBG ../../sleep/sleep_noop.go:33 > Unregister noop sleep events
2024-07-20T16:35:10.659 INF ../../cmd/node.go:102 > Sleep notifier stopped
2024-07-20T16:35:10.659 INF ../../services/wireguard/service/service.go:273 > Wireguard: stopping
2024-07-20T16:35:10.659 INF ../../services/wireguard/service/service.go:301 > Wireguard: stopped
2024-07-20T16:35:10.659 DBG ../../eventbus/event_bus.go:101 > Published topic="Service status" event={ID:1ee6443d-913c-4a07-8995-9426652e5c90 ProviderID:0xeed77101df82afde19dddfa2a58cd94ae1818696 Type:scraping Status:NotRunning}
2024-07-20T16:35:10.659 INF ../../services/wireguard/service/service.go:273 > Wireguard: stopping
2024-07-20T16:35:10.659 INF ../../services/wireguard/service/service.go:301 > Wireguard: stopped
2024-07-20T16:35:10.659 DBG ../../eventbus/event_bus.go:101 > Published topic="Service status" event={ID:8a46ad79-76e5-417c-88a3-c77fe15f823f ProviderID:0xeed77101df82afde19dddfa2a58cd94ae1818696 Type:data_transfer Status:NotRunning}
2024-07-20T16:35:10.659 INF ../../services/wireguard/service/service.go:273 > Wireguard: stopping
2024-07-20T16:35:10.660 INF ../../services/wireguard/service/service.go:301 > Wireguard: stopped
2024-07-20T16:35:10.660 DBG ../../eventbus/event_bus.go:101 > Published topic="Service status" event={ID:e075e54d-d89b-4a02-8c23-047fdd697888 ProviderID:0xeed77101df82afde19dddfa2a58cd94ae1818696 Type:dvpn Status:NotRunning}
2024-07-20T16:35:10.660 INF ../../nat/service_iptables.go:80 > Deleting NAT/Firewall rules
2024-07-20T16:35:10.660 INF ../../core/discovery/discovery.go:145 > Stopping discovery loop...
2024-07-20T16:35:10.659 INF ../../core/discovery/discovery.go:145 > Stopping discovery loop...
2024-07-20T16:35:10.661 DBG ../../session/pingpong/hermes_promise_settler.go:297 > Ignoring service event with status NotRunning
2024-07-20T16:35:10.661 ERR ../../core/service/manager.go:222 > Service stop failed error="no such instance"
2024-07-20T16:35:10.669 INF ../../core/discovery/discovery.go:145 > Stopping discovery loop...
2024-07-20T16:35:10.669 ERR ../../core/service/manager.go:222 > Service stop failed error="no such instance"
2024-07-20T16:35:10.670 DBG ../../session/pingpong/hermes_promise_settler.go:297 > Ignoring service event with status NotRunning
2024-07-20T16:35:10.670 ERR ../../core/service/manager.go:222 > Service stop failed error="no such instance"
2024-07-20T16:35:10.670 DBG ../../session/pingpong/hermes_promise_settler.go:297 > Ignoring service event with status NotRunning
2024-07-20T16:35:10.672 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D MYST --destination 10.0.0.0/8 --jump DNAT --to-destination 240.0.0.1 --table nat" output:

2024-07-20T16:35:10.680 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D MYST --destination 172.16.0.0/12 --jump DNAT --to-destination 240.0.0.1 --table nat" output:

2024-07-20T16:35:10.685 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D MYST --destination 192.168.0.0/16 --jump DNAT --to-destination 240.0.0.1 --table nat" output:

2024-07-20T16:35:10.694 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D MYST --destination 127.0.0.0/8 --jump DNAT --to-destination 240.0.0.1 --table nat" output:

2024-07-20T16:35:10.695 INF ../../nat/service_iptables.go:92 > Deleting NAT/Firewall rules... done
2024-07-20T16:35:10.700 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables --flush MYST --table nat" output:

2024-07-20T16:35:10.705 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables --delete-chain MYST --table nat" output:

2024-07-20T16:35:10.929 DBG ../../eventbus/event_bus.go:101 > Published topic="location-update-event" event={IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting}
2024-07-20T16:35:10.930 DBG ../../communication/nats/sender.go:59 > Message "signed.Oshb9RmlzHURIZ1c7wSb-AHsGm99SRw1dWABg1UD51ErwxBPz1E_CGig_-Nnoa5fWOOD1cPXSJU898NUAeso8AA.1721493310.proposal-unregister.v3" sending: {"proposal":{"id":0,"format":"service-proposal/v3","compatibility":2,"provider_id":"0xeed77101df82afde19dddfa2a58cd94ae1818696","service_type":"data_transfer","location":{"continent":"NA","country":"US","region":"Virginia","city":"Ashburn","asn":14618,"isp":"Amazon Data Services NoVa","ip_type":"hosting"},"contacts":[{"type":"nats/p2p/v1","definition":{"broker_addresses":["nats://broker.mysterium.network:4222","nats://broker.mysterium.network:4222","nats://51.158.204.30:4222","nats://51.158.204.75:4222","nats://51.158.204.9:4222","nats://51.158.204.23:4222"]}}],"access_policies":[{"id":"mysterium","source":"https://trust.mysterium.network/api/v1/access-policies/mysterium"}],"quality":{"quality":0,"latency":0,"bandwidth":0,"uptime":0}}}
2024-07-20T16:35:10.930 INF ../../core/discovery/discovery.go:224 > Proposal unregistered
2024-07-20T16:35:10.931 DBG ../../communication/nats/sender.go:59 > Message "signed.Oshb9RmlzHURIZ1c7wSb-AHsGm99SRw1dWABg1UD51ErwxBPz1E_CGig_-Nnoa5fWOOD1cPXSJU898NUAeso8AA.1721493310.proposal-unregister.v3" sending: {"proposal":{"id":0,"format":"service-proposal/v3","compatibility":2,"provider_id":"0xeed77101df82afde19dddfa2a58cd94ae1818696","service_type":"scraping","location":{"continent":"NA","country":"US","region":"Virginia","city":"Ashburn","asn":14618,"isp":"Amazon Data Services NoVa","ip_type":"hosting"},"contacts":[{"type":"nats/p2p/v1","definition":{"broker_addresses":["nats://broker.mysterium.network:4222","nats://broker.mysterium.network:4222","nats://51.158.204.30:4222","nats://51.158.204.75:4222","nats://51.158.204.9:4222","nats://51.158.204.23:4222"]}}],"access_policies":[{"id":"mysterium","source":"https://trust.mysterium.network/api/v1/access-policies/mysterium"}],"quality":{"quality":0,"latency":0,"bandwidth":0,"uptime":0}}}
2024-07-20T16:35:10.931 INF ../../core/discovery/discovery.go:224 > Proposal unregistered
2024-07-20T16:35:10.931 DBG ../../communication/nats/sender.go:59 > Message "signed.Oshb9RmlzHURIZ1c7wSb-AHsGm99SRw1dWABg1UD51ErwxBPz1E_CGig_-Nnoa5fWOOD1cPXSJU898NUAeso8AA.1721493310.proposal-unregister.v3" sending: {"proposal":{"id":0,"format":"service-proposal/v3","compatibility":2,"provider_id":"0xeed77101df82afde19dddfa2a58cd94ae1818696","service_type":"dvpn","location":{"continent":"NA","country":"US","region":"Virginia","city":"Ashburn","asn":14618,"isp":"Amazon Data Services NoVa","ip_type":"hosting"},"contacts":[{"type":"nats/p2p/v1","definition":{"broker_addresses":["nats://broker.mysterium.network:4222","nats://broker.mysterium.network:4222","nats://51.158.204.30:4222","nats://51.158.204.75:4222","nats://51.158.204.9:4222","nats://51.158.204.23:4222"]}}],"access_policies":[{"id":"mysterium","source":"https://trust.mysterium.network/api/v1/access-policies/mysterium"}],"quality":{"quality":0,"latency":0,"bandwidth":0,"uptime":0}}}
2024-07-20T16:35:10.932 INF ../../core/discovery/discovery.go:224 > Proposal unregistered
2024-07-20T16:35:15.364 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2024-07-20T16:35:15.364 DBG ../../eventbus/event_bus.go:101 > Published topic="registration_event_topic" event={ID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Status:Registered ChainID:137}
2024-07-20T16:35:15.364 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2024-07-20T16:35:15.364 DBG ../../core/discovery/discovery.go:161 > Registration event received for 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:35:15.364 INF ../../core/discovery/discovery.go:169 > Identity registered, proceeding with proposal registration
2024-07-20T16:35:15.364 DBG ../../core/discovery/discovery.go:161 > Registration event received for 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:35:15.365 INF ../../core/discovery/discovery.go:169 > Identity registered, proceeding with proposal registration
2024-07-20T16:35:15.365 DBG ../../core/discovery/discovery.go:161 > Registration event received for 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:35:15.365 INF ../../core/discovery/discovery.go:169 > Identity registered, proceeding with proposal registration
2024-07-20T16:35:15.364 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.30:4222 removed
2024-07-20T16:35:15.365 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.75:4222 removed
2024-07-20T16:35:15.365 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.9:4222 removed
2024-07-20T16:35:15.365 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.23:4222 removed
2024-07-20T16:35:15.364 WRN ../../communication/nats/connection_wrap.go:105 > NATS: disconnected
2024-07-20T16:35:15.365 WRN ../../communication/nats/connection_wrap.go:104 > NATS: connection closed
2024-07-20T16:35:15.365 INF ../../session/pingpong/hermes_promise_settler.go:321 > Identity registration event received for provider {"0xeed77101df82afde19dddfa2a58cd94ae1818696"}
2024-07-20T16:35:15.366 INF ../../session/pingpong/hermes_promise_settler.go:326 > Identity registration event handled for provider {"0xeed77101df82afde19dddfa2a58cd94ae1818696"}
2024-07-20T16:35:15.744 INF ../../firewall/incoming_firewall_noop.go:38 > Rules reset was requested
2024-07-20T16:35:15.744 INF ../../firewall/outgoing_firewall_noop.go:35 > Rules reset was requested
iptables basepath detected: /usr/sbin
2024-07-20T16:36:56.922 DBG ../../config/config.go:81 > Loading user configuration: /var/lib/mysterium-node/config-mainnet.toml
2024-07-20T16:36:56.923 INF ../../config/config.go:93 > User configuration loaded:
{"active-services":"scraping","node":{"version":"9564203725"},"terms":{"consumer-agreed":true,"provider-agreed":true,"version":"0.0.53"}}
2024-07-20T16:36:56.935 DBG ../../config/config.go:216 > Returning CLI value data-dir:/var/lib/mysterium-node
2024-07-20T16:36:56.935 DBG ../../config/config.go:216 > Returning CLI value data-dir:/var/lib/mysterium-node
2024-07-20T16:36:56.935 DBG ../../config/config.go:216 > Returning CLI value script-dir:/etc/mysterium-node
2024-07-20T16:36:56.936 DBG ../../config/config.go:216 > Returning CLI value runtime-dir:/var/run/mysterium-node
2024-07-20T16:36:56.938 INF ../../logconfig/config.go:74 > Log level: debug
2024-07-20T16:36:56.938 INF ../../logconfig/config.go:76 > Log file path: /root/.mysterium/logs/mysterium-node
2024-07-20T16:36:56.940 DBG ../../logconfig/rollingwriter/rollingwriter.go:80 > Found 0 old log files in log directory, skipping cleanup
2024-07-20T16:36:56.942 INF ../../cmd/di.go:223 > Starting Mysterium Node 1.29.23
2024-07-20T16:36:56.943 INF ../../firewall/incoming_firewall_noop.go:32 > Rules bootstrap was requested
2024-07-20T16:36:56.947 INF ../../cmd/di.go:700 > Using local DNS: broker.mysterium.network -> [51.158.204.30 51.158.204.75 51.158.204.9 51.158.204.23]
2024-07-20T16:36:56.947 INF ../../cmd/di.go:700 > Using local DNS: transactor.mysterium.network -> [51.158.204.30 51.158.204.75 51.158.204.9 51.158.204.23]
2024-07-20T16:36:56.948 INF ../../cmd/di.go:700 > Using local DNS: affiliator.mysterium.network -> [51.158.204.30 51.158.204.75 51.158.204.9 51.158.204.23]
2024-07-20T16:36:56.948 INF ../../cmd/di.go:700 > Using local DNS: pilvytis.mysterium.network -> [51.158.204.30 51.158.204.75 51.158.204.9 51.158.204.23]
2024-07-20T16:36:56.948 INF ../../cmd/di.go:700 > Using local DNS: feedback.mysterium.network -> [116.203.17.150]
2024-07-20T16:36:56.948 INF ../../cmd/di.go:700 > 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]
2024-07-20T16:36:56.948 INF ../../cmd/di.go:700 > Using local DNS: badupnp.benjojo.co.uk -> [104.22.70.70 104.22.71.70 172.67.25.154]
2024-07-20T16:36:56.948 INF ../../cmd/di.go:700 > Using local DNS: discovery.mysterium.network -> [51.158.204.30 51.158.204.75 51.158.204.9 51.158.204.23]
2024-07-20T16:36:56.948 INF ../../cmd/di.go:700 > Using local DNS: trust.mysterium.network -> [51.158.204.30 51.158.204.75 51.158.204.9 51.158.204.23]
2024-07-20T16:36:56.948 INF ../../cmd/di.go:700 > Using local DNS: location.mysterium.network -> [51.158.129.204]
2024-07-20T16:36:56.949 INF ../../cmd/di.go:700 > Using local DNS: quality.mysterium.network -> [51.158.129.204]
2024-07-20T16:36:56.949 INF ../../cmd/di.go:700 > Using local DNS: observer.mysterium.network -> [51.158.204.30 51.158.204.75 51.158.204.9 51.158.204.23]
2024-07-20T16:36:56.952 DBG ../../communication/nats/connector.go:79 > Connecting to NATS servers: [nats://broker.mysterium.network:4222]
2024-07-20T16:36:56.952 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2024-07-20T16:36:56.953 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2024-07-20T16:36:56.953 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.30:4222 access
2024-07-20T16:36:56.953 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.75:4222 access
2024-07-20T16:36:56.953 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.9:4222 access
2024-07-20T16:36:56.953 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.23:4222 access
2024-07-20T16:36:58.820 INF ../../cmd/di.go:729 > Using L1 Eth endpoints: [https://ethereum1.mysterium.network/ https://cloudflare-eth.com/]
2024-07-20T16:36:58.820 INF ../../cmd/di.go:730 > Using L2 Eth endpoints: [https://polygon1.mysterium.network/ https://polygon-rpc.com/]
2024-07-20T16:36:59.354 INF ../../cmd/di.go:518 > Node chain id 137
2024-07-20T16:36:59.738 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://discovery.mysterium.network/api/v4 access
2024-07-20T16:36:59.738 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://transactor.mysterium.network/api/v1 access
2024-07-20T16:36:59.739 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://affiliator.mysterium.network/api/v1 access
2024-07-20T16:36:59.739 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://hermes3.mysterium.network/api/v2 access
2024-07-20T16:36:59.739 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://pilvytis.mysterium.network access
2024-07-20T16:36:59.739 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://ethereum1.mysterium.network/ access
2024-07-20T16:36:59.739 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://cloudflare-eth.com/ access
2024-07-20T16:36:59.739 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://polygon1.mysterium.network/ access
2024-07-20T16:36:59.739 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://polygon-rpc.com/ access
2024-07-20T16:36:59.739 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://discovery.mysterium.network/api/v4 access
2024-07-20T16:36:59.740 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://transactor.mysterium.network/api/v1 access
2024-07-20T16:36:59.740 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://affiliator.mysterium.network/api/v1 access
2024-07-20T16:36:59.740 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://hermes3.mysterium.network/api/v2 access
2024-07-20T16:36:59.740 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://pilvytis.mysterium.network access
2024-07-20T16:36:59.740 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://ethereum1.mysterium.network/ access
2024-07-20T16:36:59.740 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://cloudflare-eth.com/ access
2024-07-20T16:36:59.740 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://polygon1.mysterium.network/ access
2024-07-20T16:36:59.740 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://polygon-rpc.com/ access
2024-07-20T16:36:59.740 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://location.mysterium.network/api/v1/location access
2024-07-20T16:36:59.740 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://location.mysterium.network/api/v1/location access
2024-07-20T16:36:59.740 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://location.mysterium.network/api/v1/location access
2024-07-20T16:36:59.741 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://location.mysterium.network/api/v1/location access
2024-07-20T16:36:59.741 DBG ../../cmd/di.go:856 > Using lightweight keystore
2024-07-20T16:36:59.743 DBG ../../config/config.go:216 > Returning CLI value data-dir:/var/lib/mysterium-node
2024-07-20T16:36:59.745 DBG ../../core/ip/cached_resolver.go:59 > Outbound IP cache is empty, fetching IP
2024-07-20T16:36:59.745 WRN ../../ui/server.go:94 > could not read node ui version config, falling back to bundled version
2024-07-20T16:36:59.745 DBG ../../config/config.go:216 > Returning CLI value local-service-discovery:false
2024-07-20T16:36:59.778 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables --new MYST --table nat" output:

2024-07-20T16:36:59.795 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:

2024-07-20T16:36:59.805 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:

2024-07-20T16:36:59.816 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:

2024-07-20T16:36:59.847 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:

2024-07-20T16:36:59.865 INF ../../nat/service_ipforward.go:46 > IP forwarding already enabled
2024-07-20T16:36:59.865 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL https://quality.mysterium.network/api/v3 access
2024-07-20T16:36:59.866 INF ../../firewall/incoming_firewall_noop.go:53 > Allow URL https://quality.mysterium.network/api/v3 access
2024-07-20T16:36:59.866 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2024-07-20T16:36:59.872 INF ../../feedback/reporter.go:48 > Using feedback API at: https://feedback.mysterium.network
2024-07-20T16:36:59.878 INF ../../tequilapi/http_api_server.go:135 > API started on: 127.0.0.1:4050
2024-07-20T16:36:59.878 DBG ../../eventbus/event_bus.go:101 > Published topic="Node" event={Status:Started}
2024-07-20T16:36:59.878 DBG ../../core/ip/cached_resolver.go:55 > Found cached outbound IP
2024-07-20T16:36:59.878 DBG ../../core/ip/cached_resolver.go:79 > Public IP cache is empty, fetching IP
2024-07-20T16:36:59.878 DBG ../../sleep/sleep_noop.go:28 > Register for noop sleep events
2024-07-20T16:36:59.879 INF ../../ui/discovery/discovery.go:66 > LAN discovery disabled. Starting noop local service discovery.
2024-07-20T16:36:59.879 DBG ../../core/ip/cached_resolver.go:55 > Found cached outbound IP
2024-07-20T16:36:59.879 INF ../../ui/server.go:158 > UI starting on: 172.31.81.235:4449
2024-07-20T16:36:59.879 INF ../../ui/server.go:158 > UI starting on: 127.0.0.1:4449
2024-07-20T16:36:59.880 INF ../../identity/registry/registry_contract.go:321 > Starting registry...
2024-07-20T16:36:59.880 INF ../../session/pingpong/hermes_promise_settler.go:384 > Listening for settlement events
2024-07-20T16:36:59.880 DBG ../../identity/registry/registry_contract.go:329 > Loading initial state
2024-07-20T16:36:59.880 DBG ../../identity/registry/registry_contract.go:347 > Identity {"0xeed77101df82afde19dddfa2a58cd94ae1818696"} already registered, skipping
2024-07-20T16:36:59.881 DBG ../../core/location/oracle_resolver.go:67 > Detecting with oracle resolver
2024-07-20T16:36:59.975 INF ../../session/pingpong/hermes_promise_settler.go:569 > no inactive hermeses found for chain: 137
2024-07-20T16:37:00.255 INF ../../cmd/di.go:310 > Mysterium node started!
2024-07-20T16:37:00.255 DBG ../../config/config.go:221 > Returning user config value active-services:scraping
2024-07-20T16:37:00.256 DBG ../../identity/selector/handler.go:98 > Attempting to use last identity
2024-07-20T16:37:00.256 DBG ../../identity/selector/handler.go:103 > Found identity in cache: 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:37:00.256 DBG ../../tequilapi/endpoints/terms.go:89 > Setting user config value: "terms.consumer-agreed" = %!q(bool=true)
2024-07-20T16:37:00.256 DBG ../../eventbus/event_bus.go:101 > Published topic="config:terms.consumer-agreed" event=true
2024-07-20T16:37:00.257 DBG ../../tequilapi/endpoints/terms.go:89 > Setting user config value: "terms.provider-agreed" = %!q(bool=true)
2024-07-20T16:37:00.259 DBG ../../eventbus/event_bus.go:101 > Published topic="config:terms.provider-agreed" event=true
2024-07-20T16:37:00.260 DBG ../../tequilapi/endpoints/terms.go:89 > Setting user config value: "terms.version" = "0.0.53"
2024-07-20T16:37:00.262 DBG ../../eventbus/event_bus.go:101 > Published topic="config:terms.version" event=0.0.53
2024-07-20T16:37:00.265 INF ../../config/config.go:99 > Saving user configuration
2024-07-20T16:37:00.266 INF ../../config/config.go:118 > User configuration written:
{"active-services":"scraping","node":{"version":"9564203725"},"terms":{"consumer-agreed":true,"provider-agreed":true,"version":"0.0.53"}}
2024-07-20T16:37:00.270 DBG ../../core/location/cache.go:133 > original location detected: US (hosting)
2024-07-20T16:37:00.357 DBG ../../identity/manager.go:166 > Caching unlocked address: 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:37:00.358 DBG ../../identity/selector/handler.go:108 > Unlocked identity: 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:37:00.358 DBG ../../eventbus/event_bus.go:101 > Published topic="identity-unlocked" event={ChainID:137 ID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:37:00.358 DBG ../../eventbus/event_bus.go:101 > Published topic="resident-country" event={ID:0xeed77101df82afde19dddfa2a58cd94ae1818696 Country:US}
2024-07-20T16:37:00.358 INF ../../cmd/commands/service/command.go:130 > Unlocked identity: 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:37:00.358 DBG ../../config/config.go:221 > Returning user config value node.version:9564203725
2024-07-20T16:37:00.359 DBG ../../eventbus/event_bus.go:101 > Published topic="config:node.version" event=9564203725
2024-07-20T16:37:00.359 INF ../../config/config.go:99 > Saving user configuration
2024-07-20T16:37:00.359 INF ../../config/config.go:118 > User configuration written:
{"active-services":"scraping","node":{"version":"9564203725"},"terms":{"consumer-agreed":true,"provider-agreed":true,"version":"0.0.53"}}
2024-07-20T16:37:00.360 INF ../../tequilapi/endpoints/service.go:183 > Service start options: {ProviderID:0xeed77101df82afde19dddfa2a58cd94ae1818696 Type:scraping AccessPolicies:0xc00101bc38 Options:{Subnet:{IP:10.182.0.0 Mask:ffff0000}}}
2024-07-20T16:37:00.360 DBG ../../core/service/manager.go:133 > Starting service options={"subnet":"10.182.0.0/16"} policyIDs=["mysterium"] providerID=0xeed77101df82afde19dddfa2a58cd94ae1818696 serviceType=scraping
2024-07-20T16:37:00.360 DBG ../../core/location/oracle_resolver.go:67 > Detecting with oracle resolver
2024-07-20T16:37:00.383 INF ../../session/pingpong/pricing.go:223 > pricing info loaded. expires @ 2024-07-20 16:38:29.676994145 +0000 UTC
2024-07-20T16:37:00.646 DBG ../../session/pingpong/hermes_promise_handler.go:231 > hermes promise handler started
2024-07-20T16:37:00.727 DBG ../../session/pingpong/consumer_balance_tracker.go:680 > Loaded hermes state: already promised: 26834482057289
2024-07-20T16:37:00.727 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+26834482057289 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:37:00.739 DBG ../../eventbus/event_bus.go:101 > Published topic="location-update-event" event={IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting}
2024-07-20T16:37:00.740 INF ../../core/discovery/discovery.go:92 > Starting discovery...
2024-07-20T16:37:00.742 DBG ../../eventbus/event_bus.go:101 > Published topic="Service status" event={ID:128422c2-fbcb-486f-870c-5eda4813cb7f ProviderID:0xeed77101df82afde19dddfa2a58cd94ae1818696 Type:scraping Status:Running}
2024-07-20T16:37:00.742 INF ../../services/wireguard/service/service.go:249 > Wireguard: starting
2024-07-20T16:37:00.743 DBG ../../core/ip/cached_resolver.go:55 > Found cached outbound IP
2024-07-20T16:37:00.743 DBG ../../communication/nats/sender.go:59 > Message "signed.fOfzSty0mGsk275tvdKUvGci897yLbTxP-ZmO_7Xy3JtsplPjVGIVGEw_tQafVCOyxm_WN9v4CB4dpLkqYlTdAE.1721493420.*.proposal-register.v3" sending: {"proposal":{"id":0,"format":"service-proposal/v3","compatibility":2,"provider_id":"0xeed77101df82afde19dddfa2a58cd94ae1818696","service_type":"scraping","location":{"continent":"NA","country":"US","region":"Virginia","city":"Ashburn","asn":14618,"isp":"Amazon Data Services NoVa","ip_type":"hosting"},"contacts":[{"type":"nats/p2p/v1","definition":{"broker_addresses":["nats://broker.mysterium.network:4222","nats://broker.mysterium.network:4222","nats://51.158.204.30:4222","nats://51.158.204.75:4222","nats://51.158.204.9:4222","nats://51.158.204.23:4222"]}}],"access_policies":[{"id":"mysterium","source":"https://trust.mysterium.network/api/v1/access-policies/mysterium"}],"quality":{"quality":0,"latency":0,"bandwidth":0,"uptime":0}}}
2024-07-20T16:37:00.748 INF ../../dns/proxy.go:67 > Starting DNS proxy on: :11253
2024-07-20T16:37:00.749 INF ../../services/wireguard/service/service.go:266 > Wireguard: started
2024-07-20T16:37:00.749 DBG ../../mmn/mmn.go:100 > Identity unlocked, registration to MMN disabled because the API key missing in config.
2024-07-20T16:37:00.752 INF ../../session/pingpong/hermes_promise_settler.go:228 > State for {0xeed77101df82afde19dddfa2a58cd94ae1818696} already loaded, skipping
2024-07-20T16:37:00.759 DBG ../../tequilapi/endpoints/config.go:165 > Setting user config value: "active-services" = "scraping"
2024-07-20T16:37:00.760 DBG ../../eventbus/event_bus.go:101 > Published topic="config:active-services" event=scraping
2024-07-20T16:37:00.761 INF ../../config/config.go:99 > Saving user configuration
2024-07-20T16:37:00.762 INF ../../config/config.go:118 > User configuration written:
{"active-services":"scraping","node":{"version":"9564203725"},"terms":{"consumer-agreed":true,"provider-agreed":true,"version":"0.0.53"}}
2024-07-20T16:37:01.076 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+0 Current:+41991921219293361}
2024-07-20T16:37:01.967 INF ../../nat/upnp/discover.go:58 > UPnP gateways detected: 0
2024-07-20T16:37:17.756 DBG ../../identity/selector/handler.go:98 > Attempting to use last identity
2024-07-20T16:37:17.757 DBG ../../identity/selector/handler.go:103 > Found identity in cache: 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:37:17.757 DBG ../../identity/manager.go:153 > Unlocked identity found in cache, skipping keystore: 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:37:17.757 DBG ../../identity/selector/handler.go:108 > Unlocked identity: 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:37:23.499 DBG ../../identity/selector/handler.go:98 > Attempting to use last identity
2024-07-20T16:37:23.499 DBG ../../identity/selector/handler.go:103 > Found identity in cache: 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:37:23.499 DBG ../../identity/manager.go:153 > Unlocked identity found in cache, skipping keystore: 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:37:23.499 DBG ../../identity/selector/handler.go:108 > Unlocked identity: 0xeed77101df82afde19dddfa2a58cd94ae1818696
2024-07-20T16:37:23.620 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID: ConsumerID:0xeed77101df82afde19dddfa2a58cd94ae1818696 HermesID:0x80ed28d84792d8b153bf2f25f0c4b7a1381de4ab Error: Stage:registration_registered}
2024-07-20T16:37:23.621 INF ../../tequilapi/endpoints/connection.go:185 > identity "0xeed77101df82afde19dddfa2a58cd94ae1818696" is registered, continuing...
2024-07-20T16:37:23.621 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":null,"QualityMin":0,"ServiceType":"wireguard"}
2024-07-20T16:37:25.114 DBG ../../market/mysterium/mysterium_api.go:66 > Total proposals: 9883 supported: 9883
2024-07-20T16:37:25.163 DBG ../../core/discovery/repository.go:94 > Returning 9883 unique proposals
2024-07-20T16:37:25.182 INF ../../core/connection/manager.go:744 > Connection state: NotConnected -> Connecting
2024-07-20T16:37:25.182 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 State:Connecting SessionInfo:{StartedAt:2024-07-20 16:37:25.182182167 +0000 UTC m=+28.648413230 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} 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:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ServiceType:wireguard Location:{Continent:AS Country:PH Region:Negros Occidental City:Asia ASN:18190 ISP:Asia Town Information Technology Park DSL-Network IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] AccessPolicies: Quality:{Quality:2.5 Latency:1277.02 Bandwidth:161.63 Uptime:24}} Price:326671414291221/h, 1306685657164884162/GiB }}}
2024-07-20T16:37:25.183 DBG ../../communication/nats/connector.go:79 > Connecting to NATS servers: [nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]
2024-07-20T16:37:25.183 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2024-07-20T16:37:25.183 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2024-07-20T16:37:25.183 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.30:4222 access
2024-07-20T16:37:25.184 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.75:4222 access
2024-07-20T16:37:25.183 INF ../../core/state/state.go:399 > Session ID: , state: Connecting, duration: 1.309393ms data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2024-07-20T16:37:25.184 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.9:4222 access
2024-07-20T16:37:25.184 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.23:4222 access
2024-07-20T16:37:25.185 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2024-07-20T16:37:25.185 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.30:4222 access
2024-07-20T16:37:25.185 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.75:4222 access
2024-07-20T16:37:25.185 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.9:4222 access
2024-07-20T16:37:25.185 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.23:4222 access
2024-07-20T16:37:25.186 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://broker.mysterium.network:4222 access
2024-07-20T16:37:25.186 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.30:4222 access
2024-07-20T16:37:25.186 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.75:4222 access
2024-07-20T16:37:25.186 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.9:4222 access
2024-07-20T16:37:25.187 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.23:4222 access
2024-07-20T16:37:25.187 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.30:4222 access
2024-07-20T16:37:25.187 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.75:4222 access
2024-07-20T16:37:25.187 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.9:4222 access
2024-07-20T16:37:25.187 INF ../../firewall/outgoing_firewall_noop.go:57 > Allow URL nats://51.158.204.23:4222 access
2024-07-20T16:37:26.971 DBG ../../p2p/dialer.go:200 > Consumer 0xeed77101df82afde19dddfa2a58cd94ae1818696 sending public key 0b9aa22ea99555af55100bbf269c64ba1e119dcc34f5fa9abb6264baf8a5df0a to provider 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751
2024-07-20T16:37:31.988 INF ../../router/router_desktop.go:226 > Default gateway changed to 172.31.80.1, reconfiguring routes.
2024-07-20T16:37:32.000 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2024-07-20T16:37:32.000 DBG ../../core/ip/cached_resolver.go:75 > Found cached public IP
2024-07-20T16:37:32.002 INF ../../core/port/pool.go:54 > Supplying port 43649
2024-07-20T16:37:32.002 INF ../../core/port/pool.go:54 > Supplying port 13252
2024-07-20T16:37:32.002 INF ../../core/port/pool.go:54 > Supplying port 30906
2024-07-20T16:37:32.002 INF ../../core/port/pool.go:54 > Supplying port 15923
2024-07-20T16:37:32.003 INF ../../core/port/pool.go:54 > Supplying port 32649
2024-07-20T16:37:32.003 INF ../../core/port/pool.go:54 > Supplying port 59552
2024-07-20T16:37:32.003 INF ../../core/port/pool.go:54 > Supplying port 48154
2024-07-20T16:37:32.004 INF ../../core/port/pool.go:54 > Supplying port 50517
2024-07-20T16:37:32.004 INF ../../core/port/pool.go:54 > Supplying port 17251
2024-07-20T16:37:32.004 INF ../../core/port/pool.go:54 > Supplying port 35318
2024-07-20T16:37:32.004 INF ../../core/port/pool.go:54 > Supplying port 57488
2024-07-20T16:37:32.008 INF ../../core/port/pool.go:54 > Supplying port 49500
2024-07-20T16:37:32.008 INF ../../core/port/pool.go:54 > Supplying port 10995
2024-07-20T16:37:32.008 INF ../../core/port/pool.go:54 > Supplying port 43104
2024-07-20T16:37:32.008 INF ../../core/port/pool.go:54 > Supplying port 13462
2024-07-20T16:37:32.008 INF ../../core/port/pool.go:54 > Supplying port 16367
2024-07-20T16:37:32.009 INF ../../core/port/pool.go:54 > Supplying port 11619
2024-07-20T16:37:32.009 INF ../../core/port/pool.go:54 > Supplying port 28132
2024-07-20T16:37:32.009 INF ../../core/port/pool.go:54 > Supplying port 27122
2024-07-20T16:37:32.009 INF ../../core/port/pool.go:54 > Supplying port 32307
2024-07-20T16:37:32.013 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.014 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.014 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.015 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.015 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.015 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.015 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.016 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.016 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.016 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.016 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.017 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.017 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.017 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.017 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.018 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.018 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.018 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.019 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.019 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:37:32.019 DBG ../../p2p/dialer.go:254 > Consumer 0xeed77101df82afde19dddfa2a58cd94ae1818696 sending ack with encrypted config to provider 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751
2024-07-20T16:37:32.440 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2024-07-20T16:37:32.441 DBG ../../p2p/dialer.go:327 > Pinging provider 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 using ports [43104 11619 15923 32649 59552 49500 27122 43649 13252 48154 28132 30906 10995 32307 13462 16367 50517 17251 35318 57488]:[38019 43770 32404 48547 21812 27016 10631 18449 37228 47881 33803 51094 50487 58197 14827 36525 56147 31063 50027 27201]
2024-07-20T16:37:32.441 INF ../../nat/traversal/pinger.go:190 > NAT pinging to remote peer
2024-07-20T16:37:32.441 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:28132
2024-07-20T16:37:32.442 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:11619
2024-07-20T16:37:32.442 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:15923
2024-07-20T16:37:32.442 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:32649
2024-07-20T16:37:32.443 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:59552
2024-07-20T16:37:32.443 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:49500
2024-07-20T16:37:32.443 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:43104
2024-07-20T16:37:32.444 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:43649
2024-07-20T16:37:32.444 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:30906
2024-07-20T16:37:32.445 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:13252
2024-07-20T16:37:32.445 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:10995
2024-07-20T16:37:32.445 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:32307
2024-07-20T16:37:32.445 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:48154
2024-07-20T16:37:32.446 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:13462
2024-07-20T16:37:32.443 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:27122
2024-07-20T16:37:32.448 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:16367
2024-07-20T16:37:32.448 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:50517
2024-07-20T16:37:32.449 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:35318
2024-07-20T16:37:32.448 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:17251
2024-07-20T16:37:32.450 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:57488
2024-07-20T16:37:32.677 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.678 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.678 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.679 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.679 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.682 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.682 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.684 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.679 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.689 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.689 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.690 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.690 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.691 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.692 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.692 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.692 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.692 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 2
2024-07-20T16:37:32.787 WRN ../../nat/traversal/pinger.go:100 > Sanitizing ping response on traversal.pingResponse{conn:(*net.UDPConn)(0xc000012b88), err:error(nil), id:3}
2024-07-20T16:37:32.788 WRN ../../nat/traversal/pinger.go:103 > Collected dangling socket: 172.31.81.235:32649
2024-07-20T16:37:32.788 WRN ../../nat/traversal/pinger.go:100 > Sanitizing ping response on traversal.pingResponse{conn:(*net.UDPConn)(0xc000012e40), err:error(nil), id:15}
2024-07-20T16:37:32.789 WRN ../../nat/traversal/pinger.go:103 > Collected dangling socket: 172.31.81.235:16367
2024-07-20T16:37:33.058 DBG ../../p2p/dialer.go:148 > Received handlers ready message from provider
2024-07-20T16:37:33.061 DBG ../../p2p/channel.go:212 > Creating p2p channel with local addr: 172.31.81.235:49500, UDP session addr: 127.0.0.1:35034, proxy addr: 127.0.0.1:58489, remote peer addr: x.x.x.x:27016
2024-07-20T16:37:33.061 DBG ../../p2p/wireformat.go:63 > Using protobufWireReader
2024-07-20T16:37:33.061 DBG ../../p2p/wireformat.go:72 > Using protobufWireWriter
2024-07-20T16:37:33.061 DBG ../../p2p/channel.go:574 > Will use service conn with local port: 43649, remote port: 18449
2024-07-20T16:37:33.061 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2024-07-20T16:37:33.062 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2024-07-20T16:37:33.062 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.30:4222 removed
2024-07-20T16:37:33.062 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.75:4222 removed
2024-07-20T16:37:33.062 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.9:4222 removed
2024-07-20T16:37:33.062 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.23:4222 removed
2024-07-20T16:37:33.062 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2024-07-20T16:37:33.062 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.30:4222 removed
2024-07-20T16:37:33.063 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.75:4222 removed
2024-07-20T16:37:33.063 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.9:4222 removed
2024-07-20T16:37:33.063 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.23:4222 removed
2024-07-20T16:37:33.063 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2024-07-20T16:37:33.064 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.30:4222 removed
2024-07-20T16:37:33.064 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.75:4222 removed
2024-07-20T16:37:33.064 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.9:4222 removed
2024-07-20T16:37:33.064 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.23:4222 removed
2024-07-20T16:37:33.065 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.30:4222 removed
2024-07-20T16:37:33.065 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.75:4222 removed
2024-07-20T16:37:33.065 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.9:4222 removed
2024-07-20T16:37:33.066 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.23:4222 removed
2024-07-20T16:37:33.068 WRN ../../communication/nats/connection_wrap.go:105 > NATS: disconnected
2024-07-20T16:37:33.068 DBG ../../core/connection/manager.go:614 > Sending P2P message to "p2p-session-create": consumer:{id:"0xeed77101df82afde19dddfa2a58cd94ae1818696" hermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" paymentVersion:"v3" location:{country:"US"} pricing:{PerGib:"\x12"G\xae\x9ci(\xc2" PerHour:"\x01)\x1b\x1d\x9bk\x15"}} config:"{"PublicKey":"wwBV3rIsqsDiuiXCiirbl/jjcktpcx/CDg7Qi+617VY=","Ports":null}"
2024-07-20T16:37:33.069 WRN ../../communication/nats/connection_wrap.go:104 > NATS: connection closed
2024-07-20T16:37:33.068 DBG ../../session/pingpong/invoice_payer.go:130 > Starting...
2024-07-20T16:37:37.230 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"1" TransactorFee:"0" Hashlock:"10a63c48492eda08b25edc8a7755e0fe41d264f563c64afc7297931171554965" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" ChainID:137
2024-07-20T16:37:37.230 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {48882262075709082053820932991886408849725724726258669664339357406747085159794 1 0 10a63c48492eda08b25edc8a7755e0fe41d264f563c64afc7297931171554965 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 137}
2024-07-20T16:37:37.231 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 25521581833026534. Time component: 3.7759152489127283895e+11, data component: 2.552120424150164379e+16. Transferred: 20971520, duration: 4.161152247. Price 326671414291221/h, 1306685657164884162/GiB
2024-07-20T16:37:37.231 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.646, upper bound 42013325342168517
2024-07-20T16:37:37.231 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 26834482057289
2024-07-20T16:37:37.231 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 1
2024-07-20T16:37:37.232 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"26834482057290" Fee:"0" Hashlock:"\x10\xa6<HI.\xda\x08\xb2^܊wU\xe0\xfeA\xd2d\xf5c\xc6J\xfcr\x97\x93\x11qUIe" ChainID:137 Signature:"wR\x17\xef|MM\x86C\xa40\xb6\x04\xfd\xbd\x18\xaa\x85>\x80M\xb9\x04p\x16n\x9aZf\xd6c\xc7D\xc6\x16nMSv\x14\xd6>_\x07\xc5ч\x0b\x92K\xc1\x9a\xf38q\x12iH\x9c'\x8c\xab5\xd5\x1c"} AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"1" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" Signature:"e9af238b821766584c3e2875f31f50c7414dc26411b8c6ea839432d2f1883c2d7b22618875f80abf98085ca65616261521b9a2fa0cd0327acb42ca0f3504993e1c" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:37:37.456 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+26834482057290 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:37:37.457 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+41991921219293360}
2024-07-20T16:37:41.876 DBG ../../eventbus/event_bus.go:101 > Published topic="Session" event={Status:Created SessionInfo:{StartedAt:2024-07-20 16:37:25.182182167 +0000 UTC m=+28.648413230 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:Connecting SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ServiceType:wireguard Location:{Continent:AS Country:PH Region:Negros Occidental City:Asia ASN:18190 ISP:Asia Town Information Technology Park DSL-Network IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] AccessPolicies: Quality:{Quality:2.5 Latency:1277.02 Bandwidth:161.63 Uptime:24}} Price:326671414291221/h, 1306685657164884162/GiB }}}
2024-07-20T16:37:41.880 DBG ../../consumer/session/session_storage.go:337 > Session 4eae89f0-f36d-4b97-a505-f2fa42995ec1 saved
2024-07-20T16:37:41.880 DBG ../../core/ip/cached_resolver.go:75 > Found cached public IP
2024-07-20T16:37:41.881 INF ../../firewall/outgoing_firewall_noop.go:48 > Allow IP access
2024-07-20T16:37:41.881 DBG ../../core/connection/dns_option.go:85 > Selecting DNS servers using strategy: auto
2024-07-20T16:37:41.881 DBG ../../core/connection/dns_option.go:95 > Attempting to use provider DNS
2024-07-20T16:37:41.881 INF ../../services/wireguard/connection/connection.go:145 > Starting new connection
2024-07-20T16:37:41.943 DBG ../../services/wireguard/endpoint/wg_client.go:93 > "ip link add iswgsupported type wireguard" output:

2024-07-20T16:37:42.043 DBG ../../services/wireguard/endpoint/wg_client.go:98 > "ip link del iswgsupported" output:

2024-07-20T16:37:42.043 INF ../../services/wireguard/connection/connection.go:183 > Starting connection endpoint
2024-07-20T16:37:42.044 DBG ../../services/wireguard/endpoint/endpoint.go:72 > Allocated interface: myst0
2024-07-20T16:37:42.065 DBG ../../services/wireguard/endpoint/kernelspace/client.go:192 > "ip link add dev myst0 type wireguard" output:

2024-07-20T16:37:42.072 DBG ../../services/wireguard/endpoint/kernelspace/client.go:200 > "ip link set dev myst0 up" output:

2024-07-20T16:37:42.084 DBG ../../utils/netutil/network_linux.go:48 > "ip route add 0.0.0.0/1 dev myst0" output:

2024-07-20T16:37:42.087 DBG ../../utils/netutil/network_linux.go:52 > "ip route add 128.0.0.0/1 dev myst0" output:

2024-07-20T16:37:42.103 DBG ../../utils/netutil/network_linux.go:77 > "sysctl net.ipv6.conf.all.disable_ipv6" output:
net.ipv6.conf.all.disable_ipv6 = 0

2024-07-20T16:37:42.115 DBG ../../utils/netutil/network_linux.go:57 > "ip -6 route add ::/1 dev myst0" output:

2024-07-20T16:37:42.118 DBG ../../utils/netutil/network_linux.go:61 > "ip -6 route add 8000::/1 dev myst0" output:

2024-07-20T16:37:42.125 DBG ../../services/wireguard/endpoint/kernelspace/client.go:93 > "ip address replace dev myst0 10.182.3.2/24" output:

2024-07-20T16:37:42.222 INF ../../services/wireguard/connection/connection.go:168 > Waiting for initial handshake
2024-07-20T16:37:42.424 DBG ../../core/ip/cached_resolver.go:55 > Found cached outbound IP
2024-07-20T16:37:42.425 INF ../../firewall/outgoing_firewall_noop.go:40 > Outgoing traffic block requested
2024-07-20T16:37:42.425 DBG ../../core/ip/cached_resolver.go:101 > Clearing ip resolver cache
2024-07-20T16:37:42.425 DBG ../../core/connection/manager.go:841 > waiting for connected state
2024-07-20T16:37:42.425 DBG ../../core/connection/manager.go:873 > Connection state received: Connecting
2024-07-20T16:37:42.426 DBG ../../core/connection/manager.go:851 > Connected started event received
2024-07-20T16:37:42.426 DBG ../../core/connection/manager.go:634 > Sending P2P message to "p2p-session-acknowledge": consumerID:"0xeed77101df82afde19dddfa2a58cd94ae1818696" sessionID:"4eae89f0-f36d-4b97-a505-f2fa42995ec1"
2024-07-20T16:37:42.426 DBG ../../core/connection/manager.go:873 > Connection state received: Connected
2024-07-20T16:37:42.427 INF ../../core/connection/manager.go:744 > Connection state: Connecting -> Connected
2024-07-20T16:37:42.427 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 State:Connected SessionInfo:{StartedAt:2024-07-20 16:37:25.182182167 +0000 UTC m=+28.648413230 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:Connected SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ServiceType:wireguard Location:{Continent:AS Country:PH Region:Negros Occidental City:Asia ASN:18190 ISP:Asia Town Information Technology Park DSL-Network IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] AccessPolicies: Quality:{Quality:2.5 Latency:1277.02 Bandwidth:161.63 Uptime:24}} Price:326671414291221/h, 1306685657164884162/GiB }}}
2024-07-20T16:37:42.427 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer whole Connect Duration:17.245441809s}
2024-07-20T16:37:42.427 INF ../../cmd/di.go:1082 > Reconnecting HTTP clients due to VPN connection state change
2024-07-20T16:37:42.429 DBG ../../eventbus/event_bus.go:101 > Published topic="ether-client-reconnect" event={}
2024-07-20T16:37:42.429 DBG ../../identity/registry/registry_contract.go:329 > Loading initial state
2024-07-20T16:37:42.430 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer P2P channel creation Duration:7.88330018s}
2024-07-20T16:37:42.431 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer P2P connect Duration:1.788192632s}
2024-07-20T16:37:42.429 DBG ../../identity/registry/registry_contract.go:347 > Identity {"0xeed77101df82afde19dddfa2a58cd94ae1818696"} already registered, skipping
2024-07-20T16:37:42.431 DBG ../../core/location/oracle_resolver.go:67 > Detecting with oracle resolver
2024-07-20T16:37:42.433 INF ../../core/state/state.go:399 > Session ID: 4eae89f0-f36d-4b97-a505-f2fa42995ec1, state: Connected, duration: 17.251439417s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2024-07-20T16:37:42.435 DBG ../../core/ip/cached_resolver.go:79 > Public IP cache is empty, fetching IP
2024-07-20T16:37:42.431 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer P2P exchange Duration:5.017125665s}
2024-07-20T16:37:42.441 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer P2P exchange (ports) Duration:8.838926ms}
2024-07-20T16:37:42.441 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer P2P exchange ack Duration:421.30296ms}
2024-07-20T16:37:42.441 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer P2P dial (pinger) Duration:346.964865ms}
2024-07-20T16:37:42.441 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer P2P dial ack Duration:273.988897ms}
2024-07-20T16:37:42.443 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer session creation Duration:8.809977028s}
2024-07-20T16:37:42.444 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer session creation (start) Duration:4.386255ms}
2024-07-20T16:37:42.444 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Key:Consumer start connection Duration:544.758264ms}
2024-07-20T16:37:42.444 DBG ../../core/connection/manager.go:232 > Consumer connection trace: "Consumer whole Connect" took 17.245441809s, "Consumer P2P channel creation" took 7.88330018s, "Consumer P2P connect" took 1.788192632s, "Consumer P2P exchange" took 5.017125665s, "Consumer P2P exchange (ports)" took 8.838926ms, "Consumer P2P exchange ack" took 421.30296ms, "Consumer P2P dial (pinger)" took 346.964865ms, "Consumer P2P dial ack" took 273.988897ms, "Consumer session creation" took 8.809977028s, "Consumer session creation (start)" took 4.386255ms, "Consumer start connection" took 544.758264ms
2024-07-20T16:37:42.444 DBG ../../eventbus/event_bus.go:101 > Published topic="connection_events" event={ServiceType:wireguard ProviderID: ConsumerID:0xeed77101df82afde19dddfa2a58cd94ae1818696 HermesID:0x80ed28d84792d8b153bf2f25f0c4b7a1381de4ab Error: Stage:connection_ok}
2024-07-20T16:37:42.861 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"612062149236" TransactorFee:"0" Hashlock:"ebc75dd5b196eeec79c98f2f7d81897a8452113a3dfa7cd3daeece4377a83a33" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" ChainID:137
2024-07-20T16:37:42.861 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {48882262075709082053820932991886408849725724726258669664339357406747085159794 612062149236 0 ebc75dd5b196eeec79c98f2f7d81897a8452113a3dfa7cd3daeece4377a83a33 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 137}
2024-07-20T16:37:42.862 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 25522092808042885. Time component: 8.885665412429919021e+11, data component: 2.552120424150164379e+16. Transferred: 20971520, duration: 9.792223649. Price 326671414291221/h, 1306685657164884162/GiB
2024-07-20T16:37:42.862 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.626, upper bound 41491406368221359
2024-07-20T16:37:42.862 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 26834482057290
2024-07-20T16:37:42.862 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 612062149235
2024-07-20T16:37:42.863 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"27446544206525" Fee:"0" Hashlock:"\xeb\xc7]ձ\x96\xee\xecyɏ/}\x81\x89z\x84R\x11:=\xfa|\xd3\xda\xee\xceCw\xa8:3" ChainID:137 Signature:"\xc3nd\xd3L\x9bx\xcc8\xd2-\xbf\xa0*'橮\xdcv\x8e@\xbb\x00\x9e\xb0" \x18J\x84\xa7b\xdb\x7fѪ\x9d{D'\xf0\x06\x06\x90c\xe2\xc8\xc8\x0c\xe6@\xe7q~\xd7D *\x078\r\u0094\x1c"} AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"612062149236" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" Signature:"9d400d79bc77c00c00d8e0c8d25025bc8add1f99c7f013a5217d86bdf06ad2264ff5e535eaff83f538b4de9bfb6dab34c8b12d84dfefc25a147e604f39685f5b1c" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:37:43.088 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Invoice:{AgreementID:+48882262075709082053820932991886408849725724726258669664339357406747085159794 AgreementTotal:+612062149236 TransactorFee:+0 Hashlock:ebc75dd5b196eeec79c98f2f7d81897a8452113a3dfa7cd3daeece4377a83a33 Provider:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ChainID:137}}
2024-07-20T16:37:43.090 DBG ../../consumer/session/session_storage.go:294 > Session 4eae89f0-f36d-4b97-a505-f2fa42995ec1 updated
2024-07-20T16:37:43.090 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+27446544206525 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:37:43.090 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+41991309157144125}
2024-07-20T16:37:43.291 INF ../../core/state/state.go:450 > Session ID: 4eae89f0-f36d-4b97-a505-f2fa42995ec1, state: Connected, duration: 18.109728848s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000001MYST
2024-07-20T16:37:45.237 DBG ../../eventbus/event_bus.go:101 > Published topic="location-update-event" event={IP: ASN:18190 ISP:Asia Town Information Technology Park DSL-Network Continent:AS Country:PH Region:Negros Occidental City:Asia IPType:residential}
2024-07-20T16:37:45.247 DBG ../../core/connection/manager.go:465 > Sending session status P2P message to "p2p-session-connectivity-status": ConsumerID:"0xeed77101df82afde19dddfa2a58cd94ae1818696" SessionID:"4eae89f0-f36d-4b97-a505-f2fa42995ec1" Code:1000
2024-07-20T16:37:47.100 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:223.631951ms}
2024-07-20T16:37:49.871 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"38954035301578" TransactorFee:"0" Hashlock:"8a0bee5ed696801cac9e9224bc0eaae4006d08d73994e836ff21cf49464cc629" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" ChainID:137
2024-07-20T16:37:49.871 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {48882262075709082053820932991886408849725724726258669664339357406747085159794 38954035301578 0 8a0bee5ed696801cac9e9224bc0eaae4006d08d73994e836ff21cf49464cc629 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 137}
2024-07-20T16:37:49.871 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 25560824175352405. Time component: 1.5246609484650432467e+12, data component: 2.555929951440394021e+16. Transferred: 21002824, duration: 16.802141768. Price 326671414291221/h, 1306685657164884162/GiB
2024-07-20T16:37:49.872 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.619, upper bound 41388782710326955
2024-07-20T16:37:49.872 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 27446544206525
2024-07-20T16:37:49.872 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 38341973152342
2024-07-20T16:37:49.873 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"65788517358867" Fee:"0" Hashlock:"\x8a\x0b\xee^֖\x80\x1c\xac\x9e\x92$\xbc\x0e\xaa\xe4\x00m\x08\xd79\x94\xe86\xff!\xcfIFL\xc6)" ChainID:137 Signature:"\x86h\xe9\xca0\xd6\xc8\x1d\xc4o\xee\xb9\x7fd\x11\x8dsV\x93l?ѻ:+\x84\x8cs\x00W?\xa6N\x1dƇVb\xdc\x03\xc1௉\x87\xcci.\xf7\x03\x8b\xe2\xe78#\x8cNc\x08\xb0Ծ\x8f\x1b"} AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"38954035301578" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" Signature:"1dc0cb021dbff34b86264da17f7d75d2beff54643fc8ed0d0a0bf4e5a4cdefb61cb9c63871f1b663b3b9b93b61ab1fb98169dbdc78a028ffdb0890f8f45321401b" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:37:50.097 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Invoice:{AgreementID:+48882262075709082053820932991886408849725724726258669664339357406747085159794 AgreementTotal:+38954035301578 TransactorFee:+0 Hashlock:8a0bee5ed696801cac9e9224bc0eaae4006d08d73994e836ff21cf49464cc629 Provider:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ChainID:137}}
2024-07-20T16:37:50.100 DBG ../../consumer/session/session_storage.go:294 > Session 4eae89f0-f36d-4b97-a505-f2fa42995ec1 updated
2024-07-20T16:37:50.100 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+65788517358867 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:37:50.101 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+41952967183991783}
2024-07-20T16:37:50.114 DBG ../../core/connection/manager.go:953 > Received p2p keepalive ping with SessionID=4eae89f0-f36d-4b97-a505-f2fa42995ec1 from 0x876CFAF44f0Fd14Bc04feb418F0B2A44CE907751
2024-07-20T16:37:50.302 INF ../../core/state/state.go:450 > Session ID: 4eae89f0-f36d-4b97-a505-f2fa42995ec1, state: Connected, duration: 25.119812287s data: 11.4KiB/19.1KiB, throughput: 0bs/0bs, spent: 0.000039MYST
2024-07-20T16:37:52.324 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:223.413292ms}
2024-07-20T16:37:57.549 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:223.653836ms}
2024-07-20T16:37:58.881 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"45121336723591" TransactorFee:"0" Hashlock:"e1f8f83ac473910e487a52d1f24da29d40f1d14a7111bd1d7018dfdb8dc3d0ce" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" ChainID:137
2024-07-20T16:37:58.883 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {48882262075709082053820932991886408849725724726258669664339357406747085159794 45121336723591 0 e1f8f83ac473910e487a52d1f24da29d40f1d14a7111bd1d7018dfdb8dc3d0ce 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 137}
2024-07-20T16:37:58.883 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 25566718991268676. Time component: 2.342378776684517047e+12, data component: 2.5564376612491992238e+16. Transferred: 21006996, duration: 25.813595029. Price 326671414291221/h, 1306685657164884162/GiB
2024-07-20T16:37:58.883 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.616, upper bound 41316500071334163
2024-07-20T16:37:58.883 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 65788517358867
2024-07-20T16:37:58.883 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 6167301422013
2024-07-20T16:37:58.884 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"71955818780880" Fee:"0" Hashlock:"\xe1\xf8\xf8:\xc4s\x91\x0eHzR\xd1\xf2M\xa2\x9d@\xf1\xd1Jq\x11\xbd\x1dp\x18\xdfۍ\xc3\xd0\xce" ChainID:137 Signature:"\xf8\x99޾"\x83\x9c?\x0b\xe7.\x0eiӼ}[/_\x8c\xee;\nh s<\xc6\x19\x8a\x0f\x1e\x0e\x1cN\xfe\x87\x0esŹ\xb9\xb7\xfe\x99GuБ\x07&\xae0\x0b\x1b\xf8R\xa13\xee\xd8\xc1\xe8\xb7\x1c"} AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"45121336723591" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" Signature:"d9b5c90a2a76ce7f96c39d7e0e2c5354bae3982d5d192b525fe27c05084401c261d6460da091d0a8ec3978c488a6299d4b4bc4f9d1579735686b48efad1f41a91b" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:37:59.108 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Invoice:{AgreementID:+48882262075709082053820932991886408849725724726258669664339357406747085159794 AgreementTotal:+45121336723591 TransactorFee:+0 Hashlock:e1f8f83ac473910e487a52d1f24da29d40f1d14a7111bd1d7018dfdb8dc3d0ce Provider:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ChainID:137}}
2024-07-20T16:37:59.110 DBG ../../consumer/session/session_storage.go:294 > Session 4eae89f0-f36d-4b97-a505-f2fa42995ec1 updated
2024-07-20T16:37:59.110 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+71955818780880 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:37:59.111 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+41946799882569770}
2024-07-20T16:37:59.312 INF ../../core/state/state.go:450 > Session ID: 4eae89f0-f36d-4b97-a505-f2fa42995ec1, state: Connected, duration: 34.130122193s data: 12.3KiB/22.3KiB, throughput: 0bs/0bs, spent: 0.000045MYST
2024-07-20T16:38:02.773 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:223.54057ms}
2024-07-20T16:38:04.340 DBG ../../core/connection/manager.go:953 > Received p2p keepalive ping with SessionID=4eae89f0-f36d-4b97-a505-f2fa42995ec1 from 0x876CFAF44f0Fd14Bc04feb418F0B2A44CE907751
2024-07-20T16:38:07.997 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:223.541891ms}
2024-07-20T16:38:08.824 WRN ../../communication/nats/connection_wrap.go:105 > NATS: disconnected error="nats: stale connection"
2024-07-20T16:38:11.299 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"70221964209191" TransactorFee:"0" Hashlock:"9e62bfc8cc9d35c016754070f1d3d188944bedc3e0326fd2a6cdbf6a0da7465c" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" ChainID:137
2024-07-20T16:38:11.299 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {48882262075709082053820932991886408849725724726258669664339357406747085159794 70221964209191 0 9e62bfc8cc9d35c016754070f1d3d188944bedc3e0326fd2a6cdbf6a0da7465c 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 137}
2024-07-20T16:38:11.299 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 25591702689768543. Time component: 3.4690708244496854966e+12, data component: 2.5588233618944094814e+16. Transferred: 21026600, duration: 38.230020815. Price 326671414291221/h, 1306685657164884162/GiB
2024-07-20T16:38:11.299 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.614, upper bound 41307083468356142
2024-07-20T16:38:11.300 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 71955818780880
2024-07-20T16:38:11.300 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 25100627485600
2024-07-20T16:38:11.300 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"97056446266480" Fee:"0" Hashlock:"\x9eb\xbf\xc8̝5\xc0\x16u@p\xf1\xd3ш\x94K\xed\xc3\xe02oҦͿj\r\xa7F\" ChainID:137 Signature:"\x86\xba\xe6\x8a\xf9\xd7\x04Q\x06Z,\x87\x87|\xe1{D\x80nh#zqf\xeb!\x05\xaf\x9bݐ'\n\xe7\xeak\x94i1y|\x8d
\xcbP\x0e\x89A\xd0\xf8\x041\xe5\xbeܱ\xd9\\x1d\x8a\xf3\x84\x8a>\x1c"} AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"70221964209191" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" Signature:"35f4b9b706780878e34f8c5f7d62a7ed795e7cffac0fa30aee858977adab264d77c42e5f9617b688649324d808d36e53092ea35d5d817f926b4391d32e0f25111b" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:38:11.535 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Invoice:{AgreementID:+48882262075709082053820932991886408849725724726258669664339357406747085159794 AgreementTotal:+70221964209191 TransactorFee:+0 Hashlock:9e62bfc8cc9d35c016754070f1d3d188944bedc3e0326fd2a6cdbf6a0da7465c Provider:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ChainID:137}}
2024-07-20T16:38:11.538 DBG ../../consumer/session/session_storage.go:294 > Session 4eae89f0-f36d-4b97-a505-f2fa42995ec1 updated
2024-07-20T16:38:11.538 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+97056446266480 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:38:11.538 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+41921699255084170}
2024-07-20T16:38:11.738 INF ../../core/state/state.go:450 > Session ID: 4eae89f0-f36d-4b97-a505-f2fa42995ec1, state: Connected, duration: 46.556593235s data: 18.1KiB/35.7KiB, throughput: 0bs/0bs, spent: 0.000070MYST
2024-07-20T16:38:13.268 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:269.821465ms}
2024-07-20T16:38:13.616 WRN ../../communication/nats/connection_wrap.go:106 > NATS: reconnected
2024-07-20T16:38:18.493 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:224.373694ms}
2024-07-20T16:38:18.564 DBG ../../core/connection/manager.go:953 > Received p2p keepalive ping with SessionID=4eae89f0-f36d-4b97-a505-f2fa42995ec1 from 0x876CFAF44f0Fd14Bc04feb418F0B2A44CE907751
2024-07-20T16:38:24.497 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:1.002860116s}
2024-07-20T16:38:27.361 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"77812873348649" TransactorFee:"0" Hashlock:"fb9f284a444d006726650ba520a852e971c0cf331127cccf7454045145365de1" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" ChainID:137
2024-07-20T16:38:27.361 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {48882262075709082053820932991886408849725724726258669664339357406747085159794 77812873348649 0 fb9f284a444d006726650ba520a852e971c0cf331127cccf7454045145365de1 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 137}
2024-07-20T16:38:27.362 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 25599293623847822. Time component: 4.9265978174901326756e+12, data component: 2.5594367026030332164e+16. Transferred: 21031640, duration: 54.292329745. Price 326671414291221/h, 1306685657164884162/GiB
2024-07-20T16:38:27.362 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.613, upper bound 41288534313369355
2024-07-20T16:38:27.362 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 97056446266480
2024-07-20T16:38:27.362 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 7590909139458
2024-07-20T16:38:27.362 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"104647355405938" Fee:"0" Hashlock:"\xfb\x9f(JDM\x00g&e\x0b\xa5 \xa8R\xe9q\xc0\xcf3\x11'\xcc\xcftT\x04QE6]\xe1" ChainID:137 Signature:"6aA\xf0k\x9fNPbRWx\xb2\xdbzt\xae\x861%\xfb\xb2\xffm<\xee\xaa\xca;3WC_D\xbdIT\xb35\xae\xfd\xbc\xb7\xccD\xbc\xfc2\x8d\x96o\x985\x9d\x8bs\x16ب68\x053\x0e\x1b"} AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"77812873348649" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" Signature:"2e17757a2db0f5983499aaf8bd1546dc895900b3b11251afc95b6f9f9760fc2f06c4b5a3677b27b0aa859c2d246eca2b0c800173c0eb87f56da193035cd161071c" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:38:27.597 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Invoice:{AgreementID:+48882262075709082053820932991886408849725724726258669664339357406747085159794 AgreementTotal:+77812873348649 TransactorFee:+0 Hashlock:fb9f284a444d006726650ba520a852e971c0cf331127cccf7454045145365de1 Provider:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ChainID:137}}
2024-07-20T16:38:27.600 DBG ../../consumer/session/session_storage.go:294 > Session 4eae89f0-f36d-4b97-a505-f2fa42995ec1 updated
2024-07-20T16:38:27.600 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+104647355405938 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:38:27.600 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+41914108345944712}
2024-07-20T16:38:27.802 INF ../../core/state/state.go:450 > Session ID: 4eae89f0-f36d-4b97-a505-f2fa42995ec1, state: Connected, duration: 1m2.62013447s data: 19.7KiB/39.0KiB, throughput: 0bs/0bs, spent: 0.000078MYST
2024-07-20T16:38:29.912 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:413.987759ms}
2024-07-20T16:38:31.888 DBG ../../p2p/listener.go:259 > Received consumer public key bbfb181c29fd35f15f29338ce3aded9f75805dd7ad0f04f0c9e470d22534663d
2024-07-20T16:38:31.888 DBG ../../core/ip/cached_resolver.go:75 > Found cached public IP
2024-07-20T16:38:31.889 INF ../../core/port/pool.go:54 > Supplying port 52963
2024-07-20T16:38:31.889 INF ../../core/port/pool.go:54 > Supplying port 42499
2024-07-20T16:38:31.889 DBG ../../core/port/reachability.go:50 > Checking if port 52963 globally reachable via [echo.mysterium.network:4589]
2024-07-20T16:38:31.889 DBG ../../core/port/reachability.go:50 > Checking if port 42499 globally reachable via [echo.mysterium.network:4589]
2024-07-20T16:38:32.788 DBG ../../core/connection/manager.go:953 > Received p2p keepalive ping with SessionID=4eae89f0-f36d-4b97-a505-f2fa42995ec1 from 0x876CFAF44f0Fd14Bc04feb418F0B2A44CE907751
2024-07-20T16:38:35.136 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:223.38919ms}
2024-07-20T16:38:36.890 DBG ../../p2p/nat/manual.go:57 > Failed to check manual ports [52963 42499] globally error="local port not reachable: %!w()"
2024-07-20T16:38:36.890 DBG ../../eventbus/event_bus.go:101 > Published topic="NAT-traversal-method" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 Method:manual Success:false}
2024-07-20T16:38:36.892 INF ../../core/port/pool.go:54 > Supplying port 34503
2024-07-20T16:38:36.892 INF ../../core/port/pool.go:54 > Supplying port 32400
2024-07-20T16:38:38.894 WRN ../../nat/mapping/port_mapping.go:115 > Couldn't detect router IP address error="no UPnP or NAT-PMP router discovered"
2024-07-20T16:38:38.894 INF ../../nat/mapping/port_mapping.go:74 > Port mapping is useless, skipping it. error="failed to find router public IP"
2024-07-20T16:38:38.894 DBG ../../eventbus/event_bus.go:101 > Published topic="Traversal" event={ID: Stage:port_mapping Successful:false Error:failed to find router public IP}
2024-07-20T16:38:38.895 DBG ../../eventbus/event_bus.go:101 > Published topic="NAT-traversal-method" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 Method:upnp Success:false}
2024-07-20T16:38:38.895 INF ../../core/port/pool.go:54 > Supplying port 14516
2024-07-20T16:38:38.895 INF ../../core/port/pool.go:54 > Supplying port 23926
2024-07-20T16:38:38.896 INF ../../core/port/pool.go:54 > Supplying port 35811
2024-07-20T16:38:38.896 INF ../../core/port/pool.go:54 > Supplying port 45961
2024-07-20T16:38:38.896 INF ../../core/port/pool.go:54 > Supplying port 12930
2024-07-20T16:38:38.896 INF ../../core/port/pool.go:54 > Supplying port 51735
2024-07-20T16:38:38.896 INF ../../core/port/pool.go:54 > Supplying port 28213
2024-07-20T16:38:38.897 INF ../../core/port/pool.go:54 > Supplying port 50829
2024-07-20T16:38:38.897 INF ../../core/port/pool.go:54 > Supplying port 16845
2024-07-20T16:38:38.897 INF ../../core/port/pool.go:54 > Supplying port 46549
2024-07-20T16:38:38.897 INF ../../core/port/pool.go:54 > Supplying port 38926
2024-07-20T16:38:38.897 INF ../../core/port/pool.go:54 > Supplying port 36429
2024-07-20T16:38:38.897 INF ../../core/port/pool.go:54 > Supplying port 13350
2024-07-20T16:38:38.897 INF ../../core/port/pool.go:54 > Supplying port 16260
2024-07-20T16:38:38.898 INF ../../core/port/pool.go:54 > Supplying port 17713
2024-07-20T16:38:38.898 INF ../../core/port/pool.go:54 > Supplying port 26021
2024-07-20T16:38:38.899 INF ../../core/port/pool.go:54 > Supplying port 27773
2024-07-20T16:38:38.899 INF ../../core/port/pool.go:54 > Supplying port 35105
2024-07-20T16:38:38.899 INF ../../core/port/pool.go:54 > Supplying port 54586
2024-07-20T16:38:38.902 INF ../../core/port/pool.go:54 > Supplying port 32669
2024-07-20T16:38:38.902 DBG ../../eventbus/event_bus.go:101 > Published topic="NAT-traversal-method" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 Method:holepunching Success:true}
2024-07-20T16:38:39.154 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.155 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.155 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.155 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.156 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.156 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.156 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.157 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.157 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.157 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.157 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.158 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.158 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.158 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.158 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.158 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.159 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.159 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.159 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.160 DBG ../../eventbus/event_bus.go:101 > Published topic="STUN detection" event={Identity:0xeed77101df82afde19dddfa2a58cd94ae1818696 NATType:full}
2024-07-20T16:38:39.160 DBG ../../p2p/listener.go:295 > Sending reply with public key 9d2565931d0f6b11163231d3fe03c25255845d2961b042eedd04c2ffafa2876f and encrypted config to consumer
2024-07-20T16:38:39.689 DBG ../../p2p/listener.go:151 > Delaying pings from consumer for 50 ms
2024-07-20T16:38:39.689 DBG ../../p2p/listener.go:163 > Pinging consumer using ports [35105 35811 45961 12930 50829 38926 36429 27773 54586 51735 23926 13350 16260 17713 26021 32669 14516 28213 16845 46549]:[35579 34422 31819 59962 54151 46784 54463 11961 36027 58327 56486 38604 46725 15860 41290 18601 26981 14991 30124 13101] initial ttl: 1
2024-07-20T16:38:39.689 INF ../../nat/traversal/pinger.go:121 > NAT pinging to remote peer
2024-07-20T16:38:39.690 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:35105
2024-07-20T16:38:39.690 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:35811
2024-07-20T16:38:39.690 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:45961
2024-07-20T16:38:39.691 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:12930
2024-07-20T16:38:39.691 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:50829
2024-07-20T16:38:39.691 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:38926
2024-07-20T16:38:39.692 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:36429
2024-07-20T16:38:39.692 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:27773
2024-07-20T16:38:39.692 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:54586
2024-07-20T16:38:39.693 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:51735
2024-07-20T16:38:39.693 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:23926
2024-07-20T16:38:39.693 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:13350
2024-07-20T16:38:39.694 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:14516
2024-07-20T16:38:39.693 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:16260
2024-07-20T16:38:39.693 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:26021
2024-07-20T16:38:39.693 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:28213
2024-07-20T16:38:39.693 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:16845
2024-07-20T16:38:39.694 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:32669
2024-07-20T16:38:39.694 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:46549
2024-07-20T16:38:39.693 DBG ../../nat/traversal/pinger.go:460 > Local socket: 0.0.0.0:17713
2024-07-20T16:38:40.225 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.225 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.226 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.226 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.226 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.226 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.227 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.228 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.230 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.241 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.242 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.243 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.246 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.246 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.247 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.247 DBG ../../nat/traversal/pinger.go:394 > Remote peer data received, len: 43
2024-07-20T16:38:40.361 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:223.94446ms}
2024-07-20T16:38:40.764 DBG ../../eventbus/event_bus.go:101 > Published topic="Traversal" event={ID:remove this id Stage:hole_punching Successful:true Error:}
2024-07-20T16:38:40.765 DBG ../../p2p/channel.go:212 > Creating p2p channel with local addr: 10.182.3.2:36429, UDP session addr: 127.0.0.1:43144, proxy addr: 127.0.0.1:53762, remote peer addr: x.x.x.x:54463
2024-07-20T16:38:40.766 DBG ../../p2p/wireformat.go:63 > Using protobufWireReader
2024-07-20T16:38:40.767 DBG ../../p2p/wireformat.go:72 > Using protobufWireWriter
2024-07-20T16:38:40.767 DBG ../../p2p/channel.go:574 > Will use service conn with local port: 51735, remote port: 58327
2024-07-20T16:38:40.767 INF ../../core/service/manager.go:190 > tracking p2p.Channel: "channel:0xc0015071e0"
2024-07-20T16:38:40.768 DBG ../../p2p/listener.go:398 > Sending handlers ready message
2024-07-20T16:38:41.254 DBG ../../core/service/subscription.go:46 > Received P2P message for "p2p-session-create": consumer:{id:"0x0aebeed576ba51aadb317819a5acfebcee29968b" hermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" paymentVersion:"v3" location:{country:"US"} pricing:{PerGib:"\xeaoe\\xa2~\x95" PerHour:"\x01)\x1b\x1d\x9bk\x15"}} config:"{"PublicKey":"Z1jUp2BCXhAz3lqxZ68t9r4gBe7WQKablmI+BMMviDs=","Ports":null}"
2024-07-20T16:38:41.254 INF ../../core/service/session_manager.go:191 > session ref incr for "channel:0xc0015071e0"
2024-07-20T16:38:45.825 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:462.516402ms}
2024-07-20T16:38:47.968 DBG ../../core/connection/manager.go:953 > Received p2p keepalive ping with SessionID=4eae89f0-f36d-4b97-a505-f2fa42995ec1 from 0x876CFAF44f0Fd14Bc04feb418F0B2A44CE907751
2024-07-20T16:38:48.208 INF ../../session/pingpong/pricing.go:223 > pricing info loaded. expires @ 2024-07-20 16:43:27.480510312 +0000 UTC
2024-07-20T16:38:48.210 DBG ../../consumer/session/session_storage.go:337 > Session 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 saved
2024-07-20T16:38:48.211 INF ../../core/service/session_manager.go:323 > Using new payments
2024-07-20T16:38:48.211 INF ../../core/service/session_manager.go:345 > Waiting for a first invoice to be paid
2024-07-20T16:38:48.211 DBG ../../session/pingpong/invoice_tracker.go:280 > Starting invoice tracker for session 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096
2024-07-20T16:38:49.900 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"792033410438118" TransactorFee:"0" Hashlock:"66038918e704aa5845307414ad9fcdcbf47937343002d8df141062b1c0f43c86" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" ChainID:137
2024-07-20T16:38:49.900 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {48882262075709082053820932991886408849725724726258669664339357406747085159794 792033410438118 0 66038918e704aa5845307414ad9fcdcbf47937343002d8df141062b1c0f43c86 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 137}
2024-07-20T16:38:49.900 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 26314347420194583. Time component: 6.9718203891600251617e+12, data component: 2.6307375599805423959e+16. Transferred: 21617540, duration: 76.8311897. Price 326671414291221/h, 1306685657164884162/GiB
2024-07-20T16:38:49.901 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.551, upper bound 40802692734186036
2024-07-20T16:38:49.901 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 104647355405938
2024-07-20T16:38:49.901 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 714220537089469
2024-07-20T16:38:49.902 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"818867892495407" Fee:"0" Hashlock:"f\x03\x89\x18\xe7\x04\xaaXE0t\x14\xad\x9f\xcd\xcb\xf4y740\x02\xd8\xdf\x14\x10b\xb1\xc0\xf4<\x86" ChainID:137 Signature:"\rT\x07!\xb7\x12\x9e\xcd[͊\x90y\xbc\xf7\x9d\x13^4\x9e\x93-\xadz\xf6\xfe\xec[\xf3)\xfa1t\xf5\x8a\x92\xc3\xc6\xe2\x8c\x0f},\x1a\xca^\x95β\xde\xfe\xd4q\x1f\x17\x7f\x8b\x0c\xdf#\x96Fc\xf0\x1b"} AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"792033410438118" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" Signature:"4a4939373177e32484ee3b1f5be0e8baa58610582c3864d0653c11c86da820375ddfd872fe8a649696e354a9f6210b37105c094c44ddc21cd189ba60165d1b391b" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:38:49.948 WRN ../../requests/dialer_swarm.go:293 > Failed to lookup host: "discovery.mysterium.network" error="lookup discovery.mysterium.network on 10.182.3.1:53: dial udp 10.182.3.1:53: operation was canceled"
2024-07-20T16:38:51.055 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Invoice:{AgreementID:+48882262075709082053820932991886408849725724726258669664339357406747085159794 AgreementTotal:+792033410438118 TransactorFee:+0 Hashlock:66038918e704aa5845307414ad9fcdcbf47937343002d8df141062b1c0f43c86 Provider:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ChainID:137}}
2024-07-20T16:38:51.058 DBG ../../consumer/session/session_storage.go:294 > Session 4eae89f0-f36d-4b97-a505-f2fa42995ec1 updated
2024-07-20T16:38:51.060 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+818867892495407 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:38:51.061 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+41199887808855243}
2024-07-20T16:38:51.260 INF ../../core/state/state.go:450 > Session ID: 4eae89f0-f36d-4b97-a505-f2fa42995ec1, state: Connected, duration: 1m26.078361267s data: 316.9KiB/314.0KiB, throughput: 0bs/0bs, spent: 0.000792MYST
2024-07-20T16:38:54.415 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:3.588470037s}
2024-07-20T16:38:58.213 ERR ../../session/pingpong/hermes_status_checker.go:92 > using observer as fallback error="Post "https://polygon1.mysterium.network/": dial tcp: lookup polygon1.mysterium.network on 10.182.3.1:53: read udp 10.182.3.2:33583->10.182.3.1:53: i/o timeout"
2024-07-20T16:38:59.639 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:223.382098ms}
2024-07-20T16:39:01.254 DBG ../../core/service/subscription.go:70 > Received P2P session status message for "p2p-session-connectivity-status": ConsumerID:"0x0aebeed576ba51aadb317819a5acfebcee29968b" Code:2000 Message:"could not send p2p session create request: timeout waiting for reply to "p2p-session-create": p2p send timeout"
2024-07-20T16:39:02.409 DBG ../../core/connection/manager.go:953 > Received p2p keepalive ping with SessionID=4eae89f0-f36d-4b97-a505-f2fa42995ec1 from 0x876CFAF44f0Fd14Bc04feb418F0B2A44CE907751
2024-07-20T16:39:04.883 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:243.510447ms}
2024-07-20T16:39:07.212 DBG ../../eventbus/event_bus.go:101 > Published topic="provider_ping_p2p" event={SessionID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Duration:5.000243612s}
2024-07-20T16:39:07.212 ERR ../../core/service/session_manager.go:401 > Failed to send p2p keepalive ping. SessionID=0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 error="timeout waiting for reply to "p2p-keepalive": p2p send timeout"
2024-07-20T16:39:08.061 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 1801207083270. Time component: 1.8012070832707211543e+12, data component: 0. Transferred: 0, duration: 19.849748757. Price 326671414291221/h, 65987625686826645/GiB
2024-07-20T16:39:08.061 DBG ../../session/pingpong/invoice_tracker.go:501 > Being lenient for the first payment, asking for 1
2024-07-20T16:39:08.062 DBG ../../session/pingpong/invoice_messaging.go:57 > Sending P2P message to "p2p-payment-invoice": AgreementID:"10418093568509154802410943135725976405917904937060966659236645548545928157882" AgreementTotal:"1" TransactorFee:"0" Hashlock:"5046d3403ba7e30f06386eacd40a468aa804c9d8b4bb79c172fadf1ebbcaf6c5" Provider:"0xeed77101df82afde19dddfa2a58cd94ae1818696" ChainID:137
2024-07-20T16:39:10.510 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:626.090153ms}
2024-07-20T16:39:15.758 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_ping_p2p" event={SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Duration:246.444827ms}
2024-07-20T16:39:16.634 DBG ../../core/connection/manager.go:953 > Received p2p keepalive ping with SessionID=4eae89f0-f36d-4b97-a505-f2fa42995ec1 from 0x876CFAF44f0Fd14Bc04feb418F0B2A44CE907751
2024-07-20T16:39:17.490 DBG ../../session/pingpong/factory.go:150 > Received P2P message for "p2p-payment-invoice": AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"831226327742486" TransactorFee:"0" Hashlock:"cacd17b95cfdb850eb5d295ad06257212d0a7aa46aaef6f897e23308af0452c2" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" ChainID:137
2024-07-20T16:39:17.490 DBG ../../session/pingpong/invoice_payer.go:156 > Invoice received: {48882262075709082053820932991886408849725724726258669664339357406747085159794 831226327742486 0 cacd17b95cfdb850eb5d295ad06257212d0a7aa46aaef6f897e23308af0452c2 0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 137}
2024-07-20T16:39:17.490 DBG ../../session/pingpong/price_calculator.go:52 > Calculated price 26352882326466901. Time component: 9.47539392153425145e+12, data component: 2.6343406932545367496e+16. Transferred: 21647148, duration: 104.421190913. Price 326671414291221/h, 1306685657164884162/GiB
2024-07-20T16:39:17.491 DBG ../../session/pingpong/invoice_payer.go:189 > Estimated tolerance 1.476, upper bound 38908934584469784
2024-07-20T16:39:17.491 DBG ../../session/pingpong/invoice_payer.go:242 > Loaded previous state: already promised: 818867892495407
2024-07-20T16:39:17.491 DBG ../../session/pingpong/invoice_payer.go:243 > Incrementing promised amount by 39192917304368
2024-07-20T16:39:17.491 DBG ../../session/pingpong/exchange_messaging.go:68 > Sending P2P message to "p2p-payment-message": Promise:{ChannelID:"<\xa7u\x03\xd1ve\xc7hv\xb9\x8e\x8f\x8d\xf0\x0f\xfc\x83\xb9\x1b" Amount:"858060809799775" Fee:"0" Hashlock:"\xca\xcd\x17\xb9\\xfd\xb8P\xeb])Z\xd0bW!-\nz\xa4j\xae\xf6\xf8\x97\xe23\x08\xaf\x04R\xc2" ChainID:137 Signature:"\x15S\xd4@\x90;\xdf\xd9\xe0\xf7\x12\xba\xefZ\n\xde50\x84\x15((:\x0fZme\x0f}\x80\x90\x85P\x1d\xed\xdf\xda\x10q`\xff;ޛGK\xae\xeb\x86\xf9\xdb\xc0\xdcb.O\xfb\xbe\xda\x04\xcf\x12\xd1\xca\x1c"} AgreementID:"48882262075709082053820932991886408849725724726258669664339357406747085159794" AgreementTotal:"831226327742486" Provider:"0x876cfaf44f0fd14bc04feb418f0b2a44ce907751" Signature:"ee0b7e194b426fdab2104a45844168d4294a20efe035376a896aa1e6c4c67f055e739cb6fd23c836f13164087d584aa5d818af27dea52fbe2d7ac400ea2b9db81b" HermesID:"0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab" ChainID:137
2024-07-20T16:39:17.738 DBG ../../eventbus/event_bus.go:101 > Published topic="invoice_paid" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Invoice:{AgreementID:+48882262075709082053820932991886408849725724726258669664339357406747085159794 AgreementTotal:+831226327742486 TransactorFee:+0 Hashlock:cacd17b95cfdb850eb5d295ad06257212d0a7aa46aaef6f897e23308af0452c2 Provider:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ChainID:137}}
2024-07-20T16:39:17.740 DBG ../../consumer/session/session_storage.go:294 > Session 4eae89f0-f36d-4b97-a505-f2fa42995ec1 updated
2024-07-20T16:39:17.740 DBG ../../eventbus/event_bus.go:101 > Published topic="consumer_grand_total_change" event={Current:+858060809799775 ChainID:137 HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696}}
2024-07-20T16:39:17.740 DBG ../../eventbus/event_bus.go:101 > Published topic="balance_change" event={Identity:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} Previous:+42018755701350650 Current:+41160694891550875}
2024-07-20T16:39:17.941 INF ../../core/state/state.go:450 > Session ID: 4eae89f0-f36d-4b97-a505-f2fa42995ec1, state: Connected, duration: 1m52.759640426s data: 332.4KiB/327.4KiB, throughput: 0bs/0bs, spent: 0.000831MYST
2024-07-20T16:39:18.062 ERR ../../core/service/session_manager.go:340 > Payment engine error error="could not send first invoice: timeout waiting for reply to "p2p-payment-invoice": p2p send timeout"
2024-07-20T16:39:18.062 DBG ../../session/pingpong/invoice_tracker.go:685 > Stopping invoice tracker for session 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096
2024-07-20T16:39:18.063 INF ../../core/service/session_manager.go:194 > session ref decr for "channel:0xc0015071e0"
2024-07-20T16:39:18.063 INF ../../services/wireguard/service/service.go:102 > Accepting new WireGuard connection
2024-07-20T16:39:18.063 DBG ../../core/ip/cached_resolver.go:75 > Found cached public IP
2024-07-20T16:39:18.066 DBG ../../consumer/session/session_storage.go:316 > Session 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 updated with final data
2024-07-20T16:39:18.203 DBG ../../services/wireguard/endpoint/kernelspace/client.go:186 > "ip link del dev myst0" output:

2024-07-20T16:39:18.203 INF ../../services/wireguard/endpoint/endpoint.go:178 > Abandoned interface destroyed: myst0
2024-07-20T16:39:18.209 DBG ../../services/wireguard/endpoint/kernelspace/client.go:192 > "ip link add dev myst0 type wireguard" output:

2024-07-20T16:39:18.218 DBG ../../services/wireguard/endpoint/kernelspace/client.go:200 > "ip link set dev myst0 up" output:

2024-07-20T16:39:18.232 DBG ../../services/wireguard/endpoint/kernelspace/client.go:93 > "ip address replace dev myst0 10.182.0.1/24" output:

2024-07-20T16:39:18.254 INF ../../nat/service_iptables.go:50 > Setting up NAT/Firewall rules
2024-07-20T16:39:18.260 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -I PREROUTING 1 --source 10.182.0.2/24 --jump MYST --table nat" output:

2024-07-20T16:39:18.278 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -I MYST 1 --destination 10.182.0.1 --protocol udp --dport 53 --jump REDIRECT --to-ports 11253 --table nat" output:

2024-07-20T16:39:18.284 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -I MYST 1 --destination 10.182.0.1 --protocol tcp --dport 53 --jump REDIRECT --to-ports 11253 --table nat" output:

2024-07-20T16:39:18.289 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A POSTROUTING --source 10.182.0.2/24 ! --destination 10.182.0.2/24 --jump SNAT --to 172.31.81.235 --table nat" output:

2024-07-20T16:39:18.297 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A FORWARD --source 10.182.0.2/24 --jump ACCEPT" output:

2024-07-20T16:39:18.300 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -A FORWARD --destination 10.182.0.2/24 --jump ACCEPT" output:

2024-07-20T16:39:18.300 INF ../../nat/service_iptables.go:74 > Setting up NAT/Firewall rules... done
2024-07-20T16:39:18.312 ??? ../../usr/local/go/src/io/io.go:429 > RTNETLINK answers: No such file or directory
2024-07-20T16:39:18.318 ??? ../../usr/local/go/src/io/io.go:429 > RTNETLINK answers: No such file or directory
2024-07-20T16:39:18.323 ??? ../../usr/local/go/src/io/io.go:429 > Cannot find device "ifb0"
2024-07-20T16:39:18.329 ??? ../../usr/local/go/src/io/io.go:429 > Cannot find device "ifb0"
2024-07-20T16:39:18.329 INF ../../services/wireguard/service/service.go:163 > Cleaning up session 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096
2024-07-20T16:39:18.330 INF ../../services/wireguard/service/stats_publisher.go:65 > Stopped publishing statistics for session 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096
2024-07-20T16:39:18.333 ??? ../../usr/local/go/src/io/io.go:429 > RTNETLINK answers: No such file or directory
2024-07-20T16:39:18.336 ??? ../../usr/local/go/src/io/io.go:429 > RTNETLINK answers: No such file or directory
2024-07-20T16:39:18.341 ??? ../../usr/local/go/src/io/io.go:429 > Cannot find device "ifb0"
2024-07-20T16:39:18.346 ??? ../../usr/local/go/src/io/io.go:429 > Cannot find device "ifb0"
2024-07-20T16:39:18.347 INF ../../nat/service_iptables.go:80 > Deleting NAT/Firewall rules
2024-07-20T16:39:18.350 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D PREROUTING --source 10.182.0.2/24 --jump MYST --table nat" output:

2024-07-20T16:39:18.353 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D MYST --destination 10.182.0.1 --protocol udp --dport 53 --jump REDIRECT --to-ports 11253 --table nat" output:

2024-07-20T16:39:18.357 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D MYST --destination 10.182.0.1 --protocol tcp --dport 53 --jump REDIRECT --to-ports 11253 --table nat" output:

2024-07-20T16:39:18.360 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D POSTROUTING --source 10.182.0.2/24 ! --destination 10.182.0.2/24 --jump SNAT --to 172.31.81.235 --table nat" output:

2024-07-20T16:39:18.363 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D FORWARD --source 10.182.0.2/24 --jump ACCEPT" output:

2024-07-20T16:39:18.366 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D FORWARD --destination 10.182.0.2/24 --jump ACCEPT" output:

2024-07-20T16:39:18.366 INF ../../nat/service_iptables.go:92 > Deleting NAT/Firewall rules... done
2024-07-20T16:39:18.511 DBG ../../services/wireguard/endpoint/kernelspace/client.go:186 > "ip link del dev myst0" output:

2024-07-20T16:39:18.511 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Provider whole Connect Duration:46.623230442s}
2024-07-20T16:39:18.511 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Provider P2P exchange Duration:7.273024342s}
2024-07-20T16:39:18.511 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Provider P2P exchange (ports) Duration:7.013712318s}
2024-07-20T16:39:18.511 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:18.511 WRN ../../core/connection/stats_publisher.go:57 > Could not get connection statistics error="file does not exist"
2024-07-20T16:39:18.512 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:18.512 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Provider P2P exchange ack Duration:50.624445ms}
2024-07-20T16:39:18.512 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Provider P2P dial (preparation) Duration:1.075496385s}
2024-07-20T16:39:18.512 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Provider P2P dial ack Duration:3.585664ms}
2024-07-20T16:39:18.512 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Provider session create Duration:37.256737903s}
2024-07-20T16:39:18.512 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Session validation Duration:6.954419937s}
2024-07-20T16:39:18.513 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Provider session create (start) Duration:2.04113ms}
2024-07-20T16:39:18.513 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Provider session create (payment) Duration:29.852261509s}
2024-07-20T16:39:18.513 DBG ../../eventbus/event_bus.go:101 > Published topic="Trace" event={ID:0cdc9cbb-4977-4bfb-86bb-bb17a0c37096 Key:Provider session create (configure) Duration:447.997791ms}
2024-07-20T16:39:18.513 DBG ../../core/service/session_manager.go:209 > Provider connection trace: "Provider whole Connect" took 46.623230442s, "Provider P2P exchange" took 7.273024342s, "Provider P2P exchange (ports)" took 7.013712318s, "Provider P2P exchange ack" took 50.624445ms, "Provider P2P dial (preparation)" took 1.075496385s, "Provider P2P dial ack" took 3.585664ms, "Provider session create" took 37.256737903s, "Session validation" took 6.954419937s, "Provider session create (start)" took 2.04113ms, "Provider session create (payment)" took 29.852261509s, "Provider session create (configure)" took 447.997791ms
2024-07-20T16:39:18.513 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:18.513 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:18.513 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:18.512 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:18.513 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:18.513 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:18.513 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:18.513 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:18.513 WRN ../../core/quality/sender.go:403 > Can't recover session context error="unknown session: 0cdc9cbb-4977-4bfb-86bb-bb17a0c37096"
2024-07-20T16:39:19.513 WRN ../../core/connection/stats_publisher.go:57 > Could not get connection statistics error="file does not exist"
2024-07-20T16:39:20.514 WRN ../../core/connection/stats_publisher.go:57 > Could not get connection statistics error="file does not exist"
2024-07-20T16:39:20.629 INF ../../cmd/commands/service/command.go:103 > Stopping application
2024-07-20T16:39:20.629 INF ../../core/connection/manager.go:744 > Connection state: Connected -> Disconnecting
2024-07-20T16:39:20.630 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 State:Disconnecting SessionInfo:{StartedAt:2024-07-20 16:37:25.182182167 +0000 UTC m=+28.648413230 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:Disconnecting SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ServiceType:wireguard Location:{Continent:AS Country:PH Region:Negros Occidental City:Asia ASN:18190 ISP:Asia Town Information Technology Park DSL-Network IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] AccessPolicies: Quality:{Quality:2.5 Latency:1277.02 Bandwidth:161.63 Uptime:24}} Price:326671414291221/h, 1306685657164884162/GiB }}}
2024-07-20T16:39:20.630 INF ../../firewall/outgoing_firewall_noop.go:42 > Outgoing traffic block removed
2024-07-20T16:39:20.630 INF ../../services/wireguard/connection/connection.go:226 > Stopping WireGuard connection
2024-07-20T16:39:20.630 INF ../../firewall/outgoing_firewall_noop.go:50 > Rule for IP removed
2024-07-20T16:39:20.631 DBG ../../core/connection/manager.go:873 > Connection state received: Disconnecting
2024-07-20T16:39:20.631 INF ../../core/state/state.go:399 > Session ID: 4eae89f0-f36d-4b97-a505-f2fa42995ec1, state: Disconnecting, duration: 1m55.449618003s data: 332.4KiB/327.4KiB, throughput: 0bs/0bs, spent: 0.000831MYST
2024-07-20T16:39:20.631 DBG ../../core/connection/manager.go:962 > Stopping p2p keepalive: context canceled
2024-07-20T16:39:20.632 INF ../../core/connection/stats_publisher.go:72 > Stopped publishing connection statistics
2024-07-20T16:39:20.657 DBG ../../services/wireguard/endpoint/kernelspace/client.go:186 > "ip link del dev myst0" output:
Cannot find device "myst0"

2024-07-20T16:39:20.790 ERR ../../services/wireguard/connection/connection.go:235 > Failed to close wireguard connection error="could not close client: ErrorCollection: "ip link del dev myst0": exit status 1 output: Cannot find device "myst0"\n: exit status 1"
2024-07-20T16:39:20.790 DBG ../../eventbus/event_bus.go:101 > Published topic="Session" event={Status:Ended SessionInfo:{StartedAt:2024-07-20 16:37:25.182182167 +0000 UTC m=+28.648413230 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:Disconnecting SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ServiceType:wireguard Location:{Continent:AS Country:PH Region:Negros Occidental City:Asia ASN:18190 ISP:Asia Town Information Technology Park DSL-Network IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] AccessPolicies: Quality:{Quality:2.5 Latency:1277.02 Bandwidth:161.63 Uptime:24}} Price:326671414291221/h, 1306685657164884162/GiB }}}
2024-07-20T16:39:20.790 DBG ../../core/connection/manager.go:873 > Connection state received: NotConnected
2024-07-20T16:39:20.792 DBG ../../consumer/session/session_storage.go:316 > Session 4eae89f0-f36d-4b97-a505-f2fa42995ec1 updated with final data
2024-07-20T16:39:20.792 DBG ../../session/pingpong/invoice_payer.go:295 > Stopping...
2024-07-20T16:39:20.792 DBG ../../core/ip/cached_resolver.go:101 > Clearing ip resolver cache
2024-07-20T16:39:20.793 INF ../../core/connection/manager.go:744 > Connection state: Disconnecting -> NotConnected
2024-07-20T16:39:20.793 DBG ../../eventbus/event_bus.go:101 > Published topic="State" event={UUID:22bbc8f1-5948-49e6-bd5a-5f7b4863a6d4 State:NotConnected SessionInfo:{StartedAt:2024-07-20 16:37:25.182182167 +0000 UTC m=+28.648413230 ConsumerID:{Address:0xeed77101df82afde19dddfa2a58cd94ae1818696} ConsumerLocation:{IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting} HermesID:0x80Ed28d84792d8b153bf2F25F0C4B7a1381dE4ab State:NotConnected SessionID:4eae89f0-f36d-4b97-a505-f2fa42995ec1 Proposal:{ServiceProposal:{ID:0 Format:service-proposal/v3 Compatibility:2 ProviderID:0x876cfaf44f0fd14bc04feb418f0b2a44ce907751 ServiceType:wireguard Location:{Continent:AS Country:PH Region:Negros Occidental City:Asia ASN:18190 ISP:Asia Town Information Technology Park DSL-Network IPType:residential} Contacts:[{Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] AccessPolicies: Quality:{Quality:2.5 Latency:1277.02 Bandwidth:161.63 Uptime:24}} Price:326671414291221/h, 1306685657164884162/GiB }}}
2024-07-20T16:39:20.793 DBG ../../core/connection/manager.go:651 > Sending P2P message to "p2p-session-destroy": consumerID:"0xeed77101df82afde19dddfa2a58cd94ae1818696" sessionID:"4eae89f0-f36d-4b97-a505-f2fa42995ec1"
2024-07-20T16:39:20.794 DBG ../../core/location/oracle_resolver.go:67 > Detecting with oracle resolver
2024-07-20T16:39:20.794 INF ../../cmd/di.go:1082 > Reconnecting HTTP clients due to VPN connection state change
2024-07-20T16:39:20.796 DBG ../../eventbus/event_bus.go:101 > Published topic="ether-client-reconnect" event={}
2024-07-20T16:39:20.797 DBG ../../identity/registry/registry_contract.go:329 > Loading initial state
2024-07-20T16:39:20.797 DBG ../../identity/registry/registry_contract.go:347 > Identity {"0xeed77101df82afde19dddfa2a58cd94ae1818696"} already registered, skipping
2024-07-20T16:39:21.045 INF ../../cmd/node.go:92 > Connection closed
2024-07-20T16:39:21.045 INF ../../cmd/node.go:96 > API stopped
2024-07-20T16:39:21.045 DBG ../../eventbus/event_bus.go:101 > Published topic="Node" event={Status:Stopped}
2024-07-20T16:39:21.045 INF ../../ui/discovery/discovery.go:71 > LAN discovery disabled. Stopping noop local service discovery.
2024-07-20T16:39:21.045 INF ../../ui/server.go:177 > Server stopped
2024-07-20T16:39:21.045 INF ../../identity/registry/registry_contract.go:315 > Stopping registry...
2024-07-20T16:39:21.045 INF ../../ui/server.go:177 > Server stopped
2024-07-20T16:39:21.045 DBG ../../session/pingpong/hermes_promise_handler.go:236 > hermes promise handler stopped
2024-07-20T16:39:21.045 INF ../../cmd/node.go:99 > Web UI server stopped
2024-07-20T16:39:21.045 INF ../../session/pingpong/hermes_promise_settler.go:390 > Stopped listening for settlement events
2024-07-20T16:39:21.046 DBG ../../sleep/sleep_noop.go:33 > Unregister noop sleep events
2024-07-20T16:39:21.046 INF ../../cmd/node.go:102 > Sleep notifier stopped
2024-07-20T16:39:21.046 INF ../../services/wireguard/service/service.go:273 > Wireguard: stopping
2024-07-20T16:39:21.046 INF ../../core/discovery/discovery.go:145 > Stopping discovery loop...
2024-07-20T16:39:21.046 INF ../../services/wireguard/service/service.go:301 > Wireguard: stopped
2024-07-20T16:39:21.046 DBG ../../eventbus/event_bus.go:101 > Published topic="Service status" event={ID:128422c2-fbcb-486f-870c-5eda4813cb7f ProviderID:0xeed77101df82afde19dddfa2a58cd94ae1818696 Type:scraping Status:NotRunning}
2024-07-20T16:39:21.046 DBG ../../session/pingpong/hermes_promise_settler.go:297 > Ignoring service event with status NotRunning
2024-07-20T16:39:21.046 INF ../../nat/service_iptables.go:80 > Deleting NAT/Firewall rules
2024-07-20T16:39:21.047 ERR ../../core/service/manager.go:222 > Service stop failed error="no such instance"
2024-07-20T16:39:21.052 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D MYST --destination 10.0.0.0/8 --jump DNAT --to-destination 240.0.0.1 --table nat" output:

2024-07-20T16:39:21.056 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D MYST --destination 172.16.0.0/12 --jump DNAT --to-destination 240.0.0.1 --table nat" output:

2024-07-20T16:39:21.061 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D MYST --destination 192.168.0.0/16 --jump DNAT --to-destination 240.0.0.1 --table nat" output:

2024-07-20T16:39:21.065 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables -D MYST --destination 127.0.0.0/8 --jump DNAT --to-destination 240.0.0.1 --table nat" output:

2024-07-20T16:39:21.066 INF ../../nat/service_iptables.go:92 > Deleting NAT/Firewall rules... done
2024-07-20T16:39:21.077 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables --flush MYST --table nat" output:

2024-07-20T16:39:21.081 DBG ../../nat/service_iptables.go:229 > "/usr/sbin/iptables --delete-chain MYST --table nat" output:

2024-07-20T16:39:21.082 WRN ../../communication/nats/connection_wrap.go:105 > NATS: disconnected
2024-07-20T16:39:21.082 WRN ../../communication/nats/connection_wrap.go:104 > NATS: connection closed
2024-07-20T16:39:21.083 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2024-07-20T16:39:21.083 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://broker.mysterium.network:4222 removed
2024-07-20T16:39:21.083 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.30:4222 removed
2024-07-20T16:39:21.083 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.75:4222 removed
2024-07-20T16:39:21.083 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.9:4222 removed
2024-07-20T16:39:21.083 DBG ../../firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://51.158.204.23:4222 removed
2024-07-20T16:39:21.168 DBG ../../eventbus/event_bus.go:101 > Published topic="location-update-event" event={IP: ASN:14618 ISP:Amazon Data Services NoVa Continent:NA Country:US Region:Virginia City:Ashburn IPType:hosting}
2024-07-20T16:39:21.170 DBG ../../communication/nats/sender.go:59 > Message "signed.nfkA0TXJaJz1u_UK5bEez5la-Ou4RrAIcqabVIxucV4nAKkw2aHrqRX1r_9Ppy0-wxZ84Usp092dV8cMyIxzoQA.1721493561.proposal-unregister.v3" sending: {"proposal":{"id":0,"format":"service-proposal/v3","compatibility":2,"provider_id":"0xeed77101df82afde19dddfa2a58cd94ae1818696","service_type":"scraping","location":{"continent":"NA","country":"US","region":"Virginia","city":"Ashburn","asn":14618,"isp":"Amazon Data Services NoVa","ip_type":"hosting"},"contacts":[{"type":"nats/p2p/v1","definition":{"broker_addresses":["nats://broker.mysterium.network:4222","nats://broker.mysterium.network:4222","nats://51.158.204.30:4222","nats://51.158.204.75:4222","nats://51.158.204.9:4222","nats://51.158.204.23:4222"]}}],"access_policies":[{"id":"mysterium","source":"https://trust.mysterium.network/api/v1/access-policies/mysterium"}],"quality":{"quality":0,"latency":0,"bandwidth":0,"uptime":0}}}
2024-07-20T16:39:21.170 ERR ../../core/discovery/discovery.go:221 > Failed to unregister proposal: error="failed to unregister proposal: {0 service-proposal/v3 2 0xeed77101df82afde19dddfa2a58cd94ae1818696 scraping {NA US Virginia Ashburn 14618 Amazon Data Services NoVa hosting} [{nats/p2p/v1 {[nats://broker.mysterium.network:4222 nats://broker.mysterium.network:4222 nats://51.158.204.30:4222 nats://51.158.204.75:4222 nats://51.158.204.9:4222 nats://51.158.204.23:4222]}}] 0xc000bc5f08 {0 0 0 0}}: failed to send message 'signed.nfkA0TXJaJz1u_UK5bEez5la-Ou4RrAIcqabVIxucV4nAKkw2aHrqRX1r_9Ppy0-wxZ84Usp092dV8cMyIxzoQA.1721493561.proposal-unregister.v3': nats: connection closed"
2024-07-20T16:39:21.170 INF ../../core/discovery/discovery.go:224 > Proposal unregistered
2024-07-20T16:39:21.452 INF ../../firewall/incoming_firewall_noop.go:38 > Rules reset was requested
2024-07-20T16:39:21.453 INF ../../firewall/outgoing_firewall_noop.go:35 > Rules reset was requested

Copy link

stale bot commented Oct 28, 2024

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@stale stale bot added the stale label Oct 28, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

1 participant