Investigating in "Client Exceeded max pending messages"
in HomeAssistant i’ve found that
the problem comes from appdaemon (from the client id). Didn’t know if appdaemon is the cause or a symptom. (All appdaemon apps are running for years without issues till now - AppDaemon V 4.0.3)
Here what I’ve found:
That’s from Home Assistant Log --> The client is appdaemon (the only client)
2020-04-29 21:14:05 ERROR (MainThread) [homeassistant.components.webhook] Error processing webhook cb2a6ba9b5719bbc9ca5cc794e7f3aeffde42ddf8c51a950206f38ed1204e58c
2020-04-29 21:15:58 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.140692626535536] Client exceeded max pending messages [2]: 512
2020-04-29 21:15:58 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.140692626535536] Client exceeded max pending messages [2]: 512
That’s from AppDaemon (things starded go bad a little time before):
After Some Messages Like this:
2020-04-29 21:12:27.404924 WARNING cloro: Coroutine (<coroutine object ADAPI.set_state at 0x7fcb742552c8>) took too long (10 seconds), cancelling the task...
2020-04-29 21:12:27.408978 WARNING HASS: Timeout in set_state(default, sensor.cloro2, {'state': 'Out Of Range'})
2020-04-29 21:12:27.410966 WARNING AppDaemon: callback ppm() in cloro has now completed
I get:
2020-04-29 21:13:30.925645 WARNING HASS: Error setting Home Assistant state default.sensor.cloro1, {'state': 'Out Of Range'}
2020-04-29 21:13:30.926696 WARNING HASS: Code: 502, error: <html>
<head><title>502 Bad Gateway</title></head>
<body bgcolor="white">
<center><h1>502 Bad Gateway</h1></center>
<hr><center>nginx/1.10.3</center>
</body>
</html>
After Some messages like this one, I get the error in Home Assistant log, that degenerates in unresponsive ui…
Meanwhile in nginx:
2020/04/29 21:13:00 [error] 4974#4974: *8530 connect() failed (111: Connection refused) while connecting to upstream, client: ::ffff:127.0.0.1, server: sitename.duckdns.org, request: "POST /api/states/sensor.cloro2 HTTP/1.1", upstream: "http://[::1]:8123/api/states/sensor.cloro2", host: "127.0.0.1"
2020/04/29 21:13:17 [error] 4977#4977: *8508 upstream timed out (110: Connection timed out) while reading response header from upstream, client: ::ffff:127.0.0.1, server: sitename.duckdns.org, request: "POST /api/states/sensor.cloro2 HTTP/1.1", upstream: "http://127.0.0.1:8123/api/states/sensor.cloro2", host: "127.0.0.1"
2020/04/29 21:13:20 [error] 4977#4977: *8511 upstream timed out (110: Connection timed out) while reading response header from upstream, client: ::ffff:127.0.0.1, server: sitename.duckdns.org, request: "POST /api/states/sensor.flag_ph HTTP/1.1", upstream: "http://127.0.0.1:8123/api/states/sensor.flag_ph", host: "127.0.0.1"
2020/04/29 21:13:24 [error] 4974#4974: *8541 connect() failed (111: Connection refused) while connecting to upstream, client: ::ffff:127.0.0.1, server: sitename.duckdns.org, request: "POST /api/states/sensor.flag_ph HTTP/1.1", upstream: "http://[::1]:8123/api/states/sensor.flag_ph", host: "127.0.0.1"
2020/04/29 21:13:30 [error] 4974#4974: *8517 upstream timed out (110: Connection timed out) while reading response header from upstream, client: ::ffff:127.0.0.1, server: sitename.duckdns.org, request: "POST /api/states/sensor.cloro1 HTTP/1.1", upstream: "http://127.0.0.1:8123/api/states/sensor.cloro1", host: "127.0.0.1"
and then:
`2020/04/29 21:25:01 [error] 4977#4977: *8713 connect() failed (111: Connection refused) while connecting to upstream, client: ::ffff:192.168.1.211, server: sitename.duckdns.org, request: "POST /api/webhook/<xxxxxxxxxxxxxxxxxxxxxx> HTTP/1.1", upstream: "http://[::1]:8123/api/webhook/<xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx>", host: "sitename.duckdns.org"`
As it seems is the API that starts not responding to AppDaemon and then this causes all the things
AppDaemon Version 4.0.3
All the apps are running before without issues.
At the time of writing:
- Home Assistant V 0.190.0
- The app mentioned in logs is disabled but the same error occurs for another app after about 10hrs of system running
- Actually renewed the long-living token to see if that can be the cause.
Here the appdaemon config:
secret: /home/pi/.homeassistant/secrets.yaml
logs:
main_log:
filename: /home/pi/logs/appdaemon.log
access_log:
filename: /home/pi/logs/access.log
error_log:
filename: /home/pi/logs/appdaemon.err
diag_log:
filename: /home/pi/logs/diag.log
log_generations: 5
log_size: 1024
format: "{asctime} {levelname:<8} {appname:<10}: {message}"
appdaemon:
app_dir: /home/pi/.homeassistant/appdaemon
total_threads: 50
time_zone: Europe/Rome
latitude: <latitude>
longitude: <longitude>
elevation: 390
plugins:
HASS:
type: hass
ha_url: https://127.0.0.1
token: !secret token
#cert_path: /etc/letsencrypt/live/<url>/fullchain.pem
cert_verify: False
namespace: default
http:
url: https://<url>:5050
password: !secret pwd
dash_ssl_certificate: /etc/letsencrypt/live/<url>/fullchain.pem
dash_ssl_key: /etc/letsencrypt/live/<url>/privkey.pem
api:
admin:
configuration: self.config_dir
apps: self.app_dir
dashboard: self.dashboard_dir
Here the app that is now “causing” the issue:
import hassapi as hass
import datetime
import time
class CheckPompe(hass.Hass):
pozzo = 0
sorgente = 0
pozzostart = 0
pozzoend = 0
sorgenteend = 0
sorgentestart = 0
pozzomax = 100
sorgentemax = 100
prevevp = False
prevevs = False
presspozzo = 0
presssorge = 0
pozzocount = 0
def initialize(self):
runtime = datetime.datetime.now() + datetime.timedelta(seconds=60)
CheckPompe.pozzo = 0
CheckPompe.sorgente = 0
CheckPompe.pozzostart = 0
CheckPompe.pozzoend = 0
CheckPompe.sorgenteend = 0
CheckPompe.sorgentestart = 0
CheckPompe.pozzomax = 60
CheckPompe.sorgentemax = 60
CheckPompe.presspozzo = self.get_state("sensor.pressione_pozzo")
self.log(self.checkEV())
self.set_state("sensor.tempo_pozzo", state = str(CheckPompe.pozzo), attributes = {"friendly_name": "Tempo Pozzo"})
self.set_state("sensor.tempo_sorgente", state = str(CheckPompe.sorgente), attributes = {"friendly_name": "Tempo Sorgente"})
self.set_state("sensor.alert_pozzo", state = "OK" , attributes = {"friendly_name": "Alert Pozzo"})
self.set_state("sensor.alert_sorgente", state = "OK", attributes = {"friendly_name": "Alert Sorgente"})
self.set_state("sensor.pozzocount", state = str(CheckPompe.pozzocount), attributes = {"friendly_name": "Accensioni Pozzo in 1h"})
self.set_state("binary_sensor.pozzo_pressalert", state = "off", attributes = {"friendly_name": "PressAlert Pozzo"})
self.set_state("binary_sensor.pozzo_noev", state = "off", attributes = {"friendly_name": "NoEv Pozzo"})
self.set_state("binary_sensor.pozzo_termica", state = "off", attributes = {"friendly_name": "Protezione Termica Pozzo "})
self.set_state("binary_sensor.pozzo_high", state = "off", attributes = {"friendly_name": "Pressione Pozzo Elevata"})
self.set_state("binary_sensor.pozzo_low", state = "off", attributes = {"friendly_name": "Pressione Pozzo Bassa"})
self.log(runtime)
self.log("Tempo Sorgente " + str(CheckPompe.sorgente))
self.log("Tempo Pozzo " + str(CheckPompe.pozzo))
self.listen_state(self.pozzo_callback,"binary_sensor.pressostato_pozzo")
#self.listen_state(self.press_pozzo_callback,"sensor.pressione_pozzo")
self.listen_state(self.sorgente_callback,"binary_sensor.pressostato_sorgente")
self.run_every(self.hourlycheck, runtime, 60*10)
self.run_every(self.presscheck, runtime, 60)
self.run_every(self.press_pozzo_callback, runtime, 60)
def press_pozzo_callback(self, kwargs):
pressostato = self.get_state("binary_sensor.pressostato_pozzo")
pressione = self.get_state("sensor.pressione_pozzo")
self.log(pressostato + " , " + pressione)
if float(pressione) < 0.3:
#self.log("Low Pressure")
if pressostato == "off":
#self.log("Sgancio Termica Pozzo")
self.set_state("binary_sensor.pozzo_termica", state = "on", attributes = {"friendly_name": "Protezione Termica Pozzo "})
else:
#self.log("Consumo acqua elevato")
self.set_state("binary_sensor.pozzo_low", state = "on", attributes = {"friendly_name": "Pressione Pozzo Bassa"})
elif float(pressione) > 3:
#self.log("High Pressure")
self.set_state("binary_sensor.pozzo_high", state = "on", attributes = {"friendly_name": "Pressione Pozzo Elevata"})
else:
#self.log("Normal Pressure")
self.set_state("binary_sensor.pozzo_termica", state = "off", attributes = {"friendly_name": "Protezione Termica Pozzo "})
self.set_state("binary_sensor.pozzo_high", state = "off", attributes = {"friendly_name": "Pressione Pozzo Elevata"})
self.set_state("binary_sensor.pozzo_low", state = "off", attributes = {"friendly_name": "Pressione Pozzo Bassa"})
def checkEV(self):
evs = self.args["entities"]
opened = False
for ev in evs:
if self.get_state(ev) == "on":
self.log(ev + " Aperta")
opened = True
else:
self.log(ev + " Chiusa")
return opened
def presscheck(self, kwargs):
pressnow = self.get_state("sensor.pressione_pozzo")
self.log("Prev Press: " + str(CheckPompe.presspozzo) + " , Now Press: " + str(pressnow))
diff = float(CheckPompe.presspozzo) - float(pressnow)
diff = round(diff,2)
if diff > 0.1 and not self.checkEV():
self.log("Perdita o Rubinetto Aperto")
self.set_state("binary_sensor.pozzo_pressalert", state = "on", attributes = {"friendly_name": "PressAlert Pozzo"})
else:
self.set_state("binary_sensor.pozzo_pressalert", state = "off", attributes = {"friendly_name": "PressAlert Pozzo"})
self.log(str(diff))
CheckPompe.presspozzo = pressnow
def pozzo_callback(self, entity, attribute, old, new, kwargs):
self.log("Pozzo " + str(new) + " , " + str(old))
if not self.checkEV():
self.log("Elettrovalvole CHIUSE")
if new == "on":
CheckPompe.pozzocount = CheckPompe.pozzocount + 1
self.set_state("sensor.pozzocount", state = str(CheckPompe.pozzocount), attributes = {"friendly_name": "Accensioni Pozzo in 1h"})
self.set_state("binary_sensor.pozzo_noev", state = "on", attributes = {"friendly_name": "NoEv Pozzo"})
self.log("Pozzo si accende ma ev chiuse --> Inizio conteggio Tempo")
CheckPompe.pozzostart = datetime.datetime.now()
self.log("Pozzo-On " + CheckPompe.pozzostart.strftime("%Y-%m-%d %H:%M:%S"))
else:
if not CheckPompe.prevevp:
self.log("Pozzo si spenge, ev chiuse da ciclo precedente --> Concludo Conteggio")
CheckPompe.pozzoend = datetime.datetime.now()
self.log("Pozzo-Off " + CheckPompe.pozzoend.strftime("%Y-%m-%d %H:%M:%S"))
CheckPompe.pozzo = CheckPompe.pozzo + ((CheckPompe.pozzoend - CheckPompe.pozzostart).total_seconds())
self.set_state("sensor.tempo_pozzo", state = str(CheckPompe.pozzo), attributes = {"friendly_name": "Tempo Pozzo"})
else:
self.set_state("binary_sensor.pozzo_noev", state = "off", attributes = {"friendly_name": "NoEv Pozzo"})
self.log("Pozzo si spenge, ev chiuse ma aperte in ciclo precedente")
CheckPompe.prevevp = False
else:
self.log("Elettrovalvole APERTE")
self.set_state("binary_sensor.pozzo_noev", state = "off", attributes = {"friendly_name": "NoEv Pozzo"})
CheckPompe.prevevp = True
def sorgente_callback(self, entity, attribute, old, new, kwargs):
self.log("Sorgente " + str(new) + " , " + str(old))
if new == "on":
CheckPompe.sorgentestart = datetime.datetime.now()
self.log("Sorgente-On " + CheckPompe.sorgentestart.strftime("%Y-%m-%d %H:%M:%S"))
else:
CheckPompe.sorgenteend = datetime.datetime.now()
self.log("Sorgente Off " + CheckPompe.sorgenteend.strftime("%Y-%m-%d %H:%M:%S"))
CheckPompe.sorgente = CheckPompe.sorgente + ((CheckPompe.sorgenteend - CheckPompe.sorgentestart).total_seconds())
self.set_state("sensor.tempo_sorgente", state = str(CheckPompe.sorgente), attributes = {"friendly_name": "Tempo sorgente"})
def hourlycheck(self,kwargs):
self.log("HourlyCheck")
now = datetime.datetime.now()
if self.get_state("binary_sensor.pressostato_pozzo") == "on":
if (now - CheckPompe.pozzostart).total_seconds() > CheckPompe.pozzomax:
self.set_state("sensor.alert_pozzo", state = "Problemi Gravi" , attributes = {"friendly_name": "Alert Pozzo"})
else:
if CheckPompe.pozzo > CheckPompe.pozzomax:
self.set_state("sensor.alert_pozzo", state = "Problemi" , attributes = {"friendly_name": "Alert Pozzo"})
else:
self.set_state("sensor.alert_pozzo", state = "OK" , attributes = {"friendly_name": "Alert Pozzo"})
if self.get_state("binary_sensor.pressostato_sorgente") == "on":
if (now - CheckPompe.sorgentestart).total_seconds() > CheckPompe.sorgentemax:
self.set_state("sensor.alert_sorgente", state = "Problemi Gravi" , attributes = {"friendly_name": "Alert Sorgente"})
else:
if CheckPompe.sorgente > CheckPompe.sorgentemax:
self.set_state("sensor.alert_sorgente", state = "Problemi" , attributes = {"friendly_name": "Alert Sorgente"})
else:
self.set_state("sensor.alert_sorgente", state = "OK" , attributes = {"friendly_name": "Alert Sorgente"})
self.log("Tempo Sorgente " + str(CheckPompe.sorgente))
self.log("Tempo Pozzo " + str(CheckPompe.pozzo))
CheckPompe.pozzo = 0
self.set_state("sensor.tempo_pozzo", state = str(CheckPompe.pozzo), attributes = {"friendly_name": "Tempo Pozzo"})
CheckPompe.sorgente = 0
self.set_state("sensor.tempo_sorgente", state = str(CheckPompe.sorgente), attributes = {"friendly_name": "Tempo sorgente"})
CheckPompe.pozzocount = 0
self.set_state("sensor.pozzocount", state = str(CheckPompe.pozzocount), attributes = {"friendly_name": "Accensioni Pozzo in 1h"})
self.set_state("binary_sensor.pozzo_noev", state = "off", attributes = {"friendly_name": "NoEv Pozzo"})
Here the nginx config:
map $http_upgrade $connection_upgrade {
default upgrade;
'' close;
}
server {
# Update this line to be your domain
server_name sitename.duckdns.org;
# These shouldn't need to be changed
listen [::]:80 default_server ipv6only=off;
return 301 https://$host$request_uri;
}
server {
# Update this line to be your domain
server_name sitename.duckdns.org;
# Ensure these lines point to your SSL certificate and key
ssl_certificate /etc/letsencrypt/live/sitename.duckdns.org/fullchain.pem;
# managed by Certbot
ssl_certificate_key /etc/letsencrypt/live/sitename.duckdns.org/privkey.pem; # managed by Certbot
# Ensure this line points to your dhparams file
ssl_dhparam /etc/nginx/ssl/dhparams.pem;
# These shouldn't need to be changed
listen [::]:443 default_server ipv6only=off; # if your nginx version is >= 1.9.5 you can also add the "http2" flag here
add_header Strict-Transport-Security "max-age=31536000; includeSubdomains";
ssl on;
ssl_protocols TLSv1 TLSv1.1 TLSv1.2;
ssl_ciphers "EECDH+AESGCM:EDH+AESGCM:AES256+EECDH:AES256+EDH:!aNULL:!eNULL:!EXPORT:!DES:!MD5:!PSK:!RC4";
ssl_prefer_server_ciphers on;
ssl_session_cache shared:SSL:10m;
proxy_buffering off;
location / {
proxy_pass http://localhost:8123;
proxy_set_header Host $host;
proxy_redirect http:// https://;
proxy_http_version 1.1;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header Upgrade $http_upgrade;
proxy_set_header Connection $connection_upgrade;
}
location /api/appdaemon/ {
allow all;
proxy_pass http://localhost:5555;
proxy_set_header Host $host;
proxy_redirect http:// http://;
}
location /configurator/ {
proxy_pass https://192.168.1.236:3218;
#proxy_set_header Host $host;
#proxy_redirect http:// https://;
#proxy_http_version 1.1;
#proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
#proxy_set_header Upgrade $http_upgrade;
#proxy_set_header Connection $connection_upgrade;
}
location /picapport/ {
proxy_pass https://192.168.1.236:8080;
proxy_http_version 1.1; # default proxy http version = 1.0
}
location /grafana/ {
proxy_pass https://192.168.1.236:3001;
}
location /vs/ {
proxy_pass https://192.168.1.3:4433;
proxy_set_header Host $host;
proxy_redirect http:// https://;
proxy_http_version 1.1;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header Upgrade $http_upgrade;
proxy_set_header Connection $connection_upgrade;
}
}
server {
# Update this line to be your domain
server_name sitename2.duckdns.org; # managed by Certbot
# Ensure these lines point to your SSL certificate and key
ssl_certificate /etc/letsencrypt/live/sitename2.duckdns.org/fullchain.pem;
# managed by Certbot
ssl_certificate_key /etc/letsencrypt/live/sitename2.duckdns.org/privkey.pem; # managed by Certbot
# Ensure this line points to your dhparams file
ssl_dhparam /etc/nginx/ssl/dhparams.pem;
# These shouldn't need to be changed
listen [::]:443 ; # if your nginx version is >= 1.9.5 you can also add the "http2" flag here
add_header Strict-Transport-Security "max-age=31536000; includeSubdomains";
ssl on;
ssl_protocols TLSv1 TLSv1.1 TLSv1.2;
ssl_ciphers "EECDH+AESGCM:EDH+AESGCM:AES256+EECDH:AES256+EDH:!aNULL:!eNULL:!EXPORT:!DES:!MD5:!PSK:!RC4";
ssl_prefer_server_ciphers on;
ssl_session_cache shared:SSL:10m;
proxy_buffering off;
location / {
proxy_pass http://localhost:8123;
proxy_set_header Host $host;
proxy_redirect http:// https://;
proxy_http_version 1.1;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header Upgrade $http_upgrade;
proxy_set_header Connection $connection_upgrade;
}
location /api/appdaemon/ {
allow all;
proxy_pass http://localhost:5555;
proxy_set_header Host $host;
proxy_redirect http:// http://;
}
location /configurator/ {
proxy_pass https://192.168.1.236:3218;
#proxy_set_header Host $host;
#proxy_redirect http:// https://;
#proxy_http_version 1.1;
#proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
#proxy_set_header Upgrade $http_upgrade;
#proxy_set_header Connection $connection_upgrade;
}
location /picapport/ {
proxy_pass https://192.168.1.236:8080;
proxy_http_version 1.1; # default proxy http version = 1.0
}
location /grafana/ {
proxy_pass https://192.168.1.236:3001;
}
location /vs/ {
proxy_pass https://192.168.1.3:4433;
proxy_set_header Host $host;
proxy_redirect http:// https://;
proxy_http_version 1.1;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header Upgrade $http_upgrade;
proxy_set_header Connection $connection_upgrade;
}
}