espressif / arduino-esp32

Arduino core for the ESP32
GNU Lesser General Public License v2.1
13.27k stars 7.35k forks source link

Wire i2cread returned error 263 with periodic polling #8056

Open dizcza opened 1 year ago

dizcza commented 1 year ago

Board

Frogboard

Device Description

A regular Frogboard.

Hardware Configuration

SDA: 21 SCL: 22

Version

v2.0.4

IDE Name

Arduino IDE

Operating System

Ubuntu 22.04

Flash frequency

Default

PSRAM enabled

no

Upload speed

921600

Description

Polling an I2C sensor (Sensirion SDP810-125) at 1000 Hz

Could be related to https://github.com/espressif/arduino-esp32/issues/7209 --> It's not a library- or sensor-specific issue.

I mean, it's the Wire issue - one of the most used components of ESP32 arduino.


I have no problems whatsoever running a corresponding code with ESP-IDF v5.1 & master branch with the same I2C clock speed and timer interrupt (it works even at higher sampling rates: up to 1900 Hz, the sensor limit).

Sketch

Install https://github.com/UT2UH/SDP3x-Arduino.

#include "SDPSampler.h"

SDP8XX sensor = SDP8XX(Address5);
SDPSampler *sampler;

void setup() {
  Serial.begin(115200);
  Wire.begin(21, 22, (uint32_t) 400000);
  sampler = new SDPSampler(sensor);
  assert(sampler->begin());
  Serial.println("started");
}

void loop() {

}

SDPSampler.cpp:

#include <math.h>
#include <unistd.h>
#include <stdio.h>
#include <stdint.h>
#include <string.h>
#include <time.h>
#include <sys/time.h>

#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "freertos/queue.h"
#include "esp_log.h"
#include "esp_timer.h"
#include "esp_task_wdt.h"
#include "esp_ota_ops.h"

#include "SDPSampler.h"

#define RECORD_READ_SENSOR_PRIORITY  (configMAX_PRIORITIES - 1)

static void sdprecord_read_sensor_task(void*);

static TaskHandle_t m_task_read_handle = NULL;
static const char *TAG = "sdprecord";

void ARDUINO_ISR_ATTR onTimer()
{
    static uint32_t timer_counter = 0;
    xTaskNotifyFromISR(m_task_read_handle, timer_counter++, eSetValueWithOverwrite, NULL);
}

static void sdprecord_read_sensor_task(void* args) {
    SDPSampler* sdp_sampler = (SDPSampler*) args;
    int64_t rtc_counter = 0;

    esp_task_wdt_add(NULL);
    sdp_sampler->startTimer();

    // Skip the first sample.
    // The first sample period is less than expected.
    ulTaskNotifyTake(pdTRUE, portMAX_DELAY);

    while (1) {
        esp_task_wdt_reset();
        ulTaskNotifyTake(pdTRUE, portMAX_DELAY);
        sdp_sampler->readSensor();
    }
}

bool SDPSampler::ready() {
    return uxQueueMessagesWaiting(xQueueRecords) >= SPECTROGRAM_WINDOW_SIZE;
}

const int16_t* SDPSampler::getCapturedAudioBuffer() {
    if (!ready()) {
        return NULL;
    }
    for (int i = 0; i < SPECTROGRAM_WINDOW_SIZE; i++) {
        xQueueReceive(xQueueRecords, &raw_buffer[i], portMAX_DELAY);
    }
    return raw_buffer;
}

bool SDPSampler::readSensor() {
    int16_t dp_raw = 0;
    if (m_sensor.readMeasurement(&dp_raw, NULL, NULL)) {
        xQueueSend(xQueueRecords, &dp_raw, 0);
        return true;
    }
    return false;
}

/**
 * Better to call this function from the core
 * on which the sampler is running.
*/
void SDPSampler::startTimer()
{
    m_timer = timerBegin(0, 80, true);
    timerAttachInterrupt(m_timer, &onTimer, true);

    // Set alarm to call onTimer function every second (value in microseconds).
    // Repeat the alarm (third parameter)
    timerAlarmWrite(m_timer, 1000, true);

    // Start an alarm
    timerAlarmEnable(m_timer);
}

bool SDPSampler::begin() {
    // Always stop SDP before running again
    if (!m_sensor.stopContinuous()) {
        log_e("SDPSensor::stopContinuous failed");
    }
    delay(20);
    if (!m_sensor.startContinuous(false)) {
        log_e("SDPSensor::startContinuous failed");
        return false;
    }
    delay(20);
    xTaskCreatePinnedToCore(sdprecord_read_sensor_task, "sdp_read", 4096, this, RECORD_READ_SENSOR_PRIORITY, &m_task_read_handle, APP_CPU_NUM);
    return true;
}

void SDPSampler::stop() {
    m_sensor.stopContinuous();
    if (m_timer) {
        timerStop(m_timer);
        m_timer = NULL;
    }
    if (m_task_read_handle) {
        esp_task_wdt_delete(m_task_read_handle);
        vTaskDelete(m_task_read_handle);
        m_task_read_handle = NULL;
    }
}

SDPSampler::SDPSampler(SDPSensor& sensor) : m_sensor(sensor)
{
    m_sensor.begin();
    xQueueRecords = xQueueCreate(5000, sizeof(int16_t));
    assert(xQueueRecords != NULL);
}

SDPSampler.h:

#pragma once

#include <Arduino.h>
#include "SDPSensors.h"

#define SPECTROGRAM_WINDOW_SIZE 256

class SDPSampler {
    private:
        SDPSensor& m_sensor;
        hw_timer_t* m_timer;
        QueueHandle_t xQueueRecords;
        int16_t raw_buffer[SPECTROGRAM_WINDOW_SIZE];

    public:
        SDPSampler(SDPSensor& sensor);
        bool begin();
        void stop();
        void startTimer();
        bool readSensor();
        const int16_t* getCapturedAudioBuffer();
        bool ready();
};

Debug Message

[ 12174][E][Wire.cpp:392] requestFrom(): i2cRead returned Error 263
[ 13178][E][Wire.cpp:392] requestFrom(): i2cRead returned Error 263

Expected: no errors.

Other Steps to Reproduce

No response

I have checked existing issues, online documentation and the Troubleshooting Guide

me-no-dev commented 1 year ago

can you try installing the core from git and specifically using the esp-idf-v5.1-libs branch? It's running IDF 5.1 and it's I2C driver. Since 2.0.4 we are using the IDF driver directly, before we had our own, but that is hard to support across all chips

dizcza commented 1 year ago

How to install a custom version of esp32 arduino on Linux?

I've cloned the repo to ~/Arduino/hardware/arduino-esp32 but nothing appears in the Boards menu.

me-no-dev commented 1 year ago
mkdir -p ~/Arduino/hardware/espressif
git clone https://github.com/espressif/arduino-esp32 -b esp-idf-v5.1-libs ~/Arduino/hardware/espressif/esp32
cd ~/Arduino/hardware/espressif/esp32/tools
python3 get.py
dizcza commented 1 year ago

Thanks for the snipped, it worked out.

But I'm getting other errors:


/home/dizcza/Arduino/Projects/SDPSampler/SDPSampler.cpp: In member function 'void SDPSampler::startTimer()':
SDPSampler.cpp:90:25: error: too many arguments to function 'hw_timer_t* timerBegin(uint32_t)'
   90 |     m_timer = timerBegin(0, 80, true);
      |               ~~~~~~~~~~^~~~~~~~~~~~~
In file included from /home/dizcza/Arduino/hardware/espressif/esp32/cores/esp32/esp32-hal.h:84,
                 from /home/dizcza/Arduino/hardware/espressif/esp32/cores/esp32/Arduino.h:36,
                 from /home/dizcza/Arduino/Projects/SDPSampler/SDPSampler.h:3,
                 from /home/dizcza/Arduino/Projects/SDPSampler/SDPSampler.cpp:17:
/home/dizcza/Arduino/hardware/espressif/esp32/cores/esp32/esp32-hal-timer.h:32:14: note: declared here
   32 | hw_timer_t * timerBegin(uint32_t frequency);
      |              ^~~~~~~~~~
SDPSampler.cpp:91:25: error: too many arguments to function 'void timerAttachInterrupt(hw_timer_t*, void (*)())'
   91 |     timerAttachInterrupt(m_timer, &onTimer, true);
      |     ~~~~~~~~~~~~~~~~~~~~^~~~~~~~~~~~~~~~~~~~~~~~~
/home/dizcza/Arduino/hardware/espressif/esp32/cores/esp32/esp32-hal-timer.h:47:6: note: declared here
   47 | void timerAttachInterrupt(hw_timer_t * timer, void (*userFunc)(void));
      |      ^~~~~~~~~~~~~~~~~~~~
SDPSampler.cpp:95:5: error: 'timerAlarmWrite' was not declared in this scope; did you mean 'timerWrite'?
   95 |     timerAlarmWrite(m_timer, 1000, true);
      |     ^~~~~~~~~~~~~~~
      |     timerWrite
SDPSampler.cpp:98:5: error: 'timerAlarmEnable' was not declared in this scope; did you mean 'timerAlarm'?
   98 |     timerAlarmEnable(m_timer);
      |     ^~~~~~~~~~~~~~~~
      |     timerAlarm
exit status 1
too many arguments to function 'hw_timer_t* timerBegin(uint32_t)'
mrengineer7777 commented 1 year ago

@dizcza See #7906

dizcza commented 1 year ago

So if I set 1000 Hz freq, what alarm_value should be in

void timerAlarm(hw_timer_t * timer, uint64_t alarm_value, bool autoreload, uint64_t reload_count);

?

dizcza commented 1 year ago
void SDPSampler::startTimer()
{
    m_timer = timerBegin(1000);
    timerAttachInterrupt(m_timer, &onTimer);

    timerAlarm(m_timer, ???, true, 0);

    // Start an alarm
    timerStart(m_timer);
}
me-no-dev commented 1 year ago

Should be timerBegin(1000000) and timerAlarm, m_timer, 1000, true, 0), which means: run timer with 1MHz clock and alarm every 1000 ticks (and that equals 1ms or 1000Hz). Do not execute Wire commands in the callback though, just set a flag and do it from the loop or another task.

dizcza commented 1 year ago

Something fishy is going on:

E (101) gptimer: gptimer_disable(308): timer not in enable state
E (101) gptimer: gptimer_register_event_callbacks(235): timer not in init state
[   118][E][esp32-hal-timer.c:153] timerAttachInterruptFunctionalArg(): Timer Attach Interrupt failed, error num=259
E (113) gptimer: gptimer_enable(288): timer not in init state
E (118) gptimer: gptimer_start(337): timer is not enabled yet

I know about gptimer_init -> _enable -> _start -> _stop -> disable -> _delete GPTimer lifecycle in ESP-IDF. But I don't see the corresponding functions in Arduino timer API (link).

Do not execute Wire commands in the callback though, just set a flag and do it from the loop or another task.

Of course, that's what I'm doing in the code.

me-no-dev commented 1 year ago

@dizcza you can check this updated example for use: https://github.com/espressif/arduino-esp32/blob/esp-idf-v5.1-libs/libraries/ESP32/examples/Timer/RepeatTimer/RepeatTimer.ino

dizcza commented 1 year ago

Well, the RepeatTimer example has the very same behavior:

E (120) gptimer: gptimer_disable(308): timer not in enable state
E (120) gptimer: gptimer_register_event_callbacks(235): timer not in init state
[   124][E][esp32-hal-timer.c:153] timerAttachInterruptFunctionalArg(): Timer Attach Interrupt failed, error num=259
E (132) gptimer: gptimer_enable(288): timer not in init state
E (137) gptimer: gptimer_start(337): timer is not enabled yet

Note that you need to add a small delay, say 100 ms, after Serial.begin() in order to see these messages.

And the timer callback, of course, is never executed.

dizcza commented 1 year ago

Looks like I'm reaping arduino bugs today!

nick-mitigo commented 1 year ago

Hi,

I have the same sporadic error with Adafruit_MCP23X17 lib, doing constant mcp.digitalRead(i). https://github.com/adafruit/Adafruit-MCP23017-Arduino-Library/blob/master/src/Adafruit_MCP23XXX.cpp Can this be related?

ppescher commented 1 year ago

Hi, I found myself in a similar situation. The problem in my case is that the I2C timeout is fixed to 1 second, the value set by Wire.setTimeout() is overridden. And since the library I am using is doing several attempts, that sums up to many seconds, way too long for my application.

Hint in the source code is here:

#define I2C_CMD_ALIVE_INTERVAL_TICK    (1000 / portTICK_PERIOD_MS)

esp_err_t i2c_master_cmd_begin(i2c_port_t i2c_num, i2c_cmd_handle_t cmd_handle, TickType_t ticks_to_wait)
{
...
        if (wait_time - ticks_start > ticks_to_wait) { // out of time
            wait_time = I2C_CMD_ALIVE_INTERVAL_TICK;
        } else {
            wait_time = ticks_to_wait - (wait_time - ticks_start);
            if (wait_time < I2C_CMD_ALIVE_INTERVAL_TICK) {
                wait_time = I2C_CMD_ALIVE_INTERVAL_TICK;
            }
        }
...
}

It seems the IDF I2C driver is overriding user specified timeout with a fixed timeout of 1000 milliseconds. That's awful, because it must be fixed there before you can get it working properly on the Arduino framework now.

In my case I'm using a modified version of SoftwareWire, until I find a better solution.

mikeWShef commented 1 year ago

@ppescher thanks, this has been driving me crazy.

matiasbarone commented 10 months ago
git clone https://github.com/espressif/arduino-esp32 -b esp-idf-v5.1-libs ~/Arduino/hardware/espressif/esp32

Hello, there's no branch esp-idf-v5.1-libs which should I use to solve this?

mrengineer7777 commented 10 months ago

@matiasbarone I believe that branch has been merged into Master. https://github.com/espressif/arduino-esp32/releases/tag/3.0.0-alpha2 Master is currently in an alpha state and starts the 3.0.0 arduino-esp32 branch. Feel free to try it, but be aware some things may not work.

matiasbarone commented 10 months ago

@matiasbarone I believe that branch has been merged into Master. https://github.com/espressif/arduino-esp32/releases/tag/3.0.0-alpha2 Master is currently in an alpha state and starts the 3.0.0 arduino-esp32 branch. Feel free to try it, but be aware some things may not work.

Thanks. I used the banch idf-release/v5.1

But I still geting the error 263

[   991][I][esp32-hal-i2c.c:106] i2cInit(): Initialising I2C Master: sda=8 scl=9 freq=100000
[  1993][E][Wire.cpp:517] requestFrom(): i2cRead returned Error 263

Im ussing a ESP32-S2 with:

------------------------------------------
Software Info:
------------------------------------------
Compile Date/Time : Nov  1 2023 15:49:27
Compile Host OS   : linux
ESP-IDF Version   : v5.1.1-678-g8c6114d0d2-dirty
Arduino Version   : 3.0.0
mrengineer7777 commented 10 months ago

Sanity check: are IO pins 8, 9 available on S2 version? On my ESP32-32UE WROOM module GPIO 6-11 are connected to internal flash.

ppescher commented 10 months ago

Nothing changed in v5.1 with regards to the I2C timeout issue: https://github.com/espressif/esp-idf/blob/release/v5.1/components/driver/i2c/i2c.c#L1545-L1553

Whatever timeout you pass to that function, no less than 1 second timeout is used when waiting for the I2C transaction to complete. The correct wait time is calculated in this line alone: https://github.com/espressif/esp-idf/blob/release/v5.1/components/driver/i2c/i2c.c#L1549 All the rest is to make sure that at least 1 second timeout is given to the interrupt handler. The reason for this is not clear. Either you honor the user specified timeout value or you don't have a timeout argument and you calculate a sensible timeout value inside the function, based on the amount of data to be transferred and the bit rate. Why was 1 second deemed necessary?

I think we should really open an issue in the esp-idf repository for this.

mrengineer7777 commented 10 months ago

I think we should really open an issue in the esp-idf repository for this.

@ppescher Good analysis. I encourage you to open an issue there.

matiasbarone commented 10 months ago

Sanity check: are IO pins 8, 9 available on S2 version? On my ESP32-32UE WROOM module GPIO 6-11 are connected to internal flash.

I'm using the ESP32­-S2­-SOLO module.

GPIO8 and GPIO9 are free. Checking this I notice that my circuit is conected to pin8 and pin9 that are GPIO15, GPIO16. Probably this is causing the problem.

I will change and test. I changed it and worked perfectly.

Thanks.

handmade0octopus commented 8 months ago

I have same issue on ESP32-S3 with 2.0.11.

What is really strange is SDA acts like SCL (checked with scope) meaning it has constant clock and SDA is actually looking licke clock while trying to do periodic (using Adafruid ADXL335 library). SCL seems to be dead flat. What is even more bizzare I only send request once per 500ms and data is being sent constantly for some reason - setTimeOut also does nothing.

Stranger even is the fact that pinout is correct as sensor reports correctly and swapping them around causes .begin() to fail!

Same board with ESP32 with same parts works correctly.

    #define I2C_SCL     42
    #define I2C_SDA     41