ESP32 Forum

ESP32 Official Forum
https://esp32.com/

Need help with OTA [Solved]

https://esp32.com/viewtopic.php?t=5454

Page 2 of 3

Re: Need help with OTA [Solved]

Posted: Fri Apr 27, 2018 12:04 am
by sellonoid
Since it appears you have OTA working, I have a question.

Are you using the standard "ota_example_main" file? That's what I'm using, and I can flash my target file "blink.bin" with it, but the OTA update never seems to run once I disconnnect the USB connection and reboot the ESP32.

Re: Need help with OTA [Solved]

Posted: Fri Apr 27, 2018 12:23 am
by fly135
I started with "ota_example_main", but had to rework for my application. Can you post the log of the ota operation. It just worked once I put the OTADATA partition into my partition file. The reason why I was getting the wrong magic byte in the beginning was because the HTTP GET was failing. I did two things. 1) put a slash in front of the filepath after the GET and put a 1.1 instead of a 1.0 after the HTTP. Never went back to see which was the answer.

I went on to use SSL socket api to support https as well.

John A

Re: Need help with OTA [Solved]

Posted: Sat Apr 28, 2018 12:26 am
by sellonoid
First I ran make menuconfig and specified the SSID, PW, IP, port, and the "/blink.bin" file.

Below is the shell screen output when I run "make erase_flash flash monitor". I guess I shouldn't include the "monitor" command since there is no monitor output when I do that.

After doing the above, I edit "blink.c" for a different blink pattern then "make" it again.

Then I disconnect the USB cable and reset or cycle power to the ESP32 (now running from just a power supply), but it just comes back up running the same version of blink as before. I can browse to the server and see the latest version of "blink.bin" that I just compiled. My understanding is that it should access the SimpleHTTPServer on reset or reboot, and download whatever version of "blink.bin" it finds. Maybe I'm wrong about that.

Thanks a lot,
Jim

Code: Select all

Jim@35D MINGW32 ~/esp/esp-idf/examples/system/ota
$ make erase_flash flash monitor
Erasing entire flash...
esptool.py v2.3.1
Connecting....
Chip is ESP32D0WDQ6 (revision 1)
Features: WiFi, BT, Dual Core
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 921600
Changed.
Erasing flash (this may take a while)...
Chip erase completed successfully in 6.2s
Hard resetting via RTS pin...
Flashing binaries to serial port COM26 (app at offset 0x10000)...
esptool.py v2.3.1
Connecting........____
Chip is ESP32D0WDQ6 (revision 1)
Features: WiFi, BT, Dual Core
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 921600
Changed.
Configuring flash size...
Auto-detected Flash size: 4MB
Compressed 23360 bytes to 13194...
Wrote 23360 bytes (13194 compressed) at 0x00001000 in 0.2 seconds (effective 1055.8 kbit/s)...
Hash of data verified.
Compressed 513024 bytes to 314484...
Wrote 513024 bytes (314484 compressed) at 0x00010000 in 6.6 seconds (effective 625.8 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 138...
Wrote 3072 bytes (138 compressed) at 0x00008000 in 0.0 seconds (effective 1638.3 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting via RTS pin...
MONITOR
--- idf_monitor on COM26 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
���%�ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:7976
load:0x40078000,len:0
ho 12 tail 0 room 4
load:0x40078000,len:15288
entry 0x40079394
I (30) boot: ESP-IDF v3.1-dev-601-gda278163-dirty 2nd stage bootloader
I (30) boot: compile time 17:00:24
I (40) boot: Enabling RNG early entropy source...
D (40) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (43) boot: magic e9
D (45) boot: segments 04
D (48) boot: spi_mode 02
D (50) boot: spi_speed 00
D (53) boot: spi_size 02
I (56) boot: SPI Speed      : 40MHz
I (60) boot: SPI Mode       : DIO
I (64) boot: SPI Flash Size : 4MB
D (68) bootloader_flash: mmu set paddr=00000000 count=1
D (73) boot: mapped partition table 0x8000 at 0x3f408000
D (79) flash_parts: partition table verified, 7 entries
I (84) boot: Partition Table:
I (88) boot: ## Label            Usage          Type ST Offset   Length
D (95) boot: load partition table entry 0x3f408000
D (100) boot: type=1 subtype=2
I (103) boot:  0 nvs              WiFi data        01 02 00009000 00004000
D (110) boot: load partition table entry 0x3f408020
D (115) boot: type=1 subtype=0
I (118) boot:  1 otadata          OTA data         01 00 0000d000 00002000
D (126) boot: load partition table entry 0x3f408040
D (131) boot: type=1 subtype=1
I (134) boot:  2 phy_init         RF data          01 01 0000f000 00001000
D (142) boot: load partition table entry 0x3f408060
D (147) boot: type=0 subtype=0
I (150) boot:  3 factory          factory app      00 00 00010000 00100000
D (157) boot: load partition table entry 0x3f408080
D (162) boot: type=0 subtype=10
I (165) boot:  4 ota_0            OTA app          00 10 00110000 00100000
D (173) boot: load partition table entry 0x3f4080a0
D (178) boot: type=0 subtype=11
I (181) boot:  5 ota_1            OTA app          00 11 00210000 00100000
I (189) boot: End of partition table
D (193) boot: OTA data offset 0xd000
D (197) bootloader_flash: mmu set paddr=00000000 count=1
D (202) boot: OTA sequence values A 0xffffffff B 0xffffffff
D (208) boot: OTA sequence numbers both empty (all-0xFF)
I (213) boot: Defaulting to factory image
D (218) boot: Trying partition index -1 offs 0x10000 size 0x100000
D (224) esp_image: reading image header @ 0x10000
D (229) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (236) esp_image: image header: 0xe9 0x07 0x02 0x02 40080fd8
V (241) esp_image: loading segment header 0 at offset 0x10018
V (247) esp_image: segment data length 0x12ca0 data starts 0x10020
V (253) esp_image: segment 0 map_segment 1 segment_data_offs 0x10020 load_addr 0x3f400020
I (262) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x12ca0 ( 76960) map
D (270) bootloader_flash: mmu set paddr=00010000 count=2
V (304) esp_image: loading segment header 1 at offset 0x22cc0
D (304) bootloader_flash: mmu set block paddr=0x00020000 (was 0xffffffff)
V (305) esp_image: segment data length 0x31dc data starts 0x22cc8
V (311) esp_image: segment 1 map_segment 0 segment_data_offs 0x22cc8 load_addr 0x3ffb0000
I (320) esp_image: segment 1: paddr=0x00022cc8 vaddr=0x3ffb0000 size=0x031dc ( 12764) load
D (329) bootloader_flash: mmu set paddr=00020000 count=1
V (339) esp_image: loading segment header 2 at offset 0x25ea4
D (340) bootloader_flash: mmu set block paddr=0x00020000 (was 0xffffffff)
V (347) esp_image: segment data length 0x400 data starts 0x25eac
V (353) esp_image: segment 2 map_segment 0 segment_data_offs 0x25eac load_addr 0x40080000
0x40080000: _iram_start at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

I (361) esp_image: segment 2: paddr=0x00025eac vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _iram_start at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

D (370) bootloader_flash: mmu set paddr=00020000 count=1
V (376) esp_image: loading segment header 3 at offset 0x262ac
D (381) bootloader_flash: mmu set block paddr=0x00020000 (was 0xffffffff)
V (388) esp_image: segment data length 0x9d5c data starts 0x262b4
V (394) esp_image: segment 3 map_segment 0 segment_data_offs 0x262b4 load_addr 0x40080400
I (402) esp_image: segment 3: paddr=0x000262b4 vaddr=0x40080400 size=0x09d5c ( 40284) load
D (411) bootloader_flash: mmu set paddr=00020000 count=2
V (433) esp_image: loading segment header 4 at offset 0x30010
D (434) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
V (435) esp_image: segment data length 0x58c1c data starts 0x30018
V (441) esp_image: segment 4 map_segment 1 segment_data_offs 0x30018 load_addr 0x400d0018
0x400d0018: _stext at ??:?

I (449) esp_image: segment 4: paddr=0x00030018 vaddr=0x400d0018 size=0x58c1c (363548) map
0x400d0018: _stext at ??:?

D (458) bootloader_flash: mmu set paddr=00030000 count=6
V (594) esp_image: loading segment header 5 at offset 0x88c34
D (594) bootloader_flash: mmu set block paddr=0x00080000 (was 0xffffffff)
V (596) esp_image: segment data length 0x4798 data starts 0x88c3c
V (602) esp_image: segment 5 map_segment 0 segment_data_offs 0x88c3c load_addr 0x4008a15c
0x4008a15c: xTaskResumeAll at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/freertos/tasks.c:3529

I (610) esp_image: segment 5: paddr=0x00088c3c vaddr=0x4008a15c size=0x04798 ( 18328) load
0x4008a15c: xTaskResumeAll at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/freertos/tasks.c:3529

D (619) bootloader_flash: mmu set paddr=00080000 count=1
V (632) esp_image: loading segment header 6 at offset 0x8d3d4
D (632) bootloader_flash: mmu set block paddr=0x00080000 (was 0xffffffff)
V (637) esp_image: segment data length 0x0 data starts 0x8d3dc
V (643) esp_image: segment 6 map_segment 0 segment_data_offs 0x8d3dc load_addr 0x400c0000
I (651) esp_image: segment 6: paddr=0x0008d3dc vaddr=0x400c0000 size=0x00000 (     0) load
D (660) bootloader_flash: mmu set paddr=00080000 count=1
V (666) esp_image: image start 0x00010000 end of last section 0x0008d3dc
D (672) bootloader_flash: mmu set block paddr=0x00080000 (was 0xffffffff)
D (679) esp_image: Calculated hash: f278d44c
D (684) bootloader_flash: mmu set paddr=00080000 count=1
I (698) boot: Loaded app from partition at offset 0x10000
I (698) boot: Disabling RNG early entropy source...
D (701) boot: Mapping segment 0 as IROM
D (705) boot: Mapping segment 4 as DROM
D (708) boot: calling set_cache_and_start_app
D (713) boot: configure drom and irom and start
V (718) boot: d mmu set paddr=00030000 vaddr=400d0000 size=363548 n=6
V (724) boot: rc=0
V (726) boot: rc=0
V (728) boot: i mmu set paddr=00010000 vaddr=3f400000 size=76960 n=2
V (735) boot: rc=0
V (737) boot: rc=0
D (739) boot: start: 0x40080fd8
0x40080fd8: call_start_cpu0 at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/esp32/cpu_start.c:114

I (742) cpu_start: Pro cpu up.
I (746) cpu_start: Starting app cpu, entry point is 0x40080f88
0x40080f88: call_start_cpu1 at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/esp32/cpu_start.c:225

I (0) cpu_start: App cpu up.
I (756) heap_init: Initializing. RAM available for dynamic allocation:
D (763) heap_init: New heap initialised at 0x3ffae6e0
I (768) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
D (774) heap_init: New heap initialised at 0x3ffb9720
I (779) heap_init: At 3FFB9720 len 000268E0 (154 KiB): DRAM
I (786) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (792) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
D (798) heap_init: New heap initialised at 0x4008e8f4
I (803) heap_init: At 4008E8F4 len 0001170C (69 KiB): IRAM
I (810) cpu_start: Pro cpu start user code
D (822) clk: RTC_SLOW_CLK calibration value: 3176212
V (160) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (160) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (165) intr_alloc: Connected src 46 to int 2 (cpu 0)
V (171) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (176) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC0E
D (185) intr_alloc: Connected src 57 to int 3 (cpu 0)
V (190) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (196) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (204) intr_alloc: Connected src 24 to int 9 (cpu 0)
I (210) cpu_start: Starting scheduler on PRO CPU.
V (0) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (0) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x40E
D (10) intr_alloc: Connected src 25 to int 2 (cpu 1)
I (10) cpu_start: Starting scheduler on APP CPU.
D (259) heap_init: New heap initialised at 0x3ffe0440
D (259) heap_init: New heap initialised at 0x3ffe4350
V (269) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (269) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (269) intr_alloc: Connected src 16 to int 12 (cpu 0)
D (289) nvs: nvs_flash_init_custom partition=nvs start=9 count=4
D (349) nvs: nvs_open_from_partition misc 1
D (359) nvs: nvs_get_str_or_blob log
D (359) nvs: nvs_set_blob log 16
I (369) wifi: wifi firmware version: c202b34
I (369) wifi: config NVS flash: enabled
I (369) wifi: config nano formating: disabled
I (369) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (379) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
D (389) nvs: nvs_open_from_partition nvs.net80211 1
D (399) nvs: nvs_get opmode 1
D (399) nvs: nvs_set opmode 1 2
D (399) nvs: nvs_get_str_or_blob sta.ssid
D (409) nvs: nvs_set_blob sta.ssid 36
D (409) nvs: nvs_get_str_or_blob sta.mac
D (409) nvs: nvs_set_blob sta.mac 6
D (419) nvs: nvs_get sta.authmode 1
D (419) nvs: nvs_set sta.authmode 1 1
D (429) nvs: nvs_get_str_or_blob sta.pswd
D (429) nvs: nvs_set_blob sta.pswd 65
D (429) nvs: nvs_get_str_or_blob sta.pmk
D (439) nvs: nvs_set_blob sta.pmk 32
D (439) nvs: nvs_get sta.chan 1
D (439) nvs: nvs_set sta.chan 1 0
D (449) nvs: nvs_get auto.conn 1
D (449) nvs: nvs_set auto.conn 1 1
D (449) nvs: nvs_get bssid.set 1
D (459) nvs: nvs_set bssid.set 1 0
D (459) nvs: nvs_get_str_or_blob sta.bssid
D (459) nvs: nvs_set_blob sta.bssid 6
D (469) nvs: nvs_get sta.phym 1
D (469) nvs: nvs_set sta.phym 1 3
D (479) nvs: nvs_get sta.phybw 1
D (479) nvs: nvs_set sta.phybw 1 2
D (479) nvs: nvs_get_str_or_blob sta.apsw
D (489) nvs: nvs_set_blob sta.apsw 2
D (489) nvs: nvs_get_str_or_blob sta.apinfo
D (489) nvs: nvs_set_blob sta.apinfo 700
D (499) nvs: nvs_get sta.scan_method 1
D (499) nvs: nvs_set sta.scan_method 1 0
D (509) nvs: nvs_get sta.sort_method 1
D (509) nvs: nvs_set sta.sort_method 1 0
D (509) nvs: nvs_get sta.minrssi 1
D (519) nvs: nvs_set sta.minrssi 1 -127
D (519) nvs: nvs_get sta.minauth 1
D (519) nvs: nvs_set sta.minauth 1 0
D (529) nvs: nvs_get_str_or_blob ap.ssid
D (529) nvs: nvs_set_blob ap.ssid 36
D (539) nvs: nvs_get_str_or_blob ap.mac
D (539) nvs: nvs_set_blob ap.mac 6
D (539) nvs: nvs_get_str_or_blob ap.passwd
D (549) nvs: nvs_set_blob ap.passwd 65
D (549) nvs: nvs_get_str_or_blob ap.pmk
D (549) nvs: nvs_set_blob ap.pmk 32
D (559) nvs: nvs_get ap.chan 1
D (559) nvs: nvs_set ap.chan 1 1
D (559) nvs: nvs_get ap.authmode 1
D (569) nvs: nvs_set ap.authmode 1 0
D (569) nvs: nvs_get ap.hidden 1
D (579) nvs: nvs_set ap.hidden 1 0
D (579) nvs: nvs_get ap.max.conn 1
D (579) nvs: nvs_set ap.max.conn 1 4
D (589) nvs: nvs_get bcn.interval 2
D (589) nvs: nvs_set bcn.interval 2 100
D (589) nvs: nvs_get ap.phym 1
D (599) nvs: nvs_set ap.phym 1 3
D (599) nvs: nvs_get ap.phybw 1
D (599) nvs: nvs_set ap.phybw 1 2
D (609) nvs: nvs_get ap.sndchan 1
D (609) nvs: nvs_set ap.sndchan 1 1
D (609) nvs: nvs_set_blob sta.mac 6
D (619) nvs: nvs_set_blob ap.mac 6
I (619) wifi: Init dynamic tx buffer num: 32
I (619) wifi: Init data frame dynamic rx buffer num: 32
I (629) wifi: Init management frame dynamic rx buffer num: 32
I (629) wifi: wifi driver task: 3ffbf628, prio:23, stack:4096
I (639) wifi: Init static rx buffer num: 10
I (639) wifi: Init dynamic rx buffer num: 32
I (649) wifi: wifi power manager task: 0x3ffc59a8 prio: 21 stack: 2560
I (649) ota: Setting WiFi configuration SSID jones...
D (659) RTC_MODULE: Wi-Fi takes adc2 lock.
D (659) phy_init: loading PHY init data from application binary
D (669) nvs: nvs_open_from_partition phy 0
D (669) phy_init: esp_phy_load_cal_data_from_nvs: failed to open NVS namespace (0x1102)
W (679) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
V (689) phy_init: register_chipv7_phy, init_data=0x3f41239c, cal_data=0x3ffc5bb8, mode=2
I (879) phy: phy_version: 383.0, 79a622c, Jan 30 2018, 15:38:06, 1, 2
D (879) nvs: nvs_open_from_partition phy 1
V (879) phy_init: phy_get_rf_cal_version: 383

D (879) nvs: nvs_set cal_version 4 383
D (889) nvs: nvs_set_blob cal_mac 6
D (889) nvs: nvs_set_blob cal_data 1904
D (899) nvs: nvs_close 3
I (899) wifi: mode : sta (30:ae:a4:2d:36:c0)
D (899) event: SYSTEM_EVENT_STA_START
V (899) event: enter default callback
V (909) tcpip_adapter: check: local, if=0 fn=0x400e37e8
0x400e37e8: tcpip_adapter_start_api at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/tcpip_adapter/tcpip_adapter_lwip.c:1071


I (909) ota: Starting OTA example...
V (909) tcpip_adapter: call api in lwip: ret=0x0, give sem
V (919) tcpip_adapter: check: remote, if=0 fn=0x400e37e8
0x400e37e8: tcpip_adapter_start_api at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/tcpip_adapter/tcpip_adapter_lwip.c:1071


D (919) esp_ota_ops: found ota app max = 2
V (929) event: exit default callback
D (929) esp_ota_ops: finding factory app......
I (939) ota: Running partition type 0 subtype 0 (offset 0x00010000)
I (2019) wifi: n:9 2, o:1 0, ap:255 255, sta:9 2, prof:1
I (3009) wifi: state: init -> auth (b0)
I (3009) wifi: state: auth -> assoc (0)
I (3009) wifi: state: assoc -> run (10)
I (3029) wifi: connected with jones, channel 9
D (3029) event: SYSTEM_EVENT_STA_CONNECTED, ssid:jones, ssid_len:5, bssid:02:02:6f:cd:44:aa, channel:9, authmode:3
V (3029) event: enter default callback
V (3039) tcpip_adapter: check: local, if=0 fn=0x400e3a18
0x400e3a18: tcpip_adapter_up_api at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/tcpip_adapter/tcpip_adapter_lwip.c:1071


V (3039) tcpip_adapter: call api in lwip: ret=0x0, give sem
V (3049) tcpip_adapter: check: remote, if=0 fn=0x400e3a18
0x400e3a18: tcpip_adapter_up_api at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/tcpip_adapter/tcpip_adapter_lwip.c:1071


V (3049) tcpip_adapter: check: local, if=0 fn=0x400e3e6c
0x400e3e6c: tcpip_adapter_dhcpc_start_api at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/tcpip_adapter/tcpip_adapter_lwip.c:1071


D (3059) tcpip_adapter: dhcp client init ip/mask/gw to all-0
D (3059) tcpip_adapter: if0 start ip lost tmr: enter
D (3069) tcpip_adapter: if0 start ip lost tmr: no need start because netif=0x3ffc61bc interval=120 ip=0
D (3079) tcpip_adapter: dhcp client start successfully
V (3079) tcpip_adapter: call api in lwip: ret=0x0, give sem
V (3089) tcpip_adapter: check: remote, if=0 fn=0x400e3e6c
0x400e3e6c: tcpip_adapter_dhcpc_start_api at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/tcpip_adapter/tcpip_adapter_lwip.c:1071


V (3089) event: exit default callback
D (3859) tcpip_adapter: if0 dhcpc cb
D (3859) tcpip_adapter: if0 ip changed=1
D (3859) event: SYSTEM_EVENT_STA_GOT_IP, ip:192.168.1.25, mask:255.255.255.0, gw:192.168.1.1
V (3859) event: enter default callback
I (3859) event: sta ip: 192.168.1.25, mask: 255.255.255.0, gw: 192.168.1.1
V (3869) event: exit default callback
I (3879) ota: Connect to Wifi ! Start to Connect to Server....
I (3879) ota: Server IP: 192.168.1.12 Server Port:8070
I (3899) ota: Connected to server
I (3899) ota: Connected to http server
I (3909) ota: Send GET request to server succeeded
I (3909) ota: Writing to partition subtype 16 at offset 0x110000
I (4059) ota: esp_ota_begin succeeded
I (4069) ota: esp_ota_write header OK
I (4069) ota: Have written image length 1249
I (4069) wifi: pm start, type:0

I (4079) ota: Have written image length 1785
I (4079) ota: Have written image length 2321
I (4089) ota: Have written image length 2857
I (4099) ota: Have written image length 3393
I (4109) ota: Have written image length 3929
I (4109) ota: Have written image length 4465
I (4119) ota: Have written image length 5001
I (4119) ota: Have written image length 5537
I (4129) ota: Have written image length 6073
I (4129) ota: Have written image length 6609
I (4139) ota: Have written image length 7145
I (4139) ota: Have written image length 8169
I (4139) ota: Have written image length 8217
I (4149) ota: Have written image length 8753
I (4159) ota: Have written image length 9289
I (4159) ota: Have written image length 9825
I (4159) ota: Have written image length 10849
I (4159) ota: Have written image length 10897
I (4159) ota: Have written image length 11921
I (4169) ota: Have written image length 11969
I (4169) ota: Have written image length 12505
I (4169) ota: Have written image length 13041
I (4169) ota: Have written image length 13577
I (4169) ota: Have written image length 14113
I (4189) ota: Have written image length 14649
I (4199) ota: Have written image length 15185
I (4219) ota: Have written image length 15721
I (4219) ota: Have written image length 16257
I (4219) ota: Have written image length 16793
I (4229) ota: Have written image length 17817
I (4229) ota: Have written image length 17865
I (4239) ota: Have written image length 18401
I (4239) ota: Have written image length 18937
I (4249) ota: Have written image length 19961
I (4249) ota: Have written image length 20545
I (4259) ota: Have written image length 21569
I (4259) ota: Have written image length 21617
I (4259) ota: Have written image length 22641
I (4259) ota: Have written image length 22689
I (4259) ota: Have written image length 23713
I (4269) ota: Have written image length 23761
I (4269) ota: Have written image length 24297
I (4279) ota: Have written image length 24833
I (4279) ota: Have written image length 25369
I (4279) ota: Have written image length 25905
I (4289) ota: Have written image length 26441
I (4289) ota: Have written image length 26977
I (4289) ota: Have written image length 27513
I (4289) ota: Have written image length 28049
I (4299) ota: Have written image length 29073
I (4299) ota: Have written image length 29657
I (4299) ota: Have written image length 30193
I (4299) ota: Have written image length 30729
I (4299) ota: Have written image length 31265
I (4309) ota: Have written image length 31801
I (4309) ota: Have written image length 32337
I (4309) ota: Have written image length 32873
I (4309) ota: Have written image length 33409
I (4319) ota: Have written image length 33945
I (4319) ota: Have written image length 34481
I (4329) ota: Have written image length 35017
I (4339) ota: Have written image length 35553
I (4339) ota: Have written image length 36089
I (4349) ota: Have written image length 36625
I (4359) ota: Have written image length 37161
I (4359) ota: Have written image length 37697
I (4369) ota: Have written image length 38233
I (4379) ota: Have written image length 38769
I (4379) ota: Have written image length 39305
I (4389) ota: Have written image length 39841
I (4389) ota: Have written image length 40377
I (4399) ota: Have written image length 40913
I (4399) ota: Have written image length 41297
I (4399) ota: Have written image length 41833
I (4399) ota: Have written image length 42369
I (4399) ota: Have written image length 42905
I (4399) ota: Have written image length 43929
I (4399) ota: Have written image length 43977
I (4399) ota: Have written image length 44513
I (4409) ota: Have written image length 45049
I (4429) ota: Have written image length 45585
I (4429) ota: Have written image length 46121
I (4439) ota: Have written image length 46657
I (4459) ota: Have written image length 47193
I (4459) ota: Have written image length 47729
I (4469) ota: Have written image length 48265
I (4469) ota: Have written image length 49289
I (4469) ota: Have written image length 49337
I (4469) ota: Have written image length 50361
I (4469) ota: Have written image length 51385
I (4479) ota: Have written image length 52017
I (4479) ota: Have written image length 52553
I (4489) ota: Have written image length 53577
I (4489) ota: Have written image length 53625
I (4499) ota: Have written image length 54649
I (4499) ota: Have written image length 54697
I (4509) ota: Have written image length 55233
I (4509) ota: Have written image length 55769
I (4509) ota: Have written image length 56305
I (4519) ota: Have written image length 56841
I (4519) ota: Have written image length 57377
I (4529) ota: Have written image length 57913
I (4529) ota: Have written image length 58449
I (4539) ota: Have written image length 58985
I (4539) ota: Have written image length 59521
I (4549) ota: Have written image length 60057
I (4549) ota: Have written image length 60593
I (4549) ota: Have written image length 61129
I (4549) ota: Have written image length 61665
I (4559) ota: Have written image length 62201
I (4559) ota: Have written image length 62737
I (4569) ota: Have written image length 63273
I (4569) ota: Have written image length 63809
I (4569) ota: Have written image length 64345
I (4579) ota: Have written image length 64881
I (4579) ota: Have written image length 65417
I (4579) ota: Have written image length 65801
I (4589) ota: Have written image length 66337
I (4589) ota: Have written image length 66873
I (4589) ota: Have written image length 67409
I (4589) ota: Have written image length 67945
I (4589) ota: Have written image length 68481
I (4589) ota: Have written image length 69017
I (4589) ota: Have written image length 69553
I (4599) ota: Have written image length 70089
I (4599) ota: Have written image length 70625
I (4609) ota: Have written image length 71161
I (4609) ota: Have written image length 71697
I (4619) ota: Have written image length 72233
I (4619) ota: Have written image length 72769
I (4619) ota: Have written image length 73305
I (4629) ota: Have written image length 73841
I (4639) ota: Have written image length 74377
I (4639) ota: Have written image length 74913
I (4649) ota: Have written image length 75449
I (4649) ota: Have written image length 75985
I (4659) ota: Have written image length 76521
I (4659) ota: Have written image length 77057
I (4669) ota: Have written image length 77593
I (4669) ota: Have written image length 78129
I (4679) ota: Have written image length 78665
I (4689) ota: Have written image length 79201
I (4699) ota: Have written image length 79737
I (4699) ota: Have written image length 80273
I (4699) ota: Have written image length 80809
I (4699) ota: Have written image length 81345
I (4709) ota: Have written image length 81881
I (4719) ota: Have written image length 82417
I (4729) ota: Have written image length 82953
I (4729) ota: Have written image length 83489
I (4739) ota: Have written image length 84025
I (4739) ota: Have written image length 84561
I (4739) ota: Have written image length 85097
I (4739) ota: Have written image length 86121
I (4739) ota: Have written image length 86169
I (4739) ota: Have written image length 86705
I (4739) ota: Have written image length 87729
I (4739) ota: Have written image length 87777
I (4749) ota: Have written image length 88801
I (4749) ota: Have written image length 88849
I (4749) ota: Have written image length 89385
I (4759) ota: Have written image length 90409
I (4759) ota: Have written image length 90457
I (4769) ota: Have written image length 91481
I (4769) ota: Have written image length 91529
I (4779) ota: Have written image length 92553
I (4789) ota: Have written image length 93137
I (4789) ota: Have written image length 94161
I (4799) ota: Have written image length 94209
I (4799) ota: Have written image length 94745
I (4799) ota: Have written image length 95769
I (4799) ota: Have written image length 95817
I (4809) ota: Have written image length 96353
I (4819) ota: Have written image length 96889
I (4829) ota: Have written image length 97425
I (4829) ota: Have written image length 98449
I (4839) ota: Have written image length 98497
I (4839) ota: Have written image length 99521
I (4839) ota: Have written image length 100105
I (4839) ota: Have written image length 101129
I (4849) ota: Have written image length 101177
I (4849) ota: Have written image length 102201
I (4859) ota: Have written image length 102249
I (4859) ota: Have written image length 102785
I (4859) ota: Have written image length 103321
I (4869) ota: Have written image length 103857
I (4879) ota: Have written image length 104393
I (4879) ota: Have written image length 104929
I (4889) ota: Have written image length 105465
I (4889) ota: Have written image length 106001
I (4899) ota: Have written image length 106537
I (4899) ota: Have written image length 107073
I (4909) ota: Have written image length 107609
I (4919) ota: Have written image length 108633
I (4919) ota: Have written image length 108681
I (4919) ota: Have written image length 109705
I (4919) ota: Have written image length 109753
I (4919) ota: Have written image length 110777
I (4929) ota: Have written image length 110825
I (4929) ota: Have written image length 111361
I (4939) ota: Have written image length 111897
I (4939) ota: Have written image length 112433
I (4949) ota: Have written image length 112969
I (4949) ota: Have written image length 113993
I (4949) ota: Have written image length 114041
I (4949) ota: Have written image length 115065
I (4949) ota: Have written image length 115113
I (4959) ota: Have written image length 116137
I (4959) ota: Have written image length 116185
I (4959) ota: Have written image length 117209
I (4959) ota: Have written image length 117257
I (4959) ota: Have written image length 117793
I (4969) ota: Have written image length 118329
I (4969) ota: Have written image length 118865
I (4969) ota: Have written image length 119401
I (4969) ota: Have written image length 119937
I (4969) ota: Have written image length 120961
I (4969) ota: Have written image length 121009
I (4979) ota: Have written image length 122033
I (4979) ota: Have written image length 123057
I (4979) ota: Have written image length 123153
I (4989) ota: Have written image length 123689
I (4989) ota: Have written image length 124225
I (4999) ota: Have written image length 124761
I (4999) ota: Have written image length 125297
I (5009) ota: Have written image length 125833
I (5009) ota: Have written image length 126369
I (5009) ota: Have written image length 126905
I (5009) ota: Have written image length 127441
I (5019) ota: Have written image length 127977
I (5029) ota: Have written image length 128513
I (5029) ota: Have written image length 129049
I (5029) ota: Have written image length 129585
I (5029) ota: Have written image length 130121
I (5039) ota: Have written image length 130657
I (5039) ota: Have written image length 131193
I (5049) ota: Have written image length 131729
I (5049) ota: Have written image length 132753
I (5049) ota: Have written image length 133337
I (5059) ota: Have written image length 133873
I (5069) ota: Have written image length 134409
I (5069) ota: Have written image length 134945
I (5079) ota: Have written image length 135481
I (5079) ota: Have written image length 136017
I (5079) ota: Have written image length 137041
I (5079) ota: Have written image length 137089
I (5089) ota: Have written image length 137625
I (5089) ota: Have written image length 137824
I (5089) ota: Connection closed, all packets received
I (5099) ota: Total Write binary data length : 137824
D (5109) esp_image: reading image header @ 0x110000
D (5109) esp_image: image header: 0xe9 0x07 0x02 0x01 40080e88
V (5119) esp_image: loading segment header 0 at offset 0x110018
V (5119) esp_image: segment data length 0x5604 data starts 0x110020
V (5129) esp_image: segment 0 map_segment 1 segment_data_offs 0x110020 load_addr 0x3f400020
I (5139) esp_image: segment 0: paddr=0x00110020 vaddr=0x3f400020 size=0x05604 ( 22020) map
V (5159) esp_image: loading segment header 1 at offset 0x115624
V (5159) esp_image: segment data length 0x21c4 data starts 0x11562c
V (5169) esp_image: segment 1 map_segment 0 segment_data_offs 0x11562c load_addr 0x3ffb0000
I (5169) esp_image: segment 1: paddr=0x0011562c vaddr=0x3ffb0000 size=0x021c4 (  8644)
V (5189) esp_image: loading segment header 2 at offset 0x1177f0
V (5189) esp_image: segment data length 0x400 data starts 0x1177f8
V (5189) esp_image: segment 2 map_segment 0 segment_data_offs 0x1177f8 load_addr 0x40080000
0x40080000: _iram_start at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

I (5199) esp_image: segment 2: paddr=0x001177f8 vaddr=0x40080000 size=0x00400 (  1024)
0x40080000: _iram_start at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (5209) esp_image: loading segment header 3 at offset 0x117bf8
V (5219) esp_image: segment data length 0x8410 data starts 0x117c00
V (5219) esp_image: segment 3 map_segment 0 segment_data_offs 0x117c00 load_addr 0x40080400
I (5229) esp_image: segment 3: paddr=0x00117c00 vaddr=0x40080400 size=0x08410 ( 33808)
V (5269) esp_image: loading segment header 4 at offset 0x120010
V (5269) esp_image: segment data length 0x11764 data starts 0x120018
V (5269) esp_image: segment 4 map_segment 1 segment_data_offs 0x120018 load_addr 0x400d0018
0x400d0018: _stext at ??:?

I (5279) esp_image: segment 4: paddr=0x00120018 vaddr=0x400d0018 size=0x11764 ( 71524) map
0x400d0018: _stext at ??:?

V (5339) esp_image: loading segment header 5 at offset 0x13177c
V (5339) esp_image: segment data length 0x2a4 data starts 0x131784
V (5339) esp_image: segment 5 map_segment 0 segment_data_offs 0x131784 load_addr 0x40088810
0x40088810: ram_set_chan_cal_interp at /home/cff/gittree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_cal.c:2575

I (5349) esp_image: segment 5: paddr=0x00131784 vaddr=0x40088810 size=0x002a4 (   676)
0x40088810: ram_set_chan_cal_interp at /home/cff/gittree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_cal.c:2575

V (5359) esp_image: loading segment header 6 at offset 0x131a28
V (5369) esp_image: segment data length 0x0 data starts 0x131a30
V (5369) esp_image: segment 6 map_segment 0 segment_data_offs 0x131a30 load_addr 0x400c0000
I (5379) esp_image: segment 6: paddr=0x00131a30 vaddr=0x400c0000 size=0x00000 (     0)
V (5389) esp_image: image start 0x00110000 end of last section 0x00131a30
D (5399) esp_image: Calculated hash: 648db12d
D (5399) esp_image: reading image header @ 0x110000
D (5409) esp_image: image header: 0xe9 0x07 0x02 0x01 40080e88
V (5409) esp_image: loading segment header 0 at offset 0x110018
V (5419) esp_image: segment data length 0x5604 data starts 0x110020
V (5419) esp_image: segment 0 map_segment 1 segment_data_offs 0x110020 load_addr 0x3f400020
I (5429) esp_image: segment 0: paddr=0x00110020 vaddr=0x3f400020 size=0x05604 ( 22020) map
V (5459) esp_image: loading segment header 1 at offset 0x115624
V (5459) esp_image: segment data length 0x21c4 data starts 0x11562c
V (5459) esp_image: segment 1 map_segment 0 segment_data_offs 0x11562c load_addr 0x3ffb0000
I (5469) esp_image: segment 1: paddr=0x0011562c vaddr=0x3ffb0000 size=0x021c4 (  8644)
V (5479) esp_image: loading segment header 2 at offset 0x1177f0
V (5479) esp_image: segment data length 0x400 data starts 0x1177f8
V (5489) esp_image: segment 2 map_segment 0 segment_data_offs 0x1177f8 load_addr 0x40080000
0x40080000: _iram_start at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

I (5499) esp_image: segment 2: paddr=0x001177f8 vaddr=0x40080000 size=0x00400 (  1024)
0x40080000: _iram_start at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (5509) esp_image: loading segment header 3 at offset 0x117bf8
V (5509) esp_image: segment data length 0x8410 data starts 0x117c00
V (5519) esp_image: segment 3 map_segment 0 segment_data_offs 0x117c00 load_addr 0x40080400
I (5529) esp_image: segment 3: paddr=0x00117c00 vaddr=0x40080400 size=0x08410 ( 33808)
V (5559) esp_image: loading segment header 4 at offset 0x120010
V (5559) esp_image: segment data length 0x11764 data starts 0x120018
V (5559) esp_image: segment 4 map_segment 1 segment_data_offs 0x120018 load_addr 0x400d0018
0x400d0018: _stext at ??:?

I (5569) esp_image: segment 4: paddr=0x00120018 vaddr=0x400d0018 size=0x11764 ( 71524) map
0x400d0018: _stext at ??:?

V (5639) esp_image: loading segment header 5 at offset 0x13177c
V (5639) esp_image: segment data length 0x2a4 data starts 0x131784
V (5639) esp_image: segment 5 map_segment 0 segment_data_offs 0x131784 load_addr 0x40088810
0x40088810: ram_set_chan_cal_interp at /home/cff/gittree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_cal.c:2575

I (5649) esp_image: segment 5: paddr=0x00131784 vaddr=0x40088810 size=0x002a4 (   676)
0x40088810: ram_set_chan_cal_interp at /home/cff/gittree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_cal.c:2575

V (5659) esp_image: loading segment header 6 at offset 0x131a28
V (5659) esp_image: segment data length 0x0 data starts 0x131a30
V (5669) esp_image: segment 6 map_segment 0 segment_data_offs 0x131a30 load_addr 0x400c0000
I (5669) esp_image: segment 6: paddr=0x00131a30 vaddr=0x400c0000 size=0x00000 (     0)
V (5679) esp_image: image start 0x00110000 end of last section 0x00131a30
D (5689) esp_image: Calculated hash: 648db12d
I (5699) ota: Prepare to restart system!
I (5699) wifi: state: run -> init (0)
I (5699) wifi: pm stop, total sleep time: 0/2099521

I (5699) wifi: n:9 0, o:9 2, ap:255 255, sta:9 2, prof:1
D (5709) event: SYSTEM_EVENT_STA_DISCONNECTED, ssid:jones, ssid_len:5, bssid:02:02:6f:cd:44:aa, reason:8
V (5719) event: enter default callback
I (5719) wifi: flush txq
I (5719) wifi: stop sw txq
I (5729) wifi: lmac stop hw txq
D (5729) RTC_MODULE: Wi-Fi returns adc2 lock.
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:7976
load:0x40078000,len:0
ho 12 tail 0 room 4
load:0x40078000,len:15288
entry 0x40079394
I (31) boot: ESP-IDF v3.1-dev-601-gda278163-dirty 2nd stage bootloader
I (31) boot: compile time 17:00:24
I (40) boot: Enabling RNG early entropy source...
D (40) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (44) boot: magic e9
D (46) boot: segments 04
D (49) boot: spi_mode 02
D (51) boot: spi_speed 00
D (54) boot: spi_size 02
I (56) boot: SPI Speed      : 40MHz
I (61) boot: SPI Mode       : DIO
I (65) boot: SPI Flash Size : 4MB
D (69) bootloader_flash: mmu set paddr=00000000 count=1
D (74) boot: mapped partition table 0x8000 at 0x3f408000
D (79) flash_parts: partition table verified, 7 entries
I (85) boot: Partition Table:
I (88) boot: ## Label            Usage          Type ST Offset   Length
D (96) boot: load partition table entry 0x3f408000
D (100) boot: type=1 subtype=2
I (104) boot:  0 nvs              WiFi data        01 02 00009000 00004000
D (111) boot: load partition table entry 0x3f408020
D (116) boot: type=1 subtype=0
I (119) boot:  1 otadata          OTA data         01 00 0000d000 00002000
D (127) boot: load partition table entry 0x3f408040
D (132) boot: type=1 subtype=1
I (135) boot:  2 phy_init         RF data          01 01 0000f000 00001000
D (142) boot: load partition table entry 0x3f408060
D (147) boot: type=0 subtype=0
I (150) boot:  3 factory          factory app      00 00 00010000 00100000
D (158) boot: load partition table entry 0x3f408080
D (163) boot: type=0 subtype=10
I (166) boot:  4 ota_0            OTA app          00 10 00110000 00100000
D (174) boot: load partition table entry 0x3f4080a0
D (179) boot: type=0 subtype=11
I (182) boot:  5 ota_1            OTA app          00 11 00210000 00100000
I (189) boot: End of partition table
D (194) boot: OTA data offset 0xd000
D (197) bootloader_flash: mmu set paddr=00000000 count=1
D (203) boot: OTA sequence values A 0x00000001 B 0xffffffff
D (208) boot: Only OTA sequence A is valid. Mapping seq 0 -> OTA slot 0
D (215) boot: Trying partition index 0 offs 0x110000 size 0x100000
D (221) esp_image: reading image header @ 0x110000
D (226) bootloader_flash: mmu set block paddr=0x00110000 (was 0xffffffff)
D (233) esp_image: image header: 0xe9 0x07 0x02 0x01 40080e88
V (239) esp_image: loading segment header 0 at offset 0x110018
V (245) esp_image: segment data length 0x5604 data starts 0x110020
V (251) esp_image: segment 0 map_segment 1 segment_data_offs 0x110020 load_addr 0x3f400020
I (259) esp_image: segment 0: paddr=0x00110020 vaddr=0x3f400020 size=0x05604 ( 22020) map
D (268) bootloader_flash: mmu set paddr=00110000 count=1
V (282) esp_image: loading segment header 1 at offset 0x115624
D (282) bootloader_flash: mmu set block paddr=0x00110000 (was 0xffffffff)
V (286) esp_image: segment data length 0x21c4 data starts 0x11562c
V (293) esp_image: segment 1 map_segment 0 segment_data_offs 0x11562c load_addr 0x3ffb0000
I (301) esp_image: segment 1: paddr=0x0011562c vaddr=0x3ffb0000 size=0x021c4 (  8644) load
D (310) bootloader_flash: mmu set paddr=00110000 count=1
V (319) esp_image: loading segment header 2 at offset 0x1177f0
D (321) bootloader_flash: mmu set block paddr=0x00110000 (was 0xffffffff)
V (328) esp_image: segment data length 0x400 data starts 0x1177f8
V (334) esp_image: segment 2 map_segment 0 segment_data_offs 0x1177f8 load_addr 0x40080000
0x40080000: _iram_start at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

I (342) esp_image: segment 2: paddr=0x001177f8 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _iram_start at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

D (351) bootloader_flash: mmu set paddr=00110000 count=1
V (357) esp_image: loading segment header 3 at offset 0x117bf8
D (363) bootloader_flash: mmu set block paddr=0x00110000 (was 0xffffffff)
V (370) esp_image: segment data length 0x8410 data starts 0x117c00
V (376) esp_image: segment 3 map_segment 0 segment_data_offs 0x117c00 load_addr 0x40080400
I (384) esp_image: segment 3: paddr=0x00117c00 vaddr=0x40080400 size=0x08410 ( 33808) load
D (393) bootloader_flash: mmu set paddr=00110000 count=2
V (412) esp_image: loading segment header 4 at offset 0x120010
D (413) bootloader_flash: mmu set block paddr=0x00120000 (was 0xffffffff)
V (414) esp_image: segment data length 0x11764 data starts 0x120018
V (420) esp_image: segment 4 map_segment 1 segment_data_offs 0x120018 load_addr 0x400d0018
0x400d0018: _stext at ??:?

I (429) esp_image: segment 4: paddr=0x00120018 vaddr=0x400d0018 size=0x11764 ( 71524) map
0x400d0018: _stext at ??:?

D (438) bootloader_flash: mmu set paddr=00120000 count=2
V (469) esp_image: loading segment header 5 at offset 0x13177c
D (469) bootloader_flash: mmu set block paddr=0x00130000 (was 0xffffffff)
V (470) esp_image: segment data length 0x2a4 data starts 0x131784
V (476) esp_image: segment 5 map_segment 0 segment_data_offs 0x131784 load_addr 0x40088810
0x40088810: ram_set_chan_cal_interp at /home/cff/gittree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_cal.c:2575

I (485) esp_image: segment 5: paddr=0x00131784 vaddr=0x40088810 size=0x002a4 (   676) load
0x40088810: ram_set_chan_cal_interp at /home/cff/gittree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_cal.c:2575

D (494) bootloader_flash: mmu set paddr=00130000 count=1
V (499) esp_image: loading segment header 6 at offset 0x131a28
D (505) bootloader_flash: mmu set block paddr=0x00130000 (was 0xffffffff)
V (512) esp_image: segment data length 0x0 data starts 0x131a30
V (518) esp_image: segment 6 map_segment 0 segment_data_offs 0x131a30 load_addr 0x400c0000
I (526) esp_image: segment 6: paddr=0x00131a30 vaddr=0x400c0000 size=0x00000 (     0) load
D (535) bootloader_flash: mmu set paddr=00130000 count=1
V (540) esp_image: image start 0x00110000 end of last section 0x00131a30
D (547) bootloader_flash: mmu set block paddr=0x00130000 (was 0xffffffff)
D (554) esp_image: Calculated hash: 648db12d
D (558) bootloader_flash: mmu set paddr=00130000 count=1
I (569) boot: Loaded app from partition at offset 0x110000
I (570) boot: Disabling RNG early entropy source...
D (576) boot: Mapping segment 0 as IROM
D (579) boot: Mapping segment 4 as DROM
D (583) boot: calling set_cache_and_start_app
D (588) boot: configure drom and irom and start
V (592) boot: d mmu set paddr=00120000 vaddr=400d0000 size=71524 n=2
V (599) boot: rc=0
V (601) boot: rc=0
V (603) boot: i mmu set paddr=00110000 vaddr=3f400000 size=22020 n=1
V (609) boot: rc=0
V (611) boot: rc=0
D (614) boot: start: 0x40080e88
0x40080e88: start_cpu0_default at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/esp32/cpu_start.c:321

I (617) cpu_start: Pro cpu up.
I (620) cpu_start: Starting app cpu, entry point is 0x40080e40
0x40080e40: start_cpu0_default at C:/esp32_toolchain/msys32/home/Jim/esp/esp-idf/components/esp32/cpu_start.c:294

I (606) cpu_start: App cpu up.
I (631) heap_init: Initializing. RAM available for dynamic allocation:
I (638) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (644) heap_init: At 3FFB29B0 len 0002D650 (181 KiB): DRAM
I (650) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (657) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (663) heap_init: At 40088AB4 len 0001754C (93 KiB): IRAM
I (669) cpu_start: Pro cpu start user code
I (16) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.


Jim@35D MINGW32 ~/esp/esp-idf/examples/system/ota

Re: Need help with OTA [Solved]

Posted: Sat Apr 28, 2018 8:54 pm
by chegewara
https://gist.github.com/chegewara/4b0ce ... 2488d6cb84

Re: Need help with OTA [Solved]

Posted: Sun Apr 29, 2018 2:35 pm
by fly135
According to this line it worked...

"I (569) boot: Loaded app from partition at offset 0x110000"

If you run it repeatedly you should see that line toggle betweeen 0x110000 and 0x210000. If it does that the you are burning something to those partitions, and it's booting it.

John A

Re: Need help with OTA [Solved]

Posted: Sun Apr 29, 2018 2:54 pm
by sellonoid
Thank you for checking that out!

So after doing everything that produced the output that you looked at, I do this:

1. Edit "blink.c", and run make again. End up with new "blink.bin".
2. Disconnect ESP32 from USB cable and power it from power supply.
4. Reset ESP32 and it should access the SimpleHTTPServer via WiFi and download "blink.bin".
5. ESP32 starts running the newly downloaded "blink.bin".

Is that the way it should work?

Re: Need help with OTA [Solved]

Posted: Sun Apr 29, 2018 4:54 pm
by fly135
OK, you end up with new blink.bin and upload it to the server. Why bother disconnecting from the USB? What step required you to hook it back to the usb. If you are just editing/compiling/uploading to server, then how did the ESP32 get back on the USB in between? Leave it there and monitor the operation with the terminal program. From what I could tell you are burning into the OTA partition and booting from it. Did you verify that each OTA of a new blink.bin toggles the boot between your two OTA partitions? If so then you are burning from code delivered from the server.

John A

Re: Need help with OTA [Solved]

Posted: Sun Apr 29, 2018 8:27 pm
by sellonoid
I disconnected from the USB to satisfy myself that OTA updates were working, and I hooked it back to the server (USB) to start fresh by flashing "ota_example_main" again. Sorry if all of that is unnecessary and confusing.

I just tested again and flashing "ota_example_main" repeatedly, gives the same "I (569) boot: Loaded app from partition at offset 0x110000" every time. I never see 0x210000. I just double checked menuconfig and it shows that "Factory app, two OTA definitions" is selected.

But there's still something I don't get. What in the world actually invokes the over the air update? My amateur analysis of the code in "ota_example_main.c" looks like on each boot up, it connects to the SimpleHTTPServer. That is where I got the idea that a reboot causes the ESP32 to download the latest version of (in my case), "blink.bin". Am I right or wrong about that?

Jim

Re: Need help with OTA [Solved]

Posted: Sun Apr 29, 2018 9:23 pm
by fly135
The OTA update is initiated by you. You have to decide when and why it's updated. If it's not toggling between updates then it's not updating. You managed to burn into the first OTA partition and then you are apparently failing after that. Once you burn to an OTA it never boots from the factory (i.e. the one you burn with "make flash") again. You can flash the partition but it won't boot from it until you erase the OTADATA partition.

The OTA code is just one small part of whatever app you are writing. Somewhere in your app you have to decide what initiates an update. It could be a button on the device. I could be an MQTT message that you send. It could be that the device checks some place on the cloud to see if there is a new version.

My advice is that you hook up to the usb and log everything going on. Make sure that the OTA is completing and then rebooting to the alternate partition each time.

John A

Re: Need help with OTA [Solved]

Posted: Sun Apr 29, 2018 9:29 pm
by fly135
"That is where I got the idea that a reboot causes the ESP32 to download the latest version of (in my case), "blink.bin". Am I right or wrong about that?"

An example program isn't really going to behave the same as a real life application. So don't get hung up on that.

The following is important in your app. You should see it writing to the alternate partition every time. That's the first line in this code snip that I got from your log.

Code: Select all

I (3909) ota: Writing to partition subtype 16 at offset 0x110000
I (4059) ota: esp_ota_begin succeeded
I (4069) ota: esp_ota_write header OK
I (4069) ota: Have written image length 1249
I (4069) wifi: pm start, type:0

I (4079) ota: Have written image length 1785
I (4079) ota: Have written image length 2321
I (4089) ota: Have written image length 2857
I (4099) ota: Have written image length 3393
I (4109) ota: Have written image length 3929
Then eventually you need to see this to make sure it got all the way done...

"I (5699) ota: Prepare to restart system!"

You have a lot of debugging turned on that kind of obscures the actual OTA code in the example. But just make sure all those writes finished with the correct size of the update file and that it gives that last message.

I just incorporated the example into my application so it only updates when I tell it to and the reboot is performed by my code elsewhere. So if the example automatically updates and automatically reboots, then it's just going to be doing that repeatedly. Which is not useful for anything but an example.

John A
All times are UTC
Page 2 of 3
Powered by phpBB® Forum Software © phpBB Limited
https://www.phpbb.com/