search

dennisstritzke / ipsec_exporter

Prometheus exporter for IPsec metrics.
MIT License
51 stars 39 forks source link

ipsec_exporter crashes now and then #2

Closed czunker closed 6 years ago

czunker commented 6 years ago

From time to time ipsec_exporter crashed with this stacktrace:

May 09 15:08:42 vpnserver ipsec_exporter[32398]: fatal error: concurrent map read and map write
May 09 15:08:42 vpnserver ipsec_exporter[32398]: goroutine 25 [running]:
May 09 15:08:42 vpnserver ipsec_exporter[32398]: runtime.throw(0x837534, 0x21)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/runtime/panic.go:616 +0x81 fp=0xc420049b28 sp=0xc420049b08 pc=0x429151
May 09 15:08:42 vpnserver ipsec_exporter[32398]: runtime.mapaccess1_faststr(0x7b5420, 0xc42006b620, 0xc420117fda, 0x17, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/runtime/hashmap_fast.go:181 +0x421 fp=0xc420049b98 sp=0xc420049b28 pc=0x409f61
May 09 15:08:42 vpnserver ipsec_exporter[32398]: github.com/dennisstritzke/ipsec_exporter/ipsecexporter.IpSecStatus.PrometheusMetrics(0xc42006b620, 0xc42006b620, 0xc420022000)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /Users/STRITD/golang/src/github.com/dennisstritzke/ipsec_exporter/ipsecexporter/ipsec.go:59 +0x11f fp=0xc420049ca8 sp=0xc420049b98 pc=0x74d46f
May 09 15:08:42 vpnserver ipsec_exporter[32398]: github.com/dennisstritzke/ipsec_exporter/ipsecexporter.prometheusMetrics(0x87bfe0, 0xc4203ac000, 0xc42037c300)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /Users/STRITD/golang/src/github.com/dennisstritzke/ipsec_exporter/ipsecexporter/serve.go:40 +0x3b fp=0xc420049cf0 sp=0xc420049ca8 pc=0x74de7b
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.HandlerFunc.ServeHTTP(0x847fa0, 0x87bfe0, 0xc4203ac000, 0xc42037c300)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:1947 +0x44 fp=0xc420049d18 sp=0xc420049cf0 pc=0x7255f4
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.(*ServeMux).ServeHTTP(0xa8ac60, 0x87bfe0, 0xc4203ac000, 0xc42037c300)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:2337 +0x130 fp=0xc420049d58 sp=0xc420049d18 pc=0x727260
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.serverHandler.ServeHTTP(0xc42006cb60, 0x87bfe0, 0xc4203ac000, 0xc42037c300)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:2694 +0xbc fp=0xc420049d88 sp=0xc420049d58 pc=0x72829c
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.(*conn).serve(0xc4202a57c0, 0x87c460, 0xc42005a840)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:1830 +0x651 fp=0xc420049fc8 sp=0xc420049d88 pc=0x724611
May 09 15:08:42 vpnserver ipsec_exporter[32398]: runtime.goexit()
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/runtime/asm_amd64.s:2361 +0x1 fp=0xc420049fd0 sp=0xc420049fc8 pc=0x454c61
May 09 15:08:42 vpnserver ipsec_exporter[32398]: created by net/http.(*Server).Serve
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:2795 +0x27b
May 09 15:08:42 vpnserver ipsec_exporter[32398]: goroutine 1 [IO wait, 224 minutes]:
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.runtime_pollWait(0x7ff37d0bbf00, 0x72, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/runtime/netpoll.go:173 +0x57
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.(*pollDesc).wait(0xc42043c018, 0x72, 0xc42005a000, 0x0, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/internal/poll/fd_poll_runtime.go:85 +0x9b
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.(*pollDesc).waitRead(0xc42043c018, 0xffffffffffffff00, 0x0, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/internal/poll/fd_poll_runtime.go:90 +0x3d
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.(*FD).Accept(0xc42043c000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/internal/poll/fd_unix.go:372 +0x1a8
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net.(*netFD).accept(0xc42043c000, 0xc4200b6080, 0xc4201bfa70, 0x4021c8)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/fd_unix.go:238 +0x42
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net.(*TCPListener).accept(0xc42000c110, 0xc4201bfaa0, 0x401127, 0xc4200b6080)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/tcpsock_posix.go:136 +0x2e
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net.(*TCPListener).AcceptTCP(0xc42000c110, 0xc4201bfae8, 0xc4201bfaf0, 0x18)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/tcpsock.go:246 +0x49
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.tcpKeepAliveListener.Accept(0xc42000c110, 0x848550, 0xc4200b6000, 0x87c520, 0xc42006ba70)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:3216 +0x2f
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.(*Server).Serve(0xc42006cb60, 0x87c2e0, 0xc42000c110, 0x0, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:2770 +0x1a5
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.(*Server).ListenAndServe(0xc42006cb60, 0xc42006cb60, 0x5)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:2711 +0xa9
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.ListenAndServe(0xc42001e770, 0x5, 0x0, 0x0, 0x4, 0xc42001e770)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:2969 +0x7a
May 09 15:08:42 vpnserver ipsec_exporter[32398]: github.com/dennisstritzke/ipsec_exporter/ipsecexporter.Serve()
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /Users/STRITD/golang/src/github.com/dennisstritzke/ipsec_exporter/ipsecexporter/serve.go:29 +0x202
May 09 15:08:42 vpnserver ipsec_exporter[32398]: github.com/dennisstritzke/ipsec_exporter/cmd.defaultCommand(0xa857e0, 0xaa88d0, 0x0, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /Users/STRITD/golang/src/github.com/dennisstritzke/ipsec_exporter/cmd/root.go:40 +0x20
May 09 15:08:42 vpnserver ipsec_exporter[32398]: github.com/dennisstritzke/ipsec_exporter/vendor/github.com/spf13/cobra.(*Command).execute(0xa857e0, 0xc42001c1c0, 0x0, 0x0, 0xa857e0, 0xc42001c1c0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /Users/STRITD/golang/src/github.com/dennisstritzke/ipsec_exporter/vendor/github.com/spf13/cobra/command.go:760 +0x2c1
May 09 15:08:42 vpnserver ipsec_exporter[32398]: github.com/dennisstritzke/ipsec_exporter/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0xa857e0, 0x23, 0xc420049f58, 0x74e127)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /Users/STRITD/golang/src/github.com/dennisstritzke/ipsec_exporter/vendor/github.com/spf13/cobra/command.go:846 +0x30a
May 09 15:08:42 vpnserver ipsec_exporter[32398]: github.com/dennisstritzke/ipsec_exporter/vendor/github.com/spf13/cobra.(*Command).Execute(0xa857e0, 0xc420068058, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /Users/STRITD/golang/src/github.com/dennisstritzke/ipsec_exporter/vendor/github.com/spf13/cobra/command.go:794 +0x2b
May 09 15:08:42 vpnserver ipsec_exporter[32398]: github.com/dennisstritzke/ipsec_exporter/cmd.Execute()
...skipping...
May 09 15:08:42 vpnserver ipsec_exporter[32398]: os/exec.(*Cmd).Output(0xc4200c4580, 0x5, 0xc4201b9bf8, 0x2, 0x2, 0xc4200c4580)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/os/exec/exec.go:500 +0xf5
May 09 15:08:42 vpnserver ipsec_exporter[32398]: github.com/dennisstritzke/ipsec_exporter/ipsecexporter.IpSecStatus.QueryStatus(0xc42006b620, 0xc420024570)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /Users/STRITD/golang/src/github.com/dennisstritzke/ipsec_exporter/ipsecexporter/ipsec.go:40 +0x122
May 09 15:08:42 vpnserver ipsec_exporter[32398]: github.com/dennisstritzke/ipsec_exporter/ipsecexporter.prometheusMetrics(0x87bfe0, 0xc4203ac0e0, 0xc420094600)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /Users/STRITD/golang/src/github.com/dennisstritzke/ipsec_exporter/ipsecexporter/serve.go:40 +0x2d
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.HandlerFunc.ServeHTTP(0x847fa0, 0x87bfe0, 0xc4203ac0e0, 0xc420094600)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:1947 +0x44
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.(*ServeMux).ServeHTTP(0xa8ac60, 0x87bfe0, 0xc4203ac0e0, 0xc420094600)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:2337 +0x130
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.serverHandler.ServeHTTP(0xc42006cb60, 0x87bfe0, 0xc4203ac0e0, 0xc420094600)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:2694 +0xbc
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.(*conn).serve(0xc4200b6000, 0x87c460, 0xc4202c8040)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:1830 +0x651
May 09 15:08:42 vpnserver ipsec_exporter[32398]: created by net/http.(*Server).Serve
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:2795 +0x27b
May 09 15:08:42 vpnserver ipsec_exporter[32398]: goroutine 52115 [runnable]:
May 09 15:08:42 vpnserver ipsec_exporter[32398]: os/exec.(*Cmd).Start.func1(0xc4200c4580, 0xc4203743a0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/os/exec/exec.go:395
May 09 15:08:42 vpnserver ipsec_exporter[32398]: created by os/exec.(*Cmd).Start
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/os/exec/exec.go:395 +0x5df
May 09 15:08:42 vpnserver ipsec_exporter[32398]: goroutine 52076 [IO wait]:
May 09 15:08:42 vpnserver systemd[1]: ipsec_exporter.service: Unit entered failed state.
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.runtime_pollWait(0x7ff37d0bbc90, 0x72, 0xc4204a4658)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/runtime/netpoll.go:173 +0x57
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.(*pollDesc).wait(0xc42043c098, 0x72, 0xffffffffffffff00, 0x878b00, 0xa513e0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/internal/poll/fd_poll_runtime.go:85 +0x9b
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.(*pollDesc).waitRead(0xc42043c098, 0xc42022e000, 0x1, 0x1)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/internal/poll/fd_poll_runtime.go:90 +0x3d
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.(*FD).Read(0xc42043c080, 0xc42022e0a1, 0x1, 0x1, 0x0, 0x0, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/internal/poll/fd_unix.go:157 +0x17d
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net.(*netFD).Read(0xc42043c080, 0xc42022e0a1, 0x1, 0x1, 0x59d0ff, 0xc42026c418, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/fd_unix.go:202 +0x4f
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net.(*conn).Read(0xc420230000, 0xc42022e0a1, 0x1, 0x1, 0x0, 0x0, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/net.go:176 +0x6a
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.(*connReader).backgroundRead(0xc42022e090)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:668 +0x5a
May 09 15:08:42 vpnserver ipsec_exporter[32398]: created by net/http.(*connReader).startBackgroundRead
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:664 +0xce
May 09 15:08:42 vpnserver ipsec_exporter[32398]: goroutine 52038 [IO wait]:
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.runtime_pollWait(0x7ff37d0bbe30, 0x72, 0xc4203f4658)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/runtime/netpoll.go:173 +0x57
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.(*pollDesc).wait(0xc42043c218, 0x72, 0xffffffffffffff00, 0x878b00, 0xa513e0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/internal/poll/fd_poll_runtime.go:85 +0x9b
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.(*pollDesc).waitRead(0xc42043c218, 0xc420268200, 0x1, 0x1)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/internal/poll/fd_poll_runtime.go:90 +0x3d
May 09 15:08:42 vpnserver ipsec_exporter[32398]: internal/poll.(*FD).Read(0xc42043c200, 0xc420268221, 0x1, 0x1, 0x0, 0x0, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/internal/poll/fd_unix.go:157 +0x17d
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net.(*netFD).Read(0xc42043c200, 0xc420268221, 0x1, 0x1, 0x59d0ff, 0xc420390ef8, 0x0)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/fd_unix.go:202 +0x4f
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net.(*conn).Read(0xc42000c220, 0xc420268221, 0x1, 0x1, 0x0, 0x0, 0x0)
May 09 15:08:42 vpnserver systemd[1]: ipsec_exporter.service: Failed with result 'exit-code'.
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/net.go:176 +0x6a
May 09 15:08:42 vpnserver ipsec_exporter[32398]: net/http.(*connReader).backgroundRead(0xc420268210)
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:668 +0x5a
May 09 15:08:42 vpnserver ipsec_exporter[32398]: created by net/http.(*connReader).startBackgroundRead
May 09 15:08:42 vpnserver ipsec_exporter[32398]:         /usr/local/Cellar/go/1.10.1/libexec/src/net/http/server.go:664 +0xce

I don't know go. But as the word concurrent highlights multiple times, perhaps it has something to do with our setup. We are monitoring multiple VPN connections on the same server with ipsec_exporter. Perhaps that's the cause?

dennisstritzke commented 6 years ago

Thanks for reporting. Actually this bug might happen, if multiple HTTP requests hit at the same time. I will restructure the code to use different data structure instances for each request.

But for now your service just restarts and doesn't impact your monitoring, right?

czunker commented 6 years ago

Yes. I just added:

Restart=on-failure
RestartSec=1

to the systemd unit file and it works.

dennisstritzke commented 6 years ago

I released v0.1.2.1, which should resolve the issue. Can you verify that the issue is resolved?

czunker commented 6 years ago

I installed the new version. I will let you know whether it crashed or not.

czunker commented 6 years ago

The ipsec_exporter didn't crash since friday. Before the new release it was alive for just some hours, so assume you fixed it.

Thanks for the new release.

dennisstritzke commented 6 years ago

Thanks for validating the release!