Non-deterministic behaviour while acquiring data (Interrupts supposedly disabled))

[lmarmisa]

I wish to use the ESP32 chip for acquiring some digital samples at high rates and I detected a suspicious non-deterministic behaviour on delays in some cases. So, I wrote a simple test program trying to understand that strange behaviour.

This is the function loop():

Code: Select all

...
#define DIM_DELAYS 128
unsigned long delays[DIM_DELAYS];
unsigned long iter;

void loop() {
  unsigned long i, m, m1, d;
  boolean  s;

  esp_wifi_stop();
  noInterrupts();
  m1 = micros();
  for (i = 0UL; i< 1000000UL; i++) {
    s = digitalRead(PIN);   
    m = micros();
    d = m - m1;
    delays[d]++;
    iter++;
    m1 = m;
  }
  interrupts();
  PrintResults();
  delay(2000);
}

The function repeats a million times a loop and takes note of the delays between iterations (using micros()). Interrupts are disabled in the loop and WiFi is stopped.

The funcion PrintResult() shows the delay statistics. This is an example after some time running (percentages are shown in parts per million):

Code: Select all

delay 0: occurrences 34508900 [24561.50 ppm]
delay 1: occurrences 1365079124 [971586.63 ppm]
delay 2: occurrences 4028051 [2866.94 ppm]
delay 7: occurrences 51208 [36.45 ppm]
delay 8: occurrences 1093190 [778.07 ppm]
delay 9: occurrences 239526 [170.48 ppm]
delay 10: occurrences 1 [0.00 ppm]

97% of iterations spend between 1 and 2 microseconds. 2.46% of iterations spend less than 1 microsecond. And 0.29% of iterations spend between 2 and 3 microseconds. This sounds normal for me.

The strange behaviour belongs to the next delays. A gap is detected between 3 and 6 microseconds and then we discover some "lazy" iterations.

36 ppm needs between 7 and 8 microseconds. Then a remarkable value of 778 ppm needs between 8 and 9 microseconds. 170 ppm are associated to a delay of 9 and even a single occurrence is detected with a delay of 10 microseconds.

The sum of "lazy" iterations is almost a 0.1% of the occurrences. That's a significant percentage. I I wish to acquire data sampling at high rates and this is a serious problem for the quality of the samples. I would like to use a sampling period of 5 microseconds (maybe 10 microseconds), but this non-deterministic behaviour is a big problem for me.

I would like to know the cause of this behaviour. Is a side effect of the second core of the ESP32 blocking my loop during a few microseconds?. Is a problem related to some interrupt not disabled with cli() or noInterrupts()?. I do not know.

Do you know a way to avoid this non-deterministic behaviour?. For example, stopping the second core or disabling more interrupts?.

I would appreciate any help.

[ESP_igrr]

Looking at Arduino.h, `noInterrupts` and `interrupts` are not implemented:
https://github.com/espressif/arduino-es ... .h#L82-L85

This probably explains the issue you are seeing.

What kind of samples are you trying to collect though? ESP32 has RMT and I2S peripherals. RMT can be used to sample single-channel data at high speeds (up to 80 MHz), recording pulse lengths directly to a block of memory. I2S can sample parallel data into memory using DMA, at rates up to 20 MHz. These may be better options for data acquisition.

[lmarmisa]

Thanks a lot for your information.

Is there a work around for enabling and disabling interrupts using the Arduino IDE?. For examle, can I write my own assembler code and link it with other c modules?

These functions (cli and sei) seem essential for developing real-time firmware, but maybe they are not trivial to implement with ESP32.

Should I move to other development environment if I wish to use such functions?.

My purpose is to develop a simple logic analyzer. I need only one channel at this time, but I could consider to add more channels too. I appreciate your suggestions about RMT and I2C but I am not sure if they support some triggering capabilities. The data acquisition should start after a trigger condition is met. Non-trivial triggering capabilities are very advisable for a logic analyzer.

[ESP_igrr]

Should I move to other development environment if I wish to use such functions?.

You may use 'portENTER_CRITICAL' / 'portEXIT_CRITICAL' macros to disable interrupts on the current CPU.

Code: Select all

    static portMUX_TYPE spinlock = portMUX_INITIALIZER_UNLOCKED;

    portENTER_CRITICAL(&spinlock);
    // this code runs with interrupts disabled
    portEXIT_CRITICAL(&spinlock);

The data acquisition should start after a trigger condition is met.

From my experience most logic analyzers actually start data acquisition before trigger condition occurs, constantly writing data into a buffer. This allows one to observe system behavior short time before trigger happens, which is very useful in many cases. What you can do with I2S in parallel mode, for example, is to keep streaming data into memory using DMA, and then let your program iterate over the data, looking for trigger condition.

Software approach is also an option, probably, and is likely be easier to implement.

[lmarmisa]

static portMUX_TYPE spinlock = portMUX_INITIALIZER_UNLOCKED;

portENTER_CRITICAL(&spinlock);
// this code runs with interrupts disabled
portEXIT_CRITICAL(&spinlock);

Your solution works fine, but, if the critical code spends more than 300 msec, a wdt exception occurs:

Code: Select all

Guru Meditation Error: Core  0 panic'ed (Interrupt wdt timeout on CPU1)
Register dump:
PC      : 0x400da094  PS      : 0x00060e34  A0      : 0x800853dc  A1      : 0x3ffca8d0  
A2      : 0x00000008  A3      : 0x00000001  A4      : 0x00060023  A5      : 0x3ffcb038  
A6      : 0x00000000  A7      : 0x00000001  A8      : 0x3ffc302c  A9      : 0x3ffca8b0  
A10     : 0x00000000  A11     : 0x00060e20  A12     : 0x00000020  A13     : 0x80000020  
A14     : 0x00000003  A15     : 0x00060123  SAR     : 0x00000000  EXCCAUSE: 0x00000006  
EXCVADDR: 0x00000000  LBEG    : 0x00000000  LEND    : 0x00000000  LCOUNT  : 0x00000000  

Backtrace: 0x400da094:0x3ffca8d0 0x400853dc:0x3ffca8f0

CPU halted.

Watch dog feeding functions seem not available in the Arduino environment too.

It would be possible to increase that limit of 300 msec someway?.

Anyway the behaviour becomes deterministic when the interrupts are disabled:

Code: Select all

Interrupts disabled during 299 msec
delay 0: occurrences 852711 [12276.29 ppm]
delay 1: occurrences 68408705 [984864.75 ppm]
delay 2: occurrences 198584 [2858.97 ppm]

Thank you very sincerely for your help and suggestions.

[ESP_igrr]

Interrupt watchdog detects if interrupts are disabled for too long. 300ms is the default timeout. In Arduino IDE it isn't possible to configure this timeout, but if you compile Arduino code within ESP-IDF, then you should be able to configure this parameter using 'make menuconfig'. See "using as ESP-IDF component" section of arduino-esp32 project Readme for instructions.
Also take a look at watchdogs documentation: http://esp-idf.readthedocs.io/en/latest ... /wdts.html