Skip to content

Instantly share code, notes, and snippets.

@cvl

cvl/myst.log

Created May 21, 2020 07:30
Show Gist options
  • Save cvl/e5cf45af55b1356cec314e7fb05b6d96 to your computer and use it in GitHub Desktop.
Save cvl/e5cf45af55b1356cec314e7fb05b6d96 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
myst.log
2020-05-21T09:50:48.025 DBG Users/tadas/mygo/node/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-05-21T09:50:48.958 DBG Users/tadas/mygo/node/market/mysterium/mysterium_api.go:271 > Total proposals: 266 supported: 236
2020-05-21T09:50:48.959 INF Users/tadas/mygo/node/core/discovery/repository.go:91 > Returning 467 unique proposals
2020-05-21T09:50:50.822 INF Users/tadas/mygo/node/tequilapi/endpoints/connection.go:161 > identity "0x12345" is registered, continuing...
2020-05-21T09:50:51.034 DBG Users/tadas/mygo/node/market/mysterium/mysterium_api.go:271 > Total proposals: 1 supported: 1
2020-05-21T09:50:51.034 INF Users/tadas/mygo/node/core/connection/manager.go:537 > Connection state: NotConnected -> Connecting
2020-05-21T09:50:51.034 DBG Users/tadas/mygo/node/communication/nats/connector.go:39 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222
2020-05-21T09:50:51.034 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-05-21T09:50:51.034 DBG Users/tadas/mygo/node/eventbus/event_bus.go:81 > Published topic="State" event={State:Connecting SessionInfo:{StartedAt:2020-05-21 09:50:51.034679 +0300 EEST m=+209.809275317 ConsumerID:{Address:0x12345} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID: Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:1m0s Bytes:7669584 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x5a8c2949962d112cbc4c101b0f1fbdbff9c9d855 ProviderContacts:[{Type:nats/v1 Definition:{}} {Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:<nil>}}}
2020-05-21T09:50:51.035 INF Users/tadas/mygo/node/core/state/state.go:359 > Session ID Connecting duration: 318.347µs data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-05-21T09:50:51.267 DBG Users/tadas/mygo/node/p2p/dialer.go:144 > Consumer 0x12345 sending public key 123456 to provider 0x5a8c2949962d112cbc4c101b0f1fbdbff9c9d855
2020-05-21T09:50:52.534 DBG Users/tadas/mygo/node/p2p/dialer.go:171 > Consumer 0x12345 received provider 0x5a8c2949962d112cbc4c101b0f1fbdbff9c9d855 with config: publicIP:"123.123.123.1235" ports:41183 ports:41090
2020-05-21T09:50:53.157 DBG Users/tadas/mygo/node/core/ip/resolver.go:103 > IP detected: 123.123.123.123
2020-05-21T09:50:53.158 INF Users/tadas/mygo/node/core/port/pool.go:68 > Supplying port 49117
2020-05-21T09:50:53.158 INF Users/tadas/mygo/node/core/port/pool.go:68 > Supplying port 40635
2020-05-21T09:50:53.158 DBG Users/tadas/mygo/node/p2p/dialer.go:194 > Consumer 0x12345 sending ack with encrypted config to provider 0x5a8c2949962d112cbc4c101b0f1fbdbff9c9d855
2020-05-21T09:50:53.369 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:48 > Allow IP 123.123.123.1235 access
2020-05-21T09:50:53.370 DBG Users/tadas/mygo/node/p2p/dialer.go:99 > Skipping provider ping
2020-05-21T09:50:53.370 DBG Users/tadas/mygo/node/p2p/dialer.go:121 > Received handlers ready message from provider
2020-05-21T09:50:53.371 DBG Users/tadas/mygo/node/p2p/channel.go:200 > Creating p2p channel with local addr: 192.168.0.104:49117, UDP session addr: 127.0.0.1:53641, proxy addr: 127.0.0.1:54321, remote peer addr: x.x.x.x:41183
2020-05-21T09:50:53.371 DBG Users/tadas/mygo/node/p2p/channel.go:519 > Will use service conn with local port: 40635, remote port: 41090
2020-05-21T09:50:53.371 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://testnet-broker.mysterium.network:4222 removed
2020-05-21T09:50:53.371 WRN Users/tadas/mygo/node/communication/nats/connection_wrap.go:86 > NATS: disconnected
2020-05-21T09:50:53.371 WRN Users/tadas/mygo/node/communication/nats/connection_wrap.go:85 > NATS: connection closed
2020-05-21T09:50:53.371 DBG Users/tadas/mygo/node/session/pingpong/invoice_payer.go:120 > Starting...
2020-05-21T09:50:53.371 DBG Users/tadas/mygo/node/core/connection/manager.go:405 > Sending P2P message to "p2p-session-create": consumer:{id:"0x12345" accountantID:"0x0214281cf15C1a66b51990e2E65e1f7b7C363318" paymentVersion:"v3"} proposalID:1 config:"{\"PublicKey\":\"aaaa/aaaaa=\",\"Ports\":null}"
2020-05-21T09:50:54.214 DBG Users/tadas/mygo/node/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Created SessionInfo:{StartedAt:2020-05-21 09:50:51.034679 +0300 EEST m=+209.809275317 ConsumerID:{Address:0x12345} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Connecting SessionID:aaaa-aaaa Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:1m0s Bytes:7669584 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x5a8c2949962d112cbc4c101b0f1fbdbff9c9d855 ProviderContacts:[{Type:nats/v1 Definition:{}} {Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:<nil>}}}
2020-05-21T09:50:54.257 DBG Users/tadas/mygo/node/consumer/session/session_storage.go:178 > Session aaaa-aaaa saved
2020-05-21T09:50:54.257 DBG Users/tadas/mygo/node/consumer/statistics/reporter.go:123 > Session statistics reporter started
2020-05-21T09:50:54.553 INF Users/tadas/mygo/node/core/connection/manager.go:537 > Connection state: Connecting -> Disconnecting
2020-05-21T09:50:54.553 DBG Users/tadas/mygo/node/eventbus/event_bus.go:81 > Published topic="Session" event={Status:Ended SessionInfo:{StartedAt:2020-05-21 09:50:51.034679 +0300 EEST m=+209.809275317 ConsumerID:{Address:0x12345} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:aaaa-aaaa Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:1m0s Bytes:7669584 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x5a8c2949962d112cbc4c101b0f1fbdbff9c9d855 ProviderContacts:[{Type:nats/v1 Definition:{}} {Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:<nil>}}}
2020-05-21T09:50:54.553 DBG Users/tadas/mygo/node/eventbus/event_bus.go:81 > Published topic="State" event={State:Disconnecting SessionInfo:{StartedAt:2020-05-21 09:50:51.034679 +0300 EEST m=+209.809275317 ConsumerID:{Address:0x12345} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:Disconnecting SessionID:aaaa-aaaa Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:1m0s Bytes:7669584 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x5a8c2949962d112cbc4c101b0f1fbdbff9c9d855 ProviderContacts:[{Type:nats/v1 Definition:{}} {Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:<nil>}}}
2020-05-21T09:50:54.584 DBG Users/tadas/mygo/node/consumer/session/session_storage.go:154 > Session aaaa-aaaa updated with final data
2020-05-21T09:50:54.585 DBG Users/tadas/mygo/node/consumer/statistics/reporter.go:137 > Session statistics reporter stopping
2020-05-21T09:50:54.585 DBG Users/tadas/mygo/node/session/pingpong/invoice_payer.go:265 > Stopping...
2020-05-21T09:50:54.585 INF Users/tadas/mygo/node/core/connection/manager.go:537 > Connection state: Disconnecting -> NotConnected
2020-05-21T09:50:54.585 INF Users/tadas/mygo/node/core/state/state.go:359 > Session ID aaaa-aaaa Disconnecting duration: 3.549180423s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-05-21T09:50:54.585 DBG Users/tadas/mygo/node/core/connection/manager.go:441 > Sending P2P message to "p2p-session-destroy": consumerID:"0x12345" sessionID:"aaaa-aaaa"
2020-05-21T09:50:54.585 DBG Users/tadas/mygo/node/eventbus/event_bus.go:81 > Published topic="State" event={State:NotConnected SessionInfo:{StartedAt:2020-05-21 09:50:51.034679 +0300 EEST m=+209.809275317 ConsumerID:{Address:0x12345} AccountantID:[2 20 40 28 241 92 26 102 181 25 144 226 230 94 31 123 124 54 51 24] State:NotConnected SessionID:aaaa-aaaa Proposal:{ID:1 Format:service-proposal/v1 ServiceType:wireguard ServiceDefinition:{Location:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential} LocationOriginate:{Continent:EU Country:IT City:Latium ASN:197075 ISP:Wiplanet.it NodeType:residential}} PaymentMethodType:BYTES_TRANSFERRED_WITH_TIME PaymentMethod:{Price:0.000500MYST Duration:1m0s Bytes:7669584 Type:BYTES_TRANSFERRED_WITH_TIME} ProviderID:0x5a8c2949962d112cbc4c101b0f1fbdbff9c9d855 ProviderContacts:[{Type:nats/v1 Definition:{}} {Type:nats/p2p/v1 Definition:{BrokerAddresses:[nats://testnet-broker.mysterium.network:4222]}}] AccessPolicies:<nil>}}}
2020-05-21T09:50:54.585 DBG Users/tadas/mygo/node/core/location/oracle_resolver.go:41 > Detecting with oracle resolver
2020-05-21T09:50:54.585 INF Users/tadas/mygo/node/core/state/state.go:359 > Session ID aaaa-aaaa NotConnected duration: 3.549540843s data: 0b/0b, throughput: 0bs/0bs, spent: 0.000000MYST
2020-05-21T09:50:54.825 INF Users/tadas/mygo/node/market/mysterium/mysterium_api.go:309 > Session stats sent: aaaa-aaaa
2020-05-21T09:50:54.826 DBG Users/tadas/mygo/node/consumer/statistics/reporter.go:109 > Final stats sent
2020-05-21T09:50:54.830 DBG Users/tadas/mygo/node/core/ip/resolver.go:103 > IP detected: 123.123.123.123
2020-05-21T09:50:54.830 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:48 > Allow IP 123.123.123.1235 access
2020-05-21T09:50:54.830 INF Users/tadas/mygo/node/services/wireguard/connection/connection.go:125 > Starting new connection
2020-05-21T09:50:54.830 DBG Users/tadas/mygo/node/config/config.go:177 > Returning CLI value usermode:true
2020-05-21T09:50:54.830 DBG Users/tadas/mygo/node/services/wireguard/endpoint/remoteclient/client.go:45 > Creating remote wg client
2020-05-21T09:50:54.830 INF Users/tadas/mygo/node/services/wireguard/connection/connection.go:171 > Starting connection endpoint
2020-05-21T09:50:54.830 DBG Users/tadas/mygo/node/supervisor/client/client.go:32 > Supervisor command invoked: "wg-down -iface utun0"
2020-05-21T09:50:54.836 WRN Users/tadas/mygo/node/services/wireguard/endpoint/endpoint.go:177 > Failed to destroy abandoned interface: utun0 error="could not destroy TUN device utun0: failed to destroy wg interface: interface utun0 not found"
2020-05-21T09:50:54.836 INF Users/tadas/mygo/node/services/wireguard/endpoint/endpoint.go:179 > Abandoned interface destroyed: utun0
2020-05-21T09:50:54.836 DBG Users/tadas/mygo/node/supervisor/client/client.go:32 > Supervisor command invoked: "wg-down -iface utun1"
2020-05-21T09:50:54.836 WRN Users/tadas/mygo/node/services/wireguard/endpoint/endpoint.go:177 > Failed to destroy abandoned interface: utun1 error="could not destroy TUN device utun1: failed to destroy wg interface: interface utun1 not found"
2020-05-21T09:50:54.837 INF Users/tadas/mygo/node/services/wireguard/endpoint/endpoint.go:179 > Abandoned interface destroyed: utun1
2020-05-21T09:50:54.837 DBG Users/tadas/mygo/node/services/wireguard/endpoint/endpoint.go:64 > Allocated interface: utun2
2020-05-21T09:50:54.837 DBG Users/tadas/mygo/node/supervisor/client/client.go:32 > Supervisor command invoked: "wg-up -iface utun2 -uid 501"
2020-05-21T09:50:54.838 DBG Users/tadas/mygo/node/services/wireguard/endpoint/remoteclient/tun.go:42 > Tunnel interface created: utun2
2020-05-21T09:50:54.839 DBG Users/tadas/mygo/node/supervisor/client/client.go:32 > Supervisor command invoked: "assign-ip -iface utun2 -net 555.555.555.555/24"
2020-05-21T09:50:54.868 INF Users/tadas/mygo/node/services/wireguard/connection/connection.go:136 > Adding connection peer 123.123.123.1235:41090
2020-05-21T09:50:54.869 INF Users/tadas/mygo/node/services/wireguard/connection/connection.go:142 > Configuring routes
2020-05-21T09:50:54.869 DBG Users/tadas/mygo/node/supervisor/client/client.go:32 > Supervisor command invoked: "exclude-route -ip 123.123.123.1235"
2020-05-21T09:50:54.875 DBG Users/tadas/mygo/node/supervisor/client/client.go:32 > Supervisor command invoked: "default-route -iface utun2"
2020-05-21T09:50:54.880 INF Users/tadas/mygo/node/services/wireguard/connection/connection.go:147 > Waiting for initial handshake
2020-05-21T09:50:58.028 DBG Users/tadas/mygo/node/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-05-21T09:51:08.031 DBG Users/tadas/mygo/node/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-05-21T09:51:14.614 ERR Users/tadas/mygo/node/core/location/cache.go:91 > Location update failed error="failed to execute request: Get \"https://testnet-location.mysterium.network/api/v1/location/\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)"
2020-05-21T09:51:18.032 ERR Users/tadas/mygo/node/core/discovery/repository.go:91 > Returning 462 unique proposals error="ErrorCollection: could not query proposals: cannot fetch proposals: Get \"https://testnet-api.mysterium.network/v1/proposals?service_type=wireguard\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)"
2020-05-21T09:51:18.033 DBG Users/tadas/mygo/node/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-05-21T09:51:22.871 WRN Users/tadas/mygo/node/communication/nats/connection_wrap.go:86 > NATS: disconnected
2020-05-21T09:51:28.035 DBG Users/tadas/mygo/node/core/discovery/repository.go:61 > Retrieving proposals from 2 repositories
2020-05-21T09:51:28.035 ERR Users/tadas/mygo/node/core/discovery/repository.go:91 > Returning 439 unique proposals error="ErrorCollection: could not query proposals: cannot fetch proposals: Get \"https://testnet-api.mysterium.network/v1/proposals?service_type=wireguard\": dial tcp 0.0.0.0:0->78.47.176.149:443: i/o timeout (Client.Timeout exceeded while awaiting headers)"
2020-05-21T09:51:29.951 INF Users/tadas/mygo/node/cmd/commands/daemon/command.go:66 > Stopping application
2020-05-21T09:51:29.963 WRN Users/tadas/mygo/node/nat/service_ipforward.go:65 > Failed to disable IP forwarding: [-w net.inet.ip.forwarding=0] Cmd output: net.inet.ip.forwarding: 0
sysctl: net.inet.ip.forwarding=0: Operation not permitted
error="exit status 1"
2020-05-21T09:51:29.964 INF Users/tadas/mygo/node/nat/service_ipforward.go:68 > IP forwarding disabled
2020-05-21T09:51:29.969 DBG Users/tadas/mygo/node/nat/service_pfctl.go:188 > "/sbin/pfctl -F nat" output:
pfctl: /dev/pf: Permission denied
2020-05-21T09:51:29.970 WRN Users/tadas/mygo/node/nat/service_pfctl.go:190 > Failed cleanup NAT rules (pfctl) error="\"/sbin/pfctl -F nat\": exit status 1 output: pfctl: /dev/pf: Permission denied\n"
2020-05-21T09:51:29.970 INF Users/tadas/mygo/node/communication/nats/receiver.go:99 > Unsubscribed from *.proposal-ping
2020-05-21T09:51:29.970 INF Users/tadas/mygo/node/communication/nats/receiver.go:99 > Unsubscribed from *.proposal-unregister
2020-05-21T09:51:29.970 INF Users/tadas/mygo/node/communication/nats/receiver.go:99 > Unsubscribed from *.proposal-register
2020-05-21T09:51:29.970 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:61 > Rule for URL: nats://testnet-broker.mysterium.network:4222 removed
2020-05-21T09:51:29.970 WRN Users/tadas/mygo/node/communication/nats/connection_wrap.go:85 > NATS: connection closed
2020-05-21T09:51:44.906 DBG Users/tadas/mygo/node/logconfig/config_rollingwriter.go:70 > Found 0 old log files in log directory, skipping cleanup
2020-05-21T09:51:44.906 INF Users/tadas/mygo/node/cmd/di.go:168 > Starting Mysterium Node source.dev-build
2020-05-21T09:51:44.907 DBG Users/tadas/mygo/node/config/config.go:186 > Returning default value incoming-firewall:false
2020-05-21T09:51:44.907 INF Users/tadas/mygo/node/firewall/incoming_firewall_noop.go:32 > Rules bootstrap was requested
2020-05-21T09:51:44.907 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:57 > Allow URL wss://goerli.infura.io/ws/v3/c2c7da73fcc84ec5885a7bb0eb3c3637 access
2020-05-21T09:51:44.907 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-api.mysterium.network/v1 access
2020-05-21T09:51:44.907 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-transactor.mysterium.network/api/v1 access
2020-05-21T09:51:44.907 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:57 > Allow URL https://testnet-accountant.mysterium.network/api/v2 access
2020-05-21T09:51:44.907 INF Users/tadas/mygo/node/firewall/incoming_firewall_noop.go:53 > Allow URL wss://goerli.infura.io/ws/v3/c2c7da73fcc84ec5885a7bb0eb3c3637 access
2020-05-21T09:51:44.907 INF Users/tadas/mygo/node/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-api.mysterium.network/v1 access
2020-05-21T09:51:44.908 INF Users/tadas/mygo/node/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-transactor.mysterium.network/api/v1 access
2020-05-21T09:51:44.908 INF Users/tadas/mygo/node/firewall/incoming_firewall_noop.go:53 > Allow URL https://testnet-accountant.mysterium.network/api/v2 access
2020-05-21T09:51:44.908 INF Users/tadas/mygo/node/firewall/incoming_firewall_noop.go:53 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-05-21T09:51:44.908 DBG Users/tadas/mygo/node/communication/nats/connector.go:39 > Connecting to NATS servers: nats://testnet-broker.mysterium.network:4222
2020-05-21T09:51:44.908 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:57 > Allow URL nats://testnet-broker.mysterium.network:4222 access
2020-05-21T09:51:49.923 INF Users/tadas/mygo/node/firewall/incoming_firewall_noop.go:38 > Rules reset was requested
2020-05-21T09:51:49.923 INF Users/tadas/mygo/node/firewall/outgoing_firewall_noop.go:35 > Rules reset was requested
2020-05-21T09:51:49.923 ERR Users/tadas/mygo/node/cmd/mysterium_node/mysterium_node.go:58 > Failed to execute command: error="failed to connect to NATS servers \"[nats://testnet-broker.mysterium.network:4222]\": failed to connect to NATS servers \"[nats://testnet-broker.mysterium.network:4222]\": nats: no servers available for connection"
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment