Sensu-go: Agent reconnection to backend Issue

Created on 20 Nov 2018 · 10Comments · Source: sensu/sensu-go

Expected Behavior

When the backend nodes are back to be reachable by sensu agent. It must be able to work back normaly and run check like a charm.

Current Behavior

Context : Working on AWS plateform
Backend are reachable by our agents through an ALB AWS (Application Load Balancer)
To improve our Sensu Proof Of Concept plateform and improve our knowledge on sensu fonctionnality to block the traffic between our Agent and the Backend Node.

So we delete the port 8081 from our Security Group which make backend nodes unreachable for our sensu agent as you can see :
Nov 20 14:46:43 techops-52059 sensu-agent[26482]: {"component":"agent","error":"Connection error: websocket: close 1006 (abnormal closure): unexpected EOF","level":"error","msg":"transport receive error","time":"2018-11-20T14:46:43+01:00"}
Nov 20 14:46:53 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:46:53+01:00"}
Nov 20 14:47:13 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:47:13+01:00"}
Nov 20 14:47:33 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:47:33+01:00"}
Nov 20 14:47:53 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:47:53+01:00"}
Nov 20 14:48:13 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:48:13+01:00"}
Nov 20 14:48:33 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:48:33+01:00"}
Nov 20 14:48:53 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:48:53+01:00"}
Nov 20 14:49:13 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:49:13+01:00"}
Nov 20 14:49:33 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:49:33+01:00"}
Nov 20 14:49:53 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:49:53+01:00"}
Nov 20 14:50:13 techops-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:50:13+01:00"}
Nov 20 14:50:58 techops-52059 sensu-agent[26482]: {"component":"agent","error":"dial tcp ALB-IP:8081: connect: connection timed out","level":"error","msg":"reconnection attempt failed","time":"2018-11-20T14:50:58+01:00"}

During the outage the netstat display this before reach the "Connection Timed out " :
root@tech-52059 >netstat -lapunte |grep sensu
tcp 0 0 127.0.0.1:3030 0.0.0.0:* LISTEN 998 10005644 26482/sensu-agent
tcp 0 0 127.0.0.1:3031 0.0.0.0:* LISTEN 998 10004749 26482/sensu-agent
tcp 0 1 X.X.X.X:43610 ALB-IP:8081 SYN_SENT 998 10007611 26482/sensu-agent
udp 0 0 127.0.0.1:3030 0.0.0.0:* 998 10005643 26482/sensu-agent
udp 0 0 127.0.0.1:8125 0.0.0.0:* 998 10005645 26482/sensu-agent

Once Timed out reached :
root@tech-52059 >netstat -lapunte |grep sensu
tcp 0 0 127.0.0.1:3030 0.0.0.0:* LISTEN 998 10005644 26482/sensu-agent
tcp 0 0 127.0.0.1:3031 0.0.0.0:* LISTEN 998 10004749 26482/sensu-agent
tcp 1 0 X.X.X.X:43610 ALB-IP:8081 CLOSE_WAIT 998 10007611 26482/sensu-agent
udp 0 0 127.0.0.1:3030 0.0.0.0:* 998 10005643 26482/sensu-agent
udp 0 0 127.0.0.1:8125 0.0.0.0:* 998 10005645 26482/sensu-agent

I recover the Security Group setup and add the port 8081, agent are now reaching sensu backend and we are back in a nominal situation .. Normaly :smiling_imp:
Logs on agent side :
Nov 20 14:50:58 tech-52059 sensu-agent[26482]: {"component":"agent","error":"dial tcp ALB-IP:8081: connect: connection timed out","level":"error","msg":"reconnection attempt failed","time":"2018-11-20T14:50:58+01:00"}
Nov 20 14:52:01 tech-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"successfully connected","time":"2018-11-20T14:52:01+01:00"}
Nov 20 14:52:01 tech-52059 sensu-agent[26482]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-20T14:52:01+01:00"}

Logs on Backend side :
Nov 20 13:51:52 BACKEND-NODE sensu-backend[757]: {"check":"check-ntp-time","component":"schedulerd","level":"debug","msg":"sending check request","time":"2018-11-20T13:51:52Z","topic":"sensu::check:techops:ubuntu"}
Nov 20 13:52:01 ip-10-107-122-171 sensu-backend[757]: {"addr":"ALB-IP:60454","component":"agentd","id":"tech-52059","level":"info","msg":"agent connected","subscriptions":["ubuntu","front","entity:tech-front-52059"],"time":"2018-11-20T13:52:01Z"}
Nov 20 13:52:01 ip-10-107-122-171 sensu-backend[757]: {"component":"agentd","level":"debug","msg":"subscribing to topic","time":"2018-11-20T13:52:01Z","topic":"sensu::check:techops:ubuntu"}
Nov 20 13:52:01 ip-10-107-122-171 sensu-backend[757]: {"component":"agentd","level":"debug","msg":"subscribing to topic","time":"2018-11-20T13:52:01Z","topic":"sensu::check:techops:front"}
Nov 20 13:52:01 ip-10-107-122-171 sensu-backend[757]: {"component":"agentd","level":"debug","msg":"subscribing to topic","time":"2018-11-20T13:52:01Z","topic":"sensu::check:techops:entity:tech-front-52059"}
Nov 20 13:52:11 ip-10-107-122-171 sensu-backend[757]: {"addr":"ALB-IP:60454","component":"agentd","id":"tech-52059","level":"warning","msg":"stopping session","recv error":"Connection error: websocket: close 1006 (abnormal closure): unexpected EOF","time":"2018-11-20T13:52:11Z"}

As you can see the Backend Stopping the session => Connection Error Websocket
The agent didn't log anymore and looks like stucked no one check is performed etc.. the Netstat command return this :
netstat -lapunte |grep sensu
tcp 0 0 127.0.0.1:3030 0.0.0.0:* LISTEN 998 10005644 26482/sensu-agent
tcp 0 0 127.0.0.1:3031 0.0.0.0:* LISTEN 998 10004749 26482/sensu-agent
tcp 1 0 X.X.X.X:43610 ALB-IP:8081 CLOSE_WAIT 998 10007611 26482/sensu-agent
udp 0 0 127.0.0.1:3030 0.0.0.0:* 998 10005643 26482/sensu-agent
udp 0 0 127.0.0.1:8125 0.0.0.0:* 998 10005645 26482/sensu-agent

only the restart of all our sensu agents fix the problem :

root@tech-52059 >service sensu-agent restart
[ ~ ]
root@tech-52059 >netstat -lapunte |grep sensu
tcp 0 0 127.0.0.1:3030 0.0.0.0:* LISTEN 998 10039039 28856/sensu-agent
tcp 0 0 127.0.0.1:3031 0.0.0.0:* LISTEN 998 10039416 28856/sensu-agent
tcp 0 0 X.X.X.X:44950 ALB-IP:8081 ESTABLISHED 998 10039421 28856/sensu-agent
udp 0 0 127.0.0.1:3030 0.0.0.0:* 998 10039038 28856/sensu-agent
udp 0 0 127.0.0.1:8125 0.0.0.0:* 998 10039040 28856/sensu-agent

Looks like a poor TCP session management on sensu or a websocket depencies ?

Something goes wrong between sensu agent and sensu backend during a network interruption, I've done a tcpdump during my test and when the agent reconnected to the backend a GET request is send with following details :
Hypertext Transfer Protocol
GET / HTTP/1.1\r\n
Host: internal-poc-sensu-alb.eu-west-1.elb.amazonaws.com:8081\r\n
User-Agent: Go-http-client/1.1\r\n
Authorization: Basic XXXXX\r\n
Credentials: XXXX:XXXXX
Connection: Upgrade\r\n
Sec-WebSocket-Key: 0HpTiocDydA1b+XpCIdg4w==\r\n
Sec-WebSocket-Version: 13\r\n
Sensu-Agentname: XXXXXXXXXX \r\n
Sensu-Namespace: techops\r\n
Sensu-Subscriptions: ubuntu,front\r\n
Sensu-User: agent\r\n
Upgrade: websocket\r\n
\r\n
[Full request URI: http://internal-poc-sensu-alb.eu-west-1.elb.amazonaws.com:8081/]

Possible Solution

No one idea about possible solution, I don't know how is working the layer WebSocket between sensu agent and sensu backend.

Steps to Reproduce (for bugs)

1) be sure Agent sensu is running and working properly
2) make sensu agent unavailable to reach sensu backend
3) check logs on agent side
4) restore the link between sensu agent and sensu backend
5) check logs => agent connected to backend
6) Agent stopping work but running and TCP CLOSED.

Context

This issue can be problematic in case of network outage , the agent should be able to reconnect properly to the backend and rerun check.

Your Environment

Sensu version used :
sensu-agent version 2.0.0-beta.8-8#c07579c, build c07579c0b20f5f5e12788fb0704c3a9138882b58, built 2018-11-15T18:16:07+0000
Installation method : Following documentation installation of sensu.io
Operating System and version : Ubuntu 18.04

bug

Source

schampseix

Most helpful comment

Thank you very much. It's much clearer what is happening now. We'll work on reproducing this and let you know what we find.

grepory on 21 Nov 2018

👍3

All 10 comments

After investigation in agent logs this one return a success connected but no one request was coming to the backend.

Agent logs side :

Nov 21 15:00:30 tech-52059 sensu-agent[3604]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T15:00:30+01:00"}

Nov 21 15:00:43 tech-52059 sensu-agent[3604]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T15:00:43+01:00"}
Nov 21 15:01:03 tech-52059 sensu-agent[3604]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T15:01:03+01:00"}
Nov 21 15:01:23 tech-52059 sensu-agent[3604]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T15:01:23+01:00"}
Nov 21 15:03:46 tech-52059 sensu-agent[3604]: {"component":"agent","level":"info","msg":"successfully connected","time":"2018-11-21T15:03:46+01:00"}
Nov 21 15:03:46 tech-52059 sensu-agent[3604]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T15:03:46+01:00"}

Backend side :
ALB-IP - agent [21/Nov/2018:14:00:30 +0000] "GET / HTTP/1.1" 502 182 "-" "Go-http-client/1.1"

PS : please note that back timestamp isn't same as agent server (so you must add +1H for backend timestamp).

As you can see after 15:00 nothing appear on backend side .. how is it possible that agent return a successfully connected status when no one request is reaching the backend ?

For information this behavior looks like more easily to reproduce when the agent didn't reach the backend for large period of time around +2min for exemple.

schampseix on 21 Nov 2018

To simplify, on a reconnection of the agent, the agent logs that it successfully connected but the agent is then stuck. There is no more trafic between the agent and backend (and no more logs on agent).

Tested with various setup: direct connection / with a loadbalancer / with a reverse proxy.

In all case, the reconnection is sometimes bugged (looks like it happens more often if the interruption time of connection between agent/backend is high, I have never been able to reproduce when the disconnection is during less than 5s but always when >2 minutes).

On a test with 15 agents, with the backend shutdown for 125 seconds, all the 15 agents have been unable to properly reconnect. They all logs "successfully connected", "sending keepalive" but they are in fact stuck.

This is a serious issue.

Surian on 21 Nov 2018

👍1

Thank you for the report. We're investigating.

grepory on 21 Nov 2018

Can you please enable debug logging in the agent and send us logs? You can enable debug logging by setting the command-line flag --log-level debug. The default log level (warn) doesn't show check execution.

grepory on 21 Nov 2018

Here's the log of a test done this afternoon on an agent from the agent startup to shutdown. Logging level was already on debug. ;)

Test (and ~timeline) was:

starting the agent at 14:43
waiting for at least one check to run (done at 14:43)
stopping the backend for at least 2 minutes at 14:44
starting the backend at 14:47
waiting for the agent to reconnect (done at 14:48)
waiting for a check or any activity in the agent... nothing during 10 minutes. We then stopped the agent at 14:57. Last keepalive check of the agent visible on the backend was at 14:43 (the keepalive sent just after the message "successfully connected" never reached the backend).

Agent log:
Nov 21 14:43:22 tech-maasfront-prod-52059 systemd[1]: Started The Sensu Agent process..
Nov 21 14:43:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"cache":"/var/cache/sensu/sensu-agent","component":"asset-manager","level":"debug","msg":"initializing cache directory","time":"2018-11-21T14:43:22+01:00"}
Nov 21 14:43:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"cache":"/var/cache/sensu/sensu-agent","component":"asset-manager","level":"debug","msg":"done initializing cache directory","time":"2018-11-21T14:43:22+01:00"}
Nov 21 14:43:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"starting statsd server on address: 127.0.0.1:8125","time":"2018-11-21T14:43:22+01:00"}
Nov 21 14:43:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"starting UDP listener on address: 127.0.0.1:3030","time":"2018-11-21T14:43:22+01:00"}
Nov 21 14:43:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"starting TCP listener on address: 127.0.0.1:3030","time":"2018-11-21T14:43:22+01:00"}
Nov 21 14:43:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"starting api on address: 127.0.0.1:3031","time":"2018-11-21T14:43:22+01:00"}
Nov 21 14:43:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","event":{"Title":"Gostatsd started","Text":"Gostatsd started","DateHappened":1542807802,"Hostname":"tech-maasfront-prod-52059","AggregationKey":"","SourceTyp
eName":"","Tags":null,"SourceIP":"","Priority":1,"AlertType":0},"level":"info","msg":"statsd received an event","time":"2018-11-21T14:43:22+01:00"}
Nov 21 14:43:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"successfully connected","time":"2018-11-21T14:43:22+01:00"}
Nov 21 14:43:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:43:22+01:00"}
Nov 21 14:43:42 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:43:42+01:00"}
Nov 21 14:43:51 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"message received","payload":"{\"config\":{\"command\":\"LANG=C check_ntp_time -H ntp.eu-west-1.pbx\",\"handlers\":[\"slack\"],\"high_fl
ap_threshold\":0,\"interval\":60,\"low_flap_threshold\":0,\"publish\":true,\"runtime_assets\":[\"basic-checks\"],\"subscriptions\":[\"ubuntu\"],\"proxy_entity_name\":\"\",\"check_hooks\":null,\"stdin\":false,\"subdue\":null,\"ttl\":0,\"tim
eout\":15,\"round_robin\":false,\"output_metric_format\":\"\",\"output_metric_handlers\":[],\"env_vars\":null,\"metadata\":{\"name\":\"check-ntp-time\",\"namespace\":\"techops-maas\",\"labels\":null,\"annotations\":null}},\"assets
\":[{\"url\":\"https://s3-eu-west-1.amazonaws.com/sensu-poc-check/basic-checks.tar.gz\",\"sha512\":\"5fb84430475c47c1e7acd849a7743182ee1200192717ad8077710286cf2f60b1543be659baef4157886d7e13ce856cfb2a7f56cd17c0b57b919f165d06521c85\",\"filte
rs\":[],\"metadata\":{\"name\":\"basic-checks\",\"namespace\":\"techops-maas\",\"labels\":null,\"annotations\":null}}],\"hooks\":null,\"issued\":1542807831}","time":"2018-11-21T14:43:51+01:00","type":"check_request"}
Nov 21 14:43:51 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"scheduling check execution: check-ntp-time","time":"2018-11-21T14:43:51+01:00"}
Nov 21 14:43:51 tech-maasfront-prod-52059 sensu-agent[3279]: {"assets":["basic-checks"],"check":"check-ntp-time","component":"agent","level":"debug","msg":"fetching assets for check","namespace":"techops-maas","time":"2018-11-21T1
4:43:51+01:00"}
Nov 21 14:43:51 tech-maasfront-prod-52059 sensu-agent[3279]: {"asset":"basic-checks","component":"asset-manager","entity":"tech-maasfront-prod-52059","filters":[],"level":"debug","msg":"entity filtered, installing asset","time":"2018-11-21
T14:43:51+01:00"}
Nov 21 14:43:57 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"debug","msg":"sending message","payload":"{\"timestamp\":1542807837,\"entity\":{\"entity_class\":\"agent\",\"system\":{\"hostname\":\"tech-maasfront
-prod-52059\",\"os\":\"linux\",\"platform\":\"ubuntu\",\"platform_family\":\"debian\",\"platform_version\":\"16.04\",\"network\":{\"interfaces\":[{\"name\":\"lo\",\"addresses\":[\"127.0.0.1/8\",\"::1/128\"]},{\"name\":\"eth0\",\"mac\":\"02
:bd:df:c5:e8:e6\",\"addresses\":[\"10.107.52.59/26\",\"fe80::bd:dfff:fec5:e8e6/64\"]}]},\"arch\":\"amd64\"},\"subscriptions\":[\"ubuntu,maas-front\"],\"last_seen\":1542807802,\"deregister\":false,\"deregistration\":{},\"user\":\"agent\",\"
redact\":[\"password\",\"passwd\",\"pass\",\"api_key\",\"api_token\",\"access_key\",\"secret_key\",\"private_key\",\"secret\"],\"metadata\":{\"name\":\"tech-maasfront-prod-52059\",\"namespace\":\"techops-maas\",\"labels\":null,\"a
nnotations\":null}},\"check\":{\"command\":\"LANG=C check_ntp_time -H ntp.eu-west-1.pbx\",\"handlers\":[\"slack\"],\"high_flap_threshold\":0,\"interval\":60,\"low_flap_threshold\":0,\"publish\":true,\"runtime_assets\":[\"basic-checks\"],\"
subscriptions\":[\"ubuntu\"],\"proxy_entity_name\":\"\",\"check_hooks\":null,\"stdin\":false,\"subdue\":null,\"ttl\":0,\"timeout\":15,\"round_robin\":false,\"duration\":6.045227865,\"executed\":1542807831,\"history\":null,\"issued\":154280
7831,\"output\":\"NTP OK: Offset -3.427267075e-06 secs|offset=-0.000003s;60.000000;120.000000;\n\",\"status\":0,\"total_state_change\":0,\"last_ok\":0,\"occurrences\":0,\"occurrences_watermark\":0,\"output_metric_format\":\"\",\"output_me
tric_handlers\":[],\"env_vars\":null,\"metadata\":{\"name\":\"check-ntp-time\",\"namespace\":\"techops-maas\",\"labels\":null,\"annotations\":null}}}","time":"2018-11-21T14:43:57+01:00","type":"event"}
Nov 21 14:44:02 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"Connection error: websocket: close 1006 (abnormal closure): unexpected EOF","level":"error","msg":"transport receive error","time":"2018-11-21T14:44
:02+01:00"}
Nov 21 14:44:02 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T14:44:02+01:00"}
Nov 21 14:44:02 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T14:44:02+01:00"}
Nov 21 14:44:02 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:44:02+01:00"}
Nov 21 14:44:03 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T14:44:03+01:00"}
Nov 21 14:44:05 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T14:44:05+01:00"}
Nov 21 14:44:09 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T14:44:09+01:00"}
Nov 21 14:44:15 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T14:44:15+01:00"}
Nov 21 14:44:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:44:22+01:00"}
Nov 21 14:44:25 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T14:44:25+01:00"}
Nov 21 14:44:42 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:44:42+01:00"}
Nov 21 14:44:46 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T14:44:46+01:00"}
Nov 21 14:45:02 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:45:02+01:00"}
Nov 21 14:45:19 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T14:45:19+01:00"}
Nov 21 14:45:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:45:22+01:00"}
Nov 21 14:45:42 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:45:42+01:00"}
Nov 21 14:46:02 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:46:02+01:00"}
Nov 21 14:46:18 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","error":"handshake failed with status 502","level":"error","msg":"reconnection attempt failed","time":"2018-11-21T14:46:18+01:00"}
Nov 21 14:46:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:46:22+01:00"}
Nov 21 14:46:42 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:46:42+01:00"}
Nov 21 14:47:02 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:47:02+01:00"}
Nov 21 14:47:22 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:47:22+01:00"}
Nov 21 14:48:11 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"successfully connected","time":"2018-11-21T14:48:11+01:00"}
Nov 21 14:48:11 tech-maasfront-prod-52059 sensu-agent[3279]: {"component":"agent","level":"info","msg":"sending keepalive","time":"2018-11-21T14:48:11+01:00"}
Nov 21 14:57:23 tech-maasfront-prod-52059 systemd[1]: Stopping The Sensu Agent process....

Surian on 21 Nov 2018

👍1

Thank you very much. It's much clearer what is happening now. We'll work on reproducing this and let you know what we find.

grepory on 21 Nov 2018

👍3

Confirmed. I was able to reproduce this with our docker-compose.

echlebek on 22 Nov 2018

👍2

@echlebek can you take a look at this today?

grepory on 22 Nov 2018

Apologies for hijacking this thread but i am facing the exact same issue with version 5.14.2 and i though to post here before opening a new bug. For some reason I cannot connect to the backend from an agent. The issue i am seeing is:

{"component":"agent","level":"info","msg":"compacting api queue","time":"2019-11-18T17:41:59Z"}
{"component":"agent","level":"info","msg":"finished api queue compaction","time":"2019-11-18T17:41:59Z"}
{"component":"agent","level":"info","msg":"starting api on address: :3031","time":"2019-11-18T17:41:59Z"}
{"component":"agent","level":"info","msg":"starting UDP listener on address: :3030","time":"2019-11-18T17:41:59Z"}
{"component":"agent","level":"info","msg":"starting TCP listener on address: :3030","time":"2019-11-18T17:41:59Z"}
{"component":"agent","level":"info","msg":"using password auth","time":"2019-11-18T17:41:59Z"}
{"cache":"/var/cache/sensu/sensu-agent","component":"asset-manager","level":"debug","msg":"initializing cache directory","time":"2019-11-18T17:41:59Z"}
{"cache":"/var/cache/sensu/sensu-agent","component":"asset-manager","level":"debug","msg":"done initializing cache directory","time":"2019-11-18T17:41:59Z"}
{"component":"agent","level":"info","msg":"connecting to backend URL \"wss://:8081\"","time":"2019-11-18T17:41:59Z"}
{"component":"agent","header":"Accept: application/octet-stream","level":"debug","msg":"setting header","time":"2019-11-18T17:41:59Z"}
{"component":"agent","error":"EOF","level":"error","msg":"reconnection attempt failed","time":"2019-11-18T17:41:59Z"}
{"component":"agent","level":"info","msg":"connecting to backend URL \"wss://:8081\"","time":"2019-11-18T17:41:59Z"}
{"component":"agent","header":"Accept: application/octet-stream","level":"debug","msg":"setting header","time":"2019-11-18T17:41:59Z"}
{"component":"agent","error":"EOF","level":"error","msg":"reconnection attempt failed","time":"2019-11-18T17:41:59Z"}
{"component":"agent","level":"info","msg":"connecting to backend URL \"wss://:8081\"","time":"2019-11-18T17:41:59Z"}
{"component":"agent","header":"Accept: application/octet-stream","level":"debug","msg":"setting header","time":"2019-11-18T17:41:59Z"}
{"component":"agent","error":"EOF","level":"error","msg":"reconnection attempt failed","time":"2019-11-18T17:41:59Z"}
{"component":"agent","level":"info","msg":"connecting to backend URL \"wss://:8081\"","time":"2019-11-18T17:42:01Z"}
{"component":"agent","header":"Accept: application/octet-stream","level":"debug","msg":"setting header","time":"2019-11-18T17:42:01Z"}
{"component":"agent","error":"EOF","level":"error","msg":"reconnection attempt failed","time":"2019-11-18T17:42:01Z"}
{"component":"agent","level":"info","msg":"connecting to backend URL \"wss://:8081\"","time":"2019-11-18T17:42:11Z"}
{"component":"agent","header":"Accept: application/octet-stream","level":"debug","msg":"setting header","time":"2019-11-18T17:42:11Z"}
{"component":"agent","error":"EOF","level":"error","msg":"reconnection attempt failed","time":"2019-11-18T17:42:11Z"}
{"component":"agent","level":"info","msg":"connecting to backend URL \"wss://:8081\"","time":"2019-11-18T17:42:21Z"}
{"component":"agent","header":"Accept: application/octet-stream","level":"debug","msg":"setting header","time":"2019-11-18T17:42:21Z"}
{"component":"agent","error":"EOF","level":"error","msg":"reconnection attempt failed","time":"2019-11-18T17:42:21Z"}
{"component":"agent","level":"info","msg":"connecting to backend URL \"wss://:8081\"","time":"2019-11-18T17:42:31Z"}
{"component":"agent","header":"Accept: application/octet-stream","level":"debug","msg":"setting header","time":"2019-11-18T17:42:31Z"}

I am not really sure what to check in order to debug this at the moment. Please let me know if i can provide any more info.

gtarnaras on 18 Nov 2019

@gtarnaras Could you please open a new issue, since this one is currently closed and the problem you just reported is likely to be something different.

It would be useful if you could provide us the backend & agent configuration files, along with a bit more context; how many agents are you running? Is it only affecting a single agent? What versions of each component are you running? etc.

Thanks!