starting an edge agent with a non default checkin interval causes double polls

[chiptus]

1. in portainer - create an edge endpoint and set its interval to something other than 5 seconds.
2. start the agent and set its edge key.
3. check logs - the poll logs will appear twice

[chiptus]

I see this happening only on the edge job pr, but I don't think it's related.

I think this is a concurrency issue, where the poll service calls restart (which does stop and start) and the checkRuntimeConfig which also calls start.

see stack trace

2020/06/18 16:24:57 [INFO] [http] [server_addr: 172.17.0.3] [server_port: 9001] [secured: false] [api_version: 1.5.1] [message: Starting Agent API server]
2020/06/18 16:24:57 [INFO] [main,edge,http] [server_address: 0.0.0.0] [server_port: 80] [message: Starting Edge server]
2020/06/18 16:25:06 [DEBUG] [internal,edge] [api_addr: 172.17.0.3:9001] [edge_id: 4657f071-8a19-4102-abb6-02ddb8cf3468] [poll_frequency: 5s] [inactivity_timeout: 5m] [insecure_poll: false]
2020/06/18 16:25:06 [DEBUG] [internal,edge,logs] [message: logs manager started]
2020/06/18 16:25:06 [DEBUG] [internal,edge,docker] [message: Docker runtime configuration check] [engine_status: 1] [leader_node: false]
goroutine 37 [running]:
runtime/debug.Stack(0xc0001028a0, 0x10d5540, 0xb37800)
	/usr/lib/go-1.14/src/runtime/debug/stack.go:24 +0x9d
runtime/debug.PrintStack()
	/usr/lib/go-1.14/src/runtime/debug/stack.go:16 +0x22
github.com/portainer/agent/internal/edge.(*PollService).startStatusPollLoop(0xc0001080d0, 0x0, 0xc0001028a0)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/poll.go:128 +0x26
github.com/portainer/agent/internal/edge.(*PollService).start(0xc0001080d0, 0x72, 0xc0004bd7d8)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/poll.go:108 +0x66
github.com/portainer/agent/internal/edge.(*Manager).checkRuntimeConfig(0xc000064080, 0x2, 0x12a05f200)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/edge.go:136 +0x10c
github.com/portainer/agent/internal/edge.(*Manager).startEdgeBackgroundProcess(0xc000064080, 0xc00028e040, 0xc0000b4990)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/edge.go:102 +0x65
github.com/portainer/agent/internal/edge.(*Manager).Start(0xc000064080, 0xc000510084, 0x76)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/edge.go:78 +0x757
github.com/portainer/agent/http.(*EdgeServer).handleKeySetup.func1(0xc51f00, 0xc00050a000, 0xc0000ac200)
	/home/chaim/go/src/github.com/portainer/agent/http/edge.go:64 +0xa7
net/http.HandlerFunc.ServeHTTP(0xc000449190, 0xc51f00, 0xc00050a000, 0xc0000ac200)
	/usr/lib/go-1.14/src/net/http/server.go:2012 +0x44
github.com/portainer/agent/vendor/github.com/gorilla/mux.(*Router).ServeHTTP(0xc0004088c0, 0xc51f00, 0xc00050a000, 0xc000152000)
	/home/chaim/go/src/github.com/portainer/agent/vendor/github.com/gorilla/mux/mux.go:162 +0x112
net/http.serverHandler.ServeHTTP(0xc000366380, 0xc51f00, 0xc00050a000, 0xc000152000)
	/usr/lib/go-1.14/src/net/http/server.go:2807 +0xa3
net/http.(*conn).serve(0xc000130280, 0xc54180, 0xc00012e000)
	/usr/lib/go-1.14/src/net/http/server.go:1895 +0x86c
created by net/http.(*Server).Serve
	/usr/lib/go-1.14/src/net/http/server.go:2933 +0x35c
2020/06/18 16:25:06 [DEBUG] [internal,edge,poll] [poll_interval_seconds: 5.000000] [server_url: http://172.17.0.1:9000] [message: starting Portainer short-polling client]
2020/06/18 16:25:06 [DEBUG] [internal,edge,monitoring] [monitoring_interval_seconds: 30.000000] [inactivity_timeout: 5m0s] [message: starting activity monitoring loop]
2020/06/18 16:25:06 [INFO] [main,edge,http] [message: Edge server shutdown]
2020/06/18 16:25:11 [DEBUG] [internal,edge,poll] [status: IDLE] [port: 0] [schedule_count: 0] [checkin_interval_seconds: 10.000000]
2020/06/18 16:25:11 [DEBUG] [internal,edge,poll] [old_interval: 5.000000] [new_interval: 10.000000] [message: updating poll interval]
goroutine 11 [running]:
runtime/debug.Stack(0x86bc98, 0x1116b20, 0xc00012de88)
	/usr/lib/go-1.14/src/runtime/debug/stack.go:24 +0x9d
runtime/debug.PrintStack()
	/usr/lib/go-1.14/src/runtime/debug/stack.go:16 +0x22
github.com/portainer/agent/internal/edge.(*PollService).startStatusPollLoop(0xc0001080d0, 0xc00054a120, 0xb87548)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/poll.go:128 +0x26
github.com/portainer/agent/internal/edge.(*PollService).restartStatusPollLoop(0xc0001080d0)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/poll.go:124 +0x34
created by github.com/portainer/agent/internal/edge.(*PollService).poll
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/poll.go:290 +0xa73
2020/06/18 16:25:11 [DEBUG] [internal,edge,poll] [poll_interval_seconds: 10.000000] [server_url: http://172.17.0.1:9000] [message: starting Portainer short-polling client]
2020/06/18 16:25:11 [DEBUG] [internal,edge,poll] [message: shutting down Portainer short-polling client]
2020/06/18 16:25:11 [DEBUG] [internal,edge,docker] [message: Docker runtime configuration check] [engine_status: 1] [leader_node: false]
goroutine 32 [running]:
runtime/debug.Stack(0xc00010c0c0, 0x10d5540, 0xb37800)
	/usr/lib/go-1.14/src/runtime/debug/stack.go:24 +0x9d
runtime/debug.PrintStack()
	/usr/lib/go-1.14/src/runtime/debug/stack.go:16 +0x22
github.com/portainer/agent/internal/edge.(*PollService).startStatusPollLoop(0xc0001080d0, 0x0, 0xc00010c0c0)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/poll.go:128 +0x26
github.com/portainer/agent/internal/edge.(*PollService).start(0xc0001080d0, 0x72, 0xc00008ff58)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/poll.go:108 +0x66
github.com/portainer/agent/internal/edge.(*Manager).checkRuntimeConfig(0xc000064080, 0x0, 0x0)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/edge.go:136 +0x10c
github.com/portainer/agent/internal/edge.(*Manager).startEdgeBackgroundProcess.func1(0xc00050c1e0, 0xc000064080)
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/edge.go:113 +0x52
created by github.com/portainer/agent/internal/edge.(*Manager).startEdgeBackgroundProcess
	/home/chaim/go/src/github.com/portainer/agent/internal/edge/edge.go:109 +0xc2
2020/06/18 16:25:11 [DEBUG] [internal,edge,poll] [poll_interval_seconds: 10.000000] [server_url: http://172.17.0.1:9000] [message: starting Portainer short-polling client]
2020/06/18 16:25:11 [DEBUG] [internal,edge,monitoring] [monitoring_interval_seconds: 30.000000] [inactivity_timeout: 5m0s] [message: starting activity monitoring loop]
2020/06/18 16:25:16 [DEBUG] [internal,edge,docker] [message: Docker runtime configuration check] [engine_status: 1] [leader_node: false]
2020/06/18 16:25:21 [DEBUG] [internal,edge,poll] [status: IDLE] [port: 0] [schedule_count: 0] [checkin_interval_seconds: 10.000000]
2020/06/18 16:25:21 [DEBUG] [internal,edge,poll] [status: IDLE] [port: 0] [schedule_count: 0] [checkin_interval_seconds: 10.000000]
2020/06/18 16:25:21 [DEBUG] [internal,edge,docker] [message: Docker runtime configuration check] [engine_status: 1] [leader_node: false]

currently, when start is called there's a check to see if service is not running using

if service.refreshSignal != nil {
		return nil
	}

but I guess it's not enough