Hspi in slave mode miss interrupt when WIFI is enabled

dumarjo 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.
[ ] If there is a stack dump, I have decoded it.
[x] I have filled out all fields below.

Platform

Hardware: [ESP-8266-wroom2]
Core Version: [latest git]
Development Env: [Arduino IDE]
Operating System: [Ubuntu]

Settings in IDE

Module: [Generic ESP8266 Module]
Flash Size: [2MB]
lwip Variant: [v2 Lower Memory]
Reset Method: [ck|nodemcu]
Flash Frequency: [40Mhz]
CPU Frequency: [80Mhz]
Upload Using: [SERIAL]
Upload Speed: [115200] (serial upload only)

Problem Description

Hi all,

We use 2 esp8266 (one in master and one in slave). We use only the read status command to simplify the setup. Here the Master code. We use the Example SPI Safe Master Demo and modify it to only use the readStatus method.

#include <SPI.h>

class ESPSafeMaster {
  private:
    uint8_t _ss_pin;
    void _pulseSS() {
      digitalWrite(_ss_pin, HIGH);
      delayMicroseconds(5);
      digitalWrite(_ss_pin, LOW);
    }
  public:
    ESPSafeMaster(uint8_t pin): _ss_pin(pin) {}
    void begin() {
      pinMode(_ss_pin, OUTPUT);
      _pulseSS();
    }

    uint32_t readStatus() {
      _pulseSS();
      SPI.transfer(0x04);
      uint32_t status = (SPI.transfer(0xFF) | ((uint32_t)(SPI.transfer(0xFF)) << 8) | ((uint32_t)(SPI.transfer(0xFF)) << 16) | ((uint32_t)(SPI.transfer(0xFF)) << 24));
      _pulseSS();
      return status;
    }

    void writeStatus(uint32_t status) {
      _pulseSS();
      SPI.transfer(0x01);
      SPI.transfer(status & 0xFF);
      SPI.transfer((status >> 8) & 0xFF);
      SPI.transfer((status >> 16) & 0xFF);
      SPI.transfer((status >> 24) & 0xFF);
      _pulseSS();
    }

    void readData(uint8_t * data) {
      _pulseSS();
      SPI.transfer(0x03);
      SPI.transfer(0x00);
      for (uint8_t i = 0; i < 32; i++) {
        data[i] = SPI.transfer(0);
      }
      _pulseSS();
    }

    void writeData(uint8_t * data, size_t len) {
      uint8_t i = 0;
      _pulseSS();
      SPI.transfer(0x02);
      SPI.transfer(0x00);
      while (len-- && i < 32) {
        SPI.transfer(data[i++]);
      }
      while (i++ < 32) {
        SPI.transfer(0);
      }
      _pulseSS();
    }

    String readData() {
      char data[33];
      data[32] = 0;
      readData((uint8_t *)data);
      return String(data);
    }

    void writeData(const char * data) {
      writeData((uint8_t *)data, strlen(data));
    }
};
ESPSafeMaster esp(SS);

void setup() {
  Serial.begin(115200);
  SPI.begin();
  esp.begin();
  delay(1000);
}

uint32_t status;

void loop() {
    esp.readStatus();
}

On the slave we use this code.

#include <Arduino.h>
#include <SPISlave.h>
#include <ESP8266WiFi.h>

void setup() {
    Serial.begin(921600);
    Serial.setDebugOutput(true);
    WiFi.mode(WIFI_STA);
    WiFi.begin("MySSID","MyPassword");
        SPISlave.begin();
        SPISlave.setStatus(0x55);
}

void loop() {}

//In hspi_slave.c file
void ICACHE_RAM_ATTR _hspi_slave_isr_handler(void *arg)
{
    uint32_t status;
    uint32_t istatus;
    USF(0) = 0x01; // To be able to debug it on MSO
    istatus = SPIIR;
    ....... 
}

With this configuration, the data of the status is 0x55 (checked with an MSO) and as soon as the WiFi is connected, the data of the status is 0x00 00 00 00 and the next word is 0xFF FF FF 00. No more 0x55 is returned.

From what I seen, the When the behaviour happen, the hspi or the interrupt are disabled for a short period of time and this result in a bad command received (in our case instead of 0x04 we detect 0x01) so the command write status is executed and the status is changed from 0x55 to 0xFF. Here the screen shot of the MSO that represent the problem. Remark that every rising edge of the SPI_CS, an ISR is trigged as we write 0x01 on the UART. When the problem occur, only 1 0x01 is outputed from the serial.

scope_124

From that picture you can check with the cursor the correct and the missed isr.

Is it possible that the core (Wifi) has interrupt that isr priority is higher than the hspi isr ?

To me it's look like the hspi is not responding to the 0x04 command.

any idea of what can happen ? Jonathan

devyte commented 5 years ago

I think the current maintainers aren't directly involved with SPI. To those reading this, help is appreciated here!

JiriBilek commented 5 years ago

You may be too fast with the transmission after SS going down. My experience is that you need fairly big delay before starting the transmission. See https://github.com/JiriBilek/WiFiSpi/blob/e1f86c21b3d8bcd87002a33abf903c139c2f572d/src/utility/espspi_proxy.h#L107

JiriBilek commented 5 years ago

I am posting a picture from a logic analyzer. Don't be confused that the status message is only 2 bytes long. It's on purpose. Also there is no pulsing of CS signal as I use a hardware workaround.

See the delay between CS turning down and the first CLK. Without the delay the communication was unreliable. I don't like putting a delay here as it deliberately slows down the communication but I wasn't able to find another solution.

Edit: posted a better image

dumarjo commented 5 years ago

HI,

I you do it in in a tight loop link in my code below, and you only enable the WIFI in STA mode, do you see (from your master) status that are wrong ?

JiriBilek commented 5 years ago

I didn't test your code, I only see there is no delay after selecting the slave. Maybe, the problem is interrupt related but ESP8266 SPI runs in hardware mode and interrupts your code just when all data is received (or sent - on the other side). The documentation for ESP8266 SPI is missing, we can only try some changes and see if it helps.

Please try to delay the transmission like:

    void _pulseSS() {
      digitalWrite(_ss_pin, HIGH);
      delayMicroseconds(5);
      digitalWrite(_ss_pin, LOW);
      delayMicroseconds(25);  // <------- additional delay
    }

Moreover, did you fix SPISlave timing (https://github.com/esp8266/Arduino/pull/5489)?

dumarjo commented 5 years ago

@JiriBilek We have checked with our real setup (We have a cortex-M0 at 262Khz clock speed (spi clock is at 8Khz)) and we have 200us betweeen the faling of the CS and the first clock. We see the problem too. If you take the sketch and comment the WIFI section, we never see any problem without delay. This is why we think someting is wrong in the close source section.

Since the SPI controller on the esp8266 is a really advance one, I doubt that putting a delay could fix a problem like this, I think this only reduce the probability of getting into the problem.

As for the timing, this is depend on which mode of SPI we are working. With our M0 (mode 3), the default config of the SPI slave is perfect, but for the demo application effectively the need to fix the timing (to put it in mode 0) is require. we add this line to our hspi setup to be in real mode 0

SPI1C2=(0x2 << SPIC2MISODM_S);

JiriBilek commented 5 years ago

I agree that the delay is only a workaround. But I wasn't able to find anything better. Finally, I had to secure the protocol with XOR/CRC checks and I repeat the message if the check fails. If you find a better solution, it would be great.

dumarjo commented 5 years ago

@JiriBilek

We did that too. We have checksums and 1 pin with handshake (from the ESP to the M0). Whith that, the SPI is working safer but slower.

esp8266 / Arduino