Interrupts fail when create files with littlefs (esp32-wroom-32)
Posted: Tue Oct 31, 2023 2:04 pm
Hi,
When updating to version 2.0.12 I started to notice strange behavior with I/O and timer interruptions. When I'm creating, or even updating, a file with LittleFS, some interrupts are lost, either in the timer (timerAlarmEnable(timer2)) or even in the I/O pins (attachInterrupt(ES2a_PIN, ISR_Sensor2, CHANGE)).
In both cases some interrupts fail and do not execute. I noticed that this occurs when a file is created or even updated, even allocating another CPU to the process.
Has anyone seen something similar? Do you know how to solve it?
I built a code to simulate the problem. See below:
The ISR_Sensor2 interrupt should occur every 5ms but in certain situations it takes more than 50ms to occur.
This occurs when thred logFlush is active, but specifically when the lines that open and close the file are uncommented.
If you comment on these lines, interruptions occur normally.
Serial Debug:
count: 8182 - whith: 4971
count: 8202 - whith: 4972
count: 8222 - whith: 4971
count: 8241 - whith: 43143 ---------- Here the interruption did not occur
count: 8261 - whith: 4970
count: 8281 - whith: 4971
count: 8301 - whith: 4971
Am I doing something wrong, or is the file system blocking interrupts?
Grateful for the attention!
Daniel!
When updating to version 2.0.12 I started to notice strange behavior with I/O and timer interruptions. When I'm creating, or even updating, a file with LittleFS, some interrupts are lost, either in the timer (timerAlarmEnable(timer2)) or even in the I/O pins (attachInterrupt(ES2a_PIN, ISR_Sensor2, CHANGE)).
In both cases some interrupts fail and do not execute. I noticed that this occurs when a file is created or even updated, even allocating another CPU to the process.
Has anyone seen something similar? Do you know how to solve it?
I built a code to simulate the problem. See below:
Code: Select all
#include "Arduino.h"
#include "FS.h"
#include "LITTLEFS.h"
#include <vector>
#define ES1a_PIN 34
#define ES1b_PIN 35
#define ES2a_PIN 32
#define ES2b_PIN 33
//#define FILE_SYSTEM SPIFFS
//#define FILE_SYSTEM LITTLEFS
#define FILE_SYSTEM LittleFS
#define FORMAT_SPIFFS_IF_FAILED true
#define SAMPLES_NUM 6
typedef struct {
fs::FS *loggerFS;
String directory = "/log";
String filename = "";
size_t maxSize = (30720 * 3);
size_t individualFileSize = 9216;
uint8_t maxFiles = 10;
} logger_t;
logger_t logger;
std::vector<String> temporaryLogList;
SemaphoreHandle_t vectorMutex = NULL;
SemaphoreHandle_t logLock = NULL;
hw_timer_t *timer2 = NULL;
portMUX_TYPE mux = portMUX_INITIALIZER_UNLOCKED;
portMUX_TYPE timer2Mux = portMUX_INITIALIZER_UNLOCKED;
volatile uint32_t count = 0;
volatile uint32_t pulse_duration = 0;
void setupIO() {
pinMode(ES1a_PIN, INPUT);
pinMode(ES1b_PIN, INPUT);
pinMode(ES2a_PIN, INPUT);
pinMode(ES2b_PIN, INPUT);
}
void startFileSystem() {
if (!FILE_SYSTEM.begin(FORMAT_SPIFFS_IF_FAILED)) {
Serial.println("SPIFFS Mount Failed");
delay(15000);
ESP.restart();
}
FILE_SYSTEM.format();
// fsPresent = true;
log_i("FLASH: %ukB - FIRMWARE: %u/%ukB - %.2f%% livre", (ESP.getFlashChipSize() / 1024),
(ESP.getSketchSize() / 1024), (ESP.getFreeSketchSpace() / 1024),
(100.00 - (float_t)((float_t) ESP.getSketchSize() / (float_t) ESP.getFreeSketchSpace()) * 100));
log_i("SPIFFS: %u/%ukB - %.2f%% livre", (FILE_SYSTEM.usedBytes() / 1024),
(FILE_SYSTEM.totalBytes() / 1024),
(100.00 - (float_t)((float_t)((float_t) FILE_SYSTEM.usedBytes() / (float_t) FILE_SYSTEM.totalBytes())) * 100));
}
void makeNewLogFile(logger_t *logger) {
String fileSufix;
uint8_t sufixPisition = logger->directory.length() + 5;
fileSufix = logger->filename.substring(sufixPisition);
fileSufix = String(fileSufix.toInt() + 1);
logger->filename.remove(sufixPisition);
logger->filename += fileSufix;
log_d("Novo arquivo de log: %s ", logger->filename.c_str());
}
void logFlush(void *pvParameters) {
File file;
size_t fileSize = 0;
while (1) {
file = logger.loggerFS->open(logger.filename, FILE_APPEND);
if (file) {
xSemaphoreTake(vectorMutex, portMAX_DELAY);
while (temporaryLogList.size() > 0) {
// ets_printf("%s", temporaryLogList.back().c_str());
// file.print(temporaryLogList.back().c_str());
temporaryLogList.pop_back();
}
xSemaphoreGive(vectorMutex);
}
// file.flush();
// fileSize = file.size();
file.close();
//
// if (fileSize > logger.individualFileSize) {
// makeNewLogFile(&logger);
// }
vTaskDelay(pdMS_TO_TICKS(250));
}
}
void bufferInsert(String str) {
xSemaphoreTake(logLock, portMAX_DELAY);
temporaryLogList.insert(temporaryLogList.begin(), str);
xSemaphoreGive(logLock);
}
void IRAM_ATTR ISR_Sensor2() {
static volatile unsigned long int widthOld = micros();
volatile unsigned long int width = micros();
portENTER_CRITICAL_ISR(&mux);
if (widthOld > width) {
pulse_duration = 0xFFFFFFFF - (width - widthOld);
}
else {
pulse_duration = width - widthOld;
}
widthOld = width;
count++;
portEXIT_CRITICAL_ISR(&mux);
}
void IRAM_ATTR onTimer2() {
portENTER_CRITICAL_ISR(&timer2Mux);
static volatile uint8_t internalSample = 0;
static volatile boolean oldState = false;
boolean state = digitalRead(ES2a_PIN);
if (state != oldState) {
internalSample = 0;
oldState = state;
}
if (internalSample < SAMPLES_NUM) {
if (++internalSample == SAMPLES_NUM) {
count++;
}
}
portEXIT_CRITICAL_ISR(&timer2Mux);
}
void loggerDeleteFiles(logger_t *logger) {
File logDir = logger->loggerFS->open(logger->directory, "r");
while (logDir) {
String fileName = "/";
fileName += logDir.name();
fileName += "/";
const char *file = logDir.openNextFile().name();
if (!file) {
break;
}
fileName += file;
if (!logger->loggerFS->remove(fileName)) {
log_e("Falha ao remover arquivo do log: %s", fileName.c_str());
} else {
log_d("Arquivo de log removido: %s", fileName.c_str());
}
}
logDir.close();
}
void loggerBegin(fs::LittleFSFS &fs, boolean deleteLogOnInit) {
logger.loggerFS = &fs;
logger.directory = "/log";
logger.maxFiles = 10;
vectorMutex = xSemaphoreCreateMutex();
logLock = xSemaphoreCreateMutex();
if (!logger.loggerFS->exists(logger.directory)) {
if (!logger.loggerFS->mkdir(logger.directory)) {
log_e("Falhou ao criar diretorio de log: %s", logger.directory);
} else {
log_d("Diretorio de log criado: %s", logger.directory);
}
}
if (deleteLogOnInit) {
loggerDeleteFiles(&logger);
log_d("Aquivos de log excluidos!");
}
logger.filename = "/log_1";
xTaskCreatePinnedToCore(logFlush, "LOGGER", 4000, NULL, 0, NULL, PRO_CPU_NUM);
log_v("Logger inicializado.");
}
void startCpu() {
attachInterrupt(ES2a_PIN, ISR_Sensor2, CHANGE);
//
// timer2 = timerBegin(1, 80, true);
// timerAttachInterrupt(timer2, &onTimer2, true);
// timerAlarmWrite(timer2, 125, true);
// timerAlarmEnable (timer2);
}
void setup() {
esp_log_level_set("*", ESP_LOG_VERBOSE);
setupIO();
Serial.begin(115200);
Serial.setDebugOutput(true);
Serial.print("\n");
startFileSystem();
loggerBegin(FILE_SYSTEM, true);
log_i("POWER ON...");
log_i("Reset Mode: %X", esp_reset_reason());
startCpu();
count = 0;
}
void loop() {
bufferInsert("Insert");
Serial.print("count: ");
Serial.print(count);
Serial.print(" - whith: ");
Serial.println(pulse_duration);
delay(100);
}
This occurs when thred logFlush is active, but specifically when the lines that open and close the file are uncommented.
If you comment on these lines, interruptions occur normally.
Serial Debug:
count: 8182 - whith: 4971
count: 8202 - whith: 4972
count: 8222 - whith: 4971
count: 8241 - whith: 43143 ---------- Here the interruption did not occur
count: 8261 - whith: 4970
count: 8281 - whith: 4971
count: 8301 - whith: 4971
Am I doing something wrong, or is the file system blocking interrupts?
Grateful for the attention!
Daniel!