Thanks for support and I now have three devices provisioned and claimed.
When they were first provisioned the iPAD could see them and I could see that the node saw each press of the switch (via debug). One the devices were unplugged/reset they seems to be read to connect but the iPAD has not been able to communicate - all three devices appear offline. All nodes appear on the online dashboard.
I'm on the development master IDF, using VS environment and using devkit Wrover boards.
I'm assuming I've missed something simple?/
EDIT 1: Whilst I can see the nodes on the dashboard the 'get nodes' CLI command returns "User is not associated with any nodes"??
EDIT 2: The nodes appear on the dashboard but are not being updated - for example with the number of reboots.
Code: Select all
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:0x3fff0030,len:6956
ho 0 tail 12 room 4
load:0x40078000,len:14336
load:0x40080400,len:3672
0x40080400: _init at ??:?
entry 0x40080678
I (29) boot: ESP-IDF v4.4-dev-4-g73db14240 2nd stage bootloader
I (29) boot: compile time 14:11:51
I (29) boot: chip revision: 1
I (33) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (40) boot.esp32: SPI Speed : 40MHz
I (44) boot.esp32: SPI Mode : DIO
I (49) boot.esp32: SPI Flash Size : 4MB
I (54) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (63) boot: ## Label Usage Type ST Offset Length
I (70) boot: 0 sec_cert unknown 3f 00 0000d000 00003000
I (77) boot: 1 nvs WiFi data 01 02 00010000 00006000
I (85) boot: 2 otadata OTA data 01 00 00016000 00002000
I (92) boot: 3 phy_init RF data 01 01 00018000 00001000
I (100) boot: 4 ota_0 OTA app 00 10 00020000 00190000
I (107) boot: 5 ota_1 OTA app 00 11 001b0000 00190000
I (115) boot: 6 fctry WiFi data 01 02 00340000 00006000
I (122) boot: End of partition table
I (127) boot_comm: chip revision: 1, min. application chip revision: 0
I (134) esp_image: segment 0: paddr=00020020 vaddr=3f400020 size=39fdch (237532) map
I (226) esp_image: segment 1: paddr=0005a004 vaddr=3ffbdb60 size=051c0h ( 20928) load
I (234) esp_image: segment 2: paddr=0005f1cc vaddr=40080000 size=00e4ch ( 3660) load
I (236) esp_image: segment 3: paddr=00060020 vaddr=400d0020 size=dceb0h (904880) map
I (559) esp_image: segment 4: paddr=0013ced8 vaddr=40080e4c size=1e0cch (123084) load
I (625) boot: Loaded app from partition at offset 0x20000
I (625) boot: Disabling RNG early entropy source...
I (637) cpu_start: Pro cpu up.
I (637) cpu_start: Starting app cpu, entry point is 0x40081320
0x40081320: call_start_cpu1 at /Users/colinives/esp/esp-idf/components/esp_system/port/cpu_start.c:143
I (0) cpu_start: App cpu up.
D (645) clk: RTC_SLOW_CLK calibration value: 3359565
I (659) cpu_start: Pro cpu start user code
I (659) cpu_start: cpu freq: 160000000
I (659) cpu_start: Application information:
I (663) cpu_start: Project name: switch
I (668) cpu_start: App version: 1.0
I (672) cpu_start: Compile time: Mar 5 2021 14:11:32
I (679) cpu_start: ELF file SHA256: 94ec9a63e57c3f66...
I (685) cpu_start: ESP-IDF: v4.4-dev-4-g73db14240
D (691) memory_layout: Checking 11 reserved memory ranges:
D (696) memory_layout: Reserved memory range 0x3ffae000 - 0x3ffae6e0
D (703) memory_layout: Reserved memory range 0x3ffae6e0 - 0x3ffaff10
D (709) memory_layout: Reserved memory range 0x3ffb0000 - 0x3ffb6388
D (716) memory_layout: Reserved memory range 0x3ffb8000 - 0x3ffb9a20
D (722) memory_layout: Reserved memory range 0x3ffbdb28 - 0x3ffbdb5c
D (728) memory_layout: Reserved memory range 0x3ffbdb60 - 0x3ffc9168
D (735) memory_layout: Reserved memory range 0x3ffe0000 - 0x3ffe0440
D (741) memory_layout: Reserved memory range 0x3ffe3f20 - 0x3ffe4350
D (748) memory_layout: Reserved memory range 0x40070000 - 0x40078000
D (754) memory_layout: Reserved memory range 0x40078000 - 0x40080000
0x40080000: _WindowOverflow4 at /Users/colinives/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1730
D (760) memory_layout: Reserved memory range 0x40080000 - 0x4009ef18
0x40080000: _WindowOverflow4 at /Users/colinives/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1730
D (767) memory_layout: Building list of available memory regions:
D (773) memory_layout: Available memory region 0x3ffaff10 - 0x3ffb0000
D (780) memory_layout: Available memory region 0x3ffb6388 - 0x3ffb8000
D (786) memory_layout: Available memory region 0x3ffb9a20 - 0x3ffbdb28
D (793) memory_layout: Available memory region 0x3ffc9168 - 0x3ffca000
D (799) memory_layout: Available memory region 0x3ffca000 - 0x3ffcc000
D (806) memory_layout: Available memory region 0x3ffcc000 - 0x3ffce000
D (813) memory_layout: Available memory region 0x3ffce000 - 0x3ffd0000
D (819) memory_layout: Available memory region 0x3ffd0000 - 0x3ffd2000
D (826) memory_layout: Available memory region 0x3ffd2000 - 0x3ffd4000
D (832) memory_layout: Available memory region 0x3ffd4000 - 0x3ffd6000
D (839) memory_layout: Available memory region 0x3ffd6000 - 0x3ffd8000
D (846) memory_layout: Available memory region 0x3ffd8000 - 0x3ffda000
D (852) memory_layout: Available memory region 0x3ffda000 - 0x3ffdc000
D (859) memory_layout: Available memory region 0x3ffdc000 - 0x3ffde000
D (865) memory_layout: Available memory region 0x3ffde000 - 0x3ffe0000
D (872) memory_layout: Available memory region 0x3ffe0440 - 0x3ffe3f20
D (879) memory_layout: Available memory region 0x3ffe4350 - 0x3ffe8000
D (885) memory_layout: Available memory region 0x3ffe8000 - 0x3fff0000
D (892) memory_layout: Available memory region 0x3fff0000 - 0x3fff8000
D (898) memory_layout: Available memory region 0x3fff8000 - 0x3fffc000
D (905) memory_layout: Available memory region 0x3fffc000 - 0x40000000
D (912) memory_layout: Available memory region 0x4009ef18 - 0x400a0000
I (918) heap_init: Initializing. RAM available for dynamic allocation:
I (925) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
D (932) heap_init: New heap initialised at 0x3ffb6388
I (937) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
D (943) heap_init: New heap initialised at 0x3ffb9a20
I (948) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
D (954) heap_init: New heap initialised at 0x3ffc9168
I (959) heap_init: At 3FFC9168 len 00016E98 (91 KiB): DRAM
I (965) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (972) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
D (978) heap_init: New heap initialised at 0x4009ef18
I (983) heap_init: At 4009EF18 len 000010E8 (4 KiB): IRAM
D (990) intr_alloc: Connected src 46 to int 2 (cpu 0)
D (995) FLASH_HAL: extra_dummy: 1
D (998) spi_flash: trying chip: issi
D (1001) spi_flash: trying chip: gd
D (1005) spi_flash: trying chip: mxic
D (1009) spi_flash: trying chip: winbond
D (1013) spi_flash: trying chip: generic
I (1017) spi_flash: detected chip: generic
I (1022) spi_flash: flash io: dio
D (1026) cpu_start: calling init function: 0x401904d8
0x401904d8: http_auth_digest at /Users/colinives/esp/esp-idf/components/esp_http_client/lib/http_auth.c:77
D (1031) cpu_start: calling init function: 0x40091378
0x40091378: esp_reset_reason_init at /Users/colinives/esp/esp-idf/components/esp_system/port/soc/esp32/reset_reason.c:73
D (1036) cpu_start: calling init function: 0x401137d0
0x401137d0: outbox_enqueue at /Users/colinives/esp/esp-idf/components/mqtt/esp-mqtt/lib/mqtt_outbox.c:54
D (1041) cpu_start: calling init function: 0x400d5bb8
0x400d5bb8: uart_tcgetattr at /Users/colinives/esp/esp-idf/components/vfs/vfs_uart.c:763
D (1046) cpu_start: calling init function: 0x400d2a84
0x400d2a84: ram_en_pwdet at ??:?
D (1051) intr_alloc: Connected src 17 to int 3 (cpu 0)
D (1057) intr_alloc: Connected src 24 to int 9 (cpu 0)
I (1062) cpu_start: Starting scheduler on PRO CPU.
D (0) intr_alloc: Connected src 25 to int 2 (cpu 1)
I (0) cpu_start: Starting scheduler on APP CPU.
D (1077) heap_init: New heap initialised at 0x3ffe0440
D (1087) heap_init: New heap initialised at 0x3ffe4350
D (1097) intr_alloc: Connected src 16 to int 12 (cpu 0)
I (1097) esp_rmaker_commands: Registering command: up-time
I (1097) esp_rmaker_console: Initialising UART on port 0
I (1107) uart: queue free spaces: 8
D (1117) intr_alloc: Connected src 34 to int 13 (cpu 0)
I (1117) esp_rmaker_commands: Registering command: mem-dump
I (1127) esp_rmaker_commands: Registering command: task-dump
I (1127) esp_rmaker_commands: Registering command: cpu-dump
I (1137) esp_rmaker_commands: Registering command: sock-dump
I (1147) esp_rmaker_commands: Registering command: heap-trace
I (1147) esp_rmaker_commands: Registering command: reset-to-factory
I (1157) esp_rmaker_commands: Registering command: add-user
I (1167) esp_rmaker_commands: Registering command: get-node-id
I (1167) esp_rmaker_commands: Registering command: wifi-prov
I (1177) esp_rmaker_commands: Registering command: local-time
I (1187) esp_rmaker_commands: Registering command: tz-set
D (1187) intr_alloc: Connected src 22 to int 17 (cpu 0)
I (1197) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3
I (1207) gpio: GPIO[19]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
W (1217) ws2812_led: WS2812 LED is disabled
D (1217) partition: Loading the partition table
D (1267) esp_netif_lwip: LwIP stack has been initialized
D (1267) esp_netif_lwip: esp-netif has been successfully initialized
D (1267) event: running task for loop 0x3ffcda58
D (1267) event: created task for loop 0x3ffcda58
D (1277) event: created event loop 0x3ffcda58
D (1277) esp_netif_objects: esp_netif_add_to_list 0x3ffcea68
D (1287) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (1297) nvs: nvs_open_from_partition misc 1
D (1297) nvs: nvs_get_str_or_blob log
I (1307) wifi:wifi driver task: 3ffd1020, prio:23, stack:6656, core=0
I (1307) system_api: Base MAC address is not set
I (1307) system_api: read default base MAC address from EFUSE
D (1317) efuse: coding scheme 0
D (1317) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 8 bit
D (1327) efuse: coding scheme 0
D (1327) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 0 bit
D (1337) efuse: coding scheme 0
D (1337) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 24 bit
D (1347) efuse: coding scheme 0
D (1347) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 16 bit
D (1357) efuse: coding scheme 0
D (1357) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 8 bit
D (1367) efuse: coding scheme 0
D (1377) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 0 bit
D (1377) efuse: coding scheme 0
D (1387) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 16 bit
D (1387) nvs: nvs_open_from_partition nvs.net80211 1
D (1397) nvs: nvs_get opmode 1
D (1397) nvs: nvs_get_str_or_blob sta.ssid
D (1407) nvs: nvs_get sta.authmode 1
D (1407) nvs: nvs_get_str_or_blob sta.pswd
D (1407) nvs: nvs_get_str_or_blob sta.pmk
D (1417) nvs: nvs_get sta.chan 1
D (1417) nvs: nvs_get auto.conn 1
D (1417) nvs: nvs_get bssid.set 1
D (1427) nvs: nvs_get_str_or_blob sta.bssid
D (1427) nvs: nvs_get sta.lis_intval 2
D (1437) nvs: nvs_get sta.phym 1
D (1437) nvs: nvs_get sta.phybw 1
D (1437) nvs: nvs_get_str_or_blob sta.apsw
D (1447) nvs: nvs_get_str_or_blob sta.apinfo
D (1447) nvs: nvs_get sta.scan_method 1
D (1447) nvs: nvs_get sta.sort_method 1
D (1457) nvs: nvs_get sta.minrssi 1
D (1457) nvs: nvs_get sta.minauth 1
D (1467) nvs: nvs_get sta.pmf_e 1
D (1467) nvs: nvs_get sta.pmf_r 1
D (1467) nvs: nvs_get sta.btm_e 1
D (1477) nvs: nvs_get sta.rrm_e 1
D (1477) nvs: nvs_get_str_or_blob ap.ssid
D (1477) nvs: nvs_get_str_or_blob ap.passwd
D (1487) nvs: nvs_get_str_or_blob ap.pmk
D (1487) nvs: nvs_get ap.chan 1
D (1487) nvs: nvs_get ap.authmode 1
D (1497) nvs: nvs_get ap.hidden 1
D (1497) nvs: nvs_get ap.max.conn 1
D (1507) nvs: nvs_get bcn.interval 2
D (1507) nvs: nvs_get ap.phym 1
D (1507) nvs: nvs_get ap.phybw 1
D (1517) nvs: nvs_get ap.sndchan 1
D (1517) nvs: nvs_get ap.pmf_e 1
D (1517) nvs: nvs_get ap.pmf_r 1
D (1527) nvs: nvs_get ap.p_cipher 1
D (1527) nvs: nvs_get lorate 1
D (1527) nvs: nvs_get_str_or_blob country
D (1537) nvs: nvs_set ap.sndchan 1 1
I (1537) wifi:wifi firmware version: 6b2834e
I (1537) wifi:wifi certification version: v7.0
I (1547) wifi:config NVS flash: enabled
I (1547) wifi:config nano formating: disabled
I (1557) wifi:Init data frame dynamic rx buffer num: 32
I (1557) wifi:Init management frame dynamic rx buffer num: 32
I (1567) wifi:Init management short buffer num: 32
I (1567) wifi:Init dynamic tx buffer num: 32
I (1567) wifi:Init static rx buffer size: 1600
I (1577) wifi:Init static rx buffer num: 10
I (1577) wifi:Init dynamic rx buffer num: 32
I (1587) wifi_init: rx ba win: 6
I (1587) wifi_init: tcpip mbox: 32
I (1587) wifi_init: udp mbox: 6
I (1597) wifi_init: tcp mbox: 6
I (1597) wifi_init: tcp tx win: 5744
I (1607) wifi_init: tcp rx win: 5744
I (1607) wifi_init: tcp mss: 1440
I (1607) wifi_init: WiFi IRAM OP enabled
I (1617) wifi_init: WiFi RX IRAM OP enabled
D (1627) nvs: nvs_open_from_partition rmaker_creds 0
D (1627) nvs: nvs_get_str_or_blob node_id
D (1627) nvs: nvs_get_str_or_blob node_id
D (1637) nvs: nvs_close 3
I (1637) esp_rmaker_work_queue: Work Queue created.
D (1647) nvs: nvs_open_from_partition rmaker_creds 0
D (1647) nvs: nvs_get_str_or_blob client_key
D (1647) nvs: nvs_get_str_or_blob client_key
D (1667) nvs: nvs_close 4
D (1667) nvs: nvs_open_from_partition rmaker_creds 0
D (1667) nvs: nvs_get_str_or_blob client_cert
D (1667) nvs: nvs_get_str_or_blob client_cert
D (1687) nvs: nvs_close 5
D (1687) nvs: nvs_open_from_partition rmaker_creds 0
D (1687) nvs: nvs_get_str_or_blob mqtt_host
D (1687) nvs: nvs_get_str_or_blob mqtt_host
D (1687) nvs: nvs_close 6
I (1687) esp_mqtt_glue: Initialising MQTT
D (1697) MQTT_CLIENT: MQTT client_id=HZBp7ZqWKvGYFy4uZq4fP3
D (1707) event: created event loop 0x3ffd7a00
D (1707) event: running post RMAKER_EVENT:1 with handler 0x400da9ac and context 0x3ffcf5c4 on loop 0x3ffcda58
0x400da9ac: rtc_gpio_is_valid_gpio at /Users/colinives/esp/esp-idf/esp-rainmaker/rainmaker_examples/switch/build/../../../../components/driver/include/driver/rtc_io.h:37
(inlined by) rtc_gpio_deinit at /Users/colinives/esp/esp-idf/components/driver/rtc_io.c:54
I (1717) app_main: RainMaker Initialised.
I (1717) esp_rmaker_node: Node ID ----- HZBp7ZqWKvGYFy4uZq4fP3
D (1727) nvs: nvs_open_from_partition Switch 0
D (1727) nvs: nvs_get_str_or_blob Name
D (1737) nvs: nvs_get_str_or_blob Name
D (1737) nvs: nvs_close 7
D (1747) esp_rmaker_device: Param Name added in Switch
D (1747) esp_rmaker_device: Param Power added in Switch
I (1757) esp_rmaker_ota: OTA state = 2
D (1757) esp_rmaker_device: Param Status added in OTA
D (1767) esp_rmaker_device: Param Info added in OTA
D (1767) esp_rmaker_device: Param URL added in OTA
I (1777) esp_rmaker_ota_using_params: OTA enabled with Params
I (1777) esp_rmaker_time: Initializing SNTP. Using the SNTP server: pool.ntp.org
D (1787) nvs: nvs_open_from_partition rmaker_time 0
D (1797) nvs: nvs_open_from_partition Schedule 0
D (1797) nvs: nvs_get_str_or_blob Schedules
D (1797) nvs: nvs_get_str_or_blob Schedules
D (1807) nvs: nvs_close 8
D (1807) esp_rmaker_device: Param Schedules added in Schedule
D (1817) esp_rmaker_schedule: Scheduling Service Enabled
I (1817) esp_rmaker_core: Starting RainMaker Work Queue task
I (1827) esp_rmaker_work_queue: RainMaker Work Queue task started.
D (1827) wifi_prov_mgr: execute_event_cb : 0
D (1837) BTDM_INIT: Release DRAM [0x3ffb2730] - [0x3ffb6388]
I (1847) wifi_prov_scheme_ble: BT memory released
D (1847) event: running post WIFI_PROV_EVENT:0 with handler 0x400db4a4 and context 0x3ffce9d0 on loop 0x3ffcda58
0x400db4a4: esp_timer_create at /Users/colinives/esp/esp-idf/components/esp_timer/src/esp_timer.c:114
D (1857) event: running post WIFI_PROV_EVENT:0 with handler 0x400dd658 and context 0x3ffd5bb4 on loop 0x3ffcda58
0x400dd658: esp_rmaker_node_create at /Users/colinives/esp/esp-idf/esp-rainmaker/components/esp_rainmaker/src/core/esp_rmaker_node.c:132
D (1867) wifi_prov_mgr: Found Wi-Fi SSID : BTBHub6-5FKQ
D (1877) wifi_prov_mgr: Found Wi-Fi Password : N**********k
I (1877) app_wifi: Already provisioned, starting Wi-Fi STA
####################################################################################################
______ _____ _____ _____ _____ _ _ __ __ _ ________ _____
| ____|/ ____| __ \ | __ \ /\ |_ _| \ | | \/ | /\ | |/ / ____| __ \
| |__ | (___ | |__) | | |__) | / \ | | | \| | \ / | / \ | ' /| |__ | |__) |
| __| \___ \| ___/ | _ / / /\ \ | | | . ` | |\/| | / /\ \ | < | __| | _ /
| |____ ____) | | | | \ \ / ____ \ _| |_| |\ | | | |/ ____ \| . \| |____| | \ \
|______|_____/|_| |_| \_\/_/ \_\_____|_| \_|_| |_/_/ \_\_|\_\______|_| \_\
Welcome to ESP RainMaker switch demo application!
If you want to reset Wi-Fi credentials, or reset to factory, press and hold the Boot button.
This application uses ESP RainMaker, which is based on ESP IDF.
Check out the source code for this application here:
https://github.com/espressif/esp-rainmaker/blob/master/examples/switch
Please visit https://rainmaker.espressif.com for additional information.
####################################################################################################
D (1987) wifi_prov_mgr: Provisioning not running
D (1987) wifi_prov_mgr: execute_event_cb : 6
D (1997) BTDM_INIT: Release DRAM [0x3ffae6e0] - [0x3ffaff10]
D (1997) BTDM_INIT: Release DRAM [0x3ffb0000] - [0x3ffb2730]
D (2007) BTDM_INIT: Release DRAM [0x3ffb8000] - [0x3ffb9a20]
D (2017) BTDM_INIT: Release DRAM [0x3ffbdb28] - [0x3ffbdb5c]
D (2017) BTDM_INIT: Release BTDM BSS [0x3ffc435c] - [0x3ffc4ccc]
D (2027) BTDM_INIT: Release BTDM Data [0x3ffbdc28] - [0x3ffbdc4c]
D (2027) BTDM_INIT: Release BT BSS [0x3ffc2d20] - [0x3ffc435c]
D (2037) BTDM_INIT: Release BT Data [0x3ffbdb60] - [0x3ffbdc28]
I (2047) wifi_prov_scheme_ble: BTDM memory released
D (2047) event: running post WIFI_PROV_EVENT:6 with handler 0x400db4a4 and context 0x3ffce9d0 on loop 0x3ffcda58
0x400db4a4: esp_timer_create at /Users/colinives/esp/esp-idf/components/esp_timer/src/esp_timer.c:114
D (2057) ADC: Wi-Fi takes adc2 lock.
I (2067) phy_init: phy_version 4660,0162888,Dec 23 2020
D (2067) phy_init: loading PHY init data from application binary
D (2077) nvs: nvs_open_from_partition phy 0
D (2077) nvs: nvs_get cal_version 4
D (2087) nvs: nvs_get_str_or_blob cal_mac
D (2087) efuse: coding scheme 0
D (2087) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 8 bit
D (2097) efuse: coding scheme 0
D (2097) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 0 bit
D (2107) efuse: coding scheme 0
D (2107) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 24 bit
D (2117) efuse: coding scheme 0
D (2117) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 16 bit
D (2127) efuse: coding scheme 0
D (2127) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 8 bit
D (2137) efuse: coding scheme 0
D (2137) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 0 bit
D (2147) efuse: coding scheme 0
D (2147) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 16 bit
D (2157) nvs: nvs_get_str_or_blob cal_data
D (2167) nvs: nvs_close 9
D (2167) efuse: coding scheme 0
D (2167) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 8 bit
D (2177) efuse: coding scheme 0
D (2177) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 0 bit
D (2187) efuse: coding scheme 0
D (2187) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 24 bit
D (2197) efuse: coding scheme 0
D (2197) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 16 bit
D (2207) efuse: coding scheme 0
D (2207) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 8 bit
D (2217) efuse: coding scheme 0
D (2217) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 0 bit
D (2227) efuse: coding scheme 0
D (2227) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 16 bit
I (2327) wifi:mode : sta (ac:67:b2:53:80:f8)
I (2327) wifi:enable tsf
D (2327) event: running post WIFI_EVENT:2 with handler 0x400db4a4 and context 0x3ffcea04 on loop 0x3ffcda58
0x400db4a4: esp_timer_create at /Users/colinives/esp/esp-idf/components/esp_timer/src/esp_timer.c:114
D (2327) event: running post WIFI_EVENT:2 with handler 0x4012442c and context 0x3ffcecbc on loop 0x3ffcda58
0x4012442c: crypto_ec_point_mul at /Users/colinives/esp/esp-idf/components/wpa_supplicant/src/crypto/crypto_mbedtls-ec.c:261
I (2337) wifi:new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1
D (2347) wifi_init_default: wifi_start esp-netif:0x3ffcea68 event-id2
I (2347) wifi:state: init -> auth (b0)
D (2357) wifi_init_default: WIFI mac address: ac 67 b2 53 80 f8
D (2357) esp_netif_handlers: esp_netif action has started with netif0x3ffcea68 from event_id=2
I (2367) wifi:state: auth -> assoc (0)
D (2377) esp_netif_lwip: check: remote, if=0x3ffcea68 fn=0x401194b0
0x401194b0: esp_intr_free at /Users/colinives/esp/esp-idf/components/esp_system/intr_alloc.c:665
D (2377) esp_netif_lwip: esp_netif_start_api 0x3ffcea68
I (2387) wifi:D (2387) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3ffcea68
state: assoc -> run (10)
D (2387) esp_netif_lwip: check: local, if=0x3ffcea68 fn=0x40119f10
0x40119f10: esp_netif_next_unsafe at /Users/colinives/esp/esp-idf/components/esp_netif/esp_netif_objects.c:150
D (2397) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffcea68
D (2407) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (2407) wifi:connected with BTBHub6-5FKQ, aid = 2, channel 6, BW20, bssid = 64:66:24:d2:ee:18
I (2417) wifi:security: WPA2-PSK, phy: bgn, rssi: -56
D (2427) nvs: nvs_set sta.chan 1 6
D (2427) nvs: nvs_set_blob sta.apinfo 700
I (2437) wifi:pm start, type: 1
D (2437) event: running post WIFI_EVENT:4 with handler 0x400db4a4 and context 0x3ffcea04 on loop 0x3ffcda58
0x400db4a4: esp_timer_create at /Users/colinives/esp/esp-idf/components/esp_timer/src/esp_timer.c:114
D (2447) event: running post WIFI_EVENT:4 with handler 0x4012445c and context 0x3ffced1c on loop 0x3ffcda58
0x4012445c: crypto_ec_point_mul at /Users/colinives/esp/esp-idf/components/wpa_supplicant/src/crypto/crypto_mbedtls-ec.c:267 (discriminator 2)
D (2457) esp_netif_handlers: esp_netif action connected with netif0x3ffcea68 from event_id=4
D (2467) esp_netif_lwip: check: remote, if=0x3ffcea68 fn=0x401196d0
0x401196d0: uart_ll_get_baudrate at /Users/colinives/esp/esp-idf/esp-rainmaker/rainmaker_examples/switch/build/../../../../components/hal/esp32/include/hal/uart_ll.h:131
(inlined by) uart_hal_get_baudrate at /Users/colinives/esp/esp-idf/components/hal/uart_hal.c:35
I (2467) wifi:AP's beacon interval = 102400 us, DTIM period = 3
D (2477) esp_netif_lwip: esp_netif_up_api esp_netif:0x3ffcea68
D (2487) esp_netif_lwip: check: local, if=0x3ffcea68 fn=0x40119f10
0x40119f10: esp_netif_next_unsafe at /Users/colinives/esp/esp-idf/components/esp_netif/esp_netif_objects.c:150
D (2487) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffcea68
D (2497) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (2497) esp_netif_lwip: check: remote, if=0x3ffcea68 fn=0x401192cc
0x401192cc: esp_intr_alloc_intrstatus at /Users/colinives/esp/esp-idf/components/esp_system/intr_alloc.c:522
D (2507) esp_netif_lwip: esp_netif_dhcpc_start_api esp_netif:0x3ffcea68
D (2517) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3ffcea68
D (2517) esp_netif_lwip: if0x3ffcea68 start ip lost tmr: no need start because netif=0x3ffceae8 interval=120 ip=0
D (2527) esp_netif_lwip: starting dhcp client
D (2537) esp_netif_lwip: call api in lwip: ret=0x0, give sem
W (3767) wifi:<ba-add>idx:0 (ifx:0, 64:66:24:d2:ee:18), tid:0, ssn:2, winSize:64
D (5267) esp_netif_lwip: esp_netif_dhcpc_cb lwip-netif:0x3ffceae8
D (5267) esp_netif_lwip: if0x3ffcea68 ip changed=1
D (5267) event: running post IP_EVENT:0 with handler 0x400db4a4 and context 0x3ffcea48 on loop 0x3ffcda58
0x400db4a4: esp_timer_create at /Users/colinives/esp/esp-idf/components/esp_timer/src/esp_timer.c:114
I (5277) app_wifi: Connected with IP Address:192.168.1.241
D (5277) event: running post IP_EVENT:0 with handler 0x40124288 and context 0x3ffcedcc on loop 0x3ffcda58
0x40124288: crypto_bignum_legendre at /Users/colinives/esp/esp-idf/components/wpa_supplicant/src/crypto/crypto_mbedtls-bignum.c:225
D (5287) wifi_init_default: Got IP wifi default handler entered
D (5297) esp_netif_handlers: esp_netif action got_ip with netif0x3ffcea68 from event_id=0
I (5307) esp_netif_handlers: sta ip: 192.168.1.241, mask: 255.255.255.0, gw: 192.168.1.254
D (5317) event: running post IP_EVENT:0 with handler 0x400dbc00 and context 0x3ffd9ca8 on loop 0x3ffcda58
0x400dbc00: esp_set_time_from_rtc at /Users/colinives/esp/esp-idf/components/newlib/port/esp_time_impl.c:177
I (5327) esp_mqtt_glue: Connecting to a1p72mufdu6064-ats.iot.us-east-1.amazonaws.com
D (5337) MQTT_CLIENT: Core selection disabled
I (5337) esp_mqtt_glue: Waiting for MQTT connection. This may take time.
D (5337) esp_mqtt_glue: Other event id:7
D (5347) esp-tls: host:a1p72mufdu6064-ats.iot.us-east-1.amazonaws.com: strlen 46
D (5967) esp-tls: handshake in progress...
D (9337) MQTT_CLIENT: Transport connected to mqtts://a1p72mufdu6064-ats.iot.us-east-1.amazonaws.com:443
D (9337) MQTT_CLIENT: Sending MQTT CONNECT message, type: 1, id: 0000
D (9987) SSL TLS: add mbedtls RX buffer
D (9987) SSL TLS: end
D (9987) SSL TLS: RX left 3 bytes
D (9987) MQTT_CLIENT: mqtt_message_receive: first byte: 0x20
D (9987) TRANS_SSL: remain data in cache, need to read again
D (9997) SSL TLS: add mbedtls RX buffer
D (9997) SSL TLS: end
D (9997) SSL TLS: RX left 2 bytes
D (10007) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (10007) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (10017) TRANS_SSL: remain data in cache, need to read again
D (10027) SSL TLS: add mbedtls RX buffer
D (10027) SSL TLS: end
D (10027) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (10037) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (10047) MQTT_CLIENT: Connected
I (10047) esp_mqtt_glue: MQTT Connected
D (10047) event: no handlers have been registered for event RMAKER_COMMON_EVENT:3 posted to loop 0x3ffcda58
I (10057) esp_rmaker_node_config: Reporting Node Configuration
D (10067) esp_mqtt_glue: Publishing to node/HZBp7ZqWKvGYFy4uZq4fP3/config
D (10077) MQTT_CLIENT: mqtt_enqueue id: 58888, type=3 successful
D (10077) OUTBOX: ENQUEUE msgid=58888, msg_type=3, len=1000, size=1000
I (10087) esp_rmaker_param: Reporting params (init): {"Switch":{"Name":"Switch","Power":true},"OTA":{"Status":"","Info":"","URL":""},"Schedule":{"Schedules":[]}}
D (10097) esp_mqtt_glue: Publishing to node/HZBp7ZqWKvGYFy4uZq4fP3/params/local/init
D (10107) MQTT_CLIENT: mqtt_enqueue id: 56174, type=3 successful
D (10117) OUTBOX: ENQUEUE msgid=56174, msg_type=3, len=160, size=1160
D (10127) MQTT_CLIENT: mqtt_enqueue id: 9173, type=8 successful
D (10127) OUTBOX: ENQUEUE msgid=9173, msg_type=8, len=48, size=1208
D (10137) MQTT_CLIENT: Sent subscribe topic=node/HZBp7ZqWKvGYFy4uZq4fP3/params/remote, id: 9173, type=8 successful
D (10147) esp_mqtt_glue: Subscribed to topic: node/HZBp7ZqWKvGYFy4uZq4fP3/params/remote
D (10557) SSL TLS: add mbedtls RX buffer
D (10567) SSL TLS: end
D (10567) SSL TLS: RX left 3 bytes
D (10567) MQTT_CLIENT: mqtt_message_receive: first byte: 0x40
D (10567) TRANS_SSL: remain data in cache, need to read again
D (10577) SSL TLS: add mbedtls RX buffer
D (10577) SSL TLS: end
D (10577) SSL TLS: RX left 2 bytes
D (10587) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (10587) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (10597) TRANS_SSL: remain data in cache, need to read again
D (10607) SSL TLS: add mbedtls RX buffer
D (10607) SSL TLS: end
D (10607) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (10617) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (10617) MQTT_CLIENT: msg_type=4, msg_id=58888
D (10627) MQTT_CLIENT: pending_id=9173, pending_msg_count = 3
D (10637) OUTBOX: DELETED msgid=58888, msg_type=3, remain size=208
D (10637) MQTT_CLIENT: received MQTT_MSG_TYPE_PUBACK, finish QoS1 publish
D (10647) esp_mqtt_glue: MQTT_EVENT_PUBLISHED, msg_id=58888
D (10647) event: no handlers have been registered for event RMAKER_COMMON_EVENT:5 posted to loop 0x3ffcda58
D (11177) SSL TLS: add mbedtls RX buffer
D (11177) SSL TLS: end
D (11177) SSL TLS: RX left 3 bytes
D (11177) MQTT_CLIENT: mqtt_message_receive: first byte: 0x40
D (11177) TRANS_SSL: remain data in cache, need to read again
D (11187) SSL TLS: add mbedtls RX buffer
D (11187) SSL TLS: end
D (11197) SSL TLS: RX left 2 bytes
D (11197) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (11207) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (11207) TRANS_SSL: remain data in cache, need to read again
D (11217) SSL TLS: add mbedtls RX buffer
D (11217) SSL TLS: end
D (11227) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (11227) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (11237) MQTT_CLIENT: msg_type=4, msg_id=56174
D (11237) MQTT_CLIENT: pending_id=9173, pending_msg_count = 2
D (11247) OUTBOX: DELETED msgid=56174, msg_type=3, remain size=48
D (11247) MQTT_CLIENT: received MQTT_MSG_TYPE_PUBACK, finish QoS1 publish
D (11257) esp_mqtt_glue: MQTT_EVENT_PUBLISHED, msg_id=56174
D (11267) event: no handlers have been registered for event RMAKER_COMMON_EVENT:5 posted to loop 0x3ffcda58
D (11267) SSL TLS: add mbedtls RX buffer
D (11277) SSL TLS: end
D (11277) SSL TLS: RX left 4 bytes
D (11287) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (11287) TRANS_SSL: remain data in cache, need to read again
D (11297) SSL TLS: add mbedtls RX buffer
D (11297) SSL TLS: end
D (11297) SSL TLS: RX left 3 bytes
D (11307) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (11317) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (11317) TRANS_SSL: remain data in cache, need to read again
D (11327) SSL TLS: add mbedtls RX buffer
D (11327) SSL TLS: end
D (11337) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (11337) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (11347) MQTT_CLIENT: msg_type=9, msg_id=9173
D (11347) MQTT_CLIENT: pending_id=9173, pending_msg_count = 1
D (11357) OUTBOX: DELETED msgid=9173, msg_type=8, remain size=0
D (11357) MQTT_CLIENT: Subscribe successful
D (11367) esp_mqtt_glue: MQTT_EVENT_SUBSCRIBED, msg_id=9173
I (32987) esp_rmaker_time: SNTP Synchronised.
I (32987) esp_rmaker_time: The current time is: Fri Mar 5 23:50:54 2021 +0800[CST], DST: No.
D (33367) MQTT_CLIENT: Sent PING successful
D (33367) MQTT_CLIENT: PING sent
D (33907) SSL TLS: add mbedtls RX buffer
D (33907) SSL TLS: end
D (33907) SSL TLS: RX left 1 bytes
D (33907) MQTT_CLIENT: mqtt_message_receive: first byte: 0xd0
D (33917) TRANS_SSL: remain data in cache, need to read again
D (33917) SSL TLS: add mbedtls RX buffer
D (33927) SSL TLS: end
D (33927) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x0
D (33937) MQTT_CLIENT: mqtt_message_receive: total message length: 2 (already read: 2)
D (33937) MQTT_CLIENT: mqtt_message_receive: transport_read():2 2
D (33947) MQTT_CLIENT: msg_type=13, msg_id=0
D (33947) MQTT_CLIENT: MQTT_MSG_TYPE_PINGRESP
D (93957) MQTT_CLIENT: Sent PING successful
D (93957) MQTT_CLIENT: PING sent
D (94117) SSL TLS: add mbedtls RX buffer
D (94117) SSL TLS: end
D (94117) SSL TLS: RX left 1 bytes
D (94117) MQTT_CLIENT: mqtt_message_receive: first byte: 0xd0
D (94127) TRANS_SSL: remain data in cache, need to read again
D (94127) SSL TLS: add mbedtls RX buffer
D (94137) SSL TLS: end
D (94137) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x0
D (94147) MQTT_CLIENT: mqtt_message_receive: total message length: 2 (already read: 2)
D (94147) MQTT_CLIENT: mqtt_message_receive: transport_read():2 2
D (94157) MQTT_CLIENT: msg_type=13, msg_id=0
D (94167) MQTT_CLIENT: MQTT_MSG_TYPE_PINGRESP
D (154167) MQTT_CLIENT: Sent PING successful
D (154167) MQTT_CLIENT: PING sent
D (154327) SSL TLS: add mbedtls RX buffer
D (154327) SSL TLS: end
D (154337) SSL TLS: RX left 1 bytes
D (154337) MQTT_CLIENT: mqtt_message_receive: first byte: 0xd0
D (154337) TRANS_SSL: remain data in cache, need to read again
D (154337) SSL TLS: add mbedtls RX buffer
D (154347) SSL TLS: end
D (154347) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x0
D (154357) MQTT_CLIENT: mqtt_message_receive: total message length: 2 (already read: 2)
D (154367) MQTT_CLIENT: mqtt_message_receive: transport_read():2 2
D (154367) MQTT_CLIENT: msg_type=13, msg_id=0
D (154377) MQTT_CLIENT: MQTT_MSG_TYPE_PINGRESP
D (214377) MQTT_CLIENT: Sent PING successful
D (214377) MQTT_CLIENT: PING sent
D (214847) SSL TLS: add mbedtls RX buffer
D (214847) SSL TLS: end
D (214857) SSL TLS: RX left 1 bytes
D (214857) MQTT_CLIENT: mqtt_message_receive: first byte: 0xd0
D (214857) TRANS_SSL: remain data in cache, need to read again
D (214857) SSL TLS: add mbedtls RX buffer
D (214867) SSL TLS: end
D (214867) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x0
D (214877) MQTT_CLIENT: mqtt_message_receive: total message length: 2 (already read: 2)
D (214887) MQTT_CLIENT: mqtt_message_receive: transport_read():2 2
D (214887) MQTT_CLIENT: msg_type=13, msg_id=0
D (214897) MQTT_CLIENT: MQTT_MSG_TYPE_PINGRESP
D (274897) MQTT_CLIENT: Sent PING successful
D (274897) MQTT_CLIENT: PING sent
W (275057) wifi:<ba-del>idx
W (276287) wifi:<ba-add>idx:0 (ifx:0, 64:66:24:d2:ee:18), tid:0, ssn:36, winSize:64
D (276287) SSL TLS: add mbedtls RX buffer
D (276287) SSL TLS: end
D (276297) SSL TLS: RX left 1 bytes
D (276297) MQTT_CLIENT: mqtt_message_receive: first byte: 0xd0
D (276307) TRANS_SSL: remain data in cache, need to read again
D (276307) SSL TLS: add mbedtls RX buffer
D (276317) SSL TLS: end
D (276317) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x0
D (276327) MQTT_CLIENT: mqtt_message_receive: total message length: 2 (already read: 2)
D (276327) MQTT_CLIENT: mqtt_message_receive: transport_read():2 2
D (276337) MQTT_CLIENT: msg_type=13, msg_id=0
D (276337) MQTT_CLIENT: MQTT_MSG_TYPE_PINGRESP
D (335347) MQTT_CLIENT: Sent PING successful
D (335347) MQTT_CLIENT: PING sent
D (335887) SSL TLS: add mbedtls RX buffer
D (335897) SSL TLS: end
D (335897) SSL TLS: RX left 1 bytes
D (335897) MQTT_CLIENT: mqtt_message_receive: first byte: 0xd0
D (335897) TRANS_SSL: remain data in cache, need to read again
D (335897) SSL TLS: add mbedtls RX buffer
D (335907) SSL TLS: end
D (335907) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x0
D (335917) MQTT_CLIENT: mqtt_message_receive: total message length: 2 (already read: 2)
D (335927) MQTT_CLIENT: mqtt_message_receive: transport_read():2 2
D (335927) MQTT_CLIENT: msg_type=13, msg_id=0
D (335937) MQTT_CLIENT: MQTT_MSG_TYPE_PINGRESP
D (395937) MQTT_CLIENT: Sent PING successful
D (395937) MQTT_CLIENT: PING sent
D (396097) SSL TLS: add mbedtls RX buffer
D (396097) SSL TLS: end
D (396097) SSL TLS: RX left 1 bytes
D (396097) MQTT_CLIENT: mqtt_message_receive: first byte: 0xd0
D (396107) TRANS_SSL: remain data in cache, need to read again
D (396107) SSL TLS: add mbedtls RX buffer
D (396117) SSL TLS: end
D (396117) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x0
D (396127) MQTT_CLIENT: mqtt_message_receive: total message length: 2 (already read: 2)
D (396137) MQTT_CLIENT: mqtt_message_receive: transport_read():2 2
D (396137) MQTT_CLIENT: msg_type=13, msg_id=0
D (396147) MQTT_CLIENT: MQTT_MSG_TYPE_PINGRESP
D (456147) MQTT_CLIENT: Sent PING successful
D (456147) MQTT_CLIENT: PING sent
D (456307) SSL TLS: add mbedtls RX buffer
D (456307) SSL TLS: end
D (456317) SSL TLS: RX left 1 bytes
D (456317) MQTT_CLIENT: mqtt_message_receive: first byte: 0xd0
D (456317) TRANS_SSL: remain data in cache, need to read again
D (456317) SSL TLS: add mbedtls RX buffer
D (456327) SSL TLS: end
D (456327) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x0
D (456337) MQTT_CLIENT: mqtt_message_receive: total message length: 2 (already read: 2)
D (456347) MQTT_CLIENT: mqtt_message_receive: transport_read():2 2
D (456347) MQTT_CLIENT: msg_type=13, msg_id=0
D (456357) MQTT_CLIENT: MQTT_MSG_TYPE_PINGRESP
D (516357) MQTT_CLIENT: Sent PING successful
D (516357) MQTT_CLIENT: PING sent
D (516527) SSL TLS: add mbedtls RX buffer
D (516527) SSL TLS: end
D (516527) SSL TLS: RX left 1 bytes
D (516527) MQTT_CLIENT: mqtt_message_receive: first byte: 0xd0
D (516527) TRANS_SSL: remain data in cache, need to read again
D (516537) SSL TLS: add mbedtls RX buffer
D (516537) SSL TLS: end
D (516537) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x0
D (516547) MQTT_CLIENT: mqtt_message_receive: total message length: 2 (already read: 2)
D (516557) MQTT_CLIENT: mqtt_message_receive: transport_read():2 2
D (516567) MQTT_CLIENT: msg_type=13, msg_id=0
D (516567) MQTT_CLIENT: MQTT_MSG_TYPE_PINGRESP
D (576577) MQTT_CLIENT: Sent PING successful
D (576577) MQTT_CLIENT: PING sent
D (576737) SSL TLS: add mbedtls RX buffer
D (576737) SSL TLS: end
D (576737) SSL TLS: RX left 1 bytes
D (576737) MQTT_CLIENT: mqtt_message_receive: first byte: 0xd0
D (576737) TRANS_SSL: remain data in cache, need to read again
D (576747) SSL TLS: add mbedtls RX buffer
D (576747) SSL TLS: end
D (576757) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x0
D (576757) MQTT_CLIENT: mqtt_message_receive: total message length: 2 (already read: 2)
D (576767) MQTT_CLIENT: mqtt_message_receive: transport_read():2 2
D (576777) MQTT_CLIENT: msg_type=13, msg_id=0