ESP8266_RTOS_SDK HSPI "Core 0 was running in ISR context:"

[ichenxing]

Environment

• Development Kit:
• IDF version (git rev-parse --short HEAD to get the commit id.):
  bcc4445
• Development Env: [Make]
• Operating System: [Ubuntu]
• Power Supply: [Battery]

Problem Description

esp8266作为spi slave，连接到路由之后，通过io通知master读取状态寄存器，8266出现崩溃

Expected Behavior

Actual Behavior

Steps to repropduce

Code to reproduce this issue

static const char *TAG = "user_spi";

#define SPI_SLAVE_HANDSHARK_GPIO     5
#define SPI_SLAVE_HANDSHARK_SEL      (1ULL<<SPI_SLAVE_HANDSHARK_GPIO)

static SemaphoreHandle_t spi_wr_sta_done_sem = NULL;
static SemaphoreHandle_t spi_rd_buf_done_sem = NULL;
static SemaphoreHandle_t spi_wr_buf_done_sem = NULL;

void IRAM_ATTR spi_event_callback(int event, void *arg)
{
    BaseType_t xHigherPriorityTaskWoken;
    uint32_t status;
    uint32_t trans_done;

    switch (event) {
        case SPI_INIT_EVENT: {
            status = false;
            spi_slave_set_status(HSPI_HOST, &status);
        }
        break;

        case SPI_TRANS_START_EVENT: {

        }
        break;

        case SPI_TRANS_DONE_EVENT: {
            trans_done = *(uint32_t *)arg;

            if (trans_done & SPI_SLV_RD_BUF_DONE) {
                xSemaphoreGiveFromISR(spi_rd_buf_done_sem, &xHigherPriorityTaskWoken);
            }
            if (trans_done & SPI_SLV_WR_BUF_DONE) {
                status = false;
                spi_slave_set_status(HSPI_HOST, &status);
                xSemaphoreGiveFromISR(spi_wr_buf_done_sem, &xHigherPriorityTaskWoken);
            }
            if (trans_done & SPI_SLV_RD_STA_DONE) {
                gpio_set_level(SPI_SLAVE_HANDSHARK_GPIO, 0);
                status = false;
                spi_slave_set_status(HSPI_HOST, &status);
                printf("SPI_SLV_RD_STA_DONE\n");
            }
            if (trans_done & SPI_SLV_WR_STA_DONE) {
                gpio_set_level(SPI_SLAVE_HANDSHARK_GPIO, 0);
                spi_slave_get_status(HSPI_HOST, &status);
                if (status == true) {
                    xSemaphoreGiveFromISR(spi_wr_sta_done_sem, &xHigherPriorityTaskWoken);
                }
                printf("SPI_SLV_WR_STA_DONE\n");
            }

            if (xHigherPriorityTaskWoken == pdTRUE) {
                taskYIELD();
            }
        }
        break;

        case SPI_DEINIT_EVENT: {

        }
        break;
    }

}

static void spi_slave_write_master_task(void *arg)
{
    uint16_t cmd;
    uint32_t addr;
    uint32_t write_data[8];
    spi_trans_t trans;

    trans.cmd = &cmd;
    trans.addr = &addr;
    trans.miso = write_data;
    trans.bits.val = 0;
    // In Slave mode, spi cmd must be longer than 3 bits and shorter than 16 bits
    trans.bits.cmd = 8 * 1;
    // In Slave mode, spi addr must be longer than 1 bits and shorter than 32 bits
    trans.bits.addr = 32 * 1;
    trans.bits.mosi = 0;
    trans.bits.miso = 32 * 8;

    write_data[0] = 0xAAAAAAAA;
    write_data[1] = 0xBBBBBBBB;
    write_data[2] = 0xCCCCCCCC;
    write_data[3] = 0xDDDDDDDD;
    write_data[4] = 0xEEEEEEEE;
    write_data[5] = 0xFFFFFFFF;
    write_data[6] = 0xAAAABBBB;
    write_data[7] = 0;

    // Waiting for master idle
    xSemaphoreTake(spi_wr_sta_done_sem, portMAX_DELAY);

    while (1) {
        gpio_set_level(SPI_SLAVE_HANDSHARK_GPIO, 0);

        if (write_data[7] % 50 == 0) {
            vTaskDelay(1000 / portTICK_RATE_MS);
        }
        
        // load new data
        spi_trans(HSPI_HOST, trans);
        write_data[7]++;
        // The rising edge informs the master to get the data
        gpio_set_level(SPI_SLAVE_HANDSHARK_GPIO, 1);
        xSemaphoreTake(spi_rd_buf_done_sem, portMAX_DELAY);
        vTaskDelay(10 / portTICK_RATE_MS);
    }
}

static void spi_slave_read_master_task(void *arg)
{
    int x;
    uint16_t cmd;
    uint32_t addr;
    uint32_t read_data[8];
    spi_trans_t trans;
    uint32_t status = true;

    trans.cmd = &cmd;
    trans.addr = &addr;
    trans.mosi = read_data;
    trans.bits.val = 0;
    // In Slave mode, spi cmd must be longer than 3 bits and shorter than 16 bits
    trans.bits.cmd = 8 * 1;
    // In Slave mode, spi addr must be longer than 1 bits and shorter than 32 bits
    trans.bits.addr = 8 * 1;
    trans.bits.mosi = 32 * 8;

    xEventGroupWaitBits(wifi_event_group, connected_rt_bit, false, true, portMAX_DELAY);
    ESP_LOGI(TAG, "Connected to AP");

    status = STA_REG_ROUNTER_CONNECT;
    spi_slave_set_status(HSPI_HOST, &status);
    gpio_set_level(SPI_SLAVE_HANDSHARK_GPIO, 1);
    printf("inform spi master\n");

    while (1) {
        // spi_slave_set_status(HSPI_HOST, &status);
        xSemaphoreTake(spi_wr_buf_done_sem, portMAX_DELAY);

        spi_trans(HSPI_HOST, trans);

        if (cmd == SPI_MASTER_WRITE_DATA_TO_SLAVE_CMD) {
            ESP_LOGI(TAG, "------Slave read------\n");
            ESP_LOGI(TAG, "addr: 0x%x\n", addr);

            for (x = 0; x < 8; x++) {
                ESP_LOGI(TAG, "read_data[%d]: 0x%x\n", x, read_data[x]);
            }
        }
    }
}

void spi_slave_init(void)
{
    spi_wr_sta_done_sem = xSemaphoreCreateBinary();
    spi_rd_buf_done_sem = xSemaphoreCreateBinary();
    spi_wr_buf_done_sem = xSemaphoreCreateBinary();

    ESP_LOGI(TAG, "init gpio");
    gpio_config_t io_conf;
    io_conf.intr_type = GPIO_INTR_DISABLE;
    io_conf.mode = GPIO_MODE_OUTPUT;
    io_conf.pin_bit_mask = SPI_SLAVE_HANDSHARK_SEL;
    io_conf.pull_down_en = 0;
    io_conf.pull_up_en = 0;
    gpio_config(&io_conf);
    gpio_set_level(SPI_SLAVE_HANDSHARK_GPIO, 0);

    ESP_LOGI(TAG, "init spi");

    spi_config_t spi_config;
    // Load default interface parameters
    // CS_EN:1, MISO_EN:1, MOSI_EN:1, BYTE_TX_ORDER:1, BYTE_TX_ORDER:1, BIT_RX_ORDER:0, BIT_TX_ORDER:0, CPHA:0, CPOL:0
    spi_config.interface.val = SPI_DEFAULT_INTERFACE;
    // Load default interrupt enable
    // TRANS_DONE: false, WRITE_STATUS: true, READ_STATUS: true, WRITE_BUFFER: true, READ_BUFFER: ture
    spi_config.intr_enable.val = SPI_SLAVE_DEFAULT_INTR_ENABLE;
    // Set SPI to slave mode
    spi_config.mode = SPI_SLAVE_MODE;
    // Set the SPI clock frequency division factor
    spi_config.clk_div = SPI_8MHz_DIV;
    // Register SPI event callback function
    spi_config.event_cb = spi_event_callback;
    spi_init(HSPI_HOST, &spi_config);

    // create spi_slave_write_master_task
    //xTaskCreate(spi_slave_write_master_task, "spi_slave_write_master_task", 2048, NULL, 10, NULL);

    // create spi_slave_read_master_task
    xTaskCreate(spi_slave_read_master_task, "spi_slave_read_master_task", 2048, NULL, 10, NULL);
}

Debug Logs

I (475) main task: 1: hello world, stack: 1960.
mqtt client thread starts
I (2475) main task: 2: hello world, stack: 1316.
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 18
pm open phy_2,type:2 0 0
cnt

connected with SpeechX_2.4G, channel 11
I (3915) event: sta ip: 192.168.1.136, mask: 255.255.255.0, gw: 192.168.1.1
I (3915) main task: connect rounter.
I (3915) user_spi: Connected to AP
inform spi master
I (4475) main task: 3: hello world, stack: 1316.
I (6475) main task: 4: hello world, stack: 1316.


Core 0 was running in ISR context:

          00000000 00000004 00000008 0000000c 00000010 00000014 00000018 0000001c 00000020 00000024 00000028 0000002c 00000030 00000034 00000038 0000003c

3ffe82e0  00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffffffff 40224e94 40224e7c 00000001 40247bf8 00000000 00000000 00000000 4023c294
3ffe8320  00000000 00000000 00000000 00000000 00000000 00000000 00000000 0000ff00 00ff0000 ff000000 00000000 00000000 00000004 3ffedf50 3fff19bc 40247894
3ffe8360  00000000 00000000 00000000 40247aca 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffffffff 40224e94 40224e7c 00000001 40247bf8
3ffe83a0  00000000 00000000 00000000 4023c294 00000000 00000000 00000000 00000000 00000000 00000000 00000000 0000ff00 00ff0000 ff000000 00000000 00000000
3ffe83e0  00000004 3ffef83c 3fff1abc 40247894 00000000 00000000 00000000 40247aca 00000000 00000000 00000000 4023bfc6 40246e39 00000000 00000000 00000001
3ffe8420  00000004 3ffee7ac 3ffef7e4 40247bf8 00000004 00000000 3ffef8b4 40246849 40225d58 00000013 4022256e 00000001 3ffe8440 00000002 00000014 4023a713
3ffe8460  3ffe8498 00000004 40225d58 402468b0 3ffe9532 00000004 00000014 40100559 00000400 00000000 3ffe84ec 40102cb9 00000005 00000000 3ffef144 40100612
3ffe84a0  00000014 00000001 08000000 4023bbfc 4023bd1e 40229fa8 3ffef184 4023bd31 3fff07a0 00000001 402222ac 00000000 00000000 00000000 40105304 4010534d
      PC: 0x4023c282       PS: 0x00000031       A0: 0x3ff7ffe0       A1: 0x3ff7ffe0
      A2: 0x00000001       A3: 0x40224e94       A4: 0x40224e7c       A5: 0x0000ff00
      A6: 0x00ff0000       A7: 0xff000000       A8: 0x00454e4f       A9: 0x22800000
     A10: 0x20000000      A11: 0xcfffffff      A12: 0x3fff19bc      A13: 0x3ffedf50
     A14: 0x00000004      A15: 0xffffffff      SAR: 0x0000001b EXCCAUSE: 0x00000003

Other items if possible

[xiongyumail]

事件回调函数会在spi中断中调用，请不要使用printf,或许你可以使用ets_printf
需要包含#include"esp_libc.h"

[ichenxing]

@xiongyumail 的确中断中不能使用printf；不过spi传输数据不对，第一帧数据出现问题,，如下：

0x00020000 0x00060004 0x000A0008 0x000E000C 0x00120010 0x00160014 0x001A0018 0x001E001C 
0x11001000 0x13001200 0x15001400 0x17001600 0x19001800 0x1B001A00 0x1D001C00 0x1F001E00 
0x21002000 0x23002200 0x25002400 0x27002600 0x29002800 0x2B002A00 0x2D002C00 0x2F002E00

spi master code:

	u16 i=0,temp[16];

	for(i=0;i<16;i++)
	{
		temp[i] = i;
	}
	HSPI_Write_Pages(temp, 16);

	for(i=16;i<32;i++)
	{
		temp[i-16] = i;
	}
	HSPI_Write_Pages(temp, 16);

	for(i=32;i<48;i++)
	{
		temp[i-32] = i;
	}
	HSPI_Write_Pages(temp, 16);

sdk给的例程中的通信也有点看不懂，如下：

static void spi_master_write_slave_task(void *arg)
{
    uint16_t cmd;
    uint32_t addr;
    uint32_t write_data[8];
    spi_trans_t trans;
    uint32_t status;

    trans.cmd = &cmd;
    trans.addr = &addr;
    addr = 0x0;
    write_data[0] = 0;
    write_data[1] = 0x11111111;
    write_data[2] = 0x22222222;
    write_data[3] = 0x33333333;
    write_data[4] = 0x44444444;
    write_data[5] = 0x55555555;
    write_data[6] = 0x66666666;
    write_data[7] = 0x77777777;

    while (1) {
        if (addr % 50 == 0) {
            vTaskDelay(1000 / portTICK_RATE_MS);
        }

        trans.miso = &status;
        trans.bits.val = 0;
        trans.bits.cmd = 8 * 1;
        trans.bits.miso = 32 * 1;
        // Read status from the ESP8266 Slave use "SPI_MASTER_READ_STATUS_FROM_SLAVE_CMD" cmd
        cmd = SPI_MASTER_READ_STATUS_FROM_SLAVE_CMD;
        // Get the slave status and send data when the slave is idle
        while (1) {
            spi_trans(HSPI_HOST, trans);
            if (status == true) {
                break;
            }
            vTaskDelay(10 / portTICK_RATE_MS);
        }

        trans.mosi = write_data;
        trans.bits.val = 0;
        trans.bits.cmd = 8 * 1;
        trans.bits.addr = 32 * 1;
        trans.bits.mosi = 32 * 8;
        // Write data to the ESP8266 Slave use "SPI_MASTER_WRITE_DATA_TO_SLAVE_CMD" cmd
        cmd = SPI_MASTER_WRITE_DATA_TO_SLAVE_CMD;
        spi_trans(HSPI_HOST, trans);

        addr++;
        write_data[0]++;
        vTaskDelay(10 / portTICK_RATE_MS);
    }
}

[xiongyumail]

读写8266 slave 需要有cmd, addr
例程中通过status和io4进行流控

[ichenxing]

@xiongyumail 例程中主机读完状态寄存器后一共发送了1+4+32=37个字节，波形图中一共出现了41个字节，且write_data[0]的值并不等于0；我用的是教程后面的spi单线透传协议。

[xiongyumail]

嗯嗯，发现了，请以例程为准，波形图将会更新。谢谢!

[ichenxing]

@xiongyumail 波形图只是硬件在执行程序时的实际体现；

主机实际发送的数据应该是：

0x01000000 0x03000200 0x05000400 0x07000600 0x09000800 0x0B000A00 0x0D000C00 0x0F000E00
0x11001000 0x13001200 0x15001400 0x17001600 0x19001800 0x1B001A00 0x1D001C00 0x1F001E00 
0x21002000 0x23002200 0x25002400 0x27002600 0x29002800 0x2B002A00 0x2D002C00 0x2F002E00

esp8266接收的数据确是如下，且接收到的第一帧数据比较有意思，都是偶数：

0x00020000 0x00060004 0x000A0008 0x000E000C 0x00120010 0x00160014 0x001A0018 0x001E001C 
0x11001000 0x13001200 0x15001400 0x17001600 0x19001800 0x1B001A00 0x1D001C00 0x1F001E00 
0x21002000 0x23002200 0x25002400 0x27002600 0x29002800 0x2B002A00 0x2D002C00 0x2F002E00

程序参考：

[xiongyumail]

看上去是右移了7bit, example第一帧也有这种现象嘛？

[ichenxing]

@xiongyumail 例程没有测试，没有两块esp8266进行spi通信，不过有点看不懂例程（主机读取从机数据）的波形图如下，为什么会在03后出现8个字节 00 00 00 56 00 00 00 AB，且这些字节所对应的值都为FF？

我自己的程序主机读取esp8266状态寄存器时，读出来的值一直为0xFF？

[xiongyumail]

example中的波形图有问题，请以程序为准。
esp8266 spi只能半双工通讯，因此在发送或者接收时，有一方全为0xFF或0x00

[ichenxing]

@xiongyumail手上缺少逻辑分析仪，没办法从波形图上发现问题，

[ichenxing]

@xiongyumail 下面是主机发送从机(ESP8266)接收的波形图，一共发送了4帧数据，第一帧和第二帧发送的数据是一样的，但是8266接收到的数据确是不一样的：
esp8266接收到的数据：

采集到的波形图：

编号1：

编号2：

编号3：

编号4：

[xiongyumail]

    trans.cmd = &cmd;
    trans.addr = &addr;
    trans.mosi = read_data;
    trans.bits.val = 0;
    // In Slave mode, spi cmd must be longer than 3 bits and shorter than 16 bits
    trans.bits.cmd = 8 * 1;
    // In Slave mode, spi addr must be longer than 1 bits and shorter than 32 bits
    trans.bits.addr = 32 * 1;
    trans.bits.mosi = 32 * 8;

    spi_trans(HSPI_HOST, trans); // init spi slave buf
    while (1) {

在Slave 接收task while前加个spi_trans试试?

[ichenxing]

@xiongyumail 下面是主机读从机(ESP8266)状态寄存器的波形图，读出来的值都是0xFF，如下：
波形图：

esp8266打印的结果显示进入了2次读状态寄存器，实际程序只读了一次，波形图上也只反应进入一次读状态寄存器：

代码如下：

static void spi_slave_read_master_task(void *arg)
{
    int x;
    uint16_t cmd;
    uint32_t addr;
    uint32_t read_data[8];
    spi_trans_t trans;
    uint32_t status = true;

    trans.cmd = &cmd;
    trans.addr = &addr;
    trans.mosi = read_data;
    trans.bits.val = 0;
    // In Slave mode, spi cmd must be longer than 3 bits and shorter than 16 bits
    trans.bits.cmd = 8 * 1;
    // In Slave mode, spi addr must be longer than 1 bits and shorter than 32 bits
    trans.bits.addr = 8 * 1;
    trans.bits.mosi = 32 * 8;

    xEventGroupWaitBits(wifi_event_group, connected_rt_bit, false, true, portMAX_DELAY);
    ESP_LOGI(TAG, "Connected to AP");

    status = STA_REG_ROUNTER_CONNECT << 24 | STA_REG_ROUNTER_CONNECT << 16 | STA_REG_ROUNTER_CONNECT << 8 | STA_REG_ROUNTER_CONNECT;
    spi_slave_set_status(HSPI_HOST, &status);
    gpio_set_level(SPI_SLAVE_HANDSHARK_GPIO, 1);
    printf("inform spi master: 0x%08X\n", status);

    while (1) {
        xSemaphoreTake(spi_wr_buf_done_sem, portMAX_DELAY);

        spi_trans(HSPI_HOST, trans);

        if (cmd == SPI_MASTER_WRITE_DATA_TO_SLAVE_CMD) {

            for (x = 0; x < 8; x++) {
                printf("0x%08X ", read_data[x]);
            }
            printf("\r\n");
        }

        gpio_set_level(SPI_SLAVE_HANDSHARK_GPIO, 0);
    }
}

[ichenxing]

@xiongyumail 在Slave 接收task while前加个spi_trans试试?好像是可以了：