Using ledcWriteTone cause I2C memory fail

[tatarmiki]

Hardware:

Board: ESP32 DevKitV1 Core Installation version: 1.0.4 IDE name: Arduino IDE 1.8.10 Flash Frequency: 80Mhz PSRAM enabled: no Upload Speed: 921600 Computer OS: Windows 10

Description:

I try to make a counting device with a 4 Digit 7-Segment HT16K33 I2C Digital Led Display Module, and a beep sound every second count. My problem is with the ledcWriteTone function. When i use it to generate the beep sound with buzzer, after a certain of time it's aprox 165 min, the I2C communication fail with MEMORY error. If i not use the ledcWriteTone, everething is fine. Every 10 min count the below sketch print the free heap, and the I2C last error state. Anyone can tell me what's wrong with my code?

Sketch:

#include <Wire.h>
#include <Adafruit_LEDBackpack.h>
#include <Adafruit_GFX.h>
#include <SPI.h>

Adafruit_7segment seven_segment_display = Adafruit_7segment();
int counter = 0;
int freq = 2000;
int channel = 0;
int resolution = 8;
int cycle = 0;

void setup() {
    Wire.begin();
    ledcSetup(channel, freq, resolution);
    ledcAttachPin(26, channel);
    Serial.begin(115200);
    seven_segment_display.begin(0x70);
}

void loop() {

    // Print the free heap every minute

    if (counter == 600) {
        counter = 0;
        Serial.printf("Cycle: %d\n", cycle++);
        Serial.printf("FreeHeap/min: %i bytes\n", ESP.getFreeHeap());
        Serial.printf("I2C status = %d - (%s)\n", Wire.lastError(), Wire.getErrorText(Wire.lastError()));
    }

    // create sample for the 7 segment to display

    int seconds = counter % 60;
    int minutes = counter / 60;

    int min_first_digit = minutes / 10;
    int min_second_digit = minutes % 10;

    int sec_first_digit = seconds / 10;
    int sec_second_digit = seconds % 10;

    // write to 7 segment

    seven_segment_display.drawColon(true);
    seven_segment_display.writeDigitNum(0, min_first_digit);
    seven_segment_display.writeDigitNum(1, min_second_digit);
    seven_segment_display.writeDigitNum(3, sec_first_digit);
    seven_segment_display.writeDigitNum(4, sec_second_digit);
    seven_segment_display.writeDisplay();

    // generate beep sound for buzzer

    ledcWriteTone(channel, freq);

    // beep sound length is 50 ms
    //delay(50);

    // stop beep
    ledcWriteTone(channel, 0);

    //delay(950);

    counter++;
}

Debug Messages:

Opening port
Port open
Cycle: 0
FreeHeap/min: 342260 bytes
I2C status = 0 - (OK)
Cycle: 1
FreeHeap/min: 325472 bytes
I2C status = 0 - (OK)
Cycle: 2
FreeHeap/min: 308672 bytes
I2C status = 0 - (OK)
Cycle: 3
FreeHeap/min: 291872 bytes
I2C status = 0 - (OK)
Cycle: 4
FreeHeap/min: 275072 bytes
I2C status = 0 - (OK)
Cycle: 5
FreeHeap/min: 258272 bytes
I2C status = 0 - (OK)
Cycle: 6
FreeHeap/min: 241472 bytes
I2C status = 0 - (OK)
Cycle: 7
FreeHeap/min: 224672 bytes
I2C status = 0 - (OK)
Cycle: 8
FreeHeap/min: 207872 bytes
I2C status = 0 - (OK)
Cycle: 9
FreeHeap/min: 191084 bytes
I2C status = 0 - (OK)
Cycle: 10
FreeHeap/min: 174296 bytes
I2C status = 0 - (OK)
Cycle: 11
FreeHeap/min: 157496 bytes
I2C status = 0 - (OK)
Cycle: 12
FreeHeap/min: 140696 bytes
I2C status = 0 - (OK)
Cycle: 13
FreeHeap/min: 123896 bytes
I2C status = 0 - (OK)
Cycle: 14
FreeHeap/min: 107096 bytes
I2C status = 0 - (OK)
Cycle: 15
FreeHeap/min: 90296 bytes
I2C status = 0 - (OK)
Cycle: 16
FreeHeap/min: 73496 bytes
I2C status = 0 - (OK)
Cycle: 17
FreeHeap/min: 70584 bytes
I2C status = 6 - (MEMORY)
Cycle: 18
FreeHeap/min: 70584 bytes
I2C status = 6 - (MEMORY) 

[stickbreaker]

@tatarmiki I haven't seen any memory leak in i2c before this issue. I added some additional debug code to your example, can you run it and capture the output. Lets see if we can localize the problem.

#include <Wire.h>
#include <Adafruit_LEDBackpack.h>
#include <Adafruit_GFX.h>
#include <SPI.h>

Adafruit_7segment seven_segment_display = Adafruit_7segment();
int counter = 0;
int freq = 2000;
int channel = 0;
int resolution = 8;
int cycle = 0;
int32_t lastFreeSpace = 0;

void setup() {
    Wire.begin();
    lastFreeSpace = ESP.getFreeHeap();
    ledcSetup(channel, freq, resolution);
    ledcAttachPin(26, channel);
    Serial.begin(115200);
    seven_segment_display.begin(0x70);
}

void loop() {

    // Print the free heap every minute

    if (counter == 600) {
        counter = 0;
        Serial.printf("Cycle: %d\n", cycle++);
        Serial.printf("FreeHeap/min: %i bytes\n", ESP.getFreeHeap());
        Serial.printf("I2C status = %d - (%s)\n", Wire.lastError(), Wire.getErrorText(Wire.lastError()));
    }

    // create sample for the 7 segment to display

    int seconds = counter % 60;
    int minutes = counter / 60;

    int min_first_digit = minutes / 10;
    int min_second_digit = minutes % 10;

    int sec_first_digit = seconds / 10;
    int sec_second_digit = seconds % 10;

    // write to 7 segment
    int32_t currentFreeSpace = ESP.getFreeHeap();
    if(currentFreeSpace != lastFreeSpace){
        Serial.printf("cycle[%06d] top of loop freespace change, last =%d, current = %d, delta =%d\n",cycle,lastFreeSpace,currentFreeSpace,(currentFreeSpace-lastFreeSpace));
        lastFreeSpace = currentFreeSpace;
    }
    seven_segment_display.drawColon(true);
    seven_segment_display.writeDigitNum(0, min_first_digit);
    seven_segment_display.writeDigitNum(1, min_second_digit);
    seven_segment_display.writeDigitNum(3, sec_first_digit);
    seven_segment_display.writeDigitNum(4, sec_second_digit);
        currentFreeSpace = ESP.getFreeHeap();
    if(currentFreeSpace != lastFreeSpace){
        Serial.printf("cycle[%06d] after draw display, freespace change, last =%d, current = %d, delta =%d\n",cycle,lastFreeSpace,currentFreeSpace,(currentFreeSpace-lastFreeSpace));
        lastFreeSpace = currentFreeSpace;
    }
    seven_segment_display.writeDisplay();
        currentFreeSpace = ESP.getFreeHeap();
    if(currentFreeSpace != lastFreeSpace){
        Serial.printf("cycle[%06d] after write through I2C, freespace change, last =%d, current = %d, delta =%d\n",cycle,lastFreeSpace,currentFreeSpace,(currentFreeSpace-lastFreeSpace));
        lastFreeSpace = currentFreeSpace;
    }

    // generate beep sound for buzzer

    ledcWriteTone(channel, freq);

    // beep sound length is 50 ms
    //delay(50);

    // stop beep
    ledcWriteTone(channel, 0);

    //delay(950);

    counter++;
}

Chuck.

[tatarmiki]

Thanks for the fast response. Here's the output. I only changed my counter to 60 to see more separately the cycles.

Opening port
Port open
cycle[000000] top of loop freespace change, last =359348, current = 359052, delta =-296
cycle[000000] top of loop freespace change, last =359052, current = 359024, delta =-28
cycle[000000] top of loop freespace change, last =359024, current = 358996, delta =-28
cycle[000000] top of loop freespace change, last =358996, current = 358968, delta =-28
cycle[000000] top of loop freespace change, last =358968, current = 358940, delta =-28
cycle[000000] top of loop freespace change, last =358940, current = 358912, delta =-28
cycle[000000] top of loop freespace change, last =358912, current = 358884, delta =-28
cycle[000000] top of loop freespace change, last =358884, current = 358856, delta =-28
cycle[000000] top of loop freespace change, last =358856, current = 358828, delta =-28
cycle[000000] top of loop freespace change, last =358828, current = 358800, delta =-28
cycle[000000] top of loop freespace change, last =358800, current = 358772, delta =-28
cycle[000000] top of loop freespace change, last =358772, current = 358744, delta =-28
cycle[000000] top of loop freespace change, last =358744, current = 358716, delta =-28
cycle[000000] top of loop freespace change, last =358716, current = 358688, delta =-28
cycle[000000] top of loop freespace change, last =358688, current = 358660, delta =-28
cycle[000000] top of loop freespace change, last =358660, current = 358632, delta =-28
cycle[000000] top of loop freespace change, last =358632, current = 358604, delta =-28
cycle[000000] top of loop freespace change, last =358604, current = 358576, delta =-28
cycle[000000] top of loop freespace change, last =358576, current = 358548, delta =-28
cycle[000000] top of loop freespace change, last =358548, current = 358520, delta =-28
cycle[000000] top of loop freespace change, last =358520, current = 358492, delta =-28
cycle[000000] top of loop freespace change, last =358492, current = 358464, delta =-28
cycle[000000] top of loop freespace change, last =358464, current = 358436, delta =-28
cycle[000000] top of loop freespace change, last =358436, current = 358408, delta =-28
cycle[000000] top of loop freespace change, last =358408, current = 358380, delta =-28
cycle[000000] top of loop freespace change, last =358380, current = 358352, delta =-28
cycle[000000] top of loop freespace change, last =358352, current = 358324, delta =-28
cycle[000000] top of loop freespace change, last =358324, current = 358296, delta =-28
cycle[000000] top of loop freespace change, last =358296, current = 358268, delta =-28
cycle[000000] top of loop freespace change, last =358268, current = 358240, delta =-28
cycle[000000] top of loop freespace change, last =358240, current = 358212, delta =-28
cycle[000000] top of loop freespace change, last =358212, current = 358184, delta =-28
cycle[000000] top of loop freespace change, last =358184, current = 358156, delta =-28
cycle[000000] top of loop freespace change, last =358156, current = 358128, delta =-28
cycle[000000] top of loop freespace change, last =358128, current = 358100, delta =-28
cycle[000000] top of loop freespace change, last =358100, current = 358072, delta =-28
cycle[000000] top of loop freespace change, last =358072, current = 358044, delta =-28
cycle[000000] top of loop freespace change, last =358044, current = 358016, delta =-28
cycle[000000] top of loop freespace change, last =358016, current = 357988, delta =-28
cycle[000000] top of loop freespace change, last =357988, current = 357960, delta =-28
cycle[000000] top of loop freespace change, last =357960, current = 357932, delta =-28
cycle[000000] top of loop freespace change, last =357932, current = 357904, delta =-28
cycle[000000] top of loop freespace change, last =357904, current = 357876, delta =-28
cycle[000000] top of loop freespace change, last =357876, current = 357848, delta =-28
cycle[000000] top of loop freespace change, last =357848, current = 357820, delta =-28
cycle[000000] top of loop freespace change, last =357820, current = 357792, delta =-28
cycle[000000] top of loop freespace change, last =357792, current = 357764, delta =-28
cycle[000000] top of loop freespace change, last =357764, current = 357736, delta =-28
cycle[000000] top of loop freespace change, last =357736, current = 357708, delta =-28
cycle[000000] top of loop freespace change, last =357708, current = 357680, delta =-28
cycle[000000] top of loop freespace change, last =357680, current = 357652, delta =-28
cycle[000000] top of loop freespace change, last =357652, current = 357624, delta =-28
cycle[000000] top of loop freespace change, last =357624, current = 357596, delta =-28
cycle[000000] top of loop freespace change, last =357596, current = 357568, delta =-28
cycle[000000] top of loop freespace change, last =357568, current = 357540, delta =-28
cycle[000000] top of loop freespace change, last =357540, current = 357512, delta =-28
cycle[000000] top of loop freespace change, last =357512, current = 357484, delta =-28
cycle[000000] top of loop freespace change, last =357484, current = 357456, delta =-28
cycle[000000] top of loop freespace change, last =357456, current = 357428, delta =-28
cycle[000000] top of loop freespace change, last =357428, current = 357400, delta =-28
Cycle: 0
FreeHeap/min: 357372 bytes
I2C status = 0 - (OK)
cycle[000001] top of loop freespace change, last =357400, current = 357372, delta =-28
cycle[000001] top of loop freespace change, last =357372, current = 357344, delta =-28
cycle[000001] top of loop freespace change, last =357344, current = 357316, delta =-28
cycle[000001] top of loop freespace change, last =357316, current = 357288, delta =-28
cycle[000001] top of loop freespace change, last =357288, current = 357260, delta =-28
cycle[000001] top of loop freespace change, last =357260, current = 357232, delta =-28
cycle[000001] top of loop freespace change, last =357232, current = 357204, delta =-28

Port closed

[stickbreaker]

@tatarmiki So, it looks like the problem is in ledCWriteTone().

everytime around the loop 28 bytes is lost.

Also I looks like I use the wrong counter in my debug. Instead of cycles change it to counter.

To verify my supposition is correct, change the bottom of loop() to:

    // generate beep sound for buzzer

    ledcWriteTone(channel, freq);

       currentFreeSpace = ESP.getFreeHeap();
    if(currentFreeSpace != lastFreeSpace){
        Serial.printf("cycle[%06d] after ledCWriteTone(%d), freespace change, last =%d, current = %d, delta =%d\n",counter, freq, lastFreeSpace,currentFreeSpace,(currentFreeSpace-lastFreeSpace));
        lastFreeSpace = currentFreeSpace;
    }

    // beep sound length is 50 ms
    //delay(50);

    // stop beep
    ledcWriteTone(channel, 0);

       currentFreeSpace = ESP.getFreeHeap();
    if(currentFreeSpace != lastFreeSpace){
        Serial.printf("cycle[%06d] after ledCWriteTone(0), freespace change, last =%d, current = %d, delta =%d\n",counter,  lastFreeSpace,currentFreeSpace,(currentFreeSpace-lastFreeSpace));
        lastFreeSpace = currentFreeSpace;
    }

    //delay(950);

I'll look at lcdCWriteTone() and see if I can find where it is not freeing a buffer.

Chuck.

[stickbreaker]

@tatarmiki found the leak. There was an error using a locking semaphore. You can manually apply these fixes to esp32-hal-ledc.c. just look at pr #3560 it is just two changes.

Chuck.

[tatarmiki]

Great! Thanks for your help.

[tatarmiki]

I applied your fix manually, but the leak not disappear.

[stickbreaker]

@tatarmiki what does the console log show? Can you add those additional debugs aroung the ledcWriteTone() calls?

Chuck.

[tatarmiki]

Yes.

cycle[000000] top of loop freespace change, last =359348, current = 359052, delta =-296
cycle[000000] after ledCWriteTone(2000), freespace change, last =359052, current = 359024, delta =-28
cycle[000001] after ledCWriteTone(2000), freespace change, last =359024, current = 358996, delta =-28
cycle[000002] after ledCWriteTone(2000), freespace change, last =358996, current = 358968, delta =-28
cycle[000003] after ledCWriteTone(2000), freespace change, last =358968, current = 358940, delta =-28
cycle[000004] after ledCWriteTone(2000), freespace change, last =358940, current = 358912, delta =-28
cycle[000005] after ledCWriteTone(2000), freespace change, last =358912, current = 358884, delta =-28
cycle[000006] after ledCWriteTone(2000), freespace change, last =358884, current = 358856, delta =-28
cycle[000007] after ledCWriteTone(2000), freespace change, last =358856, current = 358828, delta =-28
cycle[000008] after ledCWriteTone(2000), freespace change, last =358828, current = 358800, delta =-28
cycle[000009] after ledCWriteTone(2000), freespace change, last =358800, current = 358772, delta =-28
cycle[000010] after ledCWriteTone(2000), freespace change, last =358772, current = 358744, delta =-28
cycle[000011] after ledCWriteTone(2000), freespace change, last =358744, current = 358716, delta =-28
cycle[000012] after ledCWriteTone(2000), freespace change, last =358716, current = 358688, delta =-28
cycle[000013] after ledCWriteTone(2000), freespace change, last =358688, current = 358660, delta =-28
cycle[000014] after ledCWriteTone(2000), freespace change, last =358660, current = 358632, delta =-28
cycle[000015] after ledCWriteTone(2000), freespace change, last =358632, current = 358604, delta =-28
cycle[000016] after ledCWriteTone(2000), freespace change, last =358604, current = 358576, delta =-28
cycle[000017] after ledCWriteTone(2000), freespace change, last =358576, current = 358548, delta =-28
cycle[000018] after ledCWriteTone(2000), freespace change, last =358548, current = 358520, delta =-28
cycle[000019] after ledCWriteTone(2000), freespace change, last =358520, current = 358492, delta =-28
cycle[000020] after ledCWriteTone(2000), freespace change, last =358492, current = 358464, delta =-28
cycle[000021] after ledCWriteTone(2000), freespace change, last =358464, current = 358436, delta =-28
cycle[000022] after ledCWriteTone(2000), freespace change, last =358436, current = 358408, delta =-28
cycle[000023] after ledCWriteTone(2000), freespace change, last =358408, current = 358380, delta =-28
cycle[000024] after ledCWriteTone(2000), freespace change, last =358380, current = 358352, delta =-28

[stickbreaker]

@tatarmiki I can't imagine why my change did not fix the problem for you. Add some debug logging to esp32-hal-ledc.c, expand that semaphore creation if() to

#if !CONFIG_DISABLE_HAL_LOCKS
        if( _ledc_sys_lock == NULL) {
           _ledc_sys_lock = xSemaphoreCreateMutex();
            log_e("sem=%d",_ledc_sys_lock);
        }
#endif

Set the Core Debug Level to at least ERROR, then try it.

I'll take another look through the ledcWriteTone() code and see if I can find something else. It has to be in the _ledcSetupTimer() function. The debug you posted shows the leak does not occur then you set the tone to zero(0). The only difference between 0 and 2000 is that a call to _ledcSetupTimer() is made.

Chuck.

[stickbreaker]

@tatarmiki nope, I'm an idiot. the problem is at the end of _ledcSetupTimer() every time through it add a cpu Frequency change callback. It only needs to do that once. I'll do some more thinking and update my pr.

Chuck.

[tatarmiki]

@tatarmiki I can't imagine why my change did not fix the problem for you. Add some debug logging to esp32-hal-ledc.c, expand that semaphore creation if() to

#if !CONFIG_DISABLE_HAL_LOCKS
        if( _ledc_sys_lock == NULL) {
           _ledc_sys_lock = xSemaphoreCreateMutex();
            log_e("sem=%d",_ledc_sys_lock);
        }
#endif

Set the Core Debug Level to at least ERROR, then try it.

I'll take another look through the ledcWriteTone() code and see if I can find something else. It has to be in the _ledcSetupTimer() function. The debug you posted shows the leak does not occur then you set the tone to zero(0). The only difference between 0 and 2000 is that a call to _ledcSetupTimer() is made.

Chuck.

I added it but is not showing in debug logging. I added a simple log_e() into the ledcWritetone function first line, and that showed in debug log, so

if( _ledc_sys_lock == NULL) {
           _ledc_sys_lock = xSemaphoreCreateMutex();
            log_e("sem=%d",_ledc_sys_lock);
}

is never called

[stickbreaker]

Your correct. that createSemaphore() call is hidden behind a STATIC initialize lock.

When I read through it first I missed: tHasStarted

   static bool tHasStarted = false;
    if(!tHasStarted) {
        tHasStarted = true;
        DPORT_SET_PERI_REG_MASK(DPORT_PERIP_CLK_EN_REG, DPORT_LEDC_CLK_EN);
        DPORT_CLEAR_PERI_REG_MASK(DPORT_PERIP_RST_EN_REG, DPORT_LEDC_RST);
        LEDC.conf.apb_clk_sel = 1;//LS use apb clock
#if !CONFIG_DISABLE_HAL_LOCKS
        if( _ledc_sys_lock == NULL) _ledc_sys_lock = xSemaphoreCreateMutex();
#endif
    }

The "REAL" problem is the call :

    uint32_t iarg = chan;
    addApbChangeCallback((void*)iarg, _on_apb_change);

It adds a callback to support CPU frequency change every time the timer is reconfigured.

I'm think about how to efficiently handle this problem. there needs to be ONE callback registered for Each Active channel. I could call `removeAPBChangeCallback() each time the freq changed, but that is wasteful. I think a bit mask is better.

Chuck.

[stickbreaker]

@tatarmiki #3560 works for me. I don't have a 7 segment display I tested it with a SSD1306 OLED using adafruits gfx library. no more memory leak!

cycle[000000] top of loop freespace change, last =358972, current = 358052, delta =-920

test code

[tatarmiki]

It's working!! No more memory leak. Thanks for your help.

[stickbreaker]

@tatarmiki The current pr#3560 branch code is still a work in progress. I'm still testing. Hopefully I'll get it finished and merged into Master in the next couple of weeks.

so, I'll close this issue and just update the pr.

Chuck.