ESP-IDF FreeRTOS Task notification(s) code review?

[brainstorm]

Is there a forum to ask for code reviews for ESP-IDF application code? Anyways, I'm having some problems putting together Direct Task Notification scheme between two tasks: pvoutput and modbus over here:

https://github.com/brainstorm/esp-modbu ... p_modbus.c
https://github.com/brainstorm/esp-modbu ... tput_org.c

I'm not sure I fully understand the Take/Give mechanism and TASK_ARRAY bits because I'm getting a lot of reboots, unfortunately (see log below).

Any pointers on why those Give/Take statements are misplaced (should emulate a binary semaphore) are very welcome!

I might just use plain semaphores instead of direct task notifications, but I also wanted to understand what am I doing wrong with direct tasks here...

Code: Select all

I (40) boot: ESP-IDF v5.1-dev-1264-g1c84cfde14 2nd stage bootloader
I (41) boot: compile time Oct 29 2022 07:28:30
I (42) boot: chip revision: V000
I (46) boot.esp32s2: SPI Speed      : 80MHz
I (51) boot.esp32s2: SPI Mode       : DIO
I (55) boot.esp32s2: SPI Flash Size : 4MB
I (60) boot: Enabling RNG early entropy source...
I (65) boot: Partition Table:
I (69) boot: ## Label            Usage          Type ST Offset   Length
I (76) boot:  0 sec_cert         unknown          3f 06 0000d000 00003000
I (84) boot:  1 nvs              WiFi data        01 02 00010000 00006000
I (91) boot:  2 otadata          OTA data         01 00 00016000 00002000
I (99) boot:  3 phy_init         RF data          01 01 00018000 00001000
I (106) boot:  4 ota_0            OTA app          00 10 00020000 00190000
I (114) boot:  5 ota_1            OTA app          00 11 001b0000 00190000
I (121) boot:  6 fctry            WiFi data        01 02 00340000 00006000
I (129) boot: End of partition table
I (133) esp_image: segment 0: paddr=00020020 vaddr=3f000020 size=49cd8h (302296) map
I (179) esp_image: segment 1: paddr=00069d00 vaddr=3ffc5aa0 size=03570h ( 13680) load
I (181) esp_image: segment 2: paddr=0006d278 vaddr=40022000 size=02da0h ( 11680) load
I (187) esp_image: segment 3: paddr=00070020 vaddr=40080020 size=a6b84h (682884) map
I (277) esp_image: segment 4: paddr=00116bac vaddr=40024da0 size=10cf4h ( 68852) load
I (290) esp_image: segment 5: paddr=001278a8 vaddr=50000000 size=00010h (    16) load
I (300) boot: Loaded app from partition at offset 0x20000
I (300) boot: Disabling RNG early entropy source...
I (312) cache: Instruction cache        : size 8KB, 4Ways, cache line size 32Byte
I (312) cpu_start: Pro cpu up.
I (326) cpu_start: Pro cpu start user code
I (326) cpu_start: cpu freq: 80000000 Hz
I (326) cpu_start: Application information:
I (331) cpu_start: Project name:     esp-modbus-power-meter
I (337) cpu_start: App version:      portimao-57-g533accc-dirty
I (344) cpu_start: Compile time:     Oct 29 2022 07:28:27
I (350) cpu_start: ELF file SHA256:  3c5b4d30746116fb...
I (356) cpu_start: ESP-IDF:          v5.1-dev-1264-g1c84cfde14
I (362) heap_init: Initializing. RAM available for dynamic allocation:
I (369) heap_init: At 3FFCD6F0 len 0002E910 (186 KiB): D/IRAM
I (376) heap_init: At 3FFFC000 len 00003A10 (14 KiB): DRAM
I (383) spi_flash: detected chip: generic
I (387) spi_flash: flash io: dio
I (396) cpu_start: Starting scheduler on PRO CPU.
I (417) app_main: All systems go
I (427) wifi:wifi driver task: 3ffff670, prio:23, stack:6656, core=0
I (427) system_api: Base MAC address is not set
I (427) system_api: read default base MAC address from EFUSE
I (437) wifi:wifi firmware version: d9947eb
I (437) wifi:wifi certification version: v7.0
I (437) wifi:config NVS flash: enabled
I (437) wifi:config nano formating: disabled
I (447) wifi:Init data frame dynamic rx buffer num: 32
I (447) wifi:Init management frame dynamic rx buffer num: 32
I (457) wifi:Init management short buffer num: 32
I (457) wifi:Init dynamic tx buffer num: 32
I (467) wifi:Init static rx buffer size: 2212
I (467) wifi:Init static rx buffer num: 10
I (467) wifi:Init dynamic rx buffer num: 32
I (477) wifi_init: rx ba win: 6
I (477) wifi_init: tcpip mbox: 32
I (487) wifi_init: udp mbox: 6
I (487) wifi_init: tcp mbox: 6
I (487) wifi_init: tcp tx win: 5744
I (497) wifi_init: tcp rx win: 5744
I (497) wifi_init: tcp mss: 1440
I (507) wifi_init: WiFi IRAM OP enabled
I (507) wifi_init: WiFi RX IRAM OP enabled
I (517) esp_rmaker_work_queue: Work Queue created.
I (527) esp_mqtt_glue: AWS PPI: ?Platform=APN3|A0|RM|EX00|RMDev|1x0|7CDFA100B502
I (527) esp_mqtt_glue: Initialising MQTT
I (527) esp_rmaker_node: Node ID ----- 7C(snip)02
I (537) esp_rmaker_time_service: Time service enabled
I (547) esp_rmaker_time: Initializing SNTP. Using the SNTP server: pt.pool.ntp.org
I (547) esp_rmaker_time: SNTP already initialized.
I (557) esp_rmaker_time: SNTP already initialized.
I (557) esp_rmaker_time: SNTP already initialized.
I (567) esp_rmaker_time: SNTP already initialized.
I (567) esp_rmaker_time: SNTP already initialized.
I (577) esp_rmaker_time: SNTP already initialized.
I (587) esp_rmaker_time: SNTP already initialized.
I (587) esp_rmaker_time: SNTP already initialized.
I (597) esp_rmaker_time: SNTP already initialized.
I (597) esp_rmaker_time: SNTP already initialized.
I (607) esp_rmaker_time: SNTP already initialized.
I (607) esp_rmaker_time: SNTP already initialized.
I (617) esp_rmaker_time: SNTP already initialized.
I (617) esp_rmaker_time: SNTP already initialized.
I (627) esp_rmaker_ota_using_topics: OTA enabled with Topics
I (637) esp_rmaker_ota: OTA state = 2
W (637) app_insights: Nodes with Self Claiming may not be accessible for Insights.
I (647) esp_insights: =========================================
I (647) esp_insights: Insights enabled for Node ID 7C(snip)02
I (657) esp_insights: =========================================
W (667) esp_insights: ESP Insights already initialized
I (667) esp_rmaker_time: SNTP already initialized.
I (677) esp_rmaker_core: Starting RainMaker Work Queue task
I (687) esp_rmaker_work_queue: RainMaker Work Queue task started.
I (687) app_wifi: Already provisioned, starting Wi-Fi STA
I (697) phy_init: phy_version 2300,d67cf06,Feb 10 2022,10:03:07
I (747) wifi:mode : sta (7c:df:a1:00:b5:02)
I (747) wifi:enable tsf
I (757) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
I (757) wifi:state: init -> auth (b0)
I (767) wifi:state: auth -> assoc (0)
I (767) wifi:state: assoc -> run (10)
I (797) wifi:connected with ThomsonB576D3, aid = 10, channel 1, BW20, bssid = 58:98:35:3b:bc:a9
I (807) wifi:security: WPA2-PSK, phy: bgn, rssi: -85
I (807) wifi:pm start, type: 1

I (867) wifi:AP's beacon interval = 102400 us, DTIM period = 3
I (1917) app_wifi: Connected with IP Address:192.168.1.191
I (1917) esp_netif_handlers: sta ip: 192.168.1.191, mask: 255.255.255.0, gw: 192.168.1.254
I (1917) esp_mqtt_glue: Connecting to a1p(snip)064-ats.iot.us-east-1.amazonaws.com
I (1927) esp_rmaker_core: Waiting for MQTT connection
W (1937) esp_rmaker_time: Waiting for time to be synchronized. This may take time.
W (2107) wifi:<ba-add>idx:0 (ifx:0, 58:98:35:3b:bc:a9), tid:3, ssn:0, winSize:64
I (2937) esp-x509-crt-bundle: Certificate validated
W (4867) wifi:<ba-add>idx:1 (ifx:0, 58:98:35:3b:bc:a9), tid:0, ssn:0, winSize:64
I (4867) esp_rmaker_time: SNTP Synchronised.
I (4867) esp_rmaker_time: The current time is: Sat Oct 29 09:12:30 2022 +0100[WEST], DST: Yes.
I (4917) esp_mqtt_glue: MQTT Connected
I (4917) esp_rmaker_node_config: Reporting Node Configuration of length 2787 bytes.
I (5177) esp_rmaker_param: Params MQTT Init done.
I (5177) esp_rmaker_param: Reporting params (init): {"Time":{"TZ":"Europe/Lisbon","TZ-POSIX":"WET0WEST,M3.5.0/1,M10.5.0"},"Power":{"Name":"Power","Power Meter":0.00000,"Amps_phase_1":0.00000,"Amps_phase_2":0.00000,"Amps_phase_3":0.00000,"Volts_phase_1":0.00000,"Volts_phase_2":0.00000,"Volts_phase_3":0.00000,"Power_Factor":0.00000,"Frequency":0.00000,"var":0.00000,"VA":0.00000,"uh":0.00000,"-uh":0.00000,"uAh":0.00000,"-uAh":0.00000}}
I (5217) esp_rmaker_param: Reporting Time Series Data for Power.Power Meter
I (5217) esp_rmaker_param: Reporting Time Series Data for Power.Amps_phase_1
I (5227) esp_rmaker_param: Reporting Time Series Data for Power.Amps_phase_2
I (5237) esp_rmaker_param: Reporting Time Series Data for Power.Amps_phase_3
I (5247) esp_rmaker_param: Reporting Time Series Data for Power.Volts_phase_1
I (5257) esp_rmaker_param: Reporting Time Series Data for Power.Volts_phase_2
I (5257) esp_rmaker_param: Reporting Time Series Data for Power.Volts_phase_3
I (5267) esp_rmaker_param: Reporting Time Series Data for Power.Power_Factor
I (5277) esp_rmaker_param: Reporting Time Series Data for Power.Frequency
I (5287) esp_rmaker_param: Reporting Time Series Data for Power.var
I (5287) esp_rmaker_param: Reporting Time Series Data for Power.VA
I (5297) esp_rmaker_param: Reporting Time Series Data for Power.uh
I (5307) esp_rmaker_param: Reporting Time Series Data for Power.-uh
I (5317) esp_rmaker_param: Reporting Time Series Data for Power.uAh
I (5417) esp_rmaker_param: Reporting Time Series Data for Power.-uAh
I (5417) esp_rmaker_cmd_resp: Enabling Command-Response Module.
I (5437) esp_rmaker_ota_using_topics: Subscribing to: node/7<SNIP>02/otaurl
I (5447) esp_insights: Scheduling Insights timer for 60 seconds.
I (6127) esp_rmaker_time: The current time is: Sat Oct 29 09:12:31 2022 +0100[WEST], DST: Yes.
I (6127) app_pvoutput: PVoutput task waits for data to be produced...

I (6127) uart: queue free spaces: 20
I (6187) app_modbus: Modbus master stack initialized...
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x10 (RTCWDT_RTC_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6108,len:0x17b4
load:0x4004c000,len:0xaa4
load:0x40050000,len:0x3130
SHA-256 comparison failed:
Calculated: 392ccf26e130f6f3253d40bece774e534878e784af55f756f8f8d34ae6650d86
Expected: ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
Attempting to boot anyway...
entry 0x4004c1bc
I (40) boot: ESP-IDF v5.1-dev-1264-g1c84cfde14 2nd stage bootloader
I (41) boot: compile time Oct 29 2022 07:28:30
I (42) boot: chip revision: V000
I (46) boot.esp32s2: SPI Speed      : 80MHz
I (51) boot.esp32s2: SPI Mode       : DIO
I (55) boot.esp32s2: SPI Flash Size : 4MB
I (60) boot: Enabling RNG early entropy source...
I (65) boot: Partition Table:
I (69) boot: ## Label            Usage          Type ST Offset   Length
(... yet another similar log ending in reboot...)

[chegewara]

Hi,
i didnt study whole code, but it looks like you have created 2 tasks which should unlock each other with xTaskNotifyGive, but the problem is there is no initial notify and both task are awaiting in ulTaskNotifyTake:
https://github.com/brainstorm/esp-modbu ... dbus.c#L68
https://github.com/brainstorm/esp-modbu ... org.c#L109

[brainstorm]

Hi,
i didnt study whole code, but it looks like you have created 2 tasks which should unlock each other with xTaskNotifyGive, but the problem is there is no initial notify and both task are awaiting in ulTaskNotifyTake:
https://github.com/brainstorm/esp-modbu ... dbus.c#L68
https://github.com/brainstorm/esp-modbu ... org.c#L109

Thanks chegewara, honored to get a reply from you, I casually check your IDF GH projects for reference and inspiration!

Indeed, I fixed it in this commit, just in case you are curious, thanks for your hints: https://github.com/brainstorm/esp-modbu ... e1b3335746

Now there's a more insidious problem with the heap usage according to ESP-Insights:

esp-insights heap usage

photo_2022-11-02 09.56.09.jpeg (46.58 KiB) Viewed 4641 times

Which tooling do you usually use for debugging/pinpointing heap usage? Any recommended static analysis tools to spot those things early before runtime (will test https://cppcheck.sourceforge.io and see if works)?

Also, for ESP-Insights devs: how come heap usage is expressed in "units" and not just bytes?

[brainstorm]

cppcheck does not find much on my code:

Code: Select all

(base) rvalls@m1 esp-modbus-power-meter % /opt/homebrew/Cellar/cppcheck/2.9.1/bin/cppcheck --quiet --enable=all src 2> cppcheck.err
(base) rvalls@m1 esp-modbus-power-meter % cat cppcheck.err
src/app_modbus.c:45:59: portability: '(void*)&holding_reg_params' is of type 'void *'. When using void pointers in calculations, the behaviour is undefined. [arithOperationsOnVoidPointer]
               instance_ptr = ((void*)&holding_reg_params + param_descriptor->param_offset - 1);
                                                          ^
src/main.c:28:0: style: The function 'app_main' is never used. [unusedFunction]

^
src/app_rgbled.c:41:0: style: The function 'app_rgbled_init' is never used. [unusedFunction]

^
src/app_pvoutput_org.c:72:0: style: The function 'print_current_datetime' is never used. [unusedFunction]

^
src/app_rmaker.c:96:0: style: The function 'send_to_rmaker_cloud' is never used. [unusedFunction]

^
nofile:0:0: information: Cppcheck cannot find all the include files (use --check-config for details) [missingInclude]

But a few nuggets elsewhere in esp-insights/rainmaker code and some of its dependencies:

Code: Select all

 % /opt/homebrew/Cellar/cppcheck/2.9.1/bin/cppcheck --quiet --enable=all lib 2> cppcheck.err
 % cat cppcheck.err | grep error
[1mlib/esp-rainmaker/components/esp-insights/components/cbor/tinycbor/tests/encoder/data.cpp:96:1: [31merror:[39m There is an unknown macro here somewhere. Configuration is required. If Q_DECLARE_METATYPE is a macro then please configure it. [unknownMacro][0m
[1mlib/esp-rainmaker/components/esp-insights/components/cbor/tinycbor/tests/parser/data.cpp:29:1: [31merror:[39m There is an unknown macro here somewhere. Configuration is required. If Q_DECLARE_METATYPE is a macro then please configure it. [unknownMacro][0m
[1mlib/esp-rainmaker/components/esp-insights/components/cbor/tinycbor/tools/json2cbor/json2cbor.c:450:13: [31merror:[39m Common realloc mistake: 'buffer' nulled but not freed upon failure [memleakOnRealloc][0m
[1mlib/esp-rainmaker/components/esp_schedule/src/esp_schedule_nvs.c:254:9: [31merror:[39m Memory leak: handle_list [memleak][0m
[1mlib/esp-rainmaker/components/qrcode/src/qrcodegen.c:771:15: [31merror:[39m Array index out of bounds; buffer 'qrcode' is accessed at offset 0. [ctuArrayIndex][0m
[1mlib/esp-rainmaker/components/qrcode/src/qrcodegen.c:780:15: [31merror:[39m Array index out of bounds; buffer 'qrcode' is accessed at offset 0. [ctuArrayIndex][0m
[1mlib/esp-rainmaker/components/qrcode/src/qrcodegen.c:794:15: [31merror:[39m Array index out of bounds; buffer 'qrcode' is accessed at offset 0. [ctuArrayIndex][0m

[chegewara]

Thanks chegewara, honored to get a reply from you, I casually check your IDF GH projects for reference and inspiration!

Thank you for kind words. I am constantly trying to improve my skills and i am sharing what i learned. Its because i could not learn that much without help and without other open source projects and libraries.

Code: Select all

instance_ptr = ((void*)&holding_reg_params + param_descriptor->param_offset - 1);

In this function, you cant increase address by some number of elements, when pointer is type of void, because sizeof(void) is unknown.
For example if the pointer is type of int and you will do pointer + 1 it will increase address by 4 bytes, and for pointer type of char, pointer + 1 will increase address by 1. Probably you need this:

Code: Select all

instance_ptr = ((void*)&(holding_reg_params + param_descriptor->param_offset - 1));

[brainstorm]

Thanks chegewara, honored to get a reply from you, I casually check your IDF GH projects for reference and inspiration!

Thank you for kind words. I am constantly trying to improve my skills and i am sharing what i learned. Its because i could not learn that much without help and without other open source projects and libraries.

Code: Select all

instance_ptr = ((void*)&holding_reg_params + param_descriptor->param_offset - 1);

In this function, you cant increase address by some number of elements, when pointer is type of void, because sizeof(void) is unknown.
For example if the pointer is type of int and you will do pointer + 1 it will increase address by 4 bytes, and for pointer type of char, pointer + 1 will increase address by 1. Probably you need this:

Code: Select all

instance_ptr = ((void*)&(holding_reg_params + param_descriptor->param_offset - 1));

Thanks again! That suggestion seems to introduce other side effects according to cppcheck, though:

Code: Select all

% /opt/homebrew/Cellar/cppcheck/2.9.1/bin/cppcheck --quiet --enable=all src
src/app_modbus.c:55:12: error: Returning pointer that will be invalid when returning. [returnDanglingLifetime]
    return instance_ptr;
           ^
src/app_modbus.c:45:39: note: Address of variable taken here.
               instance_ptr = ((void*)&(holding_reg_params + param_descriptor->param_offset - 1));
                                      ^
src/app_modbus.c:55:12: note: Returning pointer that will be invalid when returning.
    return instance_ptr;
           ^

By the way, that line of code comes from a bunch of Espressif's esp-modbus tests and examples, see here: https://github.com/espressif/esp-modbus ... ter.c#L108

Once we get this ironed out, I'll file a PR with those changes to avoid other folks having the same issues :-S

[chegewara]

Now it looks like you are trying to return pointer to (void*), just remove that reference sign (&).

[brainstorm]

Now it looks like you are trying to return pointer to (void*), just remove that reference sign (&).

Thanks but, doesn't seem to be as straightforward... I need to revisit that code from Espressif's examples and see what they wanted to do in master_get_param_data and its interaction with the "parameter description table" defined in include/cid_tables.h:

Code: Select all

/Users/rvalls/dev/personal/esp-modbus-power-meter/src/app_modbus.c: In function 'master_get_param_data':
/Users/rvalls/dev/personal/esp-modbus-power-meter/src/app_modbus.c:45:59: error: invalid operands to binary + (have 'holding_reg_params_t' and 'int')
   45 |                instance_ptr = ((void*)(holding_reg_params + param_descriptor->param_offset - 1));
      |                                                           ^ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
      |                                                                             |
      |                                                                             uint16_t {aka short unsigned int}

[chegewara]

My bad

Code: Select all

instance_ptr = ((void*)(&holding_reg_params + param_descriptor->param_offset - 1));

but yes, its good to understand the code you are working with, especially when you are working with code that someone else wrote.