PWM is blocked during SPIFFS write operations

[Gei0r]

Basic Infos

• This issue complies with the issue POLICY doc.
• I have read the documentation at readthedocs and the issue is not addressed there.
• I have tested that the issue is present in current master branch (aka latest git).
• I have searched the issue tracker for a similar issue.
• If there is a stack dump, I have decoded it. (no stack dump)
• I have filled out all fields below.

Platform

• Hardware: ESP-12
• Core Version: b26c19e
• Development Env: Platformio / Arduino IDE
• Operating System: Windows

Settings in IDE

• Module: Wemos D1 mini
  (removed rest because it's not a flashing problem)

Problem Description

The ESP8266 does not have hardware support for PWM, so the Arduino Core implements PWM in software with timer interrupts.

However, these PWM interrupts seem to be blocked by some SPIFFS write operations. In the picture below, every yellow spike shows the start of a small write operation. The green channel shows a PWM at 500 Hz.

As you can see, every 16th or so write operation takes a lot longer than the other ones (about 110 ms), and disturbs the PWM output.

I understand that SPIFFS is not realtime capable and it is unavoidable that some write operations take longer than others. But maybe the SPIFFS code can be changed so that the PWM is not affected by that?

MCVE Sketch

#include <Arduino.h>
#include <FS.h>

void setup() {
    pinMode(14, OUTPUT);

    analogWriteRange(255);
    analogWriteFreq(500);
    analogWrite(5, 128);   // GPIO5 (pin "D1" on D1 mini)

    SPIFFS.begin();
}

String toWrite = "Hello world!";

void loop() {
    // Trigger for oscilloscope (yellow channel):
    digitalWrite(14, 1);
    delayMicroseconds(100);
    digitalWrite(14, 0);

    File f = SPIFFS.open("/test.txt", "w");
    f.write((uint8_t*)toWrite.c_str(), toWrite.length());
    f.close();
}

Debug Messages

(see image)

[devyte]

@Gei0r could you please try #5511 with littleFS and test how that behaves with PWM?

[earlephilhower]

This looks like it is caused by PWM going from NMI to a regular IRQ, and SPIFFS having interrupts disabled for a very long time. @Gei0r, could you replace the following function in cores/esp8266/core_esp8266_timer.c and capture your waveform again? I don't have my logic analyzer hooked up presently so can't try it myself. It simply replaces the maskable IRQ with a non-maskable one.

void ICACHE_RAM_ATTR timer1_isr_init(){
    ETS_FRC_TIMER1_INTR_ATTACH(NULL, NULL);
    ETS_FRC_TIMER1_NMI_INTR_ATTACH(timer1_isr_handler);
}

[Gei0r]

@devyte LittleFS shows the behavior on every write:

[Gei0r]

@earlephilhower Your code snippet works:

Although I'm worried that using the NMI for timer interrupts might cause problems with other functions/libraries. It would probably be better to investigate whether the long interrupt locks can't be removed or at least split up in the FS libraries.

[earlephilhower]

I think you're seeing the IRQs disabled for an erase. 8 writes = 1 4K sector on SPIFFS, and on LittleFS a sector itself is 4K so every write you need to erase and write. Erases on flash are slow (esp. on the cheapest of cheap flash found on these devices).

PWM used to be done in an NMI, but I went back to a regular IRQ when I redid it to be tickless and shared w/tone/servo/etc.

Let me do a PR for this and some testing. It shouldn't affect anything, but it's better safe than sorry.

[Gei0r]

OK, but what's the reason that (maskable) interrupts need to be disabled during a flash erase?

[earlephilhower]

That's a very good question, @Gei0r!

I don't have a good answer, but the ESP class wraps the actual SPI erase call in a disable/enable interrupt. Theoretically, it should not have to do so. flash_erase is a synchronous call, and all IRQs are supposed to be in IRAM, so I'm not seeing any reason why this is the case. If users or core has code where the IRQ code is not marked to be in IRAM, that's a plain and simple bug and should be fixed.

@igrr, @devyte, @d-a-v, any ideas?

The least intrusive change is to make PWM NMI, but the best logical change would be to remove the IRQ disabling around spi_* operations in Esp.c (but with potentially larger impact).

[igrr]

IIRC this was done because ISRs were not placed into IRAM, initially. Seems like ISRs are in IRAM now, so we can try removing those locks.

The other consideration about keeping timer at NMI level is that other interrupts (e.g. Wi-Fi) may be running for significant enough time to prevent timer ISR from running (if both are level 1 interrupts).

[earlephilhower]

Thanks, @igrr! I was thinking the same thing. I'll split this into two PRs, one removing the IRQ disabling from the ESP.flash* wrappers and another for the tickless waveform generator->NMI.

[earlephilhower]

@Gei0r, can you try PR #5578 ?

The NMI change I mentioned above in this thread is actually not safe (but may work if only one PWM is in use and it's not updated frequently). The PR is a new one with a safe-by-design configuration and should actually give you somewhat better accuracy at low periods and few active PWM pins.

[Gei0r]

Amazing work @earlephilhower !

And the example works as well:

Thanks a lot!

[Taejun-Park]

The same thing happens with the ESP32. Is there any solution?