search

yyyar / gobetween

:cloud: Modern & minimalistic load balancer for the Сloud era
http://gobetween.io
Other
1.91k stars 210 forks source link

Prometheus metrics listener crashes randomly at startup #332

Open jjzazuet opened 1 year ago

jjzazuet commented 1 year ago

What's the problem?

Running gobetween under OpenWRT x64 starts the process normally most of the time, but on some occasions, the following stack trace can be seen when Prometheus metrics are enabled (via json config in this example):

"metrics": {
  "enabled": true,
  "bind": "0.0.0.0:9284"
},

Faulty startup sequence:

Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]: 2022/12/26 12:16:15 gobetween v0.8.0
Mon Dec 26 12:16:15 2022 daemon.info gobetween[42675]: 2022-12-26 12:16:15 [INFO ] (manager): Initializing...
Mon Dec 26 12:16:15 2022 daemon.info gobetween[42675]: 2022-12-26 12:16:15 [INFO ] (server): Creating 'REDACTED': 0.0.0.0:22 weight static ping
Mon Dec 26 12:16:15 2022 daemon.info gobetween[42675]: 2022-12-26 12:16:15 [INFO ] (scheduler): Starting scheduler REDACTED
Mon Dec 26 12:16:15 2022 daemon.info gobetween[42675]: 2022-12-26 12:16:15 [INFO ] (server): Creating 'REDACTED': 0.0.0.0:6443 weight static ping
Mon Dec 26 12:16:15 2022 daemon.info gobetween[42675]: 2022-12-26 12:16:15 [INFO ] (scheduler): Starting scheduler REDACTED
Mon Dec 26 12:16:15 2022 daemon.info gobetween[42675]: 2022-12-26 12:16:15 [INFO ] (server): Creating 'REDACTED': 0.0.0.0:6448 weight static ping
Mon Dec 26 12:16:15 2022 daemon.info gobetween[42675]: 2022-12-26 12:16:15 [INFO ] (scheduler): Starting scheduler REDACTED
Mon Dec 26 12:16:15 2022 daemon.info gobetween[42675]: 2022-12-26 12:16:15 [INFO ] (server): Creating 'REDACTED': 0.0.0.0:443 weight static ping
Mon Dec 26 12:16:15 2022 daemon.info gobetween[42675]: 2022-12-26 12:16:15 [INFO ] (healthcheck/worker): Sending to scheduler: {{REDACTED 6443} false}
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]: panic: runtime error: invalid memory address or nil pointer dereference
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0xcf95c6]
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]:
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]: goroutine 80 [running]:
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]: github.com/prometheus/client_golang/prometheus.(*GaugeVec).GetMetricWithLabelValues(...)
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]:   /home/yyyar/go/pkg/mod/github.com/prometheus/client_golang@v1.7.1/prometheus/gauge.go:183
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]: github.com/prometheus/client_golang/prometheus.(*GaugeVec).WithLabelValues(0x0, 0xc0005ae2a0, 0x3, 0x3, 0xc0006a2040, 0xc00062e0d0)
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]:   /home/yyyar/go/pkg/mod/github.com/prometheus/client_golang@v1.7.1/prometheus/gauge.go:215 +0x26
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]: github.com/yyyar/gobetween/metrics.ReportHandleBackendLiveChange(0xc0006a2040, 0x10, 0xc000036210, 0x1d, 0xc00003622e, 0x4, 0x0)
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]:   /home/yyyar/workspace/gobetween/src/metrics/metrics.go:236 +0xc2
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]: github.com/yyyar/gobetween/server/scheduler.(*Scheduler).HandleBackendLiveChange(0xc0000f2bf0, 0xc000036210, 0x1d, 0xc00003622e, 0x4, 0x0)
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]:   /home/yyyar/workspace/gobetween/src/server/scheduler/scheduler.go:224 +0x17e
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]: github.com/yyyar/gobetween/server/scheduler.(*Scheduler).Start.func1(0xc0000f2bf0, 0xc0002d21e0, 0xc00010c540)
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]:   /home/yyyar/workspace/gobetween/src/server/scheduler/scheduler.go:129 +0x66c
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]: created by github.com/yyyar/gobetween/server/scheduler.(*Scheduler).Start
Mon Dec 26 12:16:15 2022 daemon.err gobetween[42675]:   /home/yyyar/workspace/gobetween/src/server/scheduler/scheduler.go:113 +0x21c

Correct startup sequence:

Mon Dec 26 12:16:52 2022 daemon.err gobetween[42784]: 2022/12/26 12:16:52 gobetween v0.8.0
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (manager): Initializing...
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (server): Creating 'REDACTED': 0.0.0.0:443 weight static ping
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (scheduler): Starting scheduler REDACTED
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (server): Creating 'REDACTED': 0.0.0.0:22 weight static ping
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (scheduler): Starting scheduler REDACTED
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (server): Creating 'REDACTED': 0.0.0.0:6443 weight static ping
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (scheduler): Starting scheduler REDACTED
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (server): Creating 'REDACTED': 0.0.0.0:6448 weight static ping
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (scheduler): Starting scheduler REDACTED
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (manager): Initialized
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (metrics): Starting up Metrics server 0.0.0.0:9284
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (api): Starting up API
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (api): Starting HTTP server 0.0.0.0:8888
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (healthcheck/worker): Sending to scheduler: {{REDACTED 6443} false}
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (healthcheck/worker): Sending to scheduler: {{REDACTED 6443} false}
Mon Dec 26 12:16:52 2022 daemon.info gobetween[42784]: 2022-12-26 12:16:52 [INFO ] (healthcheck/worker): Sending to scheduler: {{REDACTED 6443} false}

System info

root@REDACTED:~# uname -a
Linux us-east-00-router-01 5.10.146 #0 SMP Fri Oct 14 22:44:41 2022 x86_64 GNU/Linux
root@REDACTED:~# cat /etc/openwrt_release 
DISTRIB_ID='OpenWrt'
DISTRIB_RELEASE='22.03.2'
DISTRIB_REVISION='r19803-9a599fee93'
DISTRIB_TARGET='x86/64'
DISTRIB_ARCH='x86_64'
DISTRIB_DESCRIPTION='OpenWrt 22.03.2 r19803-9a599fee93'

Let me know if I missed anything.

Thanks.