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.

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

v3.3.1b0: Template variable warning: 'dict object' has no attribute 'tempautotemp' #229

Closed
zibous opened this issue Dec 1, 2021 · 37 comments
Labels
bug Something isn't working
Milestone

Comments

@zibous
Copy link

zibous commented Dec 1, 2021

Bug description
Logger: homeassistant.helpers.template
Source: helpers/template.py:1766
First occurred: 13:53:24 (731 occurrences)
Last logged: 15:55:03

Template variable warning: 'dict object' has no attribute 'tempautotemp' when rendering '{{value_json.hc1.tempautotemp}}'

Steps to reproduce
Log Homeassistant

Expected behavior
I have already deleted all entries in the MQTT broker, restarted EMS-ESP.

Screenshots
If applicable, add screenshots to help explain your problem.

Device information
{
"System": {
"version": "3.3.1b0",
"uptime": "002+06:13:09.948",
"uptime (seconds)": 195189,
"freemem": 155,
"reset reason": "Software reset CPU / Software reset CPU",
"Dallas sensors": 0
},
"Network": {
"connection": "WiFi",
},
"Status": {
"bus status": "connected",
"bus protocol": "Buderus",
"telegrams received": 134376,
"read requests sent": 15084,
"write requests sent": 22,
"incomplete telegrams": 14,
"tx fails": 13,
"rx line quality": 100,
"tx line quality": 100,
"MQTT": "connected",
"MQTT publishes": 62142,
"MQTT publish fails": 0,
"Dallas reads": 0,
"Dallas fails": 0,
"syslog active": true
},
"Devices": [
{
"type": "Boiler",
"name": "Buderus GBx72/Trendline/Cerapur/Greenstar Si/27i (DeviceID:0x08 ProductID:123, Version:07.00)",
"handlers": "0x10 0x11 0xC2 0x14 0x15 0x1C 0x18 0x19 0x1A 0x35 0x16 0x33 0x34 0x26 0x2A 0xD1 0xE3 0xE4 0xE5 0xE6 0xE9 0xEA"
},
{
"type": "Thermostat",
"name": "RC300/RC310/Moduline 3000/1010H/CW400/Sense II (DeviceID:0x10, ProductID:158, Version:74.02)",
"handlers": "0xA3 0x06 0xA2 0x12 0x2A5 0x2B9 0x2AF 0x29B 0x471 0x2A6 0x2BA 0x2B0 0x29C 0x472 0x2A7 0x2BB 0x2B1 0x29D 0x473 0x2A8 0x2BC 0x2B2 0x29E 0x474 0x2F5 0x31B 0x31D 0x31E 0x23A 0x267 0x240"
},
{
"type": "Controller",
"name": "BC25 (DeviceID:0x09, ProductID:125, Version:03.05)"
}
]

Additional context

{"~":"ems-heizung",
  "uniq_id":"thermostat_hc1_tempautotemp",
  "stat_t":"~/thermostat_data",
  "name":"Thermostat hc1 temporary room temperature automode",
 "val_tpl":"{{value_json.hc1.tempautotemp}}",
 "unit_of_meas":"°C","ic":"mdi:coolant-temperature",
  "dev":{"ids":["ems-esp-thermostat"]}
}
@zibous zibous added the bug Something isn't working label Dec 1, 2021
@proddy
Copy link
Contributor

proddy commented Dec 1, 2021

use MQTTExplorer and search for tempautotemp. There should be two entries. Send a screenshot back if you can

@zibous
Copy link
Author

zibous commented Dec 1, 2021

@proddy
Negativ, there is no tempautotempalso no attribute tempautotemp on ems-heizung/thermostat_data

{
	"id": 158,
	"errorcode": "(0)",
	"datetime": "21:19:30 01/12/2021",
	"floordry": "off",
	"dampedoutdoortemp": 1.7,
	"floordrytemp": 0,
	"building": "light",
	"minexttemp": -10,
	"wwsettemp": 60,
	"wwmode": "own_prog",
	"wwsettemplow": 45,
	"wwcircmode": "own_prog",
	"wwchargeduration": 60,
	"wwcharge": "off",
	"wwextra1": 0,
	"wwdisinfect": "on",
	"wwdisinfectday": "we",
	"wwdisinfecttime": 180,
	"hc1": {
		"seltemp": 24,
		"temp": 24,
		"hatemp": 24,
		"hamode": "auto",
		"mode": "auto",
		"modetype": "comfort",
		"ecotemp": 15,
		"manualtemp": 24,
		"comforttemp": 25,
		"summertemp": 17,
		"designtemp": 45,
		"offsettemp": 0,
		"minflowtemp": 25,
		"maxflowtemp": 60,
		"roominfluence": 0,
		"curroominfl": 0,
		"nofrosttemp": 5,
		"targetflowtemp": 38,
		"heatingtype": "radiator",
		"summersetmode": "auto",
		"summermode": "off",
		"controlmode": "optimized",
		"program": "prog_1",
		"fastheatup": 0
	}
}

@proddy
Copy link
Contributor

proddy commented Dec 1, 2021

there must be one otherwise HA wouldn't be complaining. Is it not in homeassistant/sensor/ems-esp/..... ?

@zibous
Copy link
Author

zibous commented Dec 1, 2021

@proddy
Yes i know. But i have deleted the tempautotemp template, restart the EMS-ESP.
I think this was created by a prevoius Version.

Bildschirmfoto 2021-12-01 um 21 43 30

@proddy
Copy link
Contributor

proddy commented Dec 1, 2021

you still seeing the error in HA then?

@zibous
Copy link
Author

zibous commented Dec 2, 2021

@proddy
Now the entry is no longer available in the MQTT Brocker.
It could also be because I switched from EMS + to EMS and forgot to delete the entries in the MQTT homeassistant / ems before restarting.
Sorry.

@zibous zibous closed this as completed Dec 2, 2021
@zibous
Copy link
Author

zibous commented Dec 4, 2021

Strange, no i can see the warning again, w/o my changing anything.

Logger: homeassistant.helpers.template
Source: helpers/template.py:1772
First occurred: 04:02:10 (3 occurrences)
Last logged: 04:02:27

Template variable warning: 'dict object' has no attribute 'tempautotemp' when rendering '{{value_json.hc1.tempautotemp}}'

Bildschirmfoto 2021-12-04 um 08 57 53

2021-12-04 01:24:59.040 WARNING 336:    [mqtt]       Lost device value for thermostat_hc1_summermode. Removing HA config
2021-12-04 01:24:59.040 WARNING 337:    [mqtt]       Lost device value for thermostat_hc1_controlmode. Removing HA config
2021-12-04 01:24:59.040 WARNING 338:    [mqtt]       Lost device value for thermostat_hc1_program. Removing HA config
2021-12-04 01:24:59.040 WARNING 339:    [mqtt]       Lost device value for thermostat_hc1_tempautotemp. Removing HA config
2021-12-04 01:24:59.040 WARNING 340:    [mqtt]       Lost device value for thermostat_hc1_fastheatup. Removing HA config
2021-12-04 03:05:18.299 WARNING 341:    [telegram]   Incomplete Rx: FE 08 00 07 00 0B 01 00 00 00 00 00 00 00 00 00 00 00
2021-12-04 04:02:22.995    INFO 342:    [thermostat] Setting thermostat mode to auto for heating circuit 1
2021-12-04 04:02:23.184    INFO 343:    [thermostat] Setting thermostat temperature to 24.0 for heating circuit 1, mode auto
2021-12-04 04:20:41.336 WARNING 344:    [telegram]   Incomplete Rx: F8 08 00 2A 00 00 00 00 00 00 00 00 00 CF 00 00 80 00 00 80 00 80 00 80 00 00
2021-12-04 05:07:53.715    INFO 345:    [command]    Calling boiler command 'wwtapactivated', value false, id is default
2021-12-04 05:07:53.715    INFO 346:    [boiler]     Setting warm tap water off
2021-12-04 05:07:56.425   ERROR 347:    [telegram]   Last Tx Write operation failed after 3 retries. Ignoring request: 0B 08 1D 00 5A 00 00 64 FF 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2021-12-04 05:08:03.716    INFO 348:    [command]    Calling boiler command 'wwtapactivated', value true, id is default
2021-12-04 05:08:03.716    INFO 349:    [boiler]     Setting warm tap water on
2021-12-04 05:15:20.182    INFO 350:    [command]    Calling boiler command 'wwtapactivated', value false, id is default
2021-12-04 05:15:20.182    INFO 351:    [boiler]     Setting warm tap water off
2021-12-04 05:15:30.183    INFO 352:    [command]    Calling boiler command 'wwtapactivated', value true, id is default
2021-12-04 05:15:30.183    INFO 353:    [boiler]     Setting warm tap water on
2021-12-04 05:22:46.516    INFO 354:    [command]    Calling boiler command 'wwtapactivated', value false, id is default
2021-12-04 05:22:46.516    INFO 355:    [boiler]     Setting warm tap water off
2021-12-04 05:22:50.336   ERROR 356:    [telegram]   Last Tx Write operation failed after 3 retries. Ignoring request: 0B 08 1D 00 5A 00 00 64 FF 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2021-12-04 05:22:56.517    INFO 357:    [command]    Calling boiler command 'wwtapactivated', value true, id is default
2021-12-04 05:22:56.517    INFO 358:    [boiler]     Setting warm tap water on
2021-12-04 05:30:48.153 WARNING 359:    [mqtt]       Lost device value for thermostat_hc1_tempautotemp. Removing HA config
2021-12-04 07:31:23.402 WARNING 360:    [telegram]   Incomplete Rx: F8 08 00 18 00 27 01 C5 64 00 01 01 24 40 80 00 02 46 80 00 00 00 FF 30 59 00 CC 00 00 00
```

@zibous zibous reopened this Dec 4, 2021
@proddy
Copy link
Contributor

proddy commented Dec 4, 2021

There may be something not right then in the code. Those log messages "Lost device value for thermostat_hc1_tempautotemp. Removing HA config" should be removing that MQTT topic from the broker but it doesn't look like it's working. So either the name is wrong or something else is at hand.

Is this easy for you to reproduce on command? Then I can provide more debug information that will help track down where the problem is.

@zibous
Copy link
Author

zibous commented Dec 4, 2021

@proddy

Is this easy for you to reproduce on command? Then I can provide more debug information that will help track down where the problem is.

Testcase - is working:

mosquitto_pub -h mbsbroker.home  -p 1883 -u ******* -P ****** -t 'homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config' -n -r

But EMS-ESP32 do not remove the topic ???

617417:Dec  3 12:19:39 ems-heizung.home mqtt 001+14:55:20.236 D 170639: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#44626, retain=1, retry=1, size=281, pid=1)
663779:Dec  3 23:00:49 ems-heizung.home mqtt 002+01:36:30.300 D 216735: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#56906, retain=0, retry=1, size=0, pid=1)
674045:Dec  4 01:25:14 ems-heizung.home mqtt 002+04:00:55.849 D 227173: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#59788, retain=0, retry=1, size=0, pid=1)
674181:Dec  4 01:25:28 ems-heizung.home mqtt 002+04:01:09.693 D 227334: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#59925, retain=0, retry=1, size=0, pid=1)
685331:Dec  4 04:02:29 ems-heizung.home mqtt 002+06:38:10.266 D 238411: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#63020, retain=1, retry=1, size=281, pid=1)
692083:Dec  4 05:30:49 ems-heizung.home mqtt 002+08:06:30.254 D 245133: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#64732, retain=0, retry=1, size=0, pid=1)

@glitter-ball
Copy link

All this sounds horribly like my issue in #196 !

@zibous - you will probably find this error occurs if you override the heating temperature. At the end of the override period, tempautotemp no longer has a value so isn't published, but the template remains. @proddy did some code changes (see #196) which fixed it for me.

I just have the same problem now with 'lastcode' - I thought we'd cracked that and it's come back again...

2021-12-04 19:24:21 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'lastcode' when rendering '{{value_json.lastcode}}'
2021-12-04 19:24:21 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'lastcode' when rendering '{{value_json.lastcode}}'
2021-12-04 19:24:21 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'lastcode' when rendering '{{value_json.lastcode}}'

EMS-ESP is publishing the config topic but no data to go with it and the retained flag is set...
image

If I clear the Retained flag in MQTT Explorer it goes and stays gone. Wonder why the code change implemented for #196 isn't working with 'lastcode'?

@glitter-ball
Copy link

@zibous's screenshot shows the retained flag set too, so perhaps it's the logic around clearing that when deleting the topic? I know that was an issue in resolving #196 at one point.

@proddy
Copy link
Contributor

proddy commented Dec 4, 2021

this is frustrating. I thought we fixed it. @zibous are you able to reproduce it manually without sending MQTT payloads? Like switching the modes or timer on your thermostat and then monitoring in EMS-ESP if indeed the tempautocode is removed? I've tried to simulate this in C++ test code but its not the same as a live environment.

@zibous
Copy link
Author

zibous commented Dec 5, 2021

@proddy
I understand - here my tests:

If I change the thermostat (Homeassistant) temperature value, this is transferred and also changed to the RC310.
Then everything is in order, emsheating / thermostat_data then has the entry tempautotemp and the template works perfectly.

Bildschirmfoto 2021-12-05 um 09 01 12

After a certain time, usually overnight, the entry tempautotemp disappears.

Could this have something to do with the day / night changeover?
2021-12-05 05:30:48.182 WARNING 394: [mqtt] Lost device value for thermostat_hc1_tempautotemp. Removing HA config

Because the message Removing HA config always comes in the morning when the heating is switched from night setback to normal operation.

ems-heizung/thermostat_data

{
	"id": 158,
	"errorcode": "(0)",
	"datetime": "08:59:50 05/12/2021",
	"floordry": "off",
	"dampedoutdoortemp": 7,
	"floordrytemp": 0,
	"building": "light",
	"minexttemp": -10,
	"wwsettemp": 60,
	"wwmode": "own_prog",
	"wwsettemplow": 45,
	"wwcircmode": "own_prog",
	"wwchargeduration": 60,
	"wwcharge": "off",
	"wwextra1": 0,
	"wwdisinfect": "on",
	"wwdisinfectday": "we",
	"wwdisinfecttime": 180,
	"hc1": {
		"seltemp": 24,
		"temp": 24,
		"hatemp": 24,
		"hamode": "auto",
		"mode": "auto",
		"modetype": "comfort",
		"ecotemp": 20,
		"manualtemp": 24,
		"comforttemp": 24,
		"summertemp": 17,
		"designtemp": 45,
		"offsettemp": 0,
		"minflowtemp": 25,
		"maxflowtemp": 60,
		"roominfluence": 0,
		"curroominfl": 0,
		"nofrosttemp": 5,
		"targetflowtemp": 41,
		"heatingtype": "radiator",
		"summersetmode": "auto",
		"summermode": "off",
		"controlmode": "optimized",
		"program": "prog_1",
		"tempautotemp": 24,
		"fastheatup": 0
	}
}

homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config

{
	"~": "ems-heizung",
	"uniq_id": "thermostat_hc1_tempautotemp",
	"stat_t": "~/thermostat_data",
	"name": "Thermostat hc1 temporary room temperature automode",
	"val_tpl": "{{value_json.hc1.tempautotemp}}",
	"unit_of_meas": "°C",
	"ic": "mdi:coolant-temperature",
	"dev": { "ids": ["ems-esp-thermostat"] }
}

Syslog Data:

emslogs.txt.zip

@zibous
Copy link
Author

zibous commented Dec 5, 2021

@glitter-ball

I just have the same problem now with 'lastcode' - I thought we'd cracked that and it's come back again...

yes, also for me, when i restart the EMS-ESP.

2021-12-05 11:19:08.000    INFO 0:      [emsesp]     Last system reset reason Core0: Software reset CPU, Core1: Software reset CPU
2021-12-05 11:19:08.000    INFO 1:      [emsesp]     EMS Device library loaded with 87 records
2021-12-05 11:19:08.000    INFO 2:      [emsesp]     Starting Access Point with captive portal on 192.168.4.1
2021-12-05 11:19:12.373    INFO 3:      [emsesp]     Starting NTP
2021-12-05 11:19:12.373    INFO 4:      [emsesp]     WiFi Connected with IP=10.******, hostname=ems-heizung.home
2021-12-05 11:19:12.373    INFO 5:      [emsesp]     mDNS responder service started
2021-12-05 11:19:12.708    INFO 6:      [mqtt]       MQTT connected
2021-12-05 11:19:18.000    INFO 7:      [emsesp]     Stopping Access Point
2021-12-05 11:19:23.524    INFO 8:      [emsesp]     Recognized new boiler with device ID 0x08
2021-12-05 11:19:27.441    INFO 9:      [emsesp]     Recognized new thermostat with device ID 0x10

Bildschirmfoto 2021-12-05 um 11 31 07

2021-12-05 10:25:17 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'lastcode' when rendering '{{value_json.lastcode}}'

@proddy
Copy link
Contributor

proddy commented Dec 5, 2021

After a certain time, usually overnight, the entry tempautotemp disappears.
Could this have something to do with the day / night changeover?
2021-12-05 05:30:48.182 WARNING 394: [mqtt] Lost device value for thermostat_hc1_tempautotemp. Removing HA config
Because the message Removing HA config always comes in the morning when the heating is switched from night setback to normal operation.

The sequence looks fine. at 5am the tempautotemp entity is no longer sent in the EMS Telegrams so it's removed from the thermostat_data MQTT payload and also the Home Assistant /config should also be removed. But looks like it's not for some reason. I'm not sure why but can add some more debug code in a special build which you can try. Saves getting up at 5am and monitoring it in real-time !

@zibous
Copy link
Author

zibous commented Dec 5, 2021

@proddy

Thanks.

I'm not sure why but can add some more debug code in a special build which you can try. Saves getting up at 5am and monitoring it in real-time !

Well, I can only receive the messages via syslog, but it should work.

How can I install the special firmware update normally via OTA?

@proddy
Copy link
Contributor

proddy commented Dec 5, 2021

just drag & drop into the WebUI

@zibous
Copy link
Author

zibous commented Dec 5, 2021

@proddy
Ok, Firmware EMS-ESP-3_3_1b0-ESP32.bin and installed.

@proddy
Copy link
Contributor

proddy commented Dec 5, 2021

I haven't made the special build for you yet. I'm away on business so it'll be a week or two until I can make the changes.

@zibous
Copy link
Author

zibous commented Dec 6, 2021

@proddy
ok. I have 2 Warnings:

  • tempautotemp
  • lstcode

I have checked the EMS-ESP Log and the Mosquitto Log:

## EMS ESM Message:
--> 2021-12-05 23:00:49.136 WARNING 219:    [mqtt]       Lost device value for thermostat_hc1_tempautotemp. Removing HA config

## cat /var/log/syslog | grep "homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config"
Dec  5 05:02:24 ems-heizung.home mqtt 003+07:38:06.321 D 344699: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#26120, retain=1, retry=1, size=281, pid=1)
Dec  5 05:30:48 ems-heizung.home mqtt 003+08:06:30.283 D 346831: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#26669, retain=0, retry=1, size=0, pid=1)
Dec  5 08:56:42 ems-heizung.home mqtt 003+11:32:23.484 D 361250: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#30591, retain=1, retry=1, size=281, pid=1)
Dec  5 11:19:44 ems-heizung.home mqtt 000+00:00:37.289 D 338: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#101, retain=1, retry=1, size=281, pid=1)
Dec  5 18:09:07 ems-heizung.home mqtt 000+00:00:27.394 D 303: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#97, retain=1, retry=1, size=281, pid=1)
--> Dec  5 23:00:49 ems-heizung.home mqtt 000+04:52:10.237 D 30069: Publishing topic homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config (#5716, retain=0, retry=1, size=0, pid=1)

## cat mosquitto.log | grep "homeassistant/climate/ems-heizung/thermostat_hc1/"
2021-12-06 06:08:21: Sending PUBLISH to mqtt-explorer-a10a50f0 (d0, q0, r1, m0, 'homeassistant/climate/ems-heizung/thermostat_hc1/config', ... (591 bytes))
2021-12-06 07:28:43: Sending PUBLISH to mqtt-explorer-a10a50f0 (d0, q0, r1, m0, 'homeassistant/climate/ems-heizung/thermostat_hc1/config', ... (591 bytes))

Does this method cause deletion?

// publish empty payload to remove the topic
void Mqtt::publish_ha(const std::string & topic) {
    if (!enabled()) {
        return;
    }

    std::string fulltopic = read_flash_string(F_(homeassistant)) + topic;
#if defined(EMSESP_DEBUG)
    LOG_DEBUG(F("[DEBUG] Publishing empty HA topic=%s"), fulltopic.c_str());
#endif

    publish(fulltopic); // call it immediately, don't queue it
}

If so, why do I not see the log message Publishing empty HA topic ... ?
Could it be that "publish" fails with an empty string?

If your broker is setup with a username and password then use:

    mosquitto_pub -h hostname -t the/topic -u username -P password -n -r -d

    Replace the hostname with the hostname or IP address of your broker (e.g. localhost)
    Replace the/topic with the topic that you want the retained messages cleared for
    Replace the username and password with… Well you know…

Options used in the mosquitto_pub 65 command:

    -n = Send a null (zero length) message
    -r = Retain the message as a “last known good” value on the broker
    -d = Enable debug messages


If you send only the topic, you will get Error: Both topic and message must be supplied.


// no payload
void Mqtt::publish(const std::string & topic) {
    queue_publish_message(topic, "", false);
}

Testcase - is working:

mosquitto_pub -h mbsbroker.home -p 1883 -u ******* -P ****** -t 'homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config' -n -r

It looks as if the "Remove" topic is logged, but does not arrive at the MQTT Brocker.
How can I check why this is so?

@proddy
Copy link
Contributor

proddy commented Dec 6, 2021

If so, why do I not see the log message Publishing empty HA topic ... ?

Those debug messages are only shown when the project is built with the -DEMSESP_DEBUG flag set (in pio_local.ini). It's for additional logging messages.

@zibous
Copy link
Author

zibous commented Dec 6, 2021

@proddy
Thanks, understand - the public build has not set the -DEMSESP_DEBUG flag
But why do i not see the topic on the Mosquitto Log ?

@proddy
Copy link
Contributor

proddy commented Dec 6, 2021

you have logging enabled on Mosquitto so it's basically capturing and reporting back on all traffic, which is handy now for debugging but later you should turn it off. The log messages look like the ones you sent from MQTTExplorer. Also I noticed the retain flag is on (r1). What we're looking for are MQTT publishes from EMS-ESP with an empty payload and no retain flag

@zibous
Copy link
Author

zibous commented Dec 7, 2021

@proddy

the log messages look like the ones you sent from MQTTExplorer

Yes, this message comes when I select the topic in MQTTExplorer to look at the payload.

Testcase - no topics on the mqtt brocker.

root@nuc2020:~# mosquitto_pub -h nuc2020.siebler.home  -p 1883 -u emstester -P KQvMhzJBfK9sjTB6K3Jg26jH8F -t 'homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config'  -n  -d
Client mosq-fGV0OHLP16QnBY2gXJ sending CONNECT
Client mosq-fGV0OHLP16QnBY2gXJ received CONNACK (0)
Client mosq-fGV0OHLP16QnBY2gXJ sending PUBLISH (d0, q0, r0, m1, 'homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config', ... (0 bytes))
Client mosq-fGV0OHLP16QnBY2gXJ sending DISCONNECT
## Adds an empty topic, even if flag delete is specified

root@nuc2020:~# mosquitto_pub -h nuc2020.siebler.home  -p 1883 -u emstester -P KQvMhzJBfK9sjTB6K3Jg26jH8F -t 'homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config'  -n  -d
Client mosq-BHKElKecyvOUHfBRqk sending CONNECT
Client mosq-BHKElKecyvOUHfBRqk received CONNACK (0)
Client mosq-BHKElKecyvOUHfBRqk sending PUBLISH (d0, q0, r0, m1, 'homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config', ... (0 bytes))
Client mosq-BHKElKecyvOUHfBRqk sending DISCONNECT
## Removes the topic

Mosquitto LOG

1638864341: Received PUBLISH from mosq-fGV0OHLP16QnBY2gXJ (d0, q0, r0, m0, 'homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config', ... (0 bytes))
1638864341: Sending PUBLISH to mqtt-explorer-393b5ca9 (d0, q0, r0, m0, 'homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config', ... (0 bytes))

1638864365: Received PUBLISH from mosq-BHKElKecyvOUHfBRqk (d0, q0, r0, m0, 'homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config', ... (0 bytes))
1638864365: Sending PUBLISH to mqtt-explorer-393b5ca9 (d0, q0, r0, m0, 'homeassistant/sensor/ems-heizung/thermostat_hc1_tempautotemp/config', ... (0 bytes))

Simple Test for async-mqtt-client:

void removeMqttTopic(){
   mqttClient.publish(MQTT_TOPIC, 0, true, "");
}
void publishMqttTopic(){
   mqttClient.publish(MQTT_TOPIC, 0, true, "{\"~\":\"ems-heizung\",\"uniq_id\":\"thermostat_hc1_tempautotemp\",\"stat_t\":\"~/thermostat_data\",\"name\":\"Thermostat hc1 temporary room temperature automode\",\"val_tpl\":\"{{value_json.hc1.tempautotemp}}\",\"unit_of_meas\":\"°C\",\"ic\":\"mdi:coolant-temperature\",\"dev\":{\"ids\":[\"ems-esp-thermostat\"]}}");
}



For me it is working, but do not handle the retain flag.
main.cpp.zip

@glitter-ball
Copy link

I'm still wondering if the retain flag is the clue. The two points I have problems with (tempautotemp and lastcode) are always sitting in MQTT Explorer with the retained flag set. When I clear the flag manually, they go away and stay gone!

So, my money is one something stopping that retained flag getting cleared. Mysterious. Weird. But that's what I'm seeing. I'm using the embedded Mosquitto broker in HA - maybe there's some weird issue buried in that?

@proddy
Copy link
Contributor

proddy commented Dec 8, 2021

it could be, but doubt it. But then again, I need to do some testing. In theory if you send a MQTT message to Mosquitto with topic homeassistant/...../config and an empty payload it should remove the entry from HA. It works in my tests regardless of the retain flag being set. When I'm back this weekend I'll work on a debug version so we can trace the MQTT removals and then with logging set on Mosquitto we should be able to see why it's not working.

By design all EMS-ESP HA config topics are created with the retain flag set because if the MQTT broker is restarted it will remember the last state and Home Assistant will continue to work.

@zibous
Copy link
Author

zibous commented Dec 9, 2021

@proddy

By design all EMS-ESP HA config topics are created with the retain flag set because if the MQTT broker is restarted it will remember the last state and Home Assistant will continue to work.

That's right and it works. I tested it native, with python scripts and with an ESP32 - not just with an MQTT brocker.
It looks like it only happens with EMS-ESP32.

Can I simply download the source code, compile (pio run) it locally with PlatformIO and then transfer the firmware.bin with OTA? Or do I have to pay attention to something special?

Test:

Retrieving maximum program size .pio/build/esp32/firmware.elf
Checking size .pio/build/esp32/firmware.elf
Advanced Memory Usage is available via "PlatformIO Home > Project Inspect"
RAM:   [==        ]  15.1% (used 49352 bytes from 327680 bytes)
Flash: [========  ]  81.3% (used 1652470 bytes from 2031616 bytes)
Building .pio/build/esp32/firmware.bin
esptool.py v3.1
Merged 1 ELF section
bin_copy([".pio/build/esp32/firmware.bin"], [".pio/build/esp32/firmware.elf"])
app version: 3.3.1b0
platform: ESP32
renaming file to build/firmware/EMS-ESP-3_3_1b0-ESP32.bin
[SUCCESS] Took 99.64 seconds 

Environment    Status    Duration
-------------  --------  ------------
esp32          SUCCESS   00:01:39.636
===========================

**************************************
There is a new version 5.2.3 of PlatformIO available.
Please upgrade it via `platformio upgrade` or `pip install -U platformio` command.
Changes: https://docs.platformio.org/en/latest/history.html

@zibous
Copy link
Author

zibous commented Dec 9, 2021

@proddy

Note:
I am using the Docker version of Homeassistant. With Docker Watch, the latest version is usually installed at night and the home assistant is restarted. At this point in time I get the warning message from EMS-ESP32:


Logger: homeassistant.helpers.template
Source: helpers/template.py:1779
First occurred: 05:02:10 (4 occurrences)
Last logged: 05:02:33

Template variable warning: 'dict object' has no attribute 'tempautotemp' when rendering '{{value_json.hc1.tempautotemp}}'
--------
2021-12-09 05:02:30.110    INFO 374:    [thermostat] Setting thermostat mode to auto for heating circuit 1
2021-12-09 05:02:30.129    INFO 375:    [thermostat] Setting thermostat temperature to 24.0 for heating circuit 1, mode auto
2021-12-09 05:16:06.898 WARNING 376:    [telegram]   Incomplete Rx: FE 08 00 18 00 2A 01 5D 64 00 01 01 20 40 80 00 02 1C 80 00 00 00 FF 30 41 00 CA 00 00 00
2021-12-09 05:30:49.140 WARNING 377:    [mqtt]       Lost device value for thermostat_hc1_tempautotemp. Removing HA config

During my second installation on a different computer, the Homassistant runs and is not updated. I don't see the warning there.

@proddy
Copy link
Contributor

proddy commented Dec 9, 2021

I'm also running both HA and Mosquitto as docker containers, with watch grabbing any updates. I think what you need to do is

  • build the firmware yourself. Create an pio_local.ini using the example file and uncomment the line at the top called -DEMSESP_DEBUG. That will provide additional debug messages
  • See if when EMS-ESP detects a missing entity, like lastcode or tempautotemp that its actually physically removed from the MQTT broker with an empty payload. I think you'll be able to see this from the Mosquitto logs.
  • Like i said, in my simulation testing it seems to work.

@zibous
Copy link
Author

zibous commented Dec 9, 2021

@proddy

Like i said, in my simulation testing it seems to work.

o.k 💯

I will try it and wait for the end of your simulations.
Thanks for your help and time.

@MichaelDvP
Copy link
Contributor

@zibous

the latest version is usually installed at night and the home assistant is restarted. At this point in time I get the warning message from EMS-ESP32:

Could be: the set message has retain set, the remove publish not, after restart the broker uses the latest retain message, and set the config for tempautotemp. Try to send the remove message also with retain (replace mqtt.ccp, line 752 with:)
queue_publish_message(fulltopic, "", true); // with retain true

btw: i think tempautotemp is a useless value, if set the information is also in seltemp and after next autoswitch it goes to not set. Writing to temp/seltemp in automode sets the tempautotemp value, also no need to publish/subscribe it. But users wanted it: see #141

@proddy
Copy link
Contributor

proddy commented Dec 9, 2021

ah, perhaps yes. It's worth checking if those topics reappear after the MQTT broker is bounced.

one of things I was planning on building next into the webUI is the ability to choose which entities to show (api, mqtt, console, web dashboard). So users can just disable tempautotemp.

@glitter-ball
Copy link

Sorry to butt in... just catching up with all this.

So, I have the ongoing issue of lots of logged errors:
2021-12-10 17:14:46 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'lastcode' when rendering '{{value_json.lastcode}}'

and an orphaned point in MQTT Explorer with the retained bit set:
image

If I clear the retained flag, it'll be gone for good. Problem seems to re-occur if the gateway restarts.

I'm running v3.3.0b11 - is there a later version to try that might sort this? Thanks.

@elRadix
Copy link

elRadix commented Dec 12, 2021

I also have these kind of errors in home assistance, not able to get rid off
4619 occurrences) just a couple hours
I am using the latest EMS-ESP Version v3.3.1b0


Logger: homeassistant.helpers.template
Source: helpers/template.py:1779
First occurred: 11:55:11 (4619 occurrences)
Last logged: 12:50:41

Template variable warning: 'dict object' has no attribute 'setflowtemp' when rendering '{{value_json.setflowtemp}}'
Template variable warning: 'dict object' has no attribute 'setburnpow' when rendering '{{value_json.setburnpow}}'
Template variable warning: 'dict object' has no attribute 'servicecode' when rendering '{{value_json.servicecode}}'
Template variable warning: 'dict object' has no attribute 'wwsetpumppower' when rendering '{{value_json.wwsetpumppower}}'
Template variable warning: 'dict object' has no attribute 'duration' when rendering '{{ value_json.duration }}'

@proddy
Copy link
Contributor

proddy commented Dec 17, 2021

@glitter-ball
Copy link

@elRadix - what can you see in MQTT Explorer (or similar) about these points?

@proddy
Copy link
Contributor

proddy commented Jan 3, 2022

this should hopefully be fixed now in 3.4

@proddy proddy closed this as completed Jan 3, 2022
@proddy proddy added this to the v3.4 milestone Jan 3, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

5 participants