Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Prometheus metrics listener crashes randomly at startup #332

Open
jjzazuet opened this issue Dec 27, 2022 · 1 comment
Open

Prometheus metrics listener crashes randomly at startup #332

jjzazuet opened this issue Dec 27, 2022 · 1 comment

Comments

@jjzazuet
Copy link

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/[email protected]/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/[email protected]/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.
@GeertJohan
Copy link

GeertJohan commented Nov 25, 2024 •
edited
Loading

I just got this as well on Linux on amd64 arch.

2024-11-25 13:13:32 [INFO ] (healthcheck/worker): Sending to scheduler: {my-node-name-redacted 6443} false}
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0xcf95c6]

goroutine 28 [running]:
github.com/prometheus/client_golang/prometheus.(*GaugeVec).GetMetricWithLabelValues(...)
	/home/yyyar/go/pkg/mod/github.com/prometheus/[email protected]/prometheus/gauge.go:183
github.com/prometheus/client_golang/prometheus.(*GaugeVec).WithLabelValues(0x0, 0xc0002d2720, 0x3, 0x3, 0xc0002da100, 0xc00068e270)
	/home/yyyar/go/pkg/mod/github.com/prometheus/[email protected]/prometheus/gauge.go:215 +0x26
github.com/yyyar/gobetween/metrics.ReportHandleBackendLiveChange(0xc0002da100, 0x19, 0xc000396800, 0x26, 0xc000396827, 0x4, 0x0)
	/home/yyyar/workspace/gobetween/src/metrics/metrics.go:236 +0xc2
github.com/yyyar/gobetween/server/scheduler.(*Scheduler).HandleBackendLiveChange(0xc000398d30, 0xc000396800, 0x26, 0xc000396827, 0x4, 0x0)
	/home/yyyar/workspace/gobetween/src/server/scheduler/scheduler.go:224 +0x17e
github.com/yyyar/gobetween/server/scheduler.(*Scheduler).Start.func1(0xc000398d30, 0xc0004600a0, 0xc0003a13b0)
	/home/yyyar/workspace/gobetween/src/server/scheduler/scheduler.go:129 +0x66c
created by github.com/yyyar/gobetween/server/scheduler.(*Scheduler).Start
	/home/yyyar/workspace/gobetween/src/server/scheduler/scheduler.go:113 +0x21c
	```
	
I suspect a race condition.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@GeertJohan @jjzazuet