Boot Time

[wiredcharlie]

I have an LED display on my application. When I hadn't written much code, initialization was instant. But as my code has grown there is now a very noticeable boot delay. What factors affect boot time and how can I shorten it?

Thanks
Tony

[TD-er]

What build of ESPEasy are you using?

And can you describe a bit more what is happening and what code you did write? (rules I assume)

[Ath]

Some tips and tricks to get code executed efficiently:
- Place often executed events at the start of the Rules1 file
- Place not so often executed events at the end of the last used Rules file (depends on the amount/size of rules)
- All rules files are read and processed sequentially (1..4), do not leave Rules 2 and 3 empty when code is in Rules4, the files are still opened, and that's somewhat 'slow'
- Remove empty Rules files (Tools/File browser)
- If you need your 'on System#Boot do' event, or other startup events, to execute quickly, or if you do not need this and other startup events, then still add it early in Rules1, so it will be found quickly, and because some (unneeded) events can be empty, discarded quickly.

[wiredcharlie]

I have a Rules file of 7657 characters - quite a bit of annotation
In Devices:
7 segment display
1 wire Temp
Switch 1
Switch 2
Reg Level control (for storing value between power cycles)
4 Dummy Devices

Also, I don't really understand multiple Rules files. Are they all executed as if they are one file?

[TD-er]

Yep, it used to be a problem to upload > 1500 - 1700 bytes, so the max. limit per rules file was set to 2k.
However that's being dealt with today by using some JavaScript to let the browser perform a file upload instead of a HTTP POST.
So there's no praktical limit anymore to the file size (apart from available free space of course).

However it is still useful to have several rules files as you can differentiate where to put specific rule blocks and thus keep rules common for all your nodes in 1 file and node specifics in another one.
Makes deployment and administration a lot simpler.

The rules parser does start parsing at the first byte of the first file and continues to the next file until a matching rule block is found.

In recent builds, I have added a cache mechanism to keep the "on ... do" lines in memory including their position and file name.
This way, when handling a new event, I only need to look at this cache and see which block may match and then execute it.

What takes time during rules parsing:
- Closing and opening another file
- Seek into a file to start reading from a specific position

So it is best to have most frequently occuring events handled in the same file at the start of that file.
The rules parser keeps the last used rules file open to make sure you don't need to re-open it.

So comments do not really add up to the parsing time.

This cache is implemented differently on ESP8266 and ESP32.
On ESP8266, only the "on...do" lines are cached.
On ESP32 also the rest of the file (minus the comments) is cached in memory.

Now you also understand why I asked about the build version of ESPEasy as this cache feature wasn't present in older builds.
I guess I added it about 6 - 9 months ago. (not 100% sure)

Another thing you may want to look into...
If you call "event" instead of "asyncevent", the rules parser may take quite a lot longer to process such an event.
Especially when that event calls another event, etc.

[wiredcharlie]

That's really useful, thank you.

I'm using a late version with rules cache. The overall performance is fast enough. My only concern is the time between applying power and seeing output on the LED display. I think what you're saying is that this is a function of the size of the rules file only, because the rules are read completely prior to an execution?

[TD-er]

The flash is quite fast, so reading a few kB shouldn't be much of an issue here.
It should be able to handle several 100 kByte/sec with ease.

I think it might take a while to perform the WiFi scan and maybe try a few times to connect.

Do you maybe have WiFi with hidden SSID?

One thing to speed-up connecting to WiFi can be by checking the checkbox (tools->Advanced page) for "Use Last Connected AP from RTC:"
But this only helps after a warm (re)boot or when waking up from sleep.

Another thing you could try is "Force WiFi B/G"

When using FritzBox routers, an "Extra Wait WiFi Connect" may speed up things too, as it might prevent an extra connect attempt.

If you have "Band Steering" enabled on your access point, you can try "Enable SDK WiFi Auto Reconnect".

And if it can be changed/set in your access point, disable IGMP snooping and other multicast related settings.

[wiredcharlie]

So On Boot is not executed until Wi-Fi is connected?

[Ath]

So On Boot is not executed until Wi-Fi is connected?

No, as the documentation states: 'Right after boot', see: https://espeasy.readthedocs.io/en/lates ... vents.html
Once WiFi is successfully connected, a WiFi#Connected event is generated, and on disconnect...

[wiredcharlie]

Thanks.
But I appear to have not been clear.

I am interested in the time interval between powering the device and being able to execute On Boot in rules.

Experiment:

Code: Select all

On System#Boot Do
  TaskValueSet,1,1,%uptime_ms%
  longpulse_ms,2,0,5000
Endon

ESP_Easy_mega_20220616_normal_ESP8266_4M1M Jun 16 2022
438 mS

ESP_Easy_mega_20221224_normal_ESP8266_4M1M_VCC Dec 24 2022
10660 mS

ESP_Easy_mega_20230623_normal_ESP8266_4M1M Jun 23 2023
3458 mS

Conclusion:
Boot Time, defined as time to Rules execution, varies considerably by release.

Or am I missing something?

[Ath]

You can get the log with time stamps included, via a USB-serial connection, as that will allow to see all the log right after a reset, the boot time will depend on the time it takes to scan for WiFi networks, and that can be shortened by enabling 'Use Last Connected AP from RTC:' and depending on the type of APs in use, also by enabling the 'Enable SDK WiFi Auto Reconnect' setting.
And sometimes WiFi is just slow in responding, caused by undefined external 'interference' or by busy traffic.

[TD-er]

It is possible the WiFi scan is performed before the first event is being handled.
On ESP32 this takes roughly 6 seconds if I'm not mistaken.

In older builds I may have had the WiFi scan performed async, so it wasn't blocking, but that gave a lot of issues in connecting to WiFi.

[wiredcharlie]

In older builds I may have had the WiFi scan performed async, so it wasn't blocking, but that gave a lot of issues in connecting to WiFi.

Ahhh.....

Do you remember which is the newest older build with async wifi?

Thanks

[TD-er]

Nope, no idea when that was changed.
Probably when I added support for the ESP32 SDK based on the IDF 4.4

However I do plan on adding some kind of async scanning again, but only slightly different.

What I plan to do is scan per channel, which takes 200 - 300 msec of blocking code.
But this could be done in a different way and allows for a much more controlled way of scanning.
For example first start at the channel we last had a connection with a known AP.
And then start scanning at the most frequently used channels, like 1, 6, 11.

The main reason to change this is that I plan on letting ESPEasy have a strict defined networking state and no longer try to make it extremely dynamic as it is now.

For example on ESP32 with Ethernet, if you plug in a network cable, it will immediately try to switch to network.
And the other way around, when you unplug a network cable, it will immediately try to connect to WiFi.

However, this does cause quite a lot of issues, like much higher power consumption when WiFi and LAN are active at the same time.
Or channel lock-ups when having the WiFi trying to connect to an AP while running its own AP (e.g. in initial setup mode)

So by letting the user define a clearly set preferred network (even allowing for "no WiFi" mode, or AP only), I plan on also changing the way how WiFi scanning is done as this can be done way more intelligently.

[wiredcharlie]

ESP_Easy_mega_20221224_normal_ESP8266_4M1M_VCC Dec 24 2022 (coloured rules)
10660 mS

ESP_Easy_mega_20221105_normal_ESP8266_4M1M Nov 5 2022 (coloured rules)
11356 mS

ESP_Easy_mega_20220809_normal_beta_ESP8266_4M1M Aug 9 2022
590 mS

ESP_Easy_mega_20220616_normal_ESP8266_4M1M Jun 16 2022
438 mS

From observation, using the boot experiment described earlier:

The time between applying power and rules being executed (boot time) is affected most by choice of distribution.

Versions using the new (and very helpful) coloured rules interface are much slower to boot (see above). Is this a coincidence?

[TD-er]

The colored rules do not add to the boot time.
Depending on the build, it either is loaded from a CDN server, or downloaded from the ESP itself.
And this is only when you access the rules editor page.

I think it has to do with the changes in how WiFi is initialized, to make it work also on nodes with less than optimal power supply.

But I do realize this is really bad for battery operated units.