As soon as stork-agent is running, stock-server loop-crashes SIGSEGV
name: Bug reportDescribe the bug
I have a fresh install of stork-server 1.10 on a VM (Linux xena 5.15.0-52-generic #58-Ubuntu SMP Thu Oct 13 08:03:55 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux) using the ubuntu apt method as described in the documentation.
On two other similar VMs, I install also from apt the stork-agent and set them up so that they can communicates with the stork-server.
As soon as I start the stork-agent service via systemctl (same on either VMs with the agent), the stork-server crashes (SIGSEGV) and respawns and crashes again in a loop.
As soon as I stop the stork-agent service, the server stops crashing and behaves normal again.
To Reproduce
Steps to reproduce the behavior:
- Install stork-server 1.10 on a x86_64 linux VM. Install stork-agent 1.10 on another similar x86_64 linux VM.
- Sync them (either server or agent API Key method)
- The device with the stork-agent in my network does the following: starting the service
- stork-server does the following: loop-crashes
Expected behavior
The stork-server is not supposed to crash…
Environment:
- Stork: 1.10
- OS: Ubuntu 22.04.1 LTS x86_64
Additional Information
stork-server config: (default beside DB password)
stork-agent config: default, I do not edit it and use this command to sync it with the server sudo -u stork-agent stork-agent register -u http://[SERVER_IPV6]:8080)
stork-server log:
Apr 11 15:45:51 xena stork-server[2917436]: time="2023-04-11 15:45:51" level="warning" msg="problem with version-get and kea daemon d2: unable to forward command to the d2 service: No such file or directory. The server is likely to be offline" file=" appkea.go:210 "
Apr 11 15:45:51 xena stork-server[2917436]: time="2023-04-11 15:45:51" level="warning" msg="problem with config-get and kea daemon d2: unable to forward command to the d2 service: No such file or directory. The server is likely to be offline" file=" appkea.go:262 "
Apr 11 15:45:51 xena stork-server[2917436]: time="2023-04-11 15:45:51" level="info" msg="Event 'added <daemon id=\"13\" name=\"ca\" appId=\"4\" appType=\"kea\"> to <app id=\"4\" name=\"kea@2001:db8:1100:19::1\" type=\"kea\" version=\"2.1.7\">'" file=" eventcenter.go:122 "
Apr 11 15:45:51 xena stork-server[2917436]: time="2023-04-11 15:45:51" level="info" msg="Event 'added <daemon id=\"14\" name=\"d2\" appId=\"4\" appType=\"kea\"> to <app id=\"4\" name=\"kea@2001:db8:1100:19::1\" type=\"kea\" version=\"2.1.7\">'" file=" eventcenter.go:122 "
Apr 11 15:45:51 xena stork-server[2917436]: time="2023-04-11 15:45:51" level="info" msg="Event 'added <daemon id=\"15\" name=\"dhcp4\" appId=\"4\" appType=\"kea\"> to <app id=\"4\" name=\"kea@2001:db8:1100:19::1\" type=\"kea\" version=\"2.1.7\">'" file=" eventcenter.go:122 "
Apr 11 15:45:51 xena stork-server[2917436]: time="2023-04-11 15:45:51" level="info" msg="Event 'added <daemon id=\"16\" name=\"dhcp6\" appId=\"4\" appType=\"kea\"> to <app id=\"4\" name=\"kea@2001:db8:1100:19::1\" type=\"kea\" version=\"2.1.7\">'" file=" eventcenter.go:122 "
Apr 11 15:45:51 xena stork-server[2917436]: time="2023-04-11 15:45:51" level="info" msg="scheduling a new configuration review" file=" dispatcher.go:511 " daemon_id="13" name="ca" triggers="[config change]"
Apr 11 15:45:51 xena stork-server[2917436]: time="2023-04-11 15:45:51" level="info" msg="scheduling a new configuration review" file=" dispatcher.go:511 " daemon_id="15" name="dhcp4" triggers="[config change]"
Apr 11 15:45:51 xena stork-server[2917436]: time="2023-04-11 15:45:51" level="info" msg="scheduling a new configuration review" file=" dispatcher.go:511 " daemon_id="16" name="dhcp6" triggers="[config change]"
Apr 11 15:45:51 xena stork-server[2917436]: panic: runtime error: invalid memory address or nil pointer dereference
Apr 11 15:45:51 xena stork-server[2917436]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x28 pc=0xec3e1d]
Apr 11 15:45:51 xena stork-server[2917436]: goroutine 182 [running]:
Apr 11 15:45:51 xena stork-server[2917436]: isc.org/stork/server/configreview.findOverlaps.func1(0xc000629a70?, 0xc000c5aa50?)
Apr 11 15:45:51 xena stork-server[2917436]: /builds/isc-projects/stork/backend/server/configreview/keachecker.go:598 +0x9d
Apr 11 15:45:51 xena stork-server[2917436]: sort.insertionSort_func({0xc000c5ac48?, 0xc00082ec00?}, 0x0, 0x4)
Apr 11 15:45:51 xena stork-server[2917436]: /builds/isc-projects/stork/tools/golang/go/src/sort/zsortfunc.go:12 +0xb1
Apr 11 15:45:51 xena stork-server[2917436]: sort.pdqsort_func({0xc000c5ac48?, 0xc00082ec00?}, 0xc000629a70?, 0x0?, 0xc000700b3c?)
Apr 11 15:45:51 xena stork-server[2917436]: /builds/isc-projects/stork/tools/golang/go/src/sort/zsortfunc.go:73 +0x345
Apr 11 15:45:51 xena stork-server[2917436]: sort.Slice({0x11f4f40, 0xc000629a70}, 0x4?)
Apr 11 15:45:51 xena stork-server[2917436]: /builds/isc-projects/stork/tools/golang/go/src/sort/slice.go:23 +0x97
Apr 11 15:45:51 xena stork-server[2917436]: isc.org/stork/server/configreview.findOverlaps({0xc000a67ac0, 0x4, 0xc0002ca422?}, 0xa)
Apr 11 15:45:51 xena stork-server[2917436]: /builds/isc-projects/stork/backend/server/configreview/keachecker.go:589 +0xdc
Apr 11 15:45:51 xena stork-server[2917436]: isc.org/stork/server/configreview.subnetsOverlapping(0xc000a4ea80)
Apr 11 15:45:51 xena stork-server[2917436]: /builds/isc-projects/stork/backend/server/configreview/keachecker.go:525 +0x170
Apr 11 15:45:51 xena stork-server[2917436]: isc.org/stork/server/configreview.(*dispatcherImpl).runForDaemon(0xc0004504d0, 0xc0003f70a0, {0xc00060d310, 0x1, 0x1}, {0xc0003a85e0, 0x4, 0x0?}, 0x0)
Apr 11 15:45:51 xena stork-server[2917436]: /builds/isc-projects/stork/backend/server/configreview/dispatcher.go:438 +0x31b
Apr 11 15:45:51 xena stork-server[2917436]: created by isc.org/stork/server/configreview.(*dispatcherImpl).beginReview
Apr 11 15:45:51 xena stork-server[2917436]: /builds/isc-projects/stork/backend/server/configreview/dispatcher.go:535 +0x58a
Apr 11 15:45:51 xena systemd[1]: isc-stork-server.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Apr 11 15:45:51 xena systemd[1]: isc-stork-server.service: Failed with result 'exit-code'.
Apr 11 15:45:51 xena systemd[1]: isc-stork-server.service: Consumed 2.175s CPU time.
Apr 11 15:45:51 xena systemd[1]: isc-stork-server.service: Scheduled restart job, restart counter is at 1.
Apr 11 15:45:51 xena systemd[1]: Stopped ISC Stork Server.
Apr 11 15:45:51 xena systemd[1]: isc-stork-server.service: Consumed 2.175s CPU time.
Apr 11 15:45:51 xena systemd[1]: Started ISC Stork Server.
Apr 11 15:45:51 xena stork-server[2924837]: time="2023-04-11 15:45:51" level="info" msg="Checking connection to database" file=" connection.go:90 "
Apr 11 15:45:51 xena stork-server[2924837]: time="2023-04-11 15:45:51" level="info" msg="Connected to database /var/run/postgresql/.s.PGSQL.5432" file=" connection.go:145 "
Apr 11 15:45:51 xena stork-server[2924837]: time="2023-04-11 15:45:51" level="info" msg="Database is up-to-date" file=" connection.go:174 " version="51"
Apr 11 15:45:51 xena stork-server[2924837]: time="2023-04-11 15:45:51" level="info" msg="Preparing certs, it may take several minutes" file=" certs.go:191 "
Apr 11 15:45:51 xena stork-server[2924837]: time="2023-04-11 15:45:51" level="info" msg="Root CA key and cert OK" file=" certs.go:101 "
Apr 11 15:45:51 xena stork-server[2924837]: time="2023-04-11 15:45:51" level="info" msg="Server key and cert OK" file=" certs.go:180 "
Apr 11 15:45:51 xena stork-server[2924837]: time="2023-04-11 15:45:51" level="info" msg="Started EventCenter" file=" eventcenter.go:48 "
Apr 11 15:45:51 xena stork-server[2924837]: time="2023-04-11 15:45:51" level="info" msg="Starting the configuration review dispatcher" file=" dispatcher.go:869 "
Apr 11 15:45:51 xena stork-server[2924837]: time="2023-04-11 15:45:51" level="info" msg="Starting Apps State puller" file=" periodicexecutor.go:34 "
Apr 11 15:45:51 xena stork-server[2924837]: time="2023-04-11 15:45:51" level="info" msg="Started Apps State puller" file=" periodicexecutor.go:67 "stork-agent log:
-- Logs begin at Tue 2023-04-11 08:30:45 CEST, end at Tue 2023-04-11 15:49:29 CEST. --
Apr 11 15:45:17 radius2 systemd[1]: Started ISC Stork Agent.
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="info" msg="Starting Stork Agent, version 1.10.0, build date 2023-04-04 08:12" file=" main.go:44 "
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="warning" msg="The hook directory: '/var/lib/stork-agent/hooks' doesn't exist" file=" main.go:54 " error="cannot find plugin paths in: /var/lib/stork-agent/hooks: cannot list hook directory: /var/lib/stork-agent/hooks: open /var/lib/stork-agent/hooks: no such file or directory"
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="info" msg="The Basic Auth credentials file (/etc/stork/agent-credentials.json) is missing - HTTP authentication is not used" file=" caclient.go:72 "
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="info" msg="The Basic Auth credentials file (/etc/stork/agent-credentials.json) is missing - HTTP authentication is not used" file=" caclient.go:72 "
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="info" msg="The Basic Auth credentials file (/etc/stork/agent-credentials.json) is missing - HTTP authentication is not used" file=" caclient.go:72 "
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="info" msg="Prometheus Kea Exporter listening on 0.0.0.0:9547, stats pulling interval: 10 seconds" file=" promkeaexporter.go:638 "
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="info" msg="Started app monitor" file=" monitor.go:100 "
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="info" msg="New or updated apps detected:" file=" monitor.go:176 "
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="info" msg=" kea: control: http://127.0.0.1:8000/ (auth key: not found)" file=" monitor.go:188 "
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="warning" msg="Skipped refreshing viewable log files because config-get returned unsuccessful result" file=" kea.go:68 "
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="info" msg="Prometheus BIND 9 Exporter listening on 0.0.0.0:9119, stats pulling interval: 10 seconds" file="prombind9exporter.go:826 "
Apr 11 15:45:17 radius2 stork-agent[23543]: time="2023-04-11 15:45:17" level="info" msg="Started serving Stork Agent" file=" agent.go:445 " address="[::]:8080"
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: v4-allocation-fail" file=" promkeaexporter.go:771 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: v4-allocation-fail-classes" file=" promkeaexporter.go:771 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: v4-allocation-fail-subnet" file=" promkeaexporter.go:771 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: v4-allocation-fail-no-pools" file=" promkeaexporter.go:771 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: v4-allocation-fail-shared-network" file=" promkeaexporter.go:771 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: v6-allocation-fail-no-pools" file=" promkeaexporter.go:771 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: subnet[1].v6-allocation-fail-subnet" file=" promkeaexporter.go:764 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: v6-allocation-fail-shared-network" file=" promkeaexporter.go:771 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: v6-allocation-fail-subnet" file=" promkeaexporter.go:771 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: v6-allocation-fail" file=" promkeaexporter.go:771 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: subnet[1].v6-allocation-fail-no-pools" file=" promkeaexporter.go:764 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: pkt6-confirm-received" file=" promkeaexporter.go:737 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: subnet[1].v6-allocation-fail-classes" file=" promkeaexporter.go:764 "
Apr 11 15:45:27 radius2 stork-agent[23543]: time="2023-04-11 15:45:27" level="warning" msg="Encountered unsupported stat: v6-allocation-fail-classes" file=" promkeaexporter.go:771 "
Apr 11 15:45:51 radius2 stork-agent[23543]: time="2023-04-11 15:45:51" level="info" msg="Loaded server cert: /var/lib/stork-agent/certs/cert.pem and key: /var/lib/stork-agent/certs/key.pem\n" file=" agent.go:104 "
Apr 11 15:45:51 radius2 stork-agent[23543]: time="2023-04-11 15:45:51" level="info" msg="Loaded CA cert: /var/lib/stork-agent/certs/ca.pem\n" file=" agent.go:78 "
Apr 11 15:45:51 radius2 stork-agent[23543]: time="2023-04-11 15:45:51" level="warning" msg="Skipped refreshing viewable log files because config-get returned unsuccessful result" file=" kea.go:68 "
Apr 11 15:46:21 radius2 systemd[1]: Stopping ISC Stork Agent...
Apr 11 15:46:21 radius2 systemd[1]: isc-stork-agent.service: Main process exited, code=killed, status=15/TERM
Apr 11 15:46:21 radius2 systemd[1]: isc-stork-agent.service: Succeeded.
Apr 11 15:46:21 radius2 systemd[1]: Stopped ISC Stork Agent.Thank you for your attention on this matter