PWM is blocked during SPIFFS write operations

Gei0r commented 5 years ago

Basic Infos

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

Platform

Hardware: ESP-12
Core Version: b26c19e82e1b6c94f86a66dc2652336e8ca5bba3
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 commented 5 years ago

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

earlephilhower commented 5 years ago

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 commented 5 years ago

@devyte LittleFS shows the behavior on every write:

littlefspwm

Gei0r commented 5 years ago

@earlephilhower Your code snippet works:

nmipwm

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 commented 5 years ago

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 commented 5 years ago

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

earlephilhower commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

@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 commented 5 years ago

Amazing work @earlephilhower !

And the example works as well:

pwm

Thanks a lot!

Taejun-Park commented 3 years ago

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

esp8266 / Arduino