fail to flash after some time of use

[J00003]

Hi,
I am having a problem flashing an ESP32 with esptool v2.2.1.
It seems that after about 30mins of use, ie: working on a project and successfully re-flashing a new load a several times, it gets into a weird state where it will not flash any longer. (It does continue to run my code ok, and after resets, continues to operate normally, but just will not accept a new download).

I'm using the following:
- ESP-WROOM-32 module soldered onto a Seeed ESP32 breakout board (https://www.seeedstudio.com/ESP32-Break ... -2783.html)
- windows 10
- latest esp-idf from github (March 2, 2018).
- FDTI USB to serial board (and latest D2XX drivers from here: http://www.ftdichip.com/Drivers/D2XX.htm)

I can see that the board is ready to flash (after holding my flash button and resetting the module) via the following in the console output:

Code: Select all

ets Jun  8 2016 00:22:57
rst:0x1 (POWERON_RESET),boot:0x3 (DOWNLOAD_BOOT(UART0/UART1/SDIO_REI_REO_V2))
waiting for download

But flashing fails with this error: "A fatal error occurred: Failed to connect to ESP32: Timed out waiting for packet header"

After doing some searching around, I enabled the debug trace in the esptool and found that there are no Read logs at all.
I only see the following re-occurring failure/timeout:

Code: Select all

python /home/j/esp/esp-idf/components/esptool_py/esptool/esptool.py --trace --chip esp32 --port COM8 --baud 115200 --before default_reset --after hard_reset write_flash -z --flash_mode dio --flash_freq 40m --flash_size detect 0x1000 /c/Users/j/workspace/esp32TestProgram/build/bootloader/bootloader.bin 0x10000 /c/Users/j/workspace/esp32TestProgram/build/test-program1.bin 0x8000 /c/Users/j/workspace/esp32TestProgram/build/partitions_singleapp.bin
esptool.py v2.2.1
Connecting...
TRACE +0.000 command op=0x08 data len=36 wait_response=1 timeout=0.100 data='\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU'
TRACE +0.000 Write 46 bytes: '\xc0\x00\x08$\x00\x00\x00\x00\x00\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU\xc0'
TRACE +0.102 Timed out waiting for packet header

.TRACE +0.054 command op=0x08 data len=36 wait_response=1 timeout=0.100 data='\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU'
TRACE +0.000 Write 46 bytes: '\xc0\x00\x08$\x00\x00\x00\x00\x00\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU\xc0'
TRACE +0.102 Timed out waiting for packet header

.TRACE +0.053 command op=0x08 data len=36 wait_response=1 timeout=0.100 data='\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU'
TRACE +0.000 Write 46 bytes: '\xc0\x00\x08$\x00\x00\x00\x00\x00\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU\xc0'
TRACE +0.101 Timed out waiting for packet header

.TRACE +0.053 command op=0x08 data len=36 wait_response=1 timeout=0.100 data='\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU'
TRACE +0.000 Write 46 bytes: '\xc0\x00\x08$\x00\x00\x00\x00\x00\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU\xc0'
TRACE +0.102 Timed out waiting for packet header

<snip....>

TRACE +0.101 Timed out waiting for packet header
_TRACE +0.052 command op=0x08 data len=36 wait_response=1 timeout=0.100 data='\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU'
TRACE +0.000 Write 46 bytes: '\xc0\x00\x08$\x00\x00\x00\x00\x00\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU\xc0'
TRACE +0.102 Timed out waiting for packet header
_

A fatal error occurred: Failed to connect to ESP32: Timed out waiting for packet header

Before it started failing I captured this log, and can see that the send/receive (or write/read) is working well:

Code: Select all

python /home/j/esp/esp-idf/components/esptool_py/esptool/esptool.py --trace --chip esp32 --port COM8 --baud 115200 --before default_reset --after hard_reset write_flash -z --flash_mode dio --flash_freq 40m --flash_size detect 0x1000 /c/Users/j/workspace/esp32TestProgram/build/bootloader/bootloader.bin 0x10000 /c/Users/j/workspace/esp32TestProgram/build/test-program1.bin 0x8000 /c/Users/j/workspace/esp32TestProgram/build/partitions_singleapp.bin | tee flash.log

esptool.py v2.2.1
Connecting...TRACE +0.000 command op=0x08 data len=36 wait_response=1 timeout=0.100 data='\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU'
TRACE +0.001 Write 46 bytes: '\xc0\x00\x08$\x00\x00\x00\x00\x00\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU\xc0'
TRACE +0.100 Timed out waiting for packet header
.TRACE +0.053 command op=0x08 data len=36 wait_response=1 timeout=0.100 data='\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU'
TRACE +0.000 Write 46 bytes: '\xc0\x00\x08$\x00\x00\x00\x00\x00\x07\x07\x12 UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU\xc0'
TRACE +0.007 Read 1 bytes: '\xc0'
TRACE +0.000 Read 27 bytes: '\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00\xc0\xc0\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00\xc0'
TRACE +0.000 Full packet: '\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00'
TRACE +0.002 Full packet: '\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00'
TRACE +0.019 Read 1 bytes: '\xc0'
TRACE +0.000 Read 83 bytes: '\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00\xc0\xc0\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00\xc0\xc0\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00\xc0\xc0\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00\xc0\xc0\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00\xc0\xc0\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00\xc0'
TRACE +0.000 Full packet: '\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00'
TRACE +0.003 Full packet: '\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00'
TRACE +0.003 Full packet: '\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00'
TRACE +0.003 Full packet: '\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00'
TRACE +0.003 Full packet: '\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00'
TRACE +0.003 Full packet: '\x01\x08\x04\x00\x07\x12UU\x00\x00\x00\x00'

TRACE +0.003 command op=0x0a data len=4 wait_response=1 timeout=3.000 data='\x0c\xa0\x01`'
TRACE +0.000 Write 14 bytes: '\xc0\x00\n\x04\x00\x00\x00\x00\x00\x0c\xa0\x01`\xc0'
TRACE +0.014 Read 1 bytes: '\xc0'
TRACE +0.000 Read 13 bytes: '\x01\n\x04\x00\x00\x80\x00\x00\x00\x00\x00\x00\xc0'
TRACE +0.000 Full packet: '\x01\n\x04\x00\x00\x80\x00\x00\x00\x00\x00\x00'
Chip is ESP32D0WDQ6 (revision 1)
Uploading stub...
TRACE +0.003 command op=0x05 data len=16 wait_response=1 timeout=3.000 data=' \x0c\x00\x00\x01\x00\x00\x00\x00\x18\x00\x00\x00\x00\t@'
TRACE +0.000 Write 26 bytes: '\xc0\x00\x05\x10\x00\x00\x00\x00\x00 \x0c\x00\x00\x01\x00\x00\x00\x00\x18\x00\x00\x00\x00\t@\xc0'
TRACE +0.013 Read 1 bytes: '\xc0'
TRACE +0.000 Read 13 bytes: '\x01\x05\x04\x00\x00\x80\x00\x00\x00\x00\x00\x00\xc0'
TRACE +0.000 Full packet: '\x01\x05\x04\x00\x00\x80\x00\x00\x00\x00\x00\x00'

<snip....>

I have a 2nd identical ESP-WROOM-32 module and it works just fine. (ie: I can always flash it successfully). So pretty sure my setup/environment is good.

I left the problematic board for a few days, but tried it again today with the same results. (ie: after about 30mins of use, I cannot flash it any longer).

Any ideas here?
Is there a bug in the esptool?
Can I change the timeout (ie: this --> timeout=0.100) value somehow?

Thanks,
J

[ESP_Angus]

Hi J,

That's an unusual problem indeed!

Hi,
I am having a problem flashing an ESP32 with esptool v2.2.1.
It seems that after about 30mins of use, ie: working on a project and successfully re-flashing a new load a several times, it gets into a weird state where it will not flash any longer. (It does continue to run my code ok, and after resets, continues to operate normally, but just will not accept a new download).

When it keeps working after running for 30 minutes, does this include connecting to WiFi correctly? Does the output of the running firmware come over the FTDI interface correctly?

How is the ESP32 board being powered? And how warm is the ESP32 board at this point?

The Seeed boards don't include the recommended 10uF capacitor on the power rails for the WROOM module, so it's possible the power input is not stable enough, and temperature may exacerbate this. However it doesn't explain why your own programs keep running correctly.

If it's possible to power cycle (or unplug/replug) the FTDI independently from the ESP32, are you able to flash?

If you power cycle the whole unit quickly and restart without leaving it unpowered for more than a second or so, are you able to flash?

If you reset the module (with Flash held down) after starting esptool.py (during the "Connecting..." part), does this change anything?

Can I change the timeout (ie: this --> timeout=0.100) value somehow?

You can do this by editing the esptool.py source, but there isn't really a situation where you'd expect the ESP32 to take more than 100ms to respond to a request. The ESP32 itself should respond in almost no time (hundreds of microseconds, probably). Worst case USB/serial latency is 25ms. Windows task scheduler time slice is 15ms (I believe). So that's 41ms worst case...

My guess is you're not seeing a reply because the ESP32 isn't seeing the initial sync request, for some reason.

[J00003]

Hi ESP_Angus,
Thanks for the reply... yes it is weird behavour.

Here are some answers to your questions:
- yes, the module seems to run normally, wifi works, code is running, interrupts firing, timers working, my logging output to the FTDI looks correct. In summary, it seems to run the last successfully programmed s/w load correctly in all aspects.
- module power is supplied from a 3.3VDC breadboard power supply (700mA) from a laptop USB2.0 port (~500mA).
- the module does not feel warm to the touch at all. I would say that I can not detect any temperature rise via touch.
- I agree this feels like a temp. overload type of problem, but it does seem to still run my last programmed code ok. I would expect to see some failures or other weird behavour here too.
- I have a 10uF electrolytic cap. soldered across pins 1 & 2 on the Seeed board, in addition to a 1000uF cap on the breadboard power rail.
- the other module that works does NOT have a 10uF cap across pins 1-2, I just use the breadboard 1000uF cap in that case. I thought of removing the 10uF on the not-working-module, but I'm not sure that makes any sense? What do you think?
- I have tried to power cycle the module, once I get it into this state. But normally I wait several minutes, to let the caps drain before powering back up. I have not tried what you're suggested by cycling it quickly. [ I will try this ].
- I have tried various combinations of holding the flash button and hitting the reset button several times during esptool.py connection phase, but it does not start the transfer. (I see the FTDI tx led flash, so I can tell that the board has gone into "waiting" mode, as my code will flash a led 2x after startup).
- Thanks for the explanation on the timeout part, and since there are so many retries, I agree, it seems to be a problem with the module not receiving the data for some reason.

So I assume that since I can see the "waiting for download" msg from the module, it's ready and waiting.
I also assume from the esptool logs, that it has attempted (with many retries) to start downloading based on the trace.

Is there any other way to debug what's going wrong on the module?
Can I enable some internal module logging that will not interfere with the FTDI xfer?
Currently running the module set to the default 160MHz clock. Would it make any difference to run at 80? (or 240?)