Moddable-OpenSource / moddable

Tools for developers to create truly open IoT products using standard JavaScript on low cost microcontrollers.
http://www.moddable.com
1.34k stars 236 forks source link

ESP32 -t deploy target ideas #372

Closed wilberforce closed 3 years ago

wilberforce commented 4 years ago

During development, the bootloader and partition table are flashed everytime, however these don't change.

esptool.py -p COM3 -b 1500000 --after hard_reset write_flash --flash_mode dio --flash_freq 80m --flash_size 4MB 0x1000 bootloader/bootloader.bin 0x8000 partition_table/partition-table.bin 0x10000 xs_esp32.bin

Perhaps a new deploy target could be added that only pushes the xs_esp32.bin to the device?

It might be possible, to auto detect that these have already been published, by looking at build target times, so then a new target flag would not be required.

The other idea, would be use the OTA partitions and the otatool.py tool

https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-reference/system/ota.html#ota-tool-otatool-py

This could be used via the serial port, to write alternating between slot 1 and slot 2.

The other idea would be have a js stub ota module loaded as part of the manifest, and then a http post/put could be used to do an OTA update of firmware.

phoddie commented 4 years ago

The bootloader, partition table. and empty OTA data partition are flashed each time. That's true. It avoids a mismatch between the parts (which takes forever to figure out).

We could certainly include a build option to suppress those, if it would really make enough of a difference. Do you have a sense of how much time it would save?

Using OTA requires that you have two OTA partitions. Unless you are building a product, you often don't because the extra OTA partition uses up quite a bit of the available flash space. That said, if you want to do OTA, it works well on ESP32 using the OTA module. The modClock project uses the OTA module.

wilberforce commented 4 years ago

@phoddie

This looks like the target we want: https://docs.espressif.com/projects/esp-idf/en/v3.3.2/get-started-cmake/idf-monitor.html?highlight=idf.py#quick-compile-and-flash

idf.py app-flash target

40 secs to mcconfig -t deploy -d -m -p esp32/m5stick_c

vs 22 secs to do flash of app only: mcconfig -t app_flash -d -m -p esp32/m5stick_c

C:\Users\rhys\source\repos\M5c-tilt>mcconfig -t app_flash -d -m -p esp32/m5stick_c
python C:\Users\rhys\esp32\esp-idf\tools\idf.py -n -p COM3 -b 1500000 -B C:\Users\rhys\Projects\moddable\build\tmp\esp32\m5stick_c\debug\idf app-flash -D mxDebug=1 SDKCONFIG_H="C:\Users\rhys\Projects\moddable\build\tmp\esp32\m5stick_c\debug\idf\config\sdkconfig.h" CMAKE_MESSAGE_LOG_LEVEL=ERROR DEBUGGER_SPEED=1500000
Checking Python dependencies...
Python requirements from C:\Users\rhys\esp32\esp-idf\requirements.txt are satisfied.
Running ninja in directory C:\Users\rhys\Projects\moddable\build\tmp\esp32\m5stick_c\debug\idf
Executing "ninja app"...
ninja: no work to do.
Running esptool.py in directory C:\Users\rhys\Projects\moddable\build\tmp\esp32\m5stick_c\debug\idf
Executing "c:\python27\python.exe C:\Users\rhys\esp32\esp-idf\components/esptool_py/esptool/esptool.py -p COM3 -b 1500000 --after hard_reset write_flash @flash_app_args"...
esptool.py -p COM3 -b 1500000 --after hard_reset write_flash 0x10000 xs_esp32.bin
esptool.py v2.8
Serial port COM3
Connecting....
Detecting chip type... ESP32
Chip is ESP32-PICO-D4 (revision 1)
Features: WiFi, BT, Dual Core, 240MHz, Embedded Flash, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: d8:a0:1d:48:3c:18
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 1500000
Changed.
Configuring flash size...
Auto-detected Flash size: 4MB
Compressed 1749808 bytes to 1120906...
Wrote 1749808 bytes (1120906 compressed) at 0x00010000 in 17.5 seconds (effective 799.7 kbit/s)...
Hash of data verified.

The changes needed for: https://github.com/Moddable-OpenSource/moddable/blob/public/tools/mcconfig/nmake.esp32.mk

APP_FLASH_CMD = python %IDF_PATH%\tools\idf.py $(IDF_PY_LOG_FLAG) $(PORT_COMMAND) -b $(UPLOAD_SPEED) -B $(IDF_BUILD_DIR) app-flash -D mxDebug=1 SDKCONFIG_H="$(SDKCONFIG_H)" CMAKE_MESSAGE_LOG_LEVEL=$(CMAKE_LOG_LEVEL) DEBUGGER_SPEED=$(DEBUGGER_SPEED)

app_flash: 
    set HOME=$(PROJ_DIR)
    cd $(PROJ_DIR)
    echo $(APP_FLASH_CMD)
    $(APP_FLASH_CMD)

So it approximately halves the time, as partitions that haven't changed are remade and flashed.

At the moment the recipe is not detecting changes to main.js so those aren't getting rebuilt - the dependencies would need to be added. (I've only tested against nmake too)

phoddie commented 4 years ago

I'm 100% in favor of faster builds.

In my experience -- mostly macOS -- reflashing the partitions and OTA takes, maybe, one second. Before diving into how to make changes to speed the build, I'd like to understand the benefit. Here's a screen recording of what I see.

esp32 deploy

The OTA and partition maps are the first two "wrote xxx bytes" lines.

How is that different from what you see or what am I overlooking?

phoddie commented 4 years ago

@wilberforce, I'd like to understand why we are seeing such different results. The screen recording above shows that flashing the partition map and OTA are very fast.

FWIW - a recent change does make flashing apps that a don't use Wi-Fi faster. For example, it reduces helloworld (used above) from 627,536 compressed bytes to 201,591.

https://github.com/Moddable-OpenSource/moddable/blob/ece6a84f3190d1191bf4698c656aad0755d6d5e3/xs/platforms/esp/xsPlatform.c#L1228-L1230

wilberforce commented 4 years ago

@phoddie

Checking Python dependencies...
Python requirements from C:\Users\rhys\esp32\esp-idf\requirements.txt are satisfied.
Running ninja in directory C:\Users\rhys\Projects\moddable\build\tmp\esp32\m5stick_c\debug\idf
Executing "ninja all"...
[1/5] Performing build step for 'bootloader'
ninja: no work to do.
[3/3] Generating xs_esp32.bin

For my windows setup there is a ~18 sec delay after the ninja:no work to do.

esp32-win-600

@andycarle do you see this in your windows builds?

andycarle commented 4 years ago

No. I get maybe a one-second pause there. I'll take a look at what's happening in that part of the build this evening.

@wilberforce Could you set VERBOSE=1 before building and see if you can tell which sub-step it's pausing on there?

wilberforce commented 4 years ago

@andycarle

Thanks.

It seems the pause is between:

Executing "ninja -v all"...
[1/5] cmd.exe /C "cd /D C:\Users\rhys\Projects\moddable\build\tmp\esp32\m5stick_c\debug\idf\bootloader && "C:\Program Files\CMake\bin\cmake.exe" --build ."
ninja: no work to do.

and

[2/3] cmd.exe /C "cd . && C:\PROGRA~1\ESPRES~1\ESP-ID~1\tools\bin\XT1FE9~1.EXE  -mlongcalls  -nostdlib @CMakeFiles/xs_esp32.elf.rsp  -o xs_esp32.elf  && cd ."

esp32-win-verbose

phoddie commented 4 years ago

@andycarle or @wilberforce, any further ideas here?

andycarle commented 4 years ago

The spot where @wilberforce is seeing this pause is deep within the ESP-IDF's internal build system. I spent some time today trying to sort out exactly what work is being done there, but I have not found any obvious reason it would be drastically different from system to system. Either way, I think it is outside of our control, beyond turning the bootloader build completely on or completely off.

For comparison, here are a couple of screen captures of my builds, the first with VERBOSE=0 and the second with VERBOSE=1. On this laptop, I do get a ~2-second pause in the same spot. (Each capture was done after making a small change to the app's main.js.):

build

build_verbose

At any rate, I would be happy to implement a build variant that uses app-flash instead of build flash if we want it. But I don't believe we have any automated way of knowing when building the bootloader is necessary, so it would have to be a manual option. It could be implemented as a build target (as discussed above) or by setting an environment variable.

(As an aside: this hunt did lead me to identify and fix a bug in the build system that was causing unnecessary ESP-IDF reconfigurations. It is not directly related to this bootloader slowness, but it will speed up most incremental ESP32 builds on Windows.)

wilberforce commented 4 years ago

@andycarle

Thanks for looking into this.

phoddie commented 4 years ago

Since this delay is coming from the ESP-IDF build, perhaps it makes sense to open an issue in that repository that references this one?

phoddie commented 4 years ago

@andycarle, since you have the details of this, would you file an issue on the ESP-IDF repository?

andycarle commented 4 years ago

Apologies--I missed the most recent notification on this!

I've opened a new issue against the ESP-IDF repository (see linked issue above) to investigate this problem further.

andycarle commented 4 years ago

@wilberforce: A couple of suggestions for further diagnosis of this problem have been made in this comment on the ESP-IDF issue. These ideas seem worth investigating:

To confirm this, if you have access to the 18 second computer then please look in Windows task manager during the pause. If you see a single gcc.exe process running and using CPU the whole time, it's probably the app linker step.

The last thing I suggest checking is to show "More Details" in Task Manager and look for any service host process hogging the CPU during this time. We find that Windows Defender service can slow down the IDF build by more than 50% as it scans every file access. In ESP-IDF v4.1 the ESP-IDF Windows Tools Installer added an option to automatically add Defender exclusions for the ESP-IDF toolchain processes, as a trade-off between build time and security. There is no such option in earlier versions, but running an experiment by temporarily disabling Defender live scanning is probably worthwhile.

andycarle commented 3 years ago

@wilberforce: Circling back on this now that the ESP-IDF issue has been closed out.

Recapping what we learned over there:

I still am not able to reproduce this long pause on any system I have access to. And as far as I know, we haven't heard from anyone else experiencing this issue on Windows builds.

Because you have a workaround that works for you and we have not seen this issue on other systems, I'm a bit hesitant to add in an option covering this for everyone.

@phoddie: How would you like for us to proceed with this? Adding the option to use the app-flash target, controlled by an environment variable or a build target, is straightforward if you want it.

wilberforce commented 3 years ago

@andycarle Thanks for following up. It has indead come full circle. The build time does seem proportional to the size of the final firmware - in my current build it take about 14 secs for 1729632 bytes.

This is where I'm currently at with my home project: a. The main.js now uses LoadMod b. The (large) resources I use for web server are loaded as a module. This means I can use mcrun to make changes the source of the web pages and get a very quick re-publish when the source changes. ( well it feels this way) its abit hard to tell as even with VERBOSE=1 its a bit hard to tell when its complete:

> mcrun -d -m -p esp32/m5stick_c

        tasklist /nh /fi "imagename eq serial2xsbug.exe" | (find /i "serial2xsbug.exe" > nul) && taskkill /f /t /im "serial2xsbug.exe" >nul 2>&1
        tasklist /nh /fi "imagename eq xsbug.exe" | find /i "xsbug.exe" > nul || (start C:\Users\rhys\Projects\moddable\build\bin\win\release\xsbug.exe && echo Starting xsbug... && timeout /nobreak /t 7 > nul)
        C:\Users\rhys\Projects\moddable\build\bin\win\release\serial2xsbug COM3 1500000 8N1 -install C:\Users\rhys\Projects\moddable\build\bin\esp32\debug\www\www.xsa

Perhaps a message to say the mod has been installed?

So the next idea is to seperate into a base core, and have the main code (that is getting developed and changing) as module.

Then only the components that change get flashed with mcrun.

So things have morphed a bit since intially raising!

Thinking out loud - are you looking at deploying mcrun targets over the wire - via TCP. So have an option to install a debugger direct socket option as well as using serial2xsbug. Thanks for the support.

phoddie commented 3 years ago

@wilberforce, I'm just getting caught up on this thread. It indeed seems to have morphed, so maybe we should close it out.

But... I will add a few final notes. :)

Perhaps a message to say the mod has been installed?

Mods are installed by serial2xsbug which is run as the last step of the build started by mcrun. When the install is complete, serial2xsbug goes directly into bridging xsbug so it doesn't exit.

You can get messages about the install progress by enabling trace of the commands issued to xsbug, To do that, set mxTraceCommands to 1 in serial2xsbug.h (and rebuild tools!) . That's just a debugging capability at the moment, but if it turns out to have other uses we could make it a runtime option.

Thinking out loud - are you looking at deploying mcrun targets over the wire - via TCP. So have an option to install a debugger direct socket option as well as using serial2xsbug.

This is entirely possible. In fact, I implemented install of mods over WebSockets before implementing it for serial.

If you project runs an HTTP server, your could provide an endpoint for uploading a mod. The details of that would be about the same as I outlined on Gitter recently. If you do that, mcrun has an undocumented feature to use curl to install the mod. That's currently only for macOS but it should be straightforward to bring the support over to Windows.

wilberforce commented 3 years ago

@phoddie That looks really interesting to use mcrun to PUT directly to XS partition. I've read the gitter comments and are quite keen to try this approach.

phoddie commented 3 years ago

Excellent. Please let me know how it goes.

In my experience, it works well -- with the usual caveat that your Wi-Fi network becomes the weak link.

I'm going to close this issue because I believe the primary topic has be fully covered.