$skywire:[fix/health-timeout] sudo skywire-visor -c skywire-config.json
[2021-02-24T17:59:00-03:00] INFO []: Starting
[2021-02-24T17:59:00-03:00] DEBUG []: Process info delay=0s parent_systemd=false systemd=false
Version "v0.3.0-318-g2927fbd4" built on "2021-02-24T20:56:22Z" against commit "2927fbd4fb782b02b722f1afde40b2af4b3f3fe0"
[2021-02-24T17:59:00-03:00] INFO [visor:config]: Reading config from file. filepath="skywire-config.json"
[2021-02-24T17:59:00-03:00] INFO [visor:config]: Flushing config to file. config_version="v1.0.0" filepath="skywire-config.json"
[2021-02-24T17:59:00-03:00] INFO [visor:startup]: Begin startup. public_key=02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe
[2021-02-24T17:59:00-03:00] INFO [1/14] [visor:startup:updater]: Starting module...
[2021-02-24T17:59:00-03:00] INFO [1/14] [visor:startup:updater]: Module started successfully. elapsed=517.372µs
[2021-02-24T17:59:00-03:00] INFO [2/14] [visor:startup:eventbroadcaster]: Starting module...
[2021-02-24T17:59:00-03:00] INFO [2/14] [visor:startup:eventbroadcaster]: Module started successfully. elapsed=79.272µs
[2021-02-24T17:59:00-03:00] INFO [3/14] [visor:startup:addressresolver]: Starting module...
[2021-02-24T17:59:00-03:00] INFO [address-resolver]: Remote UDP server: "address.resolver.skywire.skycoin.com:30178"
[2021-02-24T17:59:00-03:00] INFO [3/14] [visor:startup:addressresolver]: Module started successfully. elapsed=877.544µs
[2021-02-24T17:59:00-03:00] INFO [4/14] [visor:startup:discovery]: Starting module...
[2021-02-24T17:59:00-03:00] INFO [4/14] [visor:startup:discovery]: Module started successfully. elapsed=288.961µs
[2021-02-24T17:59:00-03:00] INFO [5/14] [visor:startup:snet]: Starting module...
[2021-02-24T17:59:00-03:00] INFO [snet.dmsgC]: Discovering dmsg servers...
[2021-02-24T17:59:00-03:00] INFO [snet.dmsgC]: Connecting to the dmsg network... timeout=20s
[2021-02-24T17:59:00-03:00] INFO [stcp]: listening on addr: [::]:7777
[2021-02-24T17:59:00-03:00] INFO [address-resolver]: BindSTCPR: Address resolver is not ready yet, waiting...
[2021-02-24T17:59:00-03:00] INFO [address-resolver]: BindSUDPR: Address resolver is not ready yet, waiting...
[2021-02-24T17:59:04-03:00] INFO [address-resolver]: Connected to address resolver. STCPR/SUDPH services are available.
[2021-02-24T17:59:04-03:00] INFO [address-resolver]: BindSTCPR: Address resolver became ready, binding
[2021-02-24T17:59:04-03:00] INFO [address-resolver]: BindSUDPR: Address resolver became ready, binding
[2021-02-24T17:59:04-03:00] INFO [address-resolver]: SUDPH Local port: 51267
[2021-02-24T17:59:04-03:00] INFO [address-resolver]: Performing handshake with 172.104.161.112:30178
[2021-02-24T17:59:04-03:00] INFO [snet.dmsgC]: Dialing session... remote_pk=0226d860fd391507d4d4a24ff229d239a36851fd30c0acd5cb23be8269576a73df
[2021-02-24T17:59:04-03:00] WARN [snet.dmsgC]: Failed to establish session. error="dial tcp 172.104.158.4:30080: connect: connection refused" remote_pk=0226d860fd391507d4d4a24ff229d239a36851fd30c0acd5cb23be8269576a73df
[2021-02-24T17:59:05-03:00] INFO [snet.dmsgC]: Dialing session... remote_pk=03717576ada5b1744e395c66c2bb11cea73b0e23d0dcd54422139b1a7f12e962c4
[2021-02-24T17:59:05-03:00] INFO [stcpr]: listening on addr: [::]:50236
[2021-02-24T17:59:05-03:00] INFO [address-resolver]: Sent handshake to 172.104.161.112:30178, local addr 02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe:~, remote addr 000000000000000000000000000000000000000000000000000000000000000000:~
[2021-02-24T17:59:05-03:00] INFO [address-resolver]: Connection with 000000000000000000000000000000000000000000000000000000000000000000:~@172.104.161.112:30178 is NOT encrypted
[2021-02-24T17:59:05-03:00] INFO [sudph]: listening on addr: [::]:51267
[2021-02-24T17:59:08-03:00] INFO [snet.dmsgC]: Serving session. remote_pk=03717576ada5b1744e395c66c2bb11cea73b0e23d0dcd54422139b1a7f12e962c4
[2021-02-24T17:59:08-03:00] INFO [snet.dmsgC]: Connected to the dmsg network. timeout=20s
[2021-02-24T17:59:08-03:00] INFO [5/14] [visor:startup:snet]: Module started successfully. elapsed=8.066359666s
[2021-02-24T17:59:08-03:00] INFO [6/14] [visor:startup:dmsgpty]: Starting module...
[2021-02-24T17:59:08-03:00] INFO [6/14] [visor:startup:dmsgpty]: Module started successfully. elapsed=3.547968ms
[2021-02-24T17:59:08-03:00] INFO [7/14] [visor:startup:transport]: Starting module...
[2021-02-24T17:59:11-03:00] INFO [7/14] [visor:startup:transport]: Module started successfully. elapsed=2.757078585s
[2021-02-24T17:59:11-03:00] INFO [8/14] [visor:startup:router]: Starting module...
[2021-02-24T17:59:11-03:00] INFO [transport_manager]: listening on network: dmsg
[2021-02-24T17:59:11-03:00] INFO [transport_manager]: listening on network: stcpr
[2021-02-24T17:59:11-03:00] INFO [transport_manager]: listening on network: sudph
[2021-02-24T17:59:11-03:00] INFO [transport_manager]: listening on network: stcp
[2021-02-24T17:59:11-03:00] INFO [8/14] [visor:startup:router]: Module started successfully. elapsed=3.553969ms
[2021-02-24T17:59:11-03:00] INFO [9/14] [visor:startup:launcher]: Starting module...
[2021-02-24T17:59:11-03:00] INFO [router]: Starting router
[2021-02-24T17:59:11-03:00] INFO [9/14] [visor:startup:launcher]: Module started successfully. elapsed=143.510851ms
[2021-02-24T17:59:11-03:00] INFO [10/14] [visor:startup:cli]: Starting module...
[2021-02-24T17:59:11-03:00] INFO [10/14] [visor:startup:cli]: Module started successfully. elapsed=2.417359ms
[2021-02-24T17:59:11-03:00] INFO [11/14] [visor:startup:hypervisors]: Starting module...
[2021-02-24T17:59:11-03:00] INFO [11/14] [visor:startup:hypervisors]: Module started successfully. elapsed=12.256µs
[2021-02-24T17:59:11-03:00] INFO [12/14] [visor:startup:uptimetracker]: Starting module...
[2021-02-24T17:59:11-03:00] INFO [proc_manager]: Accepted proc conn. hello="{"proc_key":"bceb22a09e0c46eea76c215fa4212454"}" remote=127.0.0.1:50254
[2021-02-24T17:59:11-03:00] INFO [proc:skychat:bceb22a09e0c46eea76c215fa4212454]: Associated and serving proc conn.
[2021-02-24T17:59:11-03:00] INFO [proc:skychat:bceb22a09e0c46eea76c215fa4212454]: Request processed. _elapsed="16.196748ms" _method="Listen" _received="5:59PM" input=02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe:1 output=0xc000576e8e
[2021-02-24T17:59:11-03:00] INFO (STDOUT) [proc:skychat:bceb22a09e0c46eea76c215fa4212454]: Version "v0.3.0-318-g2927fbd4" built on "2021-02-24T20:58:26Z" against commit "2927fbd4fb782b02b722f1afde40b2af4b3f3fe0"
[2021-02-24T17:59:12-03:00] INFO [proc_manager]: Accepted proc conn. hello="{"proc_key":"d9e2a54f8dcc447e8e6cfd1310c8f37f"}" remote=127.0.0.1:50259
[2021-02-24T17:59:12-03:00] INFO [proc:skysocks:d9e2a54f8dcc447e8e6cfd1310c8f37f]: Associated and serving proc conn.
[2021-02-24T17:59:12-03:00] INFO [proc:skysocks:d9e2a54f8dcc447e8e6cfd1310c8f37f]: Request processed. _elapsed="2.025396ms" _method="Listen" _received="5:59PM" input=02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe:3 output=0xc00048821e
[2021-02-24T17:59:12-03:00] INFO (STDOUT) [proc:skysocks:d9e2a54f8dcc447e8e6cfd1310c8f37f]: Version "v0.3.0-318-g2927fbd4" built on "2021-02-24T20:58:26Z" against commit "2927fbd4fb782b02b722f1afde40b2af4b3f3fe0"
[2021-02-24T17:59:12-03:00] INFO (STDOUT) [proc:skysocks:d9e2a54f8dcc447e8e6cfd1310c8f37f]: Starting serving proxy server
[2021-02-24T17:59:13-03:00] INFO [tp:035927]: Serving. remote_pk=0359272a223ca2c988bd30cb91820f53e802f06120a45dc4c7fd91c1fd246f299b tp_id=b8edf314-5c7b-01c6-901c-5914dbf0e190 tp_index=1
[2021-02-24T17:59:13-03:00] INFO [transport_manager]: saved transport: remote(0359272a223ca2c988bd30cb91820f53e802f06120a45dc4c7fd91c1fd246f299b) type(stcpr) tpID(b8edf314-5c7b-01c6-901c-5914dbf0e190)
[2021-02-24T17:59:13-03:00] INFO [transport_manager]: transport manager is serving.
[2021-02-24T17:59:14-03:00] INFO [12/14] [visor:startup:uptimetracker]: Module started successfully. elapsed=2.92232582s
[2021-02-24T17:59:14-03:00] INFO [13/14] [visor:startup:trustedvisors]: Starting module...
[2021-02-24T17:59:14-03:00] INFO [13/14] [visor:startup:trustedvisors]: Module started successfully. elapsed=31.348µs
[2021-02-24T17:59:14-03:00] INFO [14/14] [visor:startup:hypervisor]: Starting module...
[2021-02-24T17:59:14-03:00] INFO [visor]: Initializing hypervisor
[2021-02-24T17:59:14-03:00] INFO [visor]: Serving RPC client over dmsg. addr=02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe:46
[2021-02-24T17:59:14-03:00] INFO [visor]: Serving hypervisor... addr=":8000" tls=false
[2021-02-24T17:59:14-03:00] INFO [visor]: Hypervisor initialized
[2021-02-24T17:59:14-03:00] INFO [14/14] [visor:startup:hypervisor]: Module started successfully. elapsed=114.919748ms
[2021-02-24T17:59:14-03:00] INFO [visor:startup]: Startup complete!
[2021-02-24T17:59:17-03:00] INFO [stcpr]: Dialing PK 0359272a223ca2c988bd30cb91820f53e802f06120a45dc4c7fd91c1fd246f299b
[2021-02-24T17:59:18-03:00] INFO [stcpr]: Resolved PK 0359272a223ca2c988bd30cb91820f53e802f06120a45dc4c7fd91c1fd246f299b to visor data {172.104.158.4 false {35667 [127.0.0.1 172.104.158.4 172.17.0.1 ::1 2a01:7e01::f03c:92ff:fe39:e541]}}
2021/02/24 17:59:18 [works-MacBook-Pro.local/Q8C0PLos1y-000001] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe HTTP/1.1" from [::1]:50265 - 401 77B in 2.748821ms
2021/02/24 17:59:18 [works-MacBook-Pro.local/Q8C0PLos1y-000002] "GET http://localhost:8000/api/user HTTP/1.1" from [::1]:50265 - 401 77B in 172.432µs
[2021-02-24T17:59:18-03:00] INFO [stcpr]: Dialed 0359272a223ca2c988bd30cb91820f53e802f06120a45dc4c7fd91c1fd246f299b:45@172.104.158.4:35667
[2021-02-24T17:59:18-03:00] INFO [stcpr]: Performing handshake with 172.104.158.4:35667
[2021-02-24T17:59:19-03:00] INFO [stcpr]: Sent handshake to 172.104.158.4:35667, local addr 02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe:49153, remote addr 0359272a223ca2c988bd30cb91820f53e802f06120a45dc4c7fd91c1fd246f299b:45
[2021-02-24T17:59:19-03:00] INFO [stcpr]: Connection with 0359272a223ca2c988bd30cb91820f53e802f06120a45dc4c7fd91c1fd246f299b:45@172.104.158.4:35667(0359272a223ca2c988bd30cb91820f53e802f06120a45dc4c7fd91c1fd246f299b) is encrypted
[2021-02-24T17:59:19-03:00] INFO [snet]: Dialed stcpr, conn local address "02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe:49153", remote address "0359272a223ca2c988bd30cb91820f53e802f06120a45dc4c7fd91c1fd246f299b:45"
[2021-02-24T17:59:21-03:00] INFO [tp:035927]: Transport status updated. status="UP"
2021/02/24 17:59:26 [works-MacBook-Pro.local/Q8C0PLos1y-000003] "POST http://localhost:8000/api/login HTTP/1.1" from [::1]:50265 - 200 5B in 469.2µs
2021/02/24 17:59:26 [works-MacBook-Pro.local/Q8C0PLos1y-000004] "GET http://localhost:8000/api/visors HTTP/1.1" from [::1]:50265 - 200 1096B in 2.188397ms
2021/02/24 17:59:26 [works-MacBook-Pro.local/Q8C0PLos1y-000005] "GET http://localhost:8000/api/dmsg HTTP/1.1" from [::1]:50265 - 200 199B in 336.019µs
2021/02/24 17:59:26 [works-MacBook-Pro.local/Q8C0PLos1y-000006] "GET http://localhost:8000/api/about HTTP/1.1" from [::1]:50265 - 200 209B in 347.026µs
2021/02/24 17:59:27 [works-MacBook-Pro.local/Q8C0PLos1y-000007] "GET http://localhost:8000/assets/fonts/skycoin/skycoin-bold-webfont.woff2 HTTP/1.1" from [::1]:50265 - 200 20052B in 6.146567ms
2021/02/24 17:59:27 [works-MacBook-Pro.local/Q8C0PLos1y-000008] "GET http://localhost:8000/assets/fonts/skycoin/skycoin-light-webfont.woff2 HTTP/1.1" from [::1]:50266 - 200 19764B in 4.198014ms
2021/02/24 17:59:28 [works-MacBook-Pro.local/Q8C0PLos1y-000009] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe HTTP/1.1" from [::1]:50266 - 200 1095B in 475.047µs
2021/02/24 17:59:28 [works-MacBook-Pro.local/Q8C0PLos1y-000010] "GET http://localhost:8000/api/dmsg HTTP/1.1" from [::1]:50266 - 200 199B in 254.613µs
[2021-02-24T17:59:32-03:00] WARN [visor]: Failed to check service health, service name: ut error="Get "https://uptime-tracker.skywire.skycoin.com:443/health": context deadline exceeded"
2021/02/24 17:59:32 [works-MacBook-Pro.local/Q8C0PLos1y-000011] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/health HTTP/1.1" from [::1]:50266 - 200 121B in 4.004128386s
2021/02/24 17:59:32 [works-MacBook-Pro.local/Q8C0PLos1y-000012] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/uptime HTTP/1.1" from [::1]:50266 - 200 9B in 222.214µs
2021/02/24 17:59:32 [works-MacBook-Pro.local/Q8C0PLos1y-000013] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/transports HTTP/1.1" from [::1]:50266 - 200 280B in 931.443µs
2021/02/24 17:59:32 [works-MacBook-Pro.local/Q8C0PLos1y-000014] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/routes HTTP/1.1" from [::1]:50266 - 200 3B in 487.191µs
2021/02/24 17:59:43 [works-MacBook-Pro.local/Q8C0PLos1y-000015] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe HTTP/1.1" from [::1]:50266 - 200 1095B in 307.396µs
2021/02/24 17:59:43 [works-MacBook-Pro.local/Q8C0PLos1y-000016] "GET http://localhost:8000/api/dmsg HTTP/1.1" from [::1]:50266 - 200 199B in 502.667µs
2021/02/24 17:59:43 [works-MacBook-Pro.local/Q8C0PLos1y-000017] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/health HTTP/1.1" from [::1]:50266 - 200 121B in 781.573182ms
2021/02/24 17:59:43 [works-MacBook-Pro.local/Q8C0PLos1y-000018] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/uptime HTTP/1.1" from [::1]:50266 - 200 10B in 282.495µs
2021/02/24 17:59:43 [works-MacBook-Pro.local/Q8C0PLos1y-000019] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/transports HTTP/1.1" from [::1]:50266 - 200 280B in 209.928µs
2021/02/24 17:59:43 [works-MacBook-Pro.local/Q8C0PLos1y-000020] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/routes HTTP/1.1" from [::1]:50266 - 200 3B in 192.429µs
2021/02/24 17:59:54 [works-MacBook-Pro.local/Q8C0PLos1y-000021] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe HTTP/1.1" from [::1]:50266 - 200 1095B in 266.213µs
2021/02/24 17:59:54 [works-MacBook-Pro.local/Q8C0PLos1y-000022] "GET http://localhost:8000/api/dmsg HTTP/1.1" from [::1]:50266 - 200 198B in 191.713µs
[2021-02-24T17:59:58-03:00] WARN [visor]: Failed to check service health, service name: ut error="Get "https://uptime-tracker.skywire.skycoin.com:443/health": context deadline exceeded"
2021/02/24 17:59:58 [works-MacBook-Pro.local/Q8C0PLos1y-000023] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/health HTTP/1.1" from [::1]:50266 - 200 121B in 4.000841866s
2021/02/24 17:59:58 [works-MacBook-Pro.local/Q8C0PLos1y-000024] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/uptime HTTP/1.1" from [::1]:50266 - 200 9B in 191.289µs
2021/02/24 17:59:58 [works-MacBook-Pro.local/Q8C0PLos1y-000025] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/transports HTTP/1.1" from [::1]:50266 - 200 280B in 221.256µs
2021/02/24 17:59:58 [works-MacBook-Pro.local/Q8C0PLos1y-000026] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/routes HTTP/1.1" from [::1]:50266 - 200 3B in 277.662µs
2021/02/24 18:00:08 [works-MacBook-Pro.local/Q8C0PLos1y-000027] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe HTTP/1.1" from [::1]:50266 - 200 1095B in 265.285µs
2021/02/24 18:00:08 [works-MacBook-Pro.local/Q8C0PLos1y-000028] "GET http://localhost:8000/api/dmsg HTTP/1.1" from [::1]:50266 - 200 198B in 227.288µs
[2021-02-24T18:00:12-03:00] WARN [visor]: Failed to check service health, service name: ut error="Get "https://uptime-tracker.skywire.skycoin.com:443/health": context deadline exceeded"
2021/02/24 18:00:12 [works-MacBook-Pro.local/Q8C0PLos1y-000029] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/health HTTP/1.1" from [::1]:50266 - 200 121B in 4.000923641s
2021/02/24 18:00:12 [works-MacBook-Pro.local/Q8C0PLos1y-000030] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/uptime HTTP/1.1" from [::1]:50266 - 200 10B in 198.997µs
2021/02/24 18:00:12 [works-MacBook-Pro.local/Q8C0PLos1y-000031] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/transports HTTP/1.1" from [::1]:50266 - 200 280B in 198.731µs
2021/02/24 18:00:12 [works-MacBook-Pro.local/Q8C0PLos1y-000032] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/routes HTTP/1.1" from [::1]:50266 - 200 3B in 212.911µs
2021/02/24 18:00:22 [works-MacBook-Pro.local/Q8C0PLos1y-000033] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe HTTP/1.1" from [::1]:50266 - 200 1095B in 256.829µs
2021/02/24 18:00:22 [works-MacBook-Pro.local/Q8C0PLos1y-000034] "GET http://localhost:8000/api/dmsg HTTP/1.1" from [::1]:50266 - 200 198B in 216.838µs
2021/02/24 18:00:27 [works-MacBook-Pro.local/Q8C0PLos1y-000035] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/health HTTP/1.1" from [::1]:50266 - 408 15B in 5.000757862s
2021/02/24 18:00:32 [works-MacBook-Pro.local/Q8C0PLos1y-000036] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/health HTTP/1.1" from [::1]:50265 - 408 15B in 5.000823645s
2021/02/24 18:00:37 [works-MacBook-Pro.local/Q8C0PLos1y-000037] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/health HTTP/1.1" from [::1]:50274 - 408 15B in 5.00291759s
2021/02/24 18:00:42 [works-MacBook-Pro.local/Q8C0PLos1y-000038] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe HTTP/1.1" from [::1]:50274 - 200 1095B in 225.792µs
2021/02/24 18:00:42 [works-MacBook-Pro.local/Q8C0PLos1y-000039] "GET http://localhost:8000/api/dmsg HTTP/1.1" from [::1]:50274 - 200 198B in 210.686µs
[2021-02-24T18:00:46-03:00] WARN [visor]: Failed to check service health, service name: ut error="Get "http://uptime-tracker.skywire.skycoin.com/health": context deadline exceeded"
[2021-02-24T18:00:46-03:00] WARN [visor]: Failed to check service health, service name: ut error="Get "http://uptime-tracker.skywire.skycoin.com/health": context deadline exceeded"
[2021-02-24T18:00:46-03:00] WARN [visor]: Failed to check service health, service name: ut error="Get "http://uptime-tracker.skywire.skycoin.com/health": context deadline exceeded"
[2021-02-24T18:00:46-03:00] WARN [visor]: Failed to check service health, service name: ut error="Get "http://uptime-tracker.skywire.skycoin.com/health": context deadline exceeded"
2021/02/24 18:00:46 [works-MacBook-Pro.local/Q8C0PLos1y-000040] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/health HTTP/1.1" from [::1]:50274 - 200 121B in 4.00567133s
2021/02/24 18:00:46 [works-MacBook-Pro.local/Q8C0PLos1y-000041] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/uptime HTTP/1.1" from [::1]:50274 - 200 11B in 238.751µs
2021/02/24 18:00:46 [works-MacBook-Pro.local/Q8C0PLos1y-000042] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/transports HTTP/1.1" from [::1]:50274 - 200 280B in 252.933µs
2021/02/24 18:00:46 [works-MacBook-Pro.local/Q8C0PLos1y-000043] "GET http://localhost:8000/api/visors/02eb5a3a5125711eca730e34d48c3c4d6b7d98baddc3b9bcbbb2ac9b7fd1a88cbe/routes HTTP/1.1" from [::1]:50274 - 200 3B in 287.31µs
^C[2021-02-24T18:00:51-03:00] INFO [proc:skysocks:d9e2a54f8dcc447e8e6cfd1310c8f37f]: Request processed. _elapsed="35.824µs" _method="CloseConn" _received="6:00PM" input=0xc0036769ca
[2021-02-24T18:00:51-03:00] INFO [proc:skychat:bceb22a09e0c46eea76c215fa4212454]: Request processed. _elapsed="1m39.538231351s" _method="Accept" _received="5:59PM" error="listening on closed connection" input=0xc0004889c8 output=&{Remote:000000000000000000000000000000000000000000000000000000000000000000:~ ConnID:0}
[2021-02-24T18:00:51-03:00] INFO [proc:skysocks:d9e2a54f8dcc447e8e6cfd1310c8f37f]: Request processed. _elapsed="1m38.700159908s" _method="Accept" _received="5:59PM" error="listening on closed connection" input=0xc000488578 output=&{Remote:000000000000000000000000000000000000000000000000000000000000000000:~ ConnID:0}
[2021-02-24T18:00:51-03:00] INFO []: Closing with received signal. signal=interrupt
[2021-02-24T18:00:51-03:00] INFO [visor:shutdown]: Begin shutdown.
[2021-02-24T18:00:51-03:00] INFO [10/10] [visor:shutdown:uptime_tracker]: Shutting down module...
[2021-02-24T18:00:51-03:00] INFO [10/10] [visor:shutdown:uptime_tracker]: Module stopped cleanly. elapsed=304.959µs
[2021-02-24T18:00:51-03:00] INFO [9/10] [visor:shutdown:cli.listener]: Shutting down module...
2021/02/24 18:00:51 rpc.Serve: accept:accept tcp 127.0.0.1:3435: use of closed network connection
[2021-02-24T18:00:51-03:00] INFO [9/10] [visor:shutdown:cli.listener]: Module stopped cleanly. elapsed=53.639µs
[2021-02-24T18:00:51-03:00] INFO [8/10] [visor:shutdown:launcher.proc_manager]: Shutting down module...
[2021-02-24T18:00:51-03:00] INFO [proc_manager]: App stopped successfully. app_name="skysocks"
[2021-02-24T18:00:51-03:00] INFO [8/10] [visor:shutdown:launcher.proc_manager]: Module stopped cleanly. elapsed=1.131427ms
[2021-02-24T18:00:51-03:00] INFO [7/10] [visor:shutdown:router.serve]: Shutting down module...
[2021-02-24T18:00:51-03:00] INFO [router]: Closing all App connections and RouteGroups
[2021-02-24T18:00:51-03:00] INFO [router]: Setup client stopped serving. error="dmsg error 200 - local entity closed"
[2021-02-24T18:00:51-03:00] INFO serveRouteGroup [launcher]: Stopped accepting routes. _=skynet error="accept skynet: use of closed network connection"
[2021-02-24T18:00:51-03:00] INFO [transport_manager]: transport manager is closing.
[2021-02-24T18:00:51-03:00] INFO [transport_manager]: transport manager closed.
[2021-02-24T18:00:51-03:00] WARN [transport_manager]: Failed to accept connection: dmsg error 200 - local entity closed
[2021-02-24T18:00:51-03:00] WARN [transport_manager]: Failed to accept connection: io: read/write on closed pipe
[2021-02-24T18:00:51-03:00] WARN [transport_manager]: Failed to accept connection: io: read/write on closed pipe
[2021-02-24T18:00:51-03:00] INFO [tp:035927]: Stopped serving. remaining_tps=0 remote_pk=0359272a223ca2c988bd30cb91820f53e802f06120a45dc4c7fd91c1fd246f299b tp_id=b8edf314-5c7b-01c6-901c-5914dbf0e190 tp_index=1
[2021-02-24T18:00:51-03:00] WARN [tp:035927]: Failed to read packet. error="read tcp 192.168.123.57:50264->172.104.158.4:35667: use of closed network connection" src="read_loop"
[2021-02-24T18:00:51-03:00] WARN [transport_manager]: Failed to accept connection: io: read/write on closed pipe
[2021-02-24T18:00:53-03:00] ERROR [7/10] [visor:shutdown:router.serve]: Module timed out. elapsed=2.00135025s
[2021-02-24T18:00:53-03:00] INFO [6/10] [visor:shutdown:transport.manager]: Shutting down module...
[2021-02-24T18:00:54-03:00] INFO [tp:035927]: Transport status updated. status="DOWN"
[2021-02-24T18:00:54-03:00] INFO [6/10] [visor:shutdown:transport.manager]: Module stopped cleanly. elapsed=1.024125483s
[2021-02-24T18:00:54-03:00] INFO [router]: Stopped reading packets error="transport is no longer being served"
[2021-02-24T18:00:54-03:00] INFO [5/10] [visor:shutdown:dmsgpty.cli]: Shutting down module...
[2021-02-24T18:00:54-03:00] INFO [dmsgpty:cli-server]: Cleanly stopped serving.
[2021-02-24T18:00:54-03:00] INFO [5/10] [visor:shutdown:dmsgpty.cli]: Module stopped cleanly. elapsed=490.661µs
[2021-02-24T18:00:54-03:00] INFO [4/10] [visor:shutdown:dmsgpty.serve]: Shutting down module...
[2021-02-24T18:00:54-03:00] INFO [snet.dmsgC]: Serve() ended. dmsgpty="host" error=<nil>
[2021-02-24T18:00:54-03:00] INFO [snet.dmsgC]: Cleanly stopped serving. dmsgpty="host" error="dmsg error 200 - local entity closed"
[2021-02-24T18:00:54-03:00] INFO [4/10] [visor:shutdown:dmsgpty.serve]: Module stopped cleanly. elapsed=320.394µs
[2021-02-24T18:00:54-03:00] INFO [3/10] [visor:shutdown:snet.dmsgctrl]: Shutting down module...
[2021-02-24T18:00:54-03:00] INFO [3/10] [visor:shutdown:snet.dmsgctrl]: Module stopped cleanly. elapsed=93.951µs
[2021-02-24T18:00:54-03:00] INFO [2/10] [visor:shutdown:snet]: Shutting down module...
[2021-02-24T18:00:54-03:00] WARN [sudph]: Failed to close connection to visors error="use of closed network connection"
[2021-02-24T18:00:54-03:00] INFO [snet.dmsgC]: Session stopped. error=<nil>
[2021-02-24T18:00:54-03:00] INFO [snet.dmsgC]: Stopped serving client!
[2021-02-24T18:00:54-03:00] INFO [snet.dmsgC]: Session closed. error=<nil>
[2021-02-24T18:00:54-03:00] INFO [snet.dmsgC]: All sessions closed.
[2021-02-24T18:00:54-03:00] WARN [snet.dmsgC]: Stopped accepting streams. error="session shutdown" session=03717576ada5b1744e395c66c2bb11cea73b0e23d0dcd54422139b1a7f12e962c4
[2021-02-24T18:00:54-03:00] ERROR [address-resolver]: Failed to read SUDPH message: use of closed network connection
[2021-02-24T18:00:54-03:00] INFO [2/10] [visor:shutdown:snet]: Module stopped cleanly. elapsed=1.002326ms
[2021-02-24T18:00:54-03:00] WARN [sudph]: failed to accept incoming connection: io: read/write on closed pipe
[2021-02-24T18:00:54-03:00] WARN [sudph]: stopped serving
[2021-02-24T18:00:54-03:00] INFO [1/10] [visor:shutdown:event_broadcaster]: Shutting down module...
[2021-02-24T18:00:54-03:00] INFO [1/10] [visor:shutdown:event_broadcaster]: Module stopped cleanly. elapsed=74.722µs
[2021-02-24T18:00:54-03:00] INFO [visor:shutdown]: Shutdown complete. Goodbye!
[2021-02-24T18:00:54-03:00] INFO []: Stopping