Runtime Error in esp_flash_write in esp_flash_api

[maximkulkin]

Runtime Error in esp_flash_write in esp_flash_api

[Kristian8606]

I use Catalina with this version
https://docs.espressif.com/projects/esp-idf/en/latest/get-started/macos-setup.html

[maximkulkin]

It looks like it has paired, but failed to write pairing info to flash. Check your flash size and address where homekit supposed to write it’s data.

[GermanSheepDog]

Hello @maximkulkin,
hello @Kristian8606,
I think, there are amongst other things some problems with the versions of esp-idf.
Last time I used:

I (38) boot: ESP-IDF v4.1-dev-369-g4dac7c7df 2nd stage bootloader

and got this runtime errors:

I (5941) gpio: GPIO[14]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
E (5951) ledc: requested frequency and duty resolution can not be achieved, try reducing freq_hz or duty_resolution. div_param=3
E (5961) camera_xclk: ledc_timer_config failed, rc=ffffffff
I (5961) sccb: pin_sda 13 pin_scl 12

I (5971) gpio: GPIO[26]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
E (6001) sccb: SCCB_Write [ff]=01 failed

E (6001) sccb: SCCB_Write [12]=80 failed

I (6021) sccb: SCCB_Probe start
E (7281) camera: Camera probe failed with error 0x20001
E (7281) esp32_camera: Camera init failed with error 0x20001

My previous version is:

I (884) cpu_start: ESP-IDF:          v4.0-dev-1191-g138c941fa

With this version I got this problem:

I (7089) gpio: GPIO[25]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (7099) gpio: GPIO[19]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (7109) camera: Allocating 2 frame buffers (75 KB total)
Guru Meditation Error: Core  0 panic'ed (StoreProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x40094eda  PS      : 0x00060533  A0      : 0x8008f52d  A1      : 0x3ffc9a90  
0x40094eda: uxPortCompareSet at /Users/username/esp/esp-idf/components/freertos/tasks.c:3507
 (inlined by) vPortCPUAcquireMutexIntsDisabledInternal at /Users/username/esp/esp-idf/components/freertos/portmux_impl.inc.h:86
 (inlined by) vPortCPUAcquireMutexIntsDisabled at /Users/username/esp/esp-idf/components/freertos/portmux_impl.h:99
 (inlined by) vTaskEnterCritical at /Users/username/esp/esp-idf/components/freertos/tasks.c:4201

I suspect a problem with my hardware. I used a "TTGO T-Kamera ESP32 WROVER & PSRAM Kamera Modul ESP32-WROVER-B OV2640 Kamera Modul 0,96 OLED" and configured it as "TTGO CAM v1.7" with "Support for external, SPI connected RAM". It is correct?

Without "Support for external, SPI connected RAM" I got an runtime error, if I started video.

Which version of esp-idf do you use?
Which hardware do you use?

[GermanSheepDog]

@maximkulkin: I like to isolate the problem and I will start one time more from scratch:
make clean; rm sdkconfig;
It will help me if I know the esp-idf version and the camera type which worked sure correctly. There are more unknown effects like MacOS Version and so on.

[maximkulkin]

What is the problem with MacOS version?? You're using a separate toolchain, not bound neither to OS, nor to Xcode.

I tested code on ESP-IDF versions 3.3 (branch "v3.3" in Git), 4.0 (branch "release/v4.0") and on "master" (commit "4dac7c7df"). Tested it on ESP-EYE, M5Stack Camera and AI-Thinker ESP32-CAM modules. With v4.x you need to apply esp32-camera.patch to components/esp32-camera, with v3.x you do not need that. I did not test all permutations (mostly I was testing esp-idf master branch on different modules and then tested different esp-idf versions on ESP-EYE module). It worked in all configurations.

[GermanSheepDog]

@maximkulkin: I suspect that with my configuration something is a little different.
Today I downloaded the newest esp32-homekit-cam and I started from scratch.
At my first test with esp-idf v3.3 and M5Camera (4M Flash, 4M PSRAM) I got this problem with stream:

..
>>> HomeKit: [Client 55] Update Characteristics
I (42203) esp32_camera: Processing session command 1
I (42203) esp32_camera: Adding streaming session
I (42203) esp32_camera: Starting streaming
I (42213) esp32_camera: Total free memory: 11256
x264 [error]: malloc of size 37984 failed
E (42223) esp32_camera: Failed to open H.264 encoder
E (42223) FreeRTOS: FreeRTOS Task "Camera Stream" should not return, Aborting now!
abort() was called at PC 0x40092e53 on core 1
0x40092e53: vPortTaskWrapper at /Users/username/esp/esp-idf/components/freertos/port.c:435

ELF file SHA256: 55fb26956f9dd62af7695bc4ec3fe4ba1fd4ebfed8b082396cbc31ec9c41b16a

Backtrace: 0x4008c3d8:0x3fffeeb0 0x4008c621:0x3fffeed0 0x40092e53:0x3fffeef0
0x4008c3d8: invoke_abort at /Users/username/esp/esp-idf/components/esp32/panic.c:715

0x4008c621: abort at /Users/username/esp/esp-idf/components/esp32/panic.c:715
0x40092e53: vPortTaskWrapper at /Users/username/esp/esp-idf/components/freertos/port.c:435

Rebooting...

Second test with same camera and esp-idf v4.0:

...
>>> HomeKit: [Client 56] Update Characteristics
I (146815) esp32_camera: Processing session command 1
I (146815) esp32_camera: Adding streaming session
I (146815) esp32_camera: Starting streaming
I (146825) esp32_camera: Total free memory: 6208
x264 [error]: malloc of size 37984 failed
E (146835) esp32_camera: Failed to open H.264 encoder
E (146835) FreeRTOS: FreeRTOS Task "Camera Stream" should not return, Aborting now!
abort() was called at PC 0x40095037 on core 1
0x40095037: vPortTaskWrapper at /Users/username/esp/esp-idf/components/freertos/port.c:435


ELF file SHA256: 8b2fdd00d1c98def1c4832ac7f15f4024aeff3677a8e9eb63f03d7d9fb1862f4

Backtrace: 0x40092561:0x3fffeeb0 0x400928e5:0x3fffeed0 0x40095037:0x3fffeef0
0x40092561: invoke_abort at /Users/username/esp/esp-idf/components/esp32/panic.c:719

0x400928e5: abort at /Users/username/esp/esp-idf/components/esp32/panic.c:719

0x40095037: vPortTaskWrapper at /Users/username/esp/esp-idf/components/freertos/port.c:435

Rebooting...

What can I do to isolate this errors?

[maximkulkin]

What can I do to isolate this errors?

Add more memory?

I (146825) esp32_camera: Total free memory: 6208

This 6208 is a problem. You're supposed to have ~4MB (well, at least 1MB, but they come in multiples of 4MB) of RAM for the whole thing to work. Make sure your module has SPI RAM installed and you have enabled SPI RAM support in config (see README).

[GermanSheepDog]

I did not pay enough attention to the memory-message. Thank you!

I double-checked the two SPI RAM parameters in menuconfig:

ESP32-specific
 - Support for external, SPI-connected RAM = check 
 - SPI RAM config
    - Initialize SPI RAM when booting the ESP32 = check -> ok
    - SPI RAM access method = Make RAM allocatable using malloc() as well -> ok

At start of ESP32 it seemed that everything was ok:

I (35) boot: SPI Speed      : 40MHz
I (39) boot: SPI Mode       : DIO
I (43) boot: SPI Flash Size : 4MB
I (47) boot: Partition Table:
I (51) boot: ## Label            Usage          Type ST Offset   Length
I (58) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (66) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (73) boot:  2 factory          factory app      00 00 00010000 00200000
I (81) boot: End of partition table
...
I (843) spiram: Found 64MBit SPI RAM device
I (846) spiram: SPI RAM mode: flash 40m sram 40m
I (852) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
...
I (889) cpu_start: App cpu up.
I (1788) spiram: SPI SRAM memory test OK
I (1788) heap_init: Initializing. RAM available for dynamic allocation:
I (1789) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1795) heap_init: At 3FFBBC80 len 00024380 (144 KiB): DRAM
I (1801) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1807) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1814) heap_init: At 400987F8 len 00007808 (30 KiB): IRAM
I (1820) cpu_start: Pro cpu start user code
I (1825) spiram: Adding pool of 4096K of external SPI memory to heap allocator
...
I (29356) esp32_camera: WiFI ready
I (29356) esp32_camera: Free heap: 4364696

I optimized using of memory:

• Homekit: Maximum number of sim. clients: 2
• Component config/ESP32-specific/SPI RAM config/Reserve this amount of bytes for data that specifically needs to bin DM =0 (old value:32768)
• Reduce both 'xTaskCreate'-statements in code to 80%
  Now I got this:

>>> HomeKit: [Client 56] Update Characteristics
I (71251) esp32_camera: Processing session command 1
I (71251) esp32_camera: Adding streaming session
I (71261) esp32_camera: Starting streaming
I (71261) esp32_camera: Total free memory: 50240
x264 [error]: malloc of size 37984 failed
E (71271) esp32_camera: Failed to open H.264 encoder
E (71271) FreeRTOS: FreeRTOS Task "Camera Stream" should not return, Aborting now!
abort() was called at PC 0x40091ce3 on core 1
0x40091ce3: vPortTaskWrapper at /Users/username/esp/esp-idf/components/freertos/port.c:435

I didn't understand these both messages:

• There are 50.240 bytes of memory free before error occurred.
• At start of program there are 4.364.696 bytes of free heap.

Is there any other Parameter in "SPI RAM config" to change?

[maximkulkin]

It looks like you do have 4MB of RAM. So where did all memory go?

[GermanSheepDog]

Yes, it looks like I do have 4MB of RAM for HEAP.

I build in some logging information like this:

ESP_LOGI(TAG, "Free heap %s 1: %d", __FUNCTION__, xPortGetFreeHeapSize());

Output of 1. test:

I (7525) camera: Free heap camera_probe 2: 4397092
I (7525) camera_xclk: Free heap camera_enable_out_clock 1: 4397092
I (7535) camera_xclk: Free heap camera_enable_out_clock 2: 4397092
I (7545) camera_xclk: Free heap camera_enable_out_clock 3: 4397092
I (7545) camera_xclk: Free heap camera_enable_out_clock 4: 202828
I (7555) camera_xclk: Free heap camera_enable_out_clock 5: 202828
I (7565) camera: Free heap camera_probe 3: 202828
I (7565) sccb: pin_sda 22 pin_scl 23

Output of 2. + 3. test:

I (7555) camera_xclk: Free heap camera_enable_out_clock 5: 4397092
I (7565) camera: Free heap camera_probe 3: 4397092
I (7565) sccb: pin_sda 22 pin_scl 23

I (7575) camera: Free heap camera_probe 4: 202416

Output of 4. test:

I (7527) camera: Free heap camera_probe 2: 4397092
I (7527) camera_xclk: Free heap camera_enable_out_clock 1: 4397092
I (7537) camera_xclk: Free heap camera_enable_out_clock 2: 4397092
I (7547) camera_xclk: Free heap camera_enable_out_clock 3: 202828
I (7547) camera_xclk: Free heap camera_enable_out_clock 4: 202828

Why are the process different?
Who stole me 4MB of RAM?
I used M5Camera with 4MB of flash and 4MB of PSRAM und ESP-IDF v4.0-beta1.

[GermanSheepDog]

I found the problem - it is the LED!
I use default parameters for LED ant it was mapped with GPIO16 (look at sdkconfig: CONFIG_CAMERA_PIN_LED=16)
I switched at my M5CameraF LED to Pin 2 (Data of Mic!) an it worked fine. I can see a stream, a little bit blurred. Today I did not need the mic.

[maximkulkin]

My M5Camera LED is GPIO 14, consult your documentation.

And congratulations!

[GermanSheepDog]

Yes, in second step I found the LED on GPIO14.

Thank you for help and congratulations.