search

skycoin / skywire

Skywire Node implementation
72 stars 45 forks source link

0.3.0 will require manual config file reformatting; visors will not start after update #564

Closed 0pcom closed 4 years ago

0pcom commented 4 years ago

With the binary release of 0.3.0 on amd64; I upgraded from 0.2.3 via the skywire package I maintain in the Arch User Repos

[user@linux  ~]$ cat /etc/skywire-visor.json
{
    "version": "v1.0.0",
    "sk": "8fddfb6c56623f7c9969a663c1843c1a6c836c3d5234f9cc37a4c1bd6e420e38",
    "pk": "03d430ef9c93cbe3d8aa9bce1a79305356e00accbc300241b1223c60cbaf823337",
    "dmsg": {
        "discovery": "http://dmsg.discovery.skywire.skycoin.com",
        "sessions_count": 1
    },
    "dmsgpty": {
        "port": 22,
        "authorization_file": "./dmsgpty/whitelist.json",
        "cli_network": "unix",
        "cli_address": "/tmp/dmsgpty.sock"
    },
    "stcp": {
        "pk_table": null,
        "local_address": ":7777"
    },
    "transport": {
        "discovery": "http://transport.discovery.skywire.skycoin.com",
        "address_resolver": "http://address.resolver.skywire.skycoin.com",
        "log_store": {
            "type": "file",
            "location": "./transport_logs"
        },
        "trusted_visors": null
    },
    "routing": {
        "setup_nodes": [
            "0324579f003e6b4048bae2def4365e634d8e0e3054a20fc7af49daf2a179658557"
        ],
        "route_finder": "http://routefinder.skywire.skycoin.com",
        "route_finder_timeout": "10s"
    },
    "uptime_tracker": {
        "addr": "http://uptime-tracker.skywire.skycoin.com"
    },
    "launcher": {
        "discovery": {
            "update_interval": "30s",
            "proxy_discovery_addr": "http://service.discovery.skycoin.com"
        },
        "apps": [
            {
                "name": "skychat",
                "args": [
                    "-addr",
                    ":8001"
                ],
                "auto_start": true,
                "port": 1
            },
            {
                "name": "skysocks",
                "auto_start": true,
                "port": 3
            },
            {
                "name": "skysocks-client",
                "auto_start": false,
                "port": 13
            },
            {
                "name": "vpn-server",
                "auto_start": false,
                "port": 44
            },
            {
                "name": "vpn-client",
                "auto_start": false,
                "port": 43
            }
        ],
        "server_addr": "localhost:5505",
        "bin_path": "./apps",
        "local_path": "./local"
    },
    "hypervisors": [{"public_key": "02a8b7e25512e213dfdbe0bef66dbb0e3642ba65cbdd00e79a052cdff0052272df"}],
    "cli_addr": "localhost:3435",
    "log_level": "info",
    "shutdown_timeout": "10s",
    "restart_check_delay": "1s"
}
[user@linux  ~]$ sudo skywire-visor
[2020-10-19T17:35:47-05:00] INFO []: Starting
[2020-10-19T17:35:47-05:00] DEBUG []: Process info delay=0s parent_systemd=false systemd=false
Version "0.3.0" built on "2020-10-19T15:03:20Z" against commit "dbec529d"
[2020-10-19T17:35:47-05:00] INFO [visor:config]: Reading config from file. filepath="skywire-config.json"
[2020-10-19T17:35:47-05:00] FATAL [visor:config]: Failed to parse config. error="json: cannot unmarshal object into Go struct field V1.hypervisors of type cipher.PubKey"

After investigating this and referring to the readme in this repository, I was able to make it work by reformatting the config file.

This is likely to cause issues with the manual update procedure. I do not see where the config file is edited in the update script, if this happenns at all.

0pcom commented 4 years ago

There is something going on here but my documentation was not correct above. Apologies for my hasty assessment and assumptions; I have no way to tell if the update would function as intended but from my tests I believed there was cause for concern.

This is aside from, but possibly related to, old config file incompatabilities with the new version.

The systemd service is enabled on my linux machine for testing, but upon logging in just now and checking to see that the visor was running on localhost, I discovered it was not.

First, let me fill in more details of my machine and installation

[user@linux  ~]$ uname -a
Linux mainframe 5.8.14-arch1-1 #1 SMP PREEMPT Wed, 07 Oct 2020 23:59:46 +0000 x86_64 GNU/Linux

binaries

[user@linux  ~]$ ls /usr/bin/skywire*
/usr/bin/skywire  /usr/bin/skywire-cli  /usr/bin/skywire-halt  /usr/bin/skywire-hypervisor  /usr/bin/skywire-tls-gen  /usr/bin/skywire-visor
[user@linux  ~]$ ls apps
skychat  skysocks  skysocks-client  vpn-client  vpn-server

binary sha256sums

26a63dc420e8b774c09154ceb8083769c4cbca9db6e834cbfec1cac648946931  /usr/bin/skywire-cli
e5459f966a334795cc049054f29ea251b3d67fbea171246e968c978935df795b  /usr/bin/skywire-hypervisor
9be941120e19e3e1746631dbd4d6597be788ecb003350919ffc4f6103bb4bc80  /usr/bin/skywire-visor
9902c31e9389cb4e75f7b08eac00e29d43fe139400d9be6e4e0a647f809dc9cd  /usr/bin/apps/skychat
4157b0295a3e4038eaca788a039297556d00f0d1d9f1c33871b6131546bf9780  /usr/bin/apps/skysocks
1a0fe79f80ae5c5c44e60432aa42c0eb44b550eb940dc9889a24c5e5aeec4d09  /usr/bin/apps/skysocks-client
5ec28ce04ef26b7ed4b286c41f9eff148dd88ea21ebd5698874e0480b5f3eb63  /usr/bin/apps/vpn-client
1e38cbb37f6432b2169eac1ea6302b996dcd6f5d1872e9fc1b9a6b508d4731c7  /usr/bin/apps/vpn-server

the systemd services

[user@linux  ~]$ cat /usr/lib/systemd/system/skywire*
[Unit]
Description=Skywire Hypervisor
After=network.target

[Service]
Type=simple
User=root
Group=root
ExecStart=/usr/bin/skywire-hypervisor -c /etc/skywire-hypervisor.json
Restart=on-failure
RestartSec=20
TimeoutSec=30

[Install]
WantedBy=multi-user.target
[Unit]
Description=Skywire Visor
After=network.target

[Service]
Type=simple
User=root
Group=root
ExecStart=/usr/bin/skywire-visor /etc/skywire-visor.json
Restart=on-failure
RestartSec=20
TimeoutSec=30

[Install]
WantedBy=multi-user.target

config files

[user@linux  ~]$ cat /etc/skywire-*.json
{
    "public_key": "02a8b7e25512e213dfdbe0bef66dbb0e3642ba65cbdd00e79a052cdff0052272df",
    "secret_key": "295059a2e32ed61279f4e7ccaa43e14e6d6db3659b147574894218523bfbb077",
    "db_path": "/users.db",
    "enable_auth": false,
    "cookies": {
        "hash_key": "bfd6aefc5eb69d2ec2a277d0f64dabec04924ec00f6f93262e0232baf42cbccc3f517195dffdffc2f7e3984397eecdfbc40c6d3d7f4d8f505e071de2c3aeaa6d",
        "block_key": "60a2905954ef6a1c109ca4c6de77499787609bed33f35cff68d50d49b41d472f",
        "expires_duration": 43200000000000,
        "path": "/",
        "domain": ""
    },
    "dmsg_discovery": "http://dmsg.discovery.skywire.skycoin.com",
    "dmsg_port": 46,
    "http_addr": ":8000",
    "enable_tls": true,
    "tls_cert_file": "/usr/lib/skycoin/skywire/ssl/cert.pem",
    "tls_key_file": "/usr/lib/skycoin/skywire/ssl/key.pem"
}{
    "version": "v1.0.0",
    "sk": "8fddfb6c56623f7c9969a663c1843c1a6c836c3d5234f9cc37a4c1bd6e420e38",
    "pk": "03d430ef9c93cbe3d8aa9bce1a79305356e00accbc300241b1223c60cbaf823337",
    "dmsg": {
        "discovery": "http://dmsg.discovery.skywire.skycoin.com",
        "sessions_count": 1
    },
    "dmsgpty": {
        "port": 22,
        "authorization_file": "./dmsgpty/whitelist.json",
        "cli_network": "unix",
        "cli_address": "/tmp/dmsgpty.sock"
    },
    "stcp": {
        "pk_table": null,
        "local_address": ":7777"
    },
    "transport": {
        "discovery": "http://transport.discovery.skywire.skycoin.com",
        "address_resolver": "http://address.resolver.skywire.skycoin.com",
        "log_store": {
            "type": "file",
            "location": "./transport_logs"
        },
        "trusted_visors": null
    },
    "routing": {
        "setup_nodes": [
            "0324579f003e6b4048bae2def4365e634d8e0e3054a20fc7af49daf2a179658557"
        ],
        "route_finder": "http://routefinder.skywire.skycoin.com",
        "route_finder_timeout": "10s"
    },
    "uptime_tracker": {
        "addr": "http://uptime-tracker.skywire.skycoin.com"
    },
    "launcher": {
        "discovery": {
            "update_interval": "30s",
            "proxy_discovery_addr": "http://service.discovery.skycoin.com"
        },
        "apps": [
            {
                "name": "skychat",
                "args": [
                    "-addr",
                    ":8001"
                ],
                "auto_start": true,
                "port": 1
            },
            {
                "name": "skysocks",
                "auto_start": true,
                "port": 3
            },
            {
                "name": "skysocks-client",
                "auto_start": false,
                "port": 13
            },
            {
                "name": "vpn-server",
                "auto_start": false,
                "port": 44
            },
            {
                "name": "vpn-client",
                "auto_start": false,
                "port": 43
            }
        ],
        "server_addr": "localhost:5505",
        "bin_path": "./apps",
        "local_path": "./local"
    },
    "hypervisors": [{"public_key": "02a8b7e25512e213dfdbe0bef66dbb0e3642ba65cbdd00e79a052cdff0052272df"}],
    "cli_addr": "localhost:3435",
    "log_level": "info",
    "shutdown_timeout": "10s",
    "restart_check_delay": "1s"
}

checking the visor service

[user@linux  ~]$ systemctl status skywire-visor.service
● skywire-visor.service - Skywire Visor
     Loaded: loaded (/usr/lib/systemd/system/skywire-visor.service; enabled; ve>
     Active: activating (auto-restart) (Result: exit-code) since Tue 2020-10-20>
    Process: 4156 ExecStart=/usr/bin/skywire-visor /etc/skywire-visor.json (cod>
   Main PID: 4156 (code=exited, status=1/FAILURE)
lines 1-5/5 (END)...skipping...
● skywire-visor.service - Skywire Visor
     Loaded: loaded (/usr/lib/systemd/system/skywire-visor.service; enabled; vendor preset: disabled)
     Active: activating (auto-restart) (Result: exit-code) since Tue 2020-10-20 15:56:47 CDT; 2s ago
    Process: 4156 ExecStart=/usr/bin/skywire-visor /etc/skywire-visor.json (code=exited, status=1/FAILURE)
   Main PID: 4156 (code=exited, status=1/FAILURE)

manually starting the visor against the above config file

[user@linux  ~]$ sudo skywire-visor /etc/skywire-visor.json
[2020-10-20T16:25:51-05:00] INFO []: Starting
[2020-10-20T16:25:51-05:00] DEBUG []: Process info delay=0s parent_systemd=false systemd=false
Version "0.3.0" built on "2020-10-19T15:03:20Z" against commit "dbec529d"
[2020-10-20T16:25:51-05:00] INFO [visor:config]: Reading config from file. filepath="/etc/skywire-visor.json"
[2020-10-20T16:25:51-05:00] FATAL [visor:config]: Failed to parse config. error="json: cannot unmarshal object into Go struct field V1.hypervisors of type cipher.PubKey"

The above is failing at the hypervisor key, I believe.

trying for a fresh config

[user@linux  ~]$ sudo skywire-cli visor gen-config -ro /etc/skywire-visor.json
[2020-10-20T16:38:34-05:00] INFO [visor:config]: Flushing config to file. config_version="v1.0.0" filepath="/etc/skywire-visor.json"
[2020-10-20T16:38:34-05:00] INFO [skywire-cli]: Updated file '/etc/skywire-visor.json' to: {
    "version": "v1.0.0",
    "sk": "a3a8468a41fd73585cb96d494efbf40ba9150a9748b4daea05681eb5d0a8ca5e",
    "pk": "03537a419f6e4584bd05a25a416e8b0c5069a05b3c2b932188cd6cf8e862bc895c",
    "dmsg": {
        "discovery": "http://dmsg.discovery.skywire.skycoin.com",
        "sessions_count": 1
    },
    "dmsgpty": {
        "port": 22,
        "authorization_file": "./dmsgpty/whitelist.json",
        "cli_network": "unix",
        "cli_address": "/tmp/dmsgpty.sock"
    },
    "stcp": {
        "pk_table": null,
        "local_address": ":7777"
    },
    "transport": {
        "discovery": "http://transport.discovery.skywire.skycoin.com",
        "address_resolver": "http://address.resolver.skywire.skycoin.com",
        "log_store": {
            "type": "file",
            "location": "./transport_logs"
        },
        "trusted_visors": null
    },
    "routing": {
        "setup_nodes": [
            "0324579f003e6b4048bae2def4365e634d8e0e3054a20fc7af49daf2a179658557"
        ],
        "route_finder": "http://routefinder.skywire.skycoin.com",
        "route_finder_timeout": "10s"
    },
    "uptime_tracker": {
        "addr": "http://uptime-tracker.skywire.skycoin.com"
    },
    "launcher": {
        "discovery": {
            "update_interval": "30s",
            "proxy_discovery_addr": "http://service.discovery.skycoin.com"
        },
        "apps": [
            {
                "name": "skychat",
                "args": [
                    "-addr",
                    ":8001"
                ],
                "auto_start": true,
                "port": 1
            },
            {
                "name": "skysocks",
                "auto_start": true,
                "port": 3
            },
            {
                "name": "skysocks-client",
                "auto_start": false,
                "port": 13
            },
            {
                "name": "vpn-server",
                "auto_start": false,
                "port": 44
            },
            {
                "name": "vpn-client",
                "auto_start": false,
                "port": 43
            }
        ],
        "server_addr": "localhost:5505",
        "bin_path": "./apps",
        "local_path": "./local"
    },
    "hypervisors": [],
    "cli_addr": "localhost:3435",
    "log_level": "info",
    "shutdown_timeout": "10s",
    "restart_check_delay": "1s"
}
[user@linux  ~]$ sudo skywire-visor /etc/skywire-visor.json
[2020-10-20T16:39:16-05:00] INFO []: Starting
[2020-10-20T16:39:16-05:00] DEBUG []: Process info delay=0s parent_systemd=false systemd=false
Version "0.3.0" built on "2020-10-19T15:03:20Z" against commit "dbec529d"
[2020-10-20T16:39:16-05:00] INFO [visor:config]: Reading config from file. filepath="/etc/skywire-visor.json"
[2020-10-20T16:39:16-05:00] INFO [visor:config]: Flushing config to file. config_version="v1.0.0" filepath="/etc/skywire-visor.json"
[2020-10-20T16:39:16-05:00] INFO [visor:startup]: Begin startup. public_key=03537a419f6e4584bd05a25a416e8b0c5069a05b3c2b932188cd6cf8e862bc895c
[2020-10-20T16:39:16-05:00] INFO [1/13] [visor:startup:updater]: Starting module...
[2020-10-20T16:39:16-05:00] INFO [1/13] [visor:startup:updater]: Module started successfully. elapsed=19.175µs
[2020-10-20T16:39:16-05:00] INFO [2/13] [visor:startup:eventbroadcaster]: Starting module...
[2020-10-20T16:39:16-05:00] INFO [2/13] [visor:startup:eventbroadcaster]: Module started successfully. elapsed=22.893µs
[2020-10-20T16:39:16-05:00] INFO [3/13] [visor:startup:addressresolver]: Starting module...
[2020-10-20T16:39:16-05:00] INFO [address-resolver]: Remote UDP server: "address.resolver.skywire.skycoin.com:30178"
[2020-10-20T16:39:16-05:00] INFO [3/13] [visor:startup:addressresolver]: Module started successfully. elapsed=54.435µs
[2020-10-20T16:39:16-05:00] INFO [4/13] [visor:startup:discovery]: Starting module...
[2020-10-20T16:39:16-05:00] INFO [4/13] [visor:startup:discovery]: Module started successfully. elapsed=31.045µs
[2020-10-20T16:39:16-05:00] INFO [5/13] [visor:startup:snet]: Starting module...
[2020-10-20T16:39:16-05:00] INFO [snet.dmsgC]: Discovering dmsg servers...
[2020-10-20T16:39:16-05:00] INFO [snet.dmsgC]: Connecting to the dmsg network... timeout=20s
[2020-10-20T16:39:16-05:00] INFO [address-resolver]: BindSUDPR: Address resolver is not ready yet, waiting...
[2020-10-20T16:39:16-05:00] INFO [stcp]: listening on addr: [::]:7777
[2020-10-20T16:39:16-05:00] INFO [address-resolver]: BindSTCPR: Address resolver is not ready yet, waiting...
[2020-10-20T16:39:17-05:00] INFO [snet.dmsgC]: Dialing session... remote_pk=03d5b55d1133b26485c664cf8b95cff6746d1e321c34e48c9fed293eff0d6d49e5
[2020-10-20T16:39:17-05:00] INFO [address-resolver]: Connected to address resolver. STCPR/SUDPH services are available.
[2020-10-20T16:39:17-05:00] INFO [address-resolver]: BindSUDPR: Address resolver became ready, binding
[2020-10-20T16:39:17-05:00] INFO [address-resolver]: BindSTCPR: Address resolver became ready, binding
[2020-10-20T16:39:17-05:00] INFO [address-resolver]: SUDPH Local port: 43751
[2020-10-20T16:39:17-05:00] INFO [address-resolver]: Performing handshake with 172.104.161.112:30178
[2020-10-20T16:39:18-05:00] INFO [stcpr]: listening on addr: [::]:37039
[2020-10-20T16:39:19-05:00] INFO [snet.dmsgC]: Connected to the dmsg network. timeout=20s
[2020-10-20T16:39:19-05:00] INFO [5/13] [visor:startup:snet]: Module started successfully. elapsed=3.104548251s
[2020-10-20T16:39:19-05:00] INFO [6/13] [visor:startup:dmsgpty]: Starting module...
[2020-10-20T16:39:19-05:00] INFO [snet.dmsgC]: Serving session. remote_pk=03d5b55d1133b26485c664cf8b95cff6746d1e321c34e48c9fed293eff0d6d49e5
[2020-10-20T16:39:19-05:00] INFO [6/13] [visor:startup:dmsgpty]: Module started successfully. elapsed=3.558627ms
[2020-10-20T16:39:19-05:00] INFO [7/13] [visor:startup:transport]: Starting module...
[2020-10-20T16:39:20-05:00] INFO [7/13] [visor:startup:transport]: Module started successfully. elapsed=1.530137677s
[2020-10-20T16:39:20-05:00] INFO [8/13] [visor:startup:router]: Starting module...
[2020-10-20T16:39:20-05:00] INFO [transport_manager]: listening on network: stcp
[2020-10-20T16:39:20-05:00] INFO [transport_manager]: listening on network: stcpr
[2020-10-20T16:39:20-05:00] INFO [router]: Starting router
[2020-10-20T16:39:20-05:00] INFO [8/13] [visor:startup:router]: Module started successfully. elapsed=286.839µs
[2020-10-20T16:39:20-05:00] INFO [9/13] [visor:startup:launcher]: Starting module...
[2020-10-20T16:39:20-05:00] INFO [transport_manager]: listening on network: sudph
[2020-10-20T16:39:20-05:00] INFO [transport_manager]: listening on network: dmsg
[2020-10-20T16:39:20-05:00] INFO [9/13] [visor:startup:launcher]: Module started successfully. elapsed=8.442571ms
[2020-10-20T16:39:20-05:00] INFO [10/13] [visor:startup:cli]: Starting module...
[2020-10-20T16:39:20-05:00] INFO [10/13] [visor:startup:cli]: Module started successfully. elapsed=318.856µs
[2020-10-20T16:39:20-05:00] INFO [11/13] [visor:startup:hypervisors]: Starting module...
[2020-10-20T16:39:20-05:00] INFO [11/13] [visor:startup:hypervisors]: Module started successfully. elapsed=14.784µs
[2020-10-20T16:39:20-05:00] INFO [12/13] [visor:startup:uptimetracker]: Starting module...
[2020-10-20T16:39:20-05:00] INFO [proc_manager]: Accepted proc conn. hello="{"proc_key":"e070a5b2bc7d45d896d4dbc8294bcf7d"}" remote=127.0.0.1:53074
[2020-10-20T16:39:20.890441305-05:00] INFO (STDOUT) [proc:skychat:e070a5b2bc7d45d896d4dbc8294bcf7d]: Version "0.3.0" built on "2020-10-19T15:03:20Z" against commit "dbec529d"
[2020-10-20T16:39:20-05:00] INFO [proc:skychat:e070a5b2bc7d45d896d4dbc8294bcf7d]: Associated and serving proc conn.
[2020-10-20T16:39:20-05:00] INFO [proc:skychat:e070a5b2bc7d45d896d4dbc8294bcf7d]: Request processed. _elapsed="2.141975ms" _method="Listen" _received="4:39PM" input=03537a419f6e4584bd05a25a416e8b0c5069a05b3c2b932188cd6cf8e862bc895c:1 output=0xc00046a13e
[2020-10-20T16:39:20.893218543-05:00] INFO (STDERR) [proc:skysocks:ffa5a73ba5e947388459e4cec293199c]: time="2020-10-20T16:39:20-05:00" level=info msg="Version \"0.3.0\" built on \"2020-10-19T15:03:20Z\" against commit \"dbec529d\""
[2020-10-20T16:39:20-05:00] INFO [proc_manager]: Accepted proc conn. hello="{"proc_key":"ffa5a73ba5e947388459e4cec293199c"}" remote=127.0.0.1:53078
[2020-10-20T16:39:20-05:00] INFO [proc:skysocks:ffa5a73ba5e947388459e4cec293199c]: Associated and serving proc conn.
[2020-10-20T16:39:20.890463165-05:00] INFO (STDERR) [proc:skychat:e070a5b2bc7d45d896d4dbc8294bcf7d]: time="2020-10-20T16:39:20-05:00" level=info msg="Successfully started skychat."
[2020-10-20T16:39:20.894455621-05:00] INFO (STDERR) [proc:skychat:e070a5b2bc7d45d896d4dbc8294bcf7d]: time="2020-10-20T16:39:20-05:00" level=info msg="Serving HTTP on :8001"
[2020-10-20T16:39:20.895593036-05:00] INFO (STDERR) [proc:skychat:e070a5b2bc7d45d896d4dbc8294bcf7d]: time="2020-10-20T16:39:20-05:00" level=info msg="Accepting skychat conn..."
[2020-10-20T16:39:20-05:00] INFO [proc:skysocks:ffa5a73ba5e947388459e4cec293199c]: Request processed. _elapsed="3.81201ms" _method="Listen" _received="4:39PM" input=03537a419f6e4584bd05a25a416e8b0c5069a05b3c2b932188cd6cf8e862bc895c:3 output=0xc00016bd1e
[2020-10-20T16:39:20.898183103-05:00] INFO (STDERR) [proc:skychat:e070a5b2bc7d45d896d4dbc8294bcf7d]: time="2020-10-20T16:39:20-05:00" level=info msg="Calling app RPC Accept"
[2020-10-20T16:39:20.898582129-05:00] INFO (STDERR) [proc:skysocks:ffa5a73ba5e947388459e4cec293199c]: time="2020-10-20T16:39:20-05:00" level=info msg="Starting serving proxy server"
[2020-10-20T16:39:20.902227558-05:00] INFO (STDERR) [proc:skysocks:ffa5a73ba5e947388459e4cec293199c]: time="2020-10-20T16:39:20-05:00" level=info msg="Calling app RPC Accept"
[2020-10-20T16:39:21-05:00] WARN [transport]: No transports found for local visor: 404 Not Found: {"error":"transport not found"}
[2020-10-20T16:39:21-05:00] INFO [transport_manager]: transport manager is serving.
^C
[user@linux  ~]$

So you can see why I would think that it wouldn't work for others. Perhaps this only affects x86_64?