Skip to content

Using ledcWriteTone cause I2C memory fail #3555

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
tatarmiki opened this issue Dec 9, 2019 · 15 comments · Fixed by #3560
Closed

Using ledcWriteTone cause I2C memory fail #3555

tatarmiki opened this issue Dec 9, 2019 · 15 comments · Fixed by #3560
Assignees
Labels

Comments

@tatarmiki
Copy link

tatarmiki commented Dec 9, 2019

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
Copy link
Contributor

@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
Copy link
Author

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
Copy link
Contributor

@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
Copy link
Contributor

@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
Copy link
Author

Great! Thanks for your help.

@tatarmiki
Copy link
Author

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

@stickbreaker
Copy link
Contributor

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

Chuck.

@tatarmiki
Copy link
Author

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
Copy link
Contributor

stickbreaker commented Dec 10, 2019

@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
Copy link
Contributor

@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
Copy link
Author

@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
Copy link
Contributor

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
Copy link
Contributor

@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
Copy link
Author

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

@stickbreaker
Copy link
Contributor

@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.

me-no-dev pushed a commit that referenced this issue Dec 30, 2019
* `ledcWriteTone()` added a `apbcallback()` evertime the tone value was non zero.  
* `addApbChangeCallback()` did not detect duplicate callbacks.
* changed the apbcallback list to a double link to support roll forward, roll back execution.  This made the sequences of clock change callback start with the newest registered -> to oldest on the `before` then oldest -> newest after the clock change.  This made the UART debug log output have minimal gibberish during the clock change.
* change how the UART callback handled the MUTEX because if any `apbchangeCallback()` executed a `log_x()` a deadlock would occur.

This fixes #3555
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants