Exceptions with experimental::SPI0Command

[mhightower83]

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.
• [x] I have filled out all fields below.

Platform

• Hardware: ESP-12
• Core Version: [685f2c97ff4b3c76b437a43be86d1dfdf6cb33e3]
• Development Env: Arduino IDE
• Operating System: Ubuntu

Settings in IDE

• Module: NodeMCU 1.0
• Flash Mode: dio
• Flash Size: 4MB
• lwip Variant: v2 Higher Bandwidth
• Reset Method: nodemcu
• Flash Frequency: 40Mhz
• CPU Frequency: 80Mhz
• Upload Using: SERIAL
• Upload Speed: 921600 (serial upload only)

Problem Description

experimental::SPI0Command causes an Exception on return to ICACHE address space. The issue was seen with flash non-volatile write operations like Write Status Register, Erase Sector, etc.

In _SPICommand, Adding a call to Wait_SPI_Idlep before restoring interrupts resolves the problem. I'll follow up with a PR.

  PRECACHE_END();
  if (!spiIfNum) {
      // w/o a call to Wait_SPI_Idlep, 'Exception 0' or other exceptions (saw
      // 28) may occur later after returning to iCache code. This issue was
      // observed with non-volatile status register writes.
      //
      // My guess: Returning too soon to uncached iCache executable space. An
      // iCache read may not complete properly because the Flash or SPI
      // interface is still busy with the last write operation. In such a case,
      // I expect new ICACHE "code or literals" Reads result in zeros. This
      // would explain an Exception 0 for code, and Exception 20, 28, and 29
      // where a literal was misread as 0 and then used as a pointer.
      Wait_SPI_Idlep((SpiFlashChip *)fchip);
      xt_wsr_ps(saved_ps);
  }
  return (timeout>0 ? SPI_RESULT_OK : SPI_RESULT_TIMEOUT);
}

MCVE Sketch

#include <spi_flash_defs.h>
#include <spi_vendors.h>
#include <flash_hal.h>
#include <spi_utils.h>
using namespace::experimental;

// 

#define ETS_PRINTF ets_uart_printf

constexpr uint8_t kSpiFlashCmd_WriteDisable       = 0x04u;
constexpr uint8_t kSpiFlashCmd_WriteEnable        = 0x06u;
constexpr uint8_t kSpiFlashCmd_EraseSector        = 0x20u;

uint32_t flashAddr;

void setup() {
  Serial.begin(115200);
  delay(100);

  // Use the last sector of the OTA space for our flash tests.
  uint32_t iromAddr  = FS_start - 4096u;
  flashAddr = iromAddr - 0x40200000u;

  Serial.printf("\r\n\r\n\r\nDemo, exception crash via 'SPI0Command()'\r\n");
  Serial.printf("Test Flash Address: 0x%08X\r\n", flashAddr);
  hotKeyHandler('?');
}

void testEraseSector() {
  union {
    uint32_t u32[16];
    uint8_t  u8[16*4];
  } spiBuf;
  memset(spiBuf.u32, 0, sizeof(spiBuf));

  spiBuf.u8[0] = flashAddr >> 16u;
  spiBuf.u8[1] = (flashAddr >> 8u) & 0xFFu;
  spiBuf.u8[2] = flashAddr & 0xFFu;

  const char *cmd_msg;
  const char *result_msg;

  do {
    result_msg = "Failed!";

    cmd_msg = "WriteEnable 1:";
    if (SPI0Command(kSpiFlashCmd_WriteEnable, NULL, 0, 0)) continue;

    cmd_msg = "SectorErase:";
    if (SPI0Command(kSpiFlashCmd_EraseSector, spiBuf.u32, 24, 0)) continue;

    result_msg = "success";
  } while (false);

  ETS_PRINTF("  %s %s\n", cmd_msg, result_msg);

  SPI0Command(kSpiFlashCmd_WriteDisable, NULL, 0, 0);
}

void hotKeyHandler(char hotKey) {
  switch (hotKey) {
    case 'e':
      Serial.println(F("Test erase sector, via 'SPI0Command()'"));
      testEraseSector();
      break;

    case '\n':
    case '\r':
      break;

    default:
    case '?':
      Serial.println(F("  e - Test erase Flash, via 'SPI0Command()'"));
      Serial.println(F("  ? - This help message\r\n"));
      break;
  }
}

void loop() {
  if (0 < Serial.available()) {
    char hotKey = Serial.read();
    hotKeyHandler(hotKey);
  }
}

Debug Messages

Demo, exception crash via 'SPI0Command()'
Test Flash Address: 0x001FF000
  e - Test erase Flash, via 'SPI0Command()'
  ? - This help message

Test erase sector, via 'SPI0Command()'

To make this dump useful, DECODE IT - https://tinyurl.com/8266dcdr
--------------- CUT HERE FOR EXCEPTION DECODER ---------------

Exception (0):
epc1=0x40201082 epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000000 depc=0x00000000

>>>stack>>>

ctx: cont
sp: 3ffffdf0 end: 3fffffc0 offset: 0150
3fffff40:  0000f01f 00000000 00000000 00000000  
3fffff50:  00000000 00000000 00000000 00000000  
3fffff60:  00000000 00000000 00000000 00000000  
3fffff70:  00000000 00000000 00000000 00000000  
3fffff80:  00000065 00000000 3fffdab0 402010e9  
3fffff90:  3fffdad0 00000000 3fffdab0 4020118d  
3fffffa0:  feefeffe 00000000 3fffdab0 40201e6e  
3fffffb0:  feefeffe feefeffe feefeffe 40100d7d  
<<<stack<<<

To make this dump useful, DECODE IT - https://tinyurl.com/8266dcdr
--------------- CUT HERE FOR EXCEPTION DECODER ---------------

 ets Jan  8 2013,rst cause:2, boot mode:(3,6)



  4020103c <_Z15testEraseSectorv>:
  4020103c:       b0c112                  addi    a1, a1, -80
  4020103f:       136102                  s32i    a0, a1, 76
  ...
  40201062:       050c                    movi.n  a5, 0
  40201064:       054d                    mov.n   a4, a5
  40201066:       053d                    mov.n   a3, a5
  40201068:       620c                    movi.n  a2, 6
  4020106a:       016e05                  call0   4020274c <SPI0Command>
  4020106d:       42dc                    bnez.n  a2, 40201085 <_Z15testEraseSectorv+0x49>
  4020106f:       050c                    movi.n  a5, 0
  40201071:       841c                    movi.n  a4, 24
  40201073:       013d                    mov.n   a3, a1
  40201075:       022c                    movi.n  a2, 32
  40201077:       016d45                  call0   4020274c <SPI0Command>
  4020107a:       32dc                    bnez.n  a2, 40201091 <_Z15testEraseSectorv+0x55>
  4020107c:       ffeb41                  l32r    a4, 40201028 <core_version+0x10>
  4020107f:       ffe931                  l32r    a3, 40201024 <core_version+0xc>
> 40201082:       000446                  j       40201097 <_Z15testEraseSectorv+0x5b>
  40201085:       ffe541                  l32r    a4, 4020101c <core_version+0x4>
  40201088:       ffe631                  l32r    a3, 40201020 <core_version+0x8>
  4020108b:       000206                  j       40201097 <_Z15testEraseSectorv+0x5b>
  4020108e:       000000                  ill
  40201091:       ffe241                  l32r    a4, 4020101c <core_version+0x4>
  40201094:       ffe431                  l32r    a3, 40201024 <core_version+0xc>
  40201097:       ffe621                  l32r    a2, 40201030 <core_version+0x18>
  4020109a:       ffe701                  l32r    a0, 40201038 <core_version+0x20>
  4020109d:       0000c0                  callx0  a0



  Exception 0: Illegal instruction
  PC: 0x40201082: testEraseSector() at /home/mhightow/Arduino/Debug/Exception0_spi_utils_v3/Exception0_spi_utils_v3.ino line 51
  EXCVADDR: 0x00000000

  Decoding stack results
  0x402010e9: hotKeyHandler(char) at /home/mhightow/Arduino/Debug/Exception0_spi_utils_v3/Exception0_spi_utils_v3.ino line 66
  0x4020118d: loop() at /home/mhightow/Arduino/Debug/Exception0_spi_utils_v3/Exception0_spi_utils_v3.ino line 83
  0x40201e6e: loop_wrapper() at /home/mhightow/Arduino/hardware/esp8266com/esp8266/cores/esp8266/core_esp8266_main.cpp line 263