MQTT Import time lack

Moderators: grovkillen, Stuntteam, TD-er

Message
Author
TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#51 Post by TD-er » 23 Nov 2022, 17:35

The column right before the #calls/sec is the total nr of calls. (since last reset of the stats)
When settings are saved, the cache is thrown out.
Thus every call to read stuff from the ExtraTaskSettings Struct (which is loaded in the LoadTaskSettings() function) will check the cache and if it isn't there, it will call a single LoadTaskSettings().

So if you clear the stats, save something and reload the stats page, you will probably see a number of LoadTaskSettings() calls probably equivalent to the nr of enabled tasks.

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#52 Post by Wiki » 23 Nov 2022, 18:28

Jep, that's how I understood the functionality and what I did to see at least something.

Taking into account that you currently have been working at the LoadTaskSettings stuff again I want to offer the opportunity for you to get some more checks concerning the thematics of LoadTaskSettings aside my initial problems with the time lack of MQTT import.

I have ESPs (8266 and 32) laying around, some sensors (i.e. Dallas, BMx280, INA219, Gyro, GPS and more),a TFT and a Nextion display, a hot soldering iron at hand and currently some time.

Wishlist is open, feel free to use it......

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#53 Post by TD-er » 23 Nov 2022, 18:41

ESP8266 will not reduce the nr. of calls to the LoadTaskSettings() function as much as on ESP32.
Mainly because flash access on ESP32 is quite a bit slower than on ESP8266 and caching data takes memory which is really limited on the ESP8266.

The Dallas plugin did make some calls to the ExtraTaskSettings and those values are now being cached on ESP32.
So if you could test it is still working on ESP32, that would be great.

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#54 Post by Wiki » 23 Nov 2022, 20:04

I will check the last linked on dropbox against a ESP_Easy_mega_20220909_normal_ESP32_4M316k.

Is that OK?

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#55 Post by TD-er » 23 Nov 2022, 20:25

Or for other builds using the same code, you can use this GH Actions build: https://github.com/letscontrolit/ESPEas ... 3534041444

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#56 Post by TD-er » 24 Nov 2022, 00:20

Please use this GH Actions build: https://github.com/letscontrolit/ESPEas ... 3535956032
It includes also another fix I made today on the longpulse command on ESP32.
It is possible to let a longpulse repeat for N counts, or infinity (count set to negative like "-1")
However the "up" and "down" step were split in 2 scheduled actions.
But those could get out of phase after a while.

So thats also fixed.

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#57 Post by Wiki » 24 Nov 2022, 09:59

Coming back to life again I give a short intermediate report.

After a runtime of 15 1/2 hours overnight the Timing Stats of the binary from the last dropbox upload posted including the additional MQTT Import task enabled tell me a LoadTaskSettings #call of 14, no time dicrepance between sent/received data. Job done I would say.

Today afternoon I will be back with the promised report about behaviour of Dallas and Lonpulse.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#58 Post by TD-er » 24 Nov 2022, 10:17

Great!
I will already merge the code, so if we see anything strange happening, we can then correct it.

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#59 Post by Wiki » 24 Nov 2022, 11:24

Where do I have too look at?

I just flashed 20220909_normal_ESP32, added two Dallas, GPIO22, one task, dual, single event with all values, 5 secs interval. No overwhelming LoadTaskSettings count, only when I leave the configuration page. Otherwise it disappears.
220909_mit_Dallas.JPG
220909_mit_Dallas.JPG (157.34 KiB) Viewed 6855 times

Right now I have to leave to visit my doc, will be back later.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#60 Post by TD-er » 24 Nov 2022, 11:34

Regarding the Dallas plugin...
You should test if it still works :)
Then I know I didn't mess up the code to read/write/cache the iWire addresses.

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#61 Post by Wiki » 24 Nov 2022, 12:07

Well checking if it works was a fast job.

Yes it does, as well as longpulse (one second -1 on onboard LED).

But now I'm gone....

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#62 Post by Wiki » 24 Nov 2022, 14:49

Dallas looks OK, I have now added an LED on GPIO 23, longpulse,23,1,1,1,-1 works as expected.

On my tablet I can't take a useable screenshot, so Timing Stats as plain text. Hope its readable.

Code: Select all

P_4_Environment - DS18b20	READ	3012	0.40	0.85	12.975	21.361	31.200
P_4_Environment - DS18b20	ONCE_A_SECOND	7534	1.00	0.00*	0.005	0.011	0.064
P_4_Environment - DS18b20	TEN_PER_SECOND	75312	9.97	0.01*	0.001	0.005	0.144
P_4_Environment - DS18b20	EVENT_OUT	1506	0.20	0.00*	0.025	0.032	0.072
P_4_Environment - DS18b20	FIFTY_PER_SECOND	372951	49.37	0.03*	0.001	0.005	0.169
C_2_Domoticz MQTT	CPLUGIN_PROTOCOL_SEND	1506	0.20	0.15	7.133	7.356	8.861
C_2_Domoticz MQTT	CPLUGIN_PROTOCOL_RECV	24022	3.18	0.17*	0.290	0.546	1.117
C_2_Domoticz MQTT	CPLUGIN_TEN_PER_SECOND	75312	9.97	0.02*	0.009	0.023	0.104
C_2_Domoticz MQTT	CPLUGIN_FIFTY_PER_SECOND	372951	49.37	0.10*	0.005	0.020	0.110
Load File		16	0.00	0.00	3.270	8.073	22.298
Save File		1	0.00	0.00	70.193	70.193	70.193
Loop		146636574	19409.49	47.25*	0.027	0.024	478.276
Plugin call 50 p/s		372951	49.37	5.09	0.889	1.030	1.765
Plugin call 10 p/s		75312	9.97	1.00	0.881	1.004	1.608
Plugin call 10 p/s U		150624	19.94	0.38*	0.013	0.189	0.443
Plugin call 1 p/s		7534	1.00	0.15	1.193	1.455	73.431
SensorSendTask()		3012	0.40	1.30	16.059	32.556	50.912
CPlugin call 10 p/s		75312	9.97	0.06*	0.031	0.064	0.309
CPlugin call 50 p/s		372951	49.37	0.36*	0.028	0.073	0.380
sendData()		1506	0.20	0.32	15.597	15.990	17.556
Compute formula		1506	0.20	0.00*	0.039	0.047	0.094
setNewTimerAt()		503845	66.69	0.50*	0.033	0.074	0.263
Delay queue MQTT		1506	0.20	0.06	0.807	2.906	5.950
hostByName()		2	0.00	0.00	21.673	31.574	41.475
WiFi.isConnected()		739495	97.88	1.83*	0.088	0.186	2.501
WiFi.isConnected() (fail)		3737	0.49	0.11	0.012	2.154	6495.462
LoadTaskSettings()		4	0.00	0.00	11.787	16.218	23.205
TryOpenFile()		39	0.01	0.01	0.638	20.754	150.106
parseSystemVariables()		1	0.00	0.00	2.130	2.130	2.130
parseSystemVariables() No change		1522	0.20	0.00*	0.001	0.024	0.090
parseTemplate_padded()		1516	0.20	0.01*	0.582	0.610	0.872
rulesProcessing()		3155	0.42	0.05	0.922	1.291	143.189
rulesMatch()		10	0.00	0.00	1.690	1.761	1.858
sendGratuitousARP()		35	0.00	0.00*	0.075	0.127	0.263
backgroundtasks()		1467185	194.20	27.34	0.116	1.407	350.792
process_system_event_queue()		24022	3.18	0.20*	0.327	0.613	1.319
handle_schedule() idle		146139450	19343.69	2.91*	0.006	0.001	5.838
handle_schedule() task		497125	65.80	11.44	0.162	1.738	147.463
handle webpage		21	0.00	0.03	9.379	95.589	327.659
WiFi Scan Sync (blocking)		2	0.00	0.15	5616.258	5620.605	5624.952
NTP Success		2	0.00	0.01	67.815	203.061	338.307
Systime Set		2	0.00	0.00	1.397	1.747	2.098
Statistics	
Start Period:	2022-11-24 12:03:25
Local Time:	2022-11-24 14:09:19
Time span:	7554.89 sec

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#63 Post by Wiki » 24 Nov 2022, 15:56

Just noticed:

MQTT Import doesn't process formulas? Tried %value%*1000, value stays original.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#64 Post by Wiki » 25 Nov 2022, 16:25

Just for curiosity I took the advange of having the ESP32 for testing available I configured 7 MQTT Import tasks, 6 for importing each 4 - different - values without Import options set out of the 43 data sets Ahoy fires every 5 seconds into the MQTT broker. One task I've configured to read the out put of my Volkszähler, JSON parsing set.

Resulted in a time lack of > 2 minutes before the values of my Volkszähler appeared in ESP Easy.

Step by step I disabled the "lean" import tasks with following reboot until only two of them left over. Every step of disabling a task resulted in a decreas of the time lack of around 15 seconds. With the two tasks with "lean" MQTT import and the one with JSON parsing option set I get a sync.

Seems as if the load of importing the data from Ahoy is just too high.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#65 Post by TD-er » 25 Nov 2022, 16:32

That's with the latest build with my tweaks?
Have you looked at the timing stats?

Also are you sending logs to the serial port? At some point this may also give quite a huge backlog in loggings as the serial port can only handle so much before it will start buffering.

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#66 Post by Wiki » 26 Nov 2022, 11:12

I took the device which I've setup for the test if the Dallas is still working. So yes, its the build from 2022-11-23 22:36:04, _normal_ESP32_4M316k.

I didn't disable the serial log. But no serial connection.

The time lack I am logging using the Web GUI with

Code: Select all

On Test5#Watt Do
  LogEntry,%systime%-Watt([Test5#Watt],1
Endon
Where Test5#Watt is a value from my Volkszähler fetched with MQTT Import and JSON parsing.
Fetching the data in a terminal session of my mqtt broker:

Code: Select all

pi@raspberrypi:~# mosquitto_sub -t "#" -v | grep Watt
Zaehler/SENSOR {"Time":"2022-11-26T11:02:36","SML":{"Verbrauch":39.352,"Einspeisung":1.277,"Watt":-14}}
Web Log Level set to "error" as I did with my solar project device.

The tasks are configured to generate events for accepted topics. But no further processing in rules.

In the timing stats there are almost no entries for LoadTaskSettings, just the ones generated by opening and saving taks manually. The level on MQTT RECV are at 4.7/sec as expected taken into account the 43 values every five seconds sent by Ahoy.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#67 Post by TD-er » 26 Nov 2022, 12:03

Wiki wrote: 26 Nov 2022, 11:12 [...]
I didn't disable the serial log. But no serial connection.
[...]
That doesn't matter if you're reading the serial log or not.
The logs will be generated anyway and thus the buffered data waiting to be sent to the serial port may pile up and slow the unit down... that is, if the serial port speed is a bottle neck.

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#68 Post by Wiki » 26 Nov 2022, 14:10

I've set Serial Log Level to none.
Same effect: Up to two of the tasks with lean MQTT import in sync, third enabled results in a time lack of 15 secs.
Couldn't test more, My pretty old, first ESP-Wroom-32 stopped working and now it is bricked. Neither flashing works. seems as if it has reached its end of life, its totally bricked.

I now have to tke care of my personal alimentation, leave for shopping. Will take some hours before I will have a test scenario setup again.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#69 Post by Wiki » 26 Nov 2022, 17:19

Back again - shopping was not possible because my old car just stopped running. Seems to be the day of not working techniques.

Replaced the ESP32 on my breadboard, so further testing will be possible.
If I shall test anything else than what I already posted please don't hesitate to give me a ping just by quoting or private message.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#70 Post by TD-er » 26 Nov 2022, 17:23

Just curious about the failed unit.
Can you flash a build on it via serial?
This way you can be sure the bootloader is matching the build.

What vendor flash chip does the unit use?
See: https://github.com/espressif/arduino-es ... 1200509232



Is it vendor ID 0x20 (XMC) ?

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#71 Post by Wiki » 27 Nov 2022, 11:54

No way to flash the device. The serial chip is recognized (think its the CP21xx) but flasher doesn't get contact to the CPU or whatever it tries to connect to. It worked stable >24h with the last firmware and I can't imagine that there is any relation to the firmware, it just gave up and exhaled its magic electronic soul. R.I.P.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#72 Post by TD-er » 27 Nov 2022, 17:54

It is best to flash the ESP32 units using one of the latest builds via serial.
Just to be sure the bootloader is also flashed.

In the link I gave, there is a lot of discussion about the flash chip actually being damaged on some ESP32 units due to some flags being set in the flash chip causing it to get damaged.
This seems to be fixed in the latest SDK, but this requires to also have the bootloader updated.
Otherwise the ESP may still set the wrong flags.
There seems to be some correlation between damaged chips and fluctuating power/voltage supplied to the chip.
The lowest voltage for the flash chip is still higher than the lowest voltage an ESP32 can safely run on.

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#73 Post by Wiki » 28 Nov 2022, 10:47

I've had a deeper look at the link you gave right away you posted it and understood what might have happened. I didn't know anything of it before.

If I remember right, I've flashed the device initially for testing the Dallas using the _factory.bin from 20220909. Does this fit your scheme of "one of the latest"? And yes, I've flashed it via serial.

But however, now its too late I think because I'm not able to flash this device anymore. Its ready for recycling. I'll take your comments for future handling of the ESP32.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#74 Post by Wiki » 28 Nov 2022, 10:50

Erm, and I did the upgrade OTA.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#75 Post by Wiki » 28 Nov 2022, 10:57

And the board has an age of around five years. I followed the link in the discussion to espressif and it seems that this old board doesn't fit in the hardware specifications they mentioned.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#76 Post by TD-er » 28 Nov 2022, 11:38

Wiki wrote: 28 Nov 2022, 10:57 And the board has an age of around five years. I followed the link in the discussion to espressif and it seems that this old board doesn't fit in the hardware specifications they mentioned.
Of course there are lots of possibilities where things may break down on ESP boards.
But flash suddenly "dying" does sound a lot like what's discussed in that thread.

Also the only things needed for this to happen (if I did understand the issue well enough) are:
- XMC flash chip
- ESP32
- "old bootloader" and/or "old SDK"

XMC flash chips are being used for years.
ESP32 had a "silicon bug" in revisions before V3 which makes it even more likely such a timing-related bug may occur.
In the later SDK versions, this timing related issue is being dealt with for "old silicon".

What seems to happen is that some byte array is being sent to registers in the flash chip.
However it may occur that switching the status bits to toggle write-enable may sometimes be bitshifted to the wrong byte due to these timing issues.
These timing issues may occur due to:
- Switching flash mode when finishing bootloader and starting sketch
- Voltage drops on the flash chip

It seems that the ESP32 also does try to write the WiFi calibration and config data on every boot. (I though that was only for ESP8266 on older SDK versions)
However, if such a write is being performed when the WiFi tries to do some RF calibration, then the power consumption is at its peak. Thus the voltage may drop to its lowest point as we never draw that much current with the sketch running.
Thus trying to switch to write enabled at that moment is just about the worst moment we could see a write attempt.

TL;DR
To me, the hypothesis of this being caused by the mentioned issue is not yet disproven.

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#77 Post by Wiki » 28 Nov 2022, 12:09

Compared with you I am just an amateur who tries to get as much out of the (Io)things. And I trust your opinion.

I did a quick check on the two ESP32 which are currently running, none of them tells me the chip verndor id 0x20, one is an also pretty old ESP32-WROOM, the other a freshly ordered ESP32 mini. Both of them are initially flashed with the _firmware.bin from 20220909 using serial connection. So I am on the safe side of the moon?

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

TD-er
Core team member
Posts: 8643
Joined: 01 Sep 2017, 22:13
Location: the Netherlands
Contact:

Re: MQTT Import time lack

#78 Post by TD-er » 28 Nov 2022, 13:10

If those units are from the same "batch" or at least show similar texts on the ESP32 WROOM module, then I guess the broken one may also not have the 'tricky' brand flash.
Still the nr of reports of damaged units is relatively low, but as long as Murphy can help it, the ones that will get damaged will be either plastered behind some wall or at least 1000km away.

So given these units are not at an unreachable place, you may not appear as interesting anymore to Mr. Murphy, which keeps your units a bit more safe.

Apart from that, try to flash any ESP32 unit with the latest FW builds via serial at least once.

Wiki
Normal user
Posts: 413
Joined: 23 Apr 2018, 17:55
Location: Germany

Re: MQTT Import time lack

#79 Post by Wiki » 28 Nov 2022, 14:38

Yep, couldn't agree more following Murphy's theorem, teached during my whole life.

The old ones are definitely out of different batches. The bricked has a red onboard LED, the one now ready for testing o blue one. Rest looks similar.

What might harden your hypothesis on the cause for bricking the device: shortly before it stopped working: I remember that there were surprisingly some MQTT disconnects written to the log, the first ones I have seen during the past days (for filtering the timestamps of received packets in the rules I am setting a logentry as an error and the Log Level set to "error", so the MQTT disconnects were clear to be seen). Might be that the device tried some training/calibration of the Wifi signal with the consequences you described. Additionally taken into account that the device might have been under really heavy load processing its MQTT imports as the reported time lack seems to show.

And thanks for your advice, I will do so.

Code: Select all

pi@raspberrypi:~ $ man woman
No manual entry for woman
pi@raspberrypi:~ $

Post Reply

Who is online

Users browsing this forum: No registered users and 34 guests