FreeBSD storagenode-updater doesn't work properly

arrogantrabbit · May 27, 2024, 7:48pm

Yes please!

The motivation, at least for FreeBSD users, is to have custom updater working properly, because we gave up on waiting for the official updater to do the right thing. I’ve filed a bug, it was “fixed” and closed and it’s broken anyway.

github.com/storj/storj

storagenode-updater on FreeBSD fails to restart the service

opened 07:01PM - 21 Nov 22 UTC

arrogantrabbit

Bug SNO

**Description** FreeBSD version of the updater successfully updates stroragen…ode binary but fails to restart the rc.d service, as a result the storage node continues running the outdated code **Steps to reproduce the issue:** 1. Setup storage node on FreeBSD, using outdated executable 2. Configure it to run via rc.d scripts. 3. Run updater **Describe the results you expected:** Updater to download new executable and restart the srtorage node service **Describe the results you received:** Updater downloaded new executable but failed to restart the node service. **Possible Fix** On FreeBSD "service" is the utility to manage the rc services. Updater recevies the storage node service name as a command line argument. It shall just call "service storagenode_service_name restart" instead of attempting to find PID and sending messages directly. I see this bug on FreeBSD jain 12 and 13, on TrueNAS, but this is not specific to TrueNAS

Today i’m using a shell script that just downloads the most recent version as soon as it is available and properly manages correct service restart, but of course it’s not ideal, especially if a lot of people do the same.

github.com

arrogantrabbit/freebsd_storj_installer/blob/984c423b8ef5cc8e395334769edb09a7590b1f5c/overlay/usr/local/bin/storagenode-updater

#!/bin/sh

STORAGENODE_UPDATE_INTERVAL_SECONDS=900
STORAGENODE_VERSION_CHECK_URL="https://version.storj.io"
TARGET_BIN_DIR="/usr/local/bin"

: "${storagenode_node_binary_location:="/usr/local/bin/storagenode"}"
: "${storagenode_updater_node_service_name:="storagenode"}"

echo "Starting replacement storagenode updater"

while true; do
    # { "version": "1.59.1", "url": "https://github.com/storj/storj/releases/download/v1.59.1/storagenode_{os}_{arch}.zip" }
    suggested=$(curl -L "${STORAGENODE_VERSION_CHECK_URL}" 2>/dev/null | jq -r '.processes.storagenode.suggested')
    current_version=$(${storagenode_node_binary_location} version 2>/dev/null | sed -n 's/Version: v\(.*\)/\1/p')
    suggested_version=$(echo "$suggested" | jq -r '.version')
    echo "Versions: current=$current_version, suggested=$suggested_version"

    if [ -z "${suggested_version}" ]; then 
        echo "Failed to determine suggested version"

This file has been truncated. show original

With this web api I could make my script a bit more compliant with gradual rollout.

elek · May 28, 2024, 11:23am

Ok, I wouldn’t like to hijack this thread, but it seems to be a simple fix for me:

https://review.dev.storj.io/c/storj/storj/+/13274

I don’t have freebsd, but I can cross compile a binary if you are open to test it…

arrogantrabbit · May 28, 2024, 4:15pm

This looks exactly right!

Lines 42-45 are now invalid — we’ll get there only if service name is empty, at which point it will attempt to kill a process with no name. Those probably shall be deleted.

I’m open to test it.

elek · May 29, 2024, 11:05am

Ups, you are right. But in this case, I wouldn’t like to change the existing behavior. Let’s not break existing setup (if they exist…)

Created an updated version which supports --restart-method service. Can be useful later to adjust Linux restarts as well… (eg. support systemctl restart)

Here is the binary, if you are interested to test: storagenode-updater_freebsd_amd64 | Storj

(built from 930e83b94)

arrogantrabbit · June 1, 2024, 6:22pm

Sorry took a while to test this.

The updater is unable to determine current version:

2024-06-01T11:37:26-07:00	INFO	storagenode-updater/loop.go:18	Downloading versions.	{"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2024-06-01T11:37:26-07:00	INFO	storagenode-updater/update.go:22	Current binary version	{"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.104.5"}
2024-06-01T11:37:26-07:00	INFO	storagenode-updater/update.go:33	Version is up to date	{"Process": "storagenode-updater", "Service": "storagenode"}
2024-06-01T11:37:26-07:00	ERROR	storagenode-updater/loop.go:33	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode-updater", "error": "unable to determine binary version", "errorVerbose": "unable to determine binary version\n\tmain.binaryVersion:40\n\tmain.update:17\n\tmain.loopFunc:31\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:138\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:267"}
main.loopFunc
	/go/src/storj.io/storj/cmd/storagenode-updater/loop.go:33
storj.io/common/sync2.(*Cycle).Run
	/go/pkg/mod/storj.io/common@v0.0.0-20240425113201-9815a85cbc32/sync2/cycle.go:99
main.cmdRun
	/go/src/storj.io/storj/cmd/storagenode-updater/cmd.go:138
storj.io/common/process.cleanup.func1.4
	/go/pkg/mod/storj.io/common@v0.0.0-20240425113201-9815a85cbc32/process/exec_conf.go:393
storj.io/common/process.cleanup.func1
	/go/pkg/mod/storj.io/common@v0.0.0-20240425113201-9815a85cbc32/process/exec_conf.go:411
github.com/spf13/cobra.(*Command).execute
	/go/pkg/mod/github.com/spf13/cobra@v1.8.0/command.go:983
github.com/spf13/cobra.(*Command).ExecuteC
	/go/pkg/mod/github.com/spf13/cobra@v1.8.0/command.go:1115
github.com/spf13/cobra.(*Command).Execute
	/go/pkg/mod/github.com/spf13/cobra@v1.8.0/command.go:1039
storj.io/common/process.ExecWithCustomOptions
	/go/pkg/mod/storj.io/common@v0.0.0-20240425113201-9815a85cbc32/process/exec_conf.go:112
storj.io/common/process.ExecWithCustomConfigAndLogger
	/go/pkg/mod/storj.io/common@v0.0.0-20240425113201-9815a85cbc32/process/exec_conf.go:77
main.main
	/go/src/storj.io/storj/cmd/storagenode-updater/main.go:22
runtime.main
	/usr/local/go/src/runtime/proc.go:267

Executed as:

/usr/local/bin/storagenode-updater run \
    --config-dir "/mnt/storagenode/config" \
    --identity-dir "/mnt/storagenode/identity/storagenode"  \
    --binary-location "/usr/local/bin/storagenode"  \
    --service-name  "storagenode" \
    --restart-method service

Full logs

storagenode_updater.log

root@test-updater:~ # cat /var/log/storagenode_updater.log
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:318	Configuration loaded	{"Process": "storagenode-updater", "Location": "/mnt/storagenode/config/config.yaml"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "contact.external-address"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "server.address"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.wallet"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage2.database-dir"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.wallet-features"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "healthcheck.details"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "console.address"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "healthcheck.enabled"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.email"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage.allocated-bandwidth"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "server.private-address"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage.allocated-disk-space"}
2024-06-01T11:10:06-07:00	INFO	process/exec_conf.go:328	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage.path"}
2024-06-01T11:10:06-07:00	INFO	process/tracing.go:73	Anonymized tracing enabled	{"Process": "storagenode-updater"}
2024-06-01T11:10:06-07:00	DEBUG	tracing collector	monkit-jaeger@v0.0.0-20240221095020-52b0792fa6cd/thrift.go:149	started	{"Process": "storagenode-updater"}
2024-06-01T11:10:06-07:00	DEBUG	process/debug.go:39	debug server listening on 127.0.0.1:54783	{"Process": "storagenode-updater"}
2024-06-01T11:10:06-07:00	INFO	storagenode-updater/cmd.go:119	Running on version	{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v0.0.0"}
2024-06-01T11:10:06-07:00	INFO	storagenode-updater/loop.go:18	Downloading versions.	{"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2024-06-01T11:10:10-07:00	INFO	storagenode-updater/update.go:22	Current binary version	{"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.104.5"}
2024-06-01T11:10:10-07:00	INFO	storagenode-updater/update.go:33	Version is up to date	{"Process": "storagenode-updater", "Service": "storagenode"}
2024-06-01T11:10:10-07:00	ERROR	storagenode-updater/loop.go:33	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode-updater", "error": "unable to determine binary version", "errorVerbose": "unable to determine binary version\n\tmain.binaryVersion:40\n\tmain.update:17\n\tmain.loopFunc:31\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:138\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:267"}
main.loopFunc
	/go/src/storj.io/storj/cmd/storagenode-updater/loop.go:33
storj.io/common/sync2.(*Cycle).Run
	/go/pkg/mod/storj.io/common@v0.0.0-20240425113201-9815a85cbc32/sync2/cycle.go:99
main.cmdRun
	/go/src/storj.io/storj/cmd/storagenode-updater/cmd.go:138
storj.io/common/process.cleanup.func1.4
	/go/pkg/mod/storj.io/common@v0.0.0-20240425113201-9815a85cbc32/process/exec_conf.go:393
storj.io/common/process.cleanup.func1
	/go/pkg/mod/storj.io/common@v0.0.0-20240425113201-9815a85cbc32/process/exec_conf.go:411
github.com/spf13/cobra.(*Command).execute
	/go/pkg/mod/github.com/spf13/cobra@v1.8.0/command.go:983
github.com/spf13/cobra.(*Command).ExecuteC
	/go/pkg/mod/github.com/spf13/cobra@v1.8.0/command.go:1115
github.com/spf13/cobra.(*Command).Execute
	/go/pkg/mod/github.com/spf13/cobra@v1.8.0/command.go:1039
storj.io/common/process.ExecWithCustomOptions
	/go/pkg/mod/storj.io/common@v0.0.0-20240425113201-9815a85cbc32/process/exec_conf.go:112
storj.io/common/process.ExecWithCustomConfigAndLogger
	/go/pkg/mod/storj.io/common@v0.0.0-20240425113201-9815a85cbc32/process/exec_conf.go:77
main.main
	/go/src/storj.io/storj/cmd/storagenode-updater/main.go:22
runtime.main
	/usr/local/go/src/runtime/proc.go:267

rc.d daemon

root@test-updater:~ # cat /usr/local/etc/rc.d/storagenode_updater
#!/bin/sh

# PROVIDE: storagenode_updater
# REQUIRE: LOGIN FILESYSTEMS netwait
# KEYWORD: SHUTDOWN

. /etc/rc.subr

name=storagenode_updater
rcvar=${name}_enable


load_rc_config $name
: "${storagenode_updater_storage_path:="/mnt/storagenode"}"
: "${storagenode_updater_enable:=yes}"
: "${storagenode_updater_executable:="/usr/local/bin/storagenode-updater"}"
: "${storagenode_updater_node_binary_location:="/usr/local/bin/storagenode"}"
: "${storagenode_updater_node_service_name:="storagenode"}"
: "${storagenode_updater_config_dir:="${storagenode_updater_storage_path}/config"}"
: "${storagenode_updater_identity_dir:="${storagenode_updater_storage_path}/identity/storagenode"}"

pidfile="/var/run/${name}.pid"
pidfile_child="/var/run/${name}_child.pid"
command="/usr/sbin/daemon"
command_args="-f -H \
  -o \"/var/log/${name}.log\" \
  -P \"${pidfile}\" \
  -p \"${pidfile_child}\" \
  -u root \
  \"${storagenode_updater_executable}\" run \
    --config-dir \"${storagenode_updater_config_dir}\" \
    --identity-dir \"${storagenode_updater_identity_dir}\" \
    --binary-location \"${storagenode_updater_node_binary_location}\" \
    --service-name \"${storagenode_updater_node_service_name}\" \
    --restart-method service"

run_rc_command "$1"

etc/rc.conf

root@test-updater:~ # cat /etc/rc.conf
cron_flags="$cron_flags -J 15"

# Disable Sendmail by default
sendmail_enable="NO"
sendmail_submit_enable="NO"
sendmail_outbound_enable="NO"
sendmail_msp_queue_enable="NO"

# Run secure syslog
syslogd_flags="-c -ss"

# Enable IPv6
ipv6_activate_all_interfaces="YES"
ifconfig_epair0b="SYNCDHCP"
netwait_ip="1.1.1.1"
storagenode_identity_dir="/mnt/storagenode/identity/storagenode"
storagenode_config_dir="/mnt/storagenode/config"
storagenode_storage_path="/mnt/storagenode"
storagenode_updater_config_dir="/mnt/storagenode/config"
storagenode_updater_identity_dir="/mnt/storagenode/identity/storagenode"
storagenode_enable="YES"
storagenode_updater_enable="YES"
newsyslog_enable="YES"
netwait_enable="YES"

file info

root@test-updater:~ # file /usr/local/bin/storagenode
/usr/local/bin/storagenode: ELF 64-bit LSB executable, x86-64, version 1 (FreeBSD), statically linked, for FreeBSD 12.3, FreeBSD-style, Go BuildID=xDRDdBUz-ti8IopWt5ao/5rWb1BXF4cehNI_Me4Zh/VO3gJB0EUrUtUqkasl2K/UJLOwf_nDvlmL8RkDepC, with debug_info, not stripped

root@test-updater:~ # /usr/local/bin/storagenode version
2024-06-01T11:21:48-07:00	INFO	Anonymized tracing enabled	{"Process": "storagenode"}
Release build
Version: v1.104.5
Build timestamp: 14 May 24 13:20 PDT
Git commit: f3a059560507912f8c471e838826a77b56b459a7

root@test-updater:~ # file /usr/local/bin/storagenode-updater
/usr/local/bin/storagenode-updater: ELF 64-bit LSB executable, x86-64, version 1 (FreeBSD), statically linked, for FreeBSD 12.3, FreeBSD-style, Go BuildID=IlKqOlZj4fKpm3U7ZYrN/q7GXJ5FzeKW05Vg1Rdwd/qjwtc0Dqy2eg1IT670xB/UbCXjc1hcRWvbUhTgFnY, with debug_info, not stripped

root@test-updater:~ # /usr/local/bin/storagenode-updater version
2024-06-01T11:22:08-07:00	INFO	process/tracing.go:73	Anonymized tracing enabled	{"Process": "storagenode-updater"}
Development build
Build timestamp: 29 May 24 03:58 PDT
Git commit: 930e83b946a665b2d1b38978d957706b9a5f21d1

elek · June 3, 2024, 6:57am

Thanks for the testing. I checked the code, and it happens when you use a development build.

Can you please check if the output of the storagenode version contains a version?

It’s missing if you build storagenode from main (or other non-released commit).

I think it’s intentional to keep custom builds instead of overwriting them with the latest version.

arrogantrabbit · June 3, 2024, 2:41pm

Storagenode is release, see the version output in my post above

arrogantrabbit:

root@test-updater:~ # /usr/local/bin/storagenode version
2024-06-01T11:21:48-07:00	INFO	Anonymized tracing enabled	{"Process": "storagenode"}
Release build
Version: v1.104.5
Build timestamp: 14 May 24 13:20 PDT
Git commit: f3a059560507912f8c471e838826a77b56b459a7