MQTT Import time lack
Moderators: grovkillen, Stuntteam, TD-er
MQTT Import time lack
Monitoring my small solar project I noticed now and then, that between a published message from the sending devices the correct data arrive in ESPEasy with a - sometimes huge - lack of time.
Are the imported messages somehow queued or buffered? If yes, is there a way to avoid reactions sometimes way far away from reality?
Are the imported messages somehow queued or buffered? If yes, is there a way to avoid reactions sometimes way far away from reality?
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
You have reported unexpected rebooting of the ESP with many tasks running this plugin concurrently. Is that a possible cause here?
Reboots can also be caused when large (JSON?) messages are being received by the ESP. You could connect to the serial port of the ESP to see all logging, as the weblog can't be updated during boot, because of the WiFi not yet being started.
Also, if the message can't be delivered, the MQTT server will keep retrying until it is delivered. That's by design.
Reboots can also be caused when large (JSON?) messages are being received by the ESP. You could connect to the serial port of the ESP to see all logging, as the weblog can't be updated during boot, because of the WiFi not yet being started.
Also, if the message can't be delivered, the MQTT server will keep retrying until it is delivered. That's by design.
/Ton (PayPal.me)
Re: MQTT Import time lack
No reboots.
The longest JSON is the one you helped me to parse.
Looking at the different monitors I can see, a value is published by one of the other devices. At that time ESPEasy receives something, but the value it receives (resp. processes) is somewhat 60-100 secs in the past. No data loss, some 60-100 secs the (too old) data appear later in ESPEasy. And if the ESP32 is in this "buffering" state it doesn't matter from which source the data are imported, they are just too old.
For me it looks like a FIFO buffer......hard to document and to describe..........and I've found up to no way to reproduce.......
After reboot of the ESP32 everything is back working again.
The longest JSON is the one you helped me to parse.
Looking at the different monitors I can see, a value is published by one of the other devices. At that time ESPEasy receives something, but the value it receives (resp. processes) is somewhat 60-100 secs in the past. No data loss, some 60-100 secs the (too old) data appear later in ESPEasy. And if the ESP32 is in this "buffering" state it doesn't matter from which source the data are imported, they are just too old.
For me it looks like a FIFO buffer......hard to document and to describe..........and I've found up to no way to reproduce.......
After reboot of the ESP32 everything is back working again.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Does ESPEasy disconnect/reconnect with the MQTT broker?
Re: MQTT Import time lack
No, no disconnects. And no loss of informations,
When the effect is visible, in ESPEasy I receive the messages with a time discrepance of 60-100 secs. But the data are received. Just too late.
Looking online at the log of ESPEasy it tells me around 60 secs later it has received the data which were sent 60 secs earlier as to be seen in an another mqtt client running in parallel. The data are identified to be received, only too late. And in case the effect happens permanently until I reboot the device. And no matter which other device is publishing the data, all of them are affected.
Like I already said: Looks like a FIFO buffer.
When the effect is visible, in ESPEasy I receive the messages with a time discrepance of 60-100 secs. But the data are received. Just too late.
Looking online at the log of ESPEasy it tells me around 60 secs later it has received the data which were sent 60 secs earlier as to be seen in an another mqtt client running in parallel. The data are identified to be received, only too late. And in case the effect happens permanently until I reboot the device. And no matter which other device is publishing the data, all of them are affected.
Like I already said: Looks like a FIFO buffer.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
60 seconds does sound a bit "too perfect" matching a frequently used default timeout/interval for lots of tasks.
Have to check the source code to see if this even is used, but I do find it a bit suspicious to see this value being mentioned here.
Have to check the source code to see if this even is used, but I do find it a bit suspicious to see this value being mentioned here.
Re: MQTT Import time lack
Any chance that the time of the ESP is off by 60 seconds? There has been work done in the time-sync/NTP code recently, maybe you have a situation where an unexpected offset is introduced.
/Ton (PayPal.me)
Re: MQTT Import time lack
That would then only have an effect on the reported timestamp, not a delay in receiving the data.
But it is worth checking out to see what we're looking at.
Is it a real delay in processing, or just misreporting the timestamps?
But it is worth checking out to see what we're looking at.
Is it a real delay in processing, or just misreporting the timestamps?
Re: MQTT Import time lack
Erm, I didn't have a look at the system time of the ESP.
I don't know anything about the data structure of the mqtt protocol - if there is a timestamp and if the data are buffered. But if the MQTT import has a look at the timestamp of the messages and interpretes it for import the behaviour of the system makes sense in case of a timeshift.
I try once again to explain, whats happening:
One device is sending a data set into mqtt, we name it "data set 1". This "data set 1" appears instantly in the mqtt monitor running in parallel on my tablet. At the same time (it feels like) ESPEasy imports a data set (somewhat "data set -10") which has been sent some time before. After 60-100 secs this "data set 1" sent by the device appears in MQTT Import.
I don't know if my description is understandable, but I can't describe better. For me the misbehaviour is not reproducable and happens only now and then. And I've noticed it only by accident, the ESP itself is running stable with no hints or hickups.
I don't know anything about the data structure of the mqtt protocol - if there is a timestamp and if the data are buffered. But if the MQTT import has a look at the timestamp of the messages and interpretes it for import the behaviour of the system makes sense in case of a timeshift.
I try once again to explain, whats happening:
One device is sending a data set into mqtt, we name it "data set 1". This "data set 1" appears instantly in the mqtt monitor running in parallel on my tablet. At the same time (it feels like) ESPEasy imports a data set (somewhat "data set -10") which has been sent some time before. After 60-100 secs this "data set 1" sent by the device appears in MQTT Import.
I don't know if my description is understandable, but I can't describe better. For me the misbehaviour is not reproducable and happens only now and then. And I've noticed it only by accident, the ESP itself is running stable with no hints or hickups.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
And don't take the 60-100 secs as a concrete measurement. Its was more a feeling.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Do you have timing statistics enabled on your node, so you can have a look at the timing stats?
Maybe we can see something there which might take a lot more time than we would like.
Not sure if the MQTT import can take so long to process data that it may cause a queue in messages to process.
Maybe we can see something there which might take a lot more time than we would like.
Not sure if the MQTT import can take so long to process data that it may cause a queue in messages to process.
Re: MQTT Import time lack
I only have limited possibilties to monitor. But just right now I have seen in a split screen that there was a time lack between the "log" on the Raspberry (mosquitto_sub -t "#" | grep Watt) and the change of the device in Domoticz of 32 secs. After reboot the time lack went down to around 4 secs. Which is normal I think due to processing time in ESPEasy.
Unfortunately I didn't have a look at the time of the ESP. Seems that the time lack increases during running time. I will continue monitoring if I have the time to and will report, hopefully with more accurate informations.
Unfortunately I didn't have a look at the time of the ESP. Seems that the time lack increases during running time. I will continue monitoring if I have the time to and will report, hopefully with more accurate informations.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Erm, where could I enable "timing statistics"?
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
We may have to look at how the MQTT client is being called.
It used to be just 'flushing' data to the broker.
So maybe the MQTT client should be called more often to check its status (flushing data and fetching messages).
You could try sending some 'bogus' data from another task to the broker.
For example sysinfo task running at an interval of 1sec, sending to the MQTT controller.
Maybe this increases the number of interactions per sec for the MQTT client?
Timing stats can be enabled at the Tools->Advanced page (near the bottom).
N.B. those may not be included in all builds.
It used to be just 'flushing' data to the broker.
So maybe the MQTT client should be called more often to check its status (flushing data and fetching messages).
You could try sending some 'bogus' data from another task to the broker.
For example sysinfo task running at an interval of 1sec, sending to the MQTT controller.
Maybe this increases the number of interactions per sec for the MQTT client?
Timing stats can be enabled at the Tools->Advanced page (near the bottom).
N.B. those may not be included in all builds.
Re: MQTT Import time lack
Found the hook for timing stats.
Which information do you need when?
Which information do you need when?
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Just have a look at stuff that typically takes > 100 msec (highlighted)
But for significant delays in MQTT processing, we might have to look at other values too.
For example how often are those functions called?
If the import calls per second are really low, then we need to have a look at those.
If they are similar to the nr. of calls to send via the MQTT controller, then we may have some indication those are "synced".
So there is not just a single value to look at.
N.B. every time you reload this timing stats page, the stats are cleared.
Thus better let it run for a few minutes.
But for significant delays in MQTT processing, we might have to look at other values too.
For example how often are those functions called?
If the import calls per second are really low, then we need to have a look at those.
If they are similar to the nr. of calls to send via the MQTT controller, then we may have some indication those are "synced".
So there is not just a single value to look at.
N.B. every time you reload this timing stats page, the stats are cleared.
Thus better let it run for a few minutes.
Re: MQTT Import time lack
I did some logging in ESPEasy and in my Raspberry in parallel.
ESPEasy:
Raspi:
If you have a look at the last lines ESPEasy is already around 19 secs behind.
Timing Stats:
I hope its helpful.....
ESPEasy:
Code: Select all
262797: 13:01:17-Watt(2),1
273161: 13:01:27-Watt(-5),1
282785: 13:01:36-Watt(-4),1
292693: 13:01:46-Watt(-5),1
303079: 13:01:56-Watt(-5),1
313656: 13:02:07-Watt(-6),1
324963: 13:02:18-Watt(2),1
335934: 13:02:29-Watt(1),1
345009: 13:02:38-Watt(0),1
353621: 13:02:47-Watt(1),1
363794: 13:02:57-Watt(16),1
374001: 13:03:07-Watt(1),1
385006: 13:03:18-Watt(7),1
395384: 13:03:29-Watt(1),1
404763: 13:03:38-Watt(4),1
412299: 13:03:46-Watt(4),1
423654: 13:03:57-Watt(12),1
432809: 13:04:06-Watt(3),1
446974: 13:04:20-Watt(10),1
Code: Select all
{"Time":"2022-11-21T13:01:01","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":2}}
{"Time":"2022-11-21T13:01:11","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":-5}}
{"Time":"2022-11-21T13:01:21","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":-4}}
{"Time":"2022-11-21T13:01:31","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":-5}}
{"Time":"2022-11-21T13:01:41","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":-5}}
{"Time":"2022-11-21T13:01:51","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":-6}}
{"Time":"2022-11-21T13:02:01","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":2}}
{"Time":"2022-11-21T13:02:11","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":1}}
{"Time":"2022-11-21T13:02:21","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":0}}
{"Time":"2022-11-21T13:02:31","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":1}}
{"Time":"2022-11-21T13:02:41","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":16}}
{"Time":"2022-11-21T13:02:51","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":1}}
{"Time":"2022-11-21T13:03:01","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":7}}
{"Time":"2022-11-21T13:03:11","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":1}}
{"Time":"2022-11-21T13:03:21","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":4}}
{"Time":"2022-11-21T13:03:31","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":4}}
{"Time":"2022-11-21T13:03:41","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":12}}
{"Time":"2022-11-21T13:03:51","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":3}}
{"Time":"2022-11-21T13:04:01","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":10}}
{"Time":"2022-11-21T13:04:11","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":9}}
{"Time":"2022-11-21T13:04:21","SML":{"Verbrauch":23.230,"Einspeisung":1.201,"Watt":11}}
Timing Stats:
I hope its helpful.....
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
You better try to load that timing stats page at the beginning, to clear the stats.
Now there's a lot of recorded calls in it from before the ESP got connected.
For example the calls to WiFi.isConnected() with a false return value.
Now I have no idea whether it may try to reconnect inbetween.
Also you seem to receive 6.7 MQTT messages per second.
No idea what the broker may do when a message is not acknowledged by the client.
This also depends on the QoS level used to send messages to the broker.
Now there's a lot of recorded calls in it from before the ESP got connected.
For example the calls to WiFi.isConnected() with a false return value.
Now I have no idea whether it may try to reconnect inbetween.
Also you seem to receive 6.7 MQTT messages per second.
No idea what the broker may do when a message is not acknowledged by the client.
This also depends on the QoS level used to send messages to the broker.
Re: MQTT Import time lack
OK, once again:
ESPEasy:
Raspberry:
Timing Stats:
Does MQTT 6.7/secs mean my overall MQTT traffic? The devices I want to fetch are sending every 5 (Ahoy) and every 10 (Volkszähler) seconds.
ESPEasy:
Code: Select all
1194215: 13:45:20-Watt(-13),1
1208505: 13:45:34-Watt(45),1
1208718: 13:45:34-PowerSet(165),1
1216774: 13:45:42-Watt(37),1
1225015: 13:45:50-Watt(46),1
1231875: 13:45:57-Watt(-3),1
1241571: 13:46:07-Watt(-11),1
1252682: 13:46:18-Watt(-8),1
1262493: 13:46:28-Watt(-4),1
1272235: 13:46:38-Watt(-10),1
1281826: 13:46:47-Watt(-5),1
1290922: 13:46:56-Watt(-10),1
1301993: 13:47:07-Watt(-9),1
1314581: 13:47:20-Watt(-2),1
1323495: 13:47:29-Watt(-2),1
1333333: 13:47:39-Watt(-1),1
1345059: 13:47:50-Watt(-10),1
1356116: 13:48:01-Watt(-15),1
1365417: 13:48:11-Watt(-19),1
1365669: 13:48:11-PowerSet(146),1
1377702: 13:48:23-Watt(-11),1
1388176: 13:48:34-Watt(-17),1
1397995: 13:48:43-Watt(-6),1
1404683: 13:48:50-Watt(-8),1
1415621: 13:49:01-Watt(-10),1
1424171: 13:49:10-Watt(-9),1
1433948: 13:49:19-Watt(-10),1
1444652: 13:49:30-Watt(14),1
1444867: 13:49:30-PowerSet(163),1
1455091: 13:49:40-Watt(21),1
Code: Select all
{"Time":"2022-11-21T13:45:01","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":-13}}
{"Time":"2022-11-21T13:45:11","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":45}}
{"Time":"2022-11-21T13:45:21","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":37}}
{"Time":"2022-11-21T13:45:31","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":46}}
{"Time":"2022-11-21T13:45:41","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":-3}}
{"Time":"2022-11-21T13:45:51","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":-11}}
{"Time":"2022-11-21T13:46:01","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":-8}}
{"Time":"2022-11-21T13:46:11","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":-4}}
{"Time":"2022-11-21T13:46:21","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":-10}}
{"Time":"2022-11-21T13:46:31","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":-5}}
{"Time":"2022-11-21T13:46:41","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":-10}}
{"Time":"2022-11-21T13:46:51","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":-9}}
{"Time":"2022-11-21T13:47:01","SML":{"Verbrauch":23.239,"Einspeisung":1.214,"Watt":-2}}
{"Time":"2022-11-21T13:47:11","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-2}}
{"Time":"2022-11-21T13:47:21","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-1}}
{"Time":"2022-11-21T13:47:31","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-10}}
{"Time":"2022-11-21T13:47:41","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-15}}
{"Time":"2022-11-21T13:47:51","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-19}}
{"Time":"2022-11-21T13:48:01","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-11}}
{"Time":"2022-11-21T13:48:11","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-17}}
{"Time":"2022-11-21T13:48:21","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-6}}
{"Time":"2022-11-21T13:48:31","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-8}}
{"Time":"2022-11-21T13:48:41","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-10}}
{"Time":"2022-11-21T13:48:51","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-9}}
{"Time":"2022-11-21T13:49:01","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":-10}}
{"Time":"2022-11-21T13:49:11","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":14}}
{"Time":"2022-11-21T13:49:21","SML":{"Verbrauch":23.239,"Einspeisung":1.215,"Watt":21}}
{"Time":"2022-11-21T13:49:31","SML":{"Verbrauch":23.240,"Einspeisung":1.215,"Watt":21}}
{"Time":"2022-11-21T13:49:41","SML":{"Verbrauch":23.240,"Einspeisung":1.215,"Watt":5}}
{"Time":"2022-11-21T13:49:51","SML":{"Verbrauch":23.240,"Einspeisung":1.215,"Watt":0}}
{"Time":"2022-11-21T13:50:01","SML":{"Verbrauch":23.240,"Einspeisung":1.215,"Watt":0}}
{
Does MQTT 6.7/secs mean my overall MQTT traffic? The devices I want to fetch are sending every 5 (Ahoy) and every 10 (Volkszähler) seconds.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
It means the MQTT client did receive some message at a rate of 6.7x sec.
If your node does subscribe to topic(s) also used by other nodes, then this may become a bottle neck.
Another possible bottle neck is the call to TryOpenFile() at roughly 29x per sec.
The ESP32 is a lot slower with file access, so this may keep the ESP board at 100% load at this rate.
Do you happen to have the rules cache disabled?
No idea why it needs to load the task settings at such an incredible high rate. That's often only needed to get the task name and taskvalue name.
But those should be cached. This cache was added because the ESP32 was having issues with reading files at a much slower rate compared to the ESP8266.
You also see an incredible slow down on the ESP32 regarding event handling when it is slowed down like this.
I think we have to focus on why it needs to open the settings file so often.
If your node does subscribe to topic(s) also used by other nodes, then this may become a bottle neck.
Another possible bottle neck is the call to TryOpenFile() at roughly 29x per sec.
The ESP32 is a lot slower with file access, so this may keep the ESP board at 100% load at this rate.
Do you happen to have the rules cache disabled?
No idea why it needs to load the task settings at such an incredible high rate. That's often only needed to get the task name and taskvalue name.
But those should be cached. This cache was added because the ESP32 was having issues with reading files at a much slower rate compared to the ESP8266.
You also see an incredible slow down on the ESP32 regarding event handling when it is slowed down like this.
I think we have to focus on why it needs to open the settings file so often.
Re: MQTT Import time lack
Erm, it looks like you've pushed me in the right direction together with my feeling, that somewhere the data are queued/spooled/buffered/whatever.
I had a look at the (default) mosquitto.conf. There was an entry persistent=true. On the other side - my tiny ESP32 - the hook "Clean Session" in the controller section wasn't set.
I don't know whatfor I could need the persistance, so I switched it off in the mosquitto configuration, restarted mosquitto and since almost an hour the communication is in almost perfect sync.
Am I right, that this combination might have been the source of my problem?
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Rules cache is enabled.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
More like the 'trigger' of your problem.
Still I wonder why your setup needs to read the ExtraTaskSettings so often.
Re: MQTT Import time lack
More: one of the tasks /four values) is subscribed to domoticz/in with JSON parsing, filtered by idx, in another task two values are subscribed to domoticz/out, filtered by idx, too.
I will change at least the import of topics from domoticz/in and see what happens...
I will change at least the import of topics from domoticz/in and see what happens...
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Well, domoticz made a very unfortunate design choice back in the day to have a single topic for all nodes.
This doesn't scale very well.
I will try to look at both the Domoticz code and the MQTT import to see if some functions don't use the cached values, or maybe request something that isn't (yet) cached.
This doesn't scale very well.
I will try to look at both the Domoticz code and the MQTT import to see if some functions don't use the cached values, or maybe request something that isn't (yet) cached.
Re: MQTT Import time lack
Digging a little bit deeper I've seen a huge amount of messages on topic domoticz/out. Häh? Why?
The configuration in Domoticz's MQTT Client gateway for "Prevent Loop" was set to false. No good idea. Set to true lowers:
Incoming MQTT to 1.32/sec
Load Task Settings to 3.9/sec
TryOpenFile to 5.61/sec
Better?
The configuration in Domoticz's MQTT Client gateway for "Prevent Loop" was set to false. No good idea. Set to true lowers:
Incoming MQTT to 1.32/sec
Load Task Settings to 3.9/sec
TryOpenFile to 5.61/sec
Better?
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
For sure more manageble.
However it still bothers me to see so many calls to LoadTaskSettings.
Those should be next to 0, unless you're writing to some files which clears the cache.
On ESP8266 this is different, as we simply haven't got as much memory available for caching.
So have to check the code for this.
However it still bothers me to see so many calls to LoadTaskSettings.
Those should be next to 0, unless you're writing to some files which clears the cache.
On ESP8266 this is different, as we simply haven't got as much memory available for caching.
So have to check the code for this.
Re: MQTT Import time lack
Hi,
I think I can reproduce the behaviour of timeshift between sent and received data. Yesterday in the evening I realized that I have to disable the setting "Prevent Loop" in the MQTT client gateway of Domoticz because otherwise publishing the "command":"switchlight" for Domoticz to switch on/off whatever doesn't work. Overnight everything was fine, sync perfectly.
Until: In the device we are talking about here I have one task with four values subscribed to domoticz/in with JSON parsing/filter on idx. Yesterday I disabled the task. I just tried to reenable the task today morning. At the moment I enable the task the timeshift tooks place. Instantly there is a shift of aroung 5-9 secs. I suppose it will increase. Disabling the task results instantly in almost perfect sync between sent/received data, max. shift of 1 sec. For this scenario I monitored the MQTT Import with JSON Filter in second level "SML.Watt" as described in this thread.
MQTT receives stay at aroung 4.5/sec, LoadTaskSettings around 14/sec as documented before.
Summarized what left from my different tries:
- disabling persistance in mosquitto.conf
- enabling "Clean Session" in Domoticz MQTT controller
- disabling the subscription to domoticz/in
And yes, as I have learned now, I have a pretty high MQTT traffic in my network. E.g. Ahoy publishes every 5 secs 43 values in seperated topics, my Tasmota (20) devices are publishing every 60 secs except the Volkszähler (every 10 secs) which are duplicated by Domoticz with disabled "Prevent Loop", my ESPEasies (10) are publishing various data in 15-60 secs interval, duplicated by Domoticz, too.
Hope, this helps.
I think I can reproduce the behaviour of timeshift between sent and received data. Yesterday in the evening I realized that I have to disable the setting "Prevent Loop" in the MQTT client gateway of Domoticz because otherwise publishing the "command":"switchlight" for Domoticz to switch on/off whatever doesn't work. Overnight everything was fine, sync perfectly.
Until: In the device we are talking about here I have one task with four values subscribed to domoticz/in with JSON parsing/filter on idx. Yesterday I disabled the task. I just tried to reenable the task today morning. At the moment I enable the task the timeshift tooks place. Instantly there is a shift of aroung 5-9 secs. I suppose it will increase. Disabling the task results instantly in almost perfect sync between sent/received data, max. shift of 1 sec. For this scenario I monitored the MQTT Import with JSON Filter in second level "SML.Watt" as described in this thread.
MQTT receives stay at aroung 4.5/sec, LoadTaskSettings around 14/sec as documented before.
Summarized what left from my different tries:
- disabling persistance in mosquitto.conf
- enabling "Clean Session" in Domoticz MQTT controller
- disabling the subscription to domoticz/in
And yes, as I have learned now, I have a pretty high MQTT traffic in my network. E.g. Ahoy publishes every 5 secs 43 values in seperated topics, my Tasmota (20) devices are publishing every 60 secs except the Volkszähler (every 10 secs) which are duplicated by Domoticz with disabled "Prevent Loop", my ESPEasies (10) are publishing various data in 15-60 secs interval, duplicated by Domoticz, too.
Hope, this helps.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Yesterday Ton already removed an unneeded call to LoadTaskSettings().
So on the next build it should already perform better.
You can test it here: https://github.com/letscontrolit/ESPEas ... 3517744710
So on the next build it should already perform better.
You can test it here: https://github.com/letscontrolit/ESPEas ... 3517744710
Re: MQTT Import time lack
First quick checK:
No timeshift anymore, perfectly synchronious send/receive, even with enabled domoticz/in subscription!
Way better performance of Web GUI
Almost no hesitation in publishing data for Domoticz (before it took at least two seconds before the data appeared in Web frontend from Domoticz)
MQTT receive down to 1.3/sec
LoadTaskSettings down to 5.3/sec
The real check will come tomorrow, when sun is shining and Ahoy is publishing.
Thank you guys, feels good, well done
No timeshift anymore, perfectly synchronious send/receive, even with enabled domoticz/in subscription!
Way better performance of Web GUI
Almost no hesitation in publishing data for Domoticz (before it took at least two seconds before the data appeared in Web frontend from Domoticz)
MQTT receive down to 1.3/sec
LoadTaskSettings down to 5.3/sec
The real check will come tomorrow, when sun is shining and Ahoy is publishing.
Thank you guys, feels good, well done
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
[OT On]
System Info / System Status Web Log Level shows "None"
This is incorrect, I've set it to "Error"
[/OT Off]
System Info / System Status Web Log Level shows "None"
This is incorrect, I've set it to "Error"
[/OT Off]
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Web log level is dynamic and is based on whether you fetch the logs.
So the shown log level is the actual log level.
Re: MQTT Import time lack
Overnight I left the task with four subscriptions to domoticz/in on. Now with sunlight and Ahoy publishing its 43 values every 5 secs as well as the four domoticz/in values published (from my Raspberry, its a relict from my first tries to get the project run) there was a timeshift of around 9 secs visible.
The TimingStats of around 14h told me a LoadTaskSettings of 9.2/sec., MQTT receive of 2.3/sec. Refreshing TimingStats and having a look on the stats after 15 minutes it tells me a LoadTaskSettings of 11.88, a MQTT receive of around 4/sec
Disabling the task with the four domoticz/in subsribed topics results - again - in an almost perfect sync of sent/received.
The TimingStats of around 14h told me a LoadTaskSettings of 9.2/sec., MQTT receive of 2.3/sec. Refreshing TimingStats and having a look on the stats after 15 minutes it tells me a LoadTaskSettings of 11.88, a MQTT receive of around 4/sec
Disabling the task with the four domoticz/in subsribed topics results - again - in an almost perfect sync of sent/received.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
That's cool, never stop learning
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Additional information:
I've changed the task with the four subscriptions to domoticz/in to import the data directly from source, Resp. I've changed the import from JSON parsing&filtering to lean MQTT Import without any options. At this moment the LoadTaskSettings raise from 12/sec to >20/sec.
For doublecheck I disabled this task and a another one with four subscription without any options and the LoadTaskSettings decreased from 12/sec to 7/sec.
Third check: I do have a "mixed" MQTT Import task, which contains two MQTT subscriptions without options (lean MQTT topics) and two subscriptions to domoticz/out with JSON parsing&filtering which I disabled. The LoadTaskSettings decreased to 0.01/sec (!).
Summarized: for me it looks like that the LoadTaskSettings calls are located in the code section for importing lean MQTT topics due to the fact, that the task with four subscriptions to domoticz/in with JSON parsing&filtering didn't affect the LoadTaskSettings, neither the remaing task with pure JSON parsing&filtering does, but every task with direct import of MQTT topi does.
I've changed the task with the four subscriptions to domoticz/in to import the data directly from source, Resp. I've changed the import from JSON parsing&filtering to lean MQTT Import without any options. At this moment the LoadTaskSettings raise from 12/sec to >20/sec.
For doublecheck I disabled this task and a another one with four subscription without any options and the LoadTaskSettings decreased from 12/sec to 7/sec.
Third check: I do have a "mixed" MQTT Import task, which contains two MQTT subscriptions without options (lean MQTT topics) and two subscriptions to domoticz/out with JSON parsing&filtering which I disabled. The LoadTaskSettings decreased to 0.01/sec (!).
Summarized: for me it looks like that the LoadTaskSettings calls are located in the code section for importing lean MQTT topics due to the fact, that the task with four subscriptions to domoticz/in with JSON parsing&filtering didn't affect the LoadTaskSettings, neither the remaing task with pure JSON parsing&filtering does, but every task with direct import of MQTT topi does.
Last edited by Wiki on 23 Nov 2022, 11:37, edited 1 time in total.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
so do I
![Erg Blij :D](./images/smilies/icon_e_biggrin.gif)
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
I took a quick look at the code and found this one:
https://github.com/letscontrolit/ESPEas ... 2.cpp#L183
I think this is the culprit for all those calls to LoadTaskSettings().
https://github.com/letscontrolit/ESPEas ... 2.cpp#L183
I think this is the culprit for all those calls to LoadTaskSettings().
Re: MQTT Import time lack
Just another question.
Do you also use a formula in one of your tasks?
Do you also use a formula in one of your tasks?
Re: MQTT Import time lack
No, no formulas.
Vales are processed in my rules if necessary.
Vales are processed in my rules if necessary.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Are you using a dallas sensor?
I'm now looking into all corners of the software where there may be use of ExtraTaskSettings.
The Dallas code does seem to use it for fetching stored 1Wire sensor addresses.
I'm now looking into all corners of the software where there may be use of ExtraTaskSettings.
The Dallas code does seem to use it for fetching stored 1Wire sensor addresses.
Re: MQTT Import time lack
No. This device is using 4 tasks MQTT Import and 2 tasks Dummy. No further tasks or sensors.
In rules dependig on a five-seconds-event I am publishing seven values to Domoticz, depending on a ten-seconds-event three values to Domoticz (both are triggered by MQTT Import events, 3-4 calculations processed using %v1%&%v2%), every minute one SendToHttp.
In rules dependig on a five-seconds-event I am publishing seven values to Domoticz, depending on a ten-seconds-event three values to Domoticz (both are triggered by MQTT Import events, 3-4 calculations processed using %v1%&%v2%), every minute one SendToHttp.
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
If you need some beta testing I would be pleased if I could do this for you. My project is not yet time critical, I can play around as much as I want. Hardware is till close to my laptop, nothing I couldn't influence manually. Time is no question currently. Open for any stupidity
.
![Knipoog ;-)](./images/smilies/icon_e_wink.gif)
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
And btw.: using ESP32_normal_4M316k
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
Lots of opportunities from my side to let you test stupid code.
https://www.dropbox.com/s/90bbvgr6v99b5 ... y.zip?dl=0
State of the code: It compiles (not yet tested)
I did add some more caching to reduce the number of calls to LoadTaskSettings().
I noticed there still one of those in the parse function to process strings so you can try to replace variables.
Given what you just wrote, I guess that call may still be affecting performance.
https://www.dropbox.com/s/90bbvgr6v99b5 ... y.zip?dl=0
State of the code: It compiles (not yet tested)
I did add some more caching to reduce the number of calls to LoadTaskSettings().
I noticed there still one of those in the parse function to process strings so you can try to replace variables.
Given what you just wrote, I guess that call may still be affecting performance.
Re: MQTT Import time lack
This one should address those issues too: https://www.dropbox.com/s/8nyp6on9a3ihb ... 9.zip?dl=0
I found a few calls to MQTT import related code where the LoadTaskSettings() is being called where it isn't needed.
I found a few calls to MQTT import related code where the LoadTaskSettings() is being called where it isn't needed.
Re: MQTT Import time lack
I'll report.....
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
....tomorrow, due to lack of sun I don't get any messages more to receive.....
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Re: MQTT Import time lack
OK, then you will probably have an even newer build to test ![Lach :)](./images/smilies/icon_e_smile.gif)
![Lach :)](./images/smilies/icon_e_smile.gif)
Re: MQTT Import time lack
I flashed the second one you've posted.
Hey man, you are kidding me. First of all I had a look at the sent/received sync. ESPEasy now is looking into the future, receive is logged one second before the time the timestamp of the Volkszähler topics show. Pretty fast, I think
And in the Timing Stats LoadTaskSettings even doesn't appear. Be honest: You've took it out of the statistic list, right?
Seriously:
There seems to be a small timeshift on the Tasmota device. First time I've noticed that, up to now ESPEasy was constantly similar or in the past.
Starting the Timing Stats page for the first time LoadTaskSettings appeared with somewhat like 0.2/sec. If now I want to have an entry there I have to open the Task Settings manually. TryOpenFile shows constantly 0.3/sec.
Seems as if you've put the finger right into the wound.
Looking forward to future testing, sincerely......
Hey man, you are kidding me. First of all I had a look at the sent/received sync. ESPEasy now is looking into the future, receive is logged one second before the time the timestamp of the Volkszähler topics show. Pretty fast, I think
![Mr. Groen :mrgreen:](./images/smilies/icon_mrgreen.gif)
And in the Timing Stats LoadTaskSettings even doesn't appear. Be honest: You've took it out of the statistic list, right?
Seriously:
There seems to be a small timeshift on the Tasmota device. First time I've noticed that, up to now ESPEasy was constantly similar or in the past.
Starting the Timing Stats page for the first time LoadTaskSettings appeared with somewhat like 0.2/sec. If now I want to have an entry there I have to open the Task Settings manually. TryOpenFile shows constantly 0.3/sec.
Seems as if you've put the finger right into the wound.
Looking forward to future testing, sincerely......
Code: Select all
pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $
Who is online
Users browsing this forum: No registered users and 53 guests