Skip to content

ESP32 with Wifi messes up i2c bus reads (MPU6050) #1352

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
echoGee opened this issue Apr 25, 2018 · 23 comments
Closed

ESP32 with Wifi messes up i2c bus reads (MPU6050) #1352

echoGee opened this issue Apr 25, 2018 · 23 comments

Comments

@echoGee
Copy link

echoGee commented Apr 25, 2018

Hardware:

Board: ESP32 DevKit V1 DoIT
Core Installation/update date: https://github.com/platformio/platform-espressif32/releases/tag/v0.12.0
IDE name: Platform.io
Flash Frequency: 80Mhz?
Upload Speed: unknown

Description:

Enabling Wifi using the connectToWiFi(networkName, networkPswd); messes up reading of the MPU6050 using the I2C bus. There are 3 different test cases.

  1. Comment the line connectToWiFi(networkName, networkPswd); in the sketch below: This reads the MPU6050 through i2c flawlessly(at ~100fps). Wifi obviously is disabled.
  2. Uncomment the line connectToWiFi(networkName, networkPswd); in the sketch below: This makes the bus unreliable and "panics" the core after sometime.
  3. Uncomment the line connectToWiFi(networkName, networkPswd); in the sketch below, and move the contents of the interrupt function void dmpDataReady() { to IRAM by modifying it to void IRAM_ATTR dmpDataReady() {. This is in reference to an issue Guru Meditation Error: Core 1 panic'ed (Cache disabled but cached memory region accessed) ESP32 ARDUINO IDE  #855. : This makes the bus unreliable and causes the bus to freeze after sometime. No core panic though.

The debugs for the 3 test cases are given below

Sketch:

The sketch is a modification of the https://github.com/jrowberg/i2cdevlib/blob/master/Arduino/MPU6050/examples/MPU6050_DMP6_ESPWiFi/MPU6050_DMP6_ESPWiFi.ino to work for ESP32 and sending through wifi UDP.

/* This driver reads quaternion data from the MPU6060 and sends
   Open Sound Control messages.

  GY-521  NodeMCU
  MPU6050 devkit 1.0
  board   Lolin         Description
  ======= ==========    ====================================================
  VCC     VU (5V USB)   Not available on all boards so use 3.3V if needed.
  GND     G             Ground
  SCL     D1 (GPIO05)   I2C clock
  SDA     D2 (GPIO04)   I2C data
  XDA     not connected
  XCL     not connected
  AD0     not connected
  INT     D8 (GPIO15)   Interrupt pin

*/


#include <WiFi.h>
#include <WiFiClient.h>
#include <WiFiUdp.h>

//#include <WiFiManager.h>         //https://github.com/tzapu/WiFiManager

// I2Cdev and MPU6050 must be installed as libraries, or else the .cpp/.h files
// for both classes must be in the include path of your project
#include "I2Cdev.h"

#include "MPU6050_6Axis_MotionApps20.h"

// Arduino Wire library is required if I2Cdev I2CDEV_ARDUINO_WIRE implementation
// is used in I2Cdev.h
#if I2CDEV_IMPLEMENTATION == I2CDEV_ARDUINO_WIRE
    #include "Wire.h"
#endif

MPU6050 mpu;
//MPU6050 mpu(0x69); // <-- use for AD0 high

/* =========================================================================
   NOTE: In addition to connection 5/3.3v, GND, SDA, and SCL, this sketch
   depends on the MPU-6050's INT pin being connected to the ESP8266 GPIO15
   pin.
 * ========================================================================= */

// MPU control/status vars
bool dmpReady = false;  // set true if DMP init was successful
uint8_t mpuIntStatus;   // holds actual interrupt status byte from MPU
uint8_t devStatus;      // return status after each device operation (0 = success, !0 = error)
uint16_t packetSize;    // expected DMP packet size (default is 42 bytes)
uint16_t fifoCount;     // count of all bytes currently in FIFO
uint8_t fifoBuffer[64]; // FIFO storage buffer

// orientation/motion vars
Quaternion q;           // [w, x, y, z]         quaternion container
VectorInt16 aa;         // [x, y, z]            accel sensor measurements
VectorInt16 aaReal;     // [x, y, z]            gravity-free accel sensor measurements
VectorInt16 aaWorld;    // [x, y, z]            world-frame accel sensor measurements
VectorFloat gravity;    // [x, y, z]            gravity vector


// uncomment "OUTPUT_READABLE_YAWPITCHROLL" if you want to see the yaw/
// pitch/roll angles (in degrees) calculated from the quaternions coming
// from the FIFO. Note this also requires gravity vector calculations.
// Also note that yaw/pitch/roll angles suffer from gimbal lock (for
// more info, see: http://en.wikipedia.org/wiki/Gimbal_lock)
#define OUTPUT_READABLE_YAWPITCHROLL


#ifdef OUTPUT_READABLE_EULER
float euler[3];         // [psi, theta, phi]    Euler angle container
#endif
#ifdef OUTPUT_READABLE_YAWPITCHROLL
float ypr[3];           // [yaw, pitch, roll]   yaw/pitch/roll container and gravity vector
#endif


#define INTERRUPT_PIN 36 // use ESP32
#define LED_PIN 27

const char * networkName = "WifiNet";
const char * networkPswd = "123456789";

//IP address to send UDP data to:
// either use the ip address of the server or
// a network broadcast address
IPAddress myIP(192,168,137,12);
IPAddress gateway(192,168,137,1);
IPAddress subnet(255,255,255,0);

//Are we currently connected?
boolean connected = false;

WiFiUDP Udp;                                // A UDP instance to let us send and receive packets over UDP
const unsigned int outPort = 3033;          // remote port to receive OSC
const char * udpAddress = "192.168.137.1";

//wifi event handler
void WiFiEvent(WiFiEvent_t event){
    Serial.print("WifiEvent: ");
    Serial.println(event);
    switch(event) {
      case SYSTEM_EVENT_STA_GOT_IP:
          //When connected set
          Serial.print("WiFi connected! IP address: ");
          Serial.println(WiFi.localIP());
          //initializes the UDP state
          //This initializes the transfer buffer
          Udp.begin(WiFi.localIP(),outPort);
          connected = true;
          break;
      case SYSTEM_EVENT_STA_DISCONNECTED:
          Serial.println("WiFi lost connection");
          connected = false;
          break;
    }
}

void connectToWiFi(const char * ssid, const char * pwd){
  Serial.println("Connecting to WiFi network: " + String(ssid));

  // delete old config
  WiFi.disconnect(true);
  //register event handler
  WiFi.onEvent(WiFiEvent);
  WiFi.config(myIP,gateway,subnet);
  //Initiate connection
  WiFi.begin(ssid, pwd);

  Serial.println("Waiting for WIFI connection...");
}


// ================================================================
// ===               INTERRUPT DETECTION ROUTINE                ===
// ================================================================

volatile bool mpuInterrupt = false;     // indicates whether MPU interrupt pin has gone high
void dmpDataReady() {
    mpuInterrupt = true;
}

void mpu_setup()
{
  // join I2C bus (I2Cdev library doesn't do this automatically)
#if I2CDEV_IMPLEMENTATION == I2CDEV_ARDUINO_WIRE
  Wire.begin();
  Wire.setClock(400000); // 400kHz I2C clock. Comment this line if having compilation difficulties
#elif I2CDEV_IMPLEMENTATION == I2CDEV_BUILTIN_FASTWIRE
  Fastwire::setup(400, true);
#endif

  // initialize device
  Serial.println(F("Initializing I2C devices..."));
  mpu.initialize();
  pinMode(INTERRUPT_PIN, INPUT);

  // verify connection
  Serial.println(F("Testing device connections..."));
  Serial.println(mpu.testConnection() ? F("MPU6050 connection successful") : F("MPU6050 connection failed"));

  // load and configure the DMP
  Serial.println(F("Initializing DMP..."));
  devStatus = mpu.dmpInitialize();

  // supply your own gyro offsets here, scaled for min sensitivity
  mpu.setXGyroOffset(220);
  mpu.setYGyroOffset(76);
  mpu.setZGyroOffset(-85);
  mpu.setZAccelOffset(1788); // 1688 factory default for my test chip

  // make sure it worked (returns 0 if so)
  if (devStatus == 0) {
    // turn on the DMP, now that it's ready
    Serial.println(F("Enabling DMP..."));
    mpu.setDMPEnabled(true);

    // enable Arduino interrupt detection
    Serial.println(F("Enabling interrupt detection (Arduino external interrupt 0)..."));
    attachInterrupt(digitalPinToInterrupt(INTERRUPT_PIN), dmpDataReady, RISING);
    mpuIntStatus = mpu.getIntStatus();

    // set our DMP Ready flag so the main loop() function knows it's okay to use it
    Serial.println(F("DMP ready! Waiting for first interrupt..."));
    dmpReady = true;

    // get expected DMP packet size for later comparison
    packetSize = mpu.dmpGetFIFOPacketSize();
  } else {
    // ERROR!
    // 1 = initial memory load failed
    // 2 = DMP configuration updates failed
    // (if it's going to break, usually the code will be 1)
    Serial.print(F("DMP Initialization failed (code "));
    Serial.print(devStatus);
    Serial.println(F(")"));
  }
}

void setup(void)
{
  Serial.begin(115200);
  pinMode(LED_PIN, OUTPUT);

  //connectToWiFi(networkName, networkPswd);
  Serial.print(F("WiFi connected! IP address: "));
  Serial.println(WiFi.localIP());

  mpu_setup();
}

void mpu_loop()
{
  // if programming failed, don't try to do anything
  if (!dmpReady) return;

  // wait for MPU interrupt or extra packet(s) available
  if (!mpuInterrupt && fifoCount < packetSize) return;

  // reset interrupt flag and get INT_STATUS byte
  mpuInterrupt = false;
  mpuIntStatus = mpu.getIntStatus();

  // get current FIFO count
  fifoCount = mpu.getFIFOCount();

  // check for overflow (this should never happen unless our code is too inefficient)
  if ((mpuIntStatus & 0x10) || fifoCount == 1024) {
    // reset so we can continue cleanly
    mpu.resetFIFO();
    Serial.println(F("FIFO overflow!"));

    // otherwise, check for DMP data ready interrupt (this should happen frequently)
  } else if (mpuIntStatus & 0x02) {
    // wait for correct available data length, should be a VERY short wait
    while (fifoCount < packetSize) fifoCount = mpu.getFIFOCount();

    // read a packet from FIFO
    mpu.getFIFOBytes(fifoBuffer, packetSize);

    // track FIFO count here in case there is > 1 packet available
    // (this lets us immediately read more without waiting for an interrupt)
    fifoCount -= packetSize;


#ifdef OUTPUT_READABLE_YAWPITCHROLL
    // display Euler angles in degrees
    mpu.dmpGetQuaternion(&q, fifoBuffer);
    mpu.dmpGetGravity(&gravity, &q);
    mpu.dmpGetYawPitchRoll(ypr, &q, &gravity);
    Serial.print("ypr\t");
    Serial.print(ypr[0] * 180/M_PI);
    Serial.print("\t");
    Serial.print(ypr[1] * 180/M_PI);
    Serial.print("\t");
    Serial.println(ypr[2] * 180/M_PI);
#endif
  }
}

void loop(void)
{
  digitalWrite(LED_PIN, HIGH);
  mpu_loop();
  digitalWrite(LED_PIN, LOW);

}

Debug Messages:

Output from scenario 1

WiFi connected! IP address: 0.0.0.0
Initializing I2C devices...
[W][esp32-hal-i2c.c:334] i2cRead(): Ack Error! Addr: 68
Testing device connections...
MPU6050 connection successful
Initializing DMP...
Selecting user bank 16...
Selecting memory byte 6...
Checking hardware revision...
Revision @ user[16][6] = 4D
Resetting memory bank selection to 0...
Reading OTP bank valid flag...
OTP bank is valid!
Reading gyro offset TC values...
X gyro offset = 63
Y gyro offset = 0
Z gyro offset = 0
Setting slave 0 address to 0x7F...
Disabling I2C Master mode...
Setting slave 0 address to 0x68 (self)...
Resetting I2C Master control...

Writing DMP code to MPU memory banks (1929 bytes)
Success! DMP code written and verified.
Writing DMP configuration to MPU memory banks (192 bytes in config def)
Success! DMP configuration written and verified.
Setting clock source to Z Gyro...
Setting DMP and FIFO_OFLOW interrupts enabled...
Setting sample rate to 200Hz...
Setting external frame sync to TEMP_OUT_L[0]...
Setting DLPF bandwidth to 42Hz...
Setting gyro sensitivity to +/- 2000 deg/sec...
Setting DMP programm start address
Clearing OTP Bank flag...
Setting X/Y/Z gyro offset TCs to previous values...
Writing final memory update 1/7 (function unknown)...
Writing final memory update 2/7 (function unknown)...
Resetting FIFO...
Reading FIFO count...
Current FIFO count=0
Setting motion detection threshold to 2...
Setting zero-motion detection threshold to 156...
Setting motion detection duration to 80...
Setting zero-motion detection duration to 0...
Resetting FIFO...
Reading FIFO count...
Current FIFO count=0
Setting motion detection threshold to 2...
Setting zero-motion detection threshold to 156...
Setting motion detection duration to 80...
Setting zero-motion detection duration to 0...
Resetting FIFO...
Enabling FIFO...
Enabling DMP...
Resetting DMP...
Writing final memory update 3/7 (function unknown)...
Writing final memory update 4/7 (function unknown)...
Writing final memory update 5/7 (function unknown)...
Waiting for FIFO count > 2...

Current FIFO count=42
Reading FIFO data...
Reading interrupt status...
Current interrupt status=7
Reading final memory update 6/7 (function unknown)...
Waiting for FIFO count > 2...
Current FIFO count=84
Reading FIFO data...
Reading interrupt status...
Current interrupt status=3
Writing final memory update 7/7 (function unknown)...
DMP is good to go! Finally.
Disabling DMP (you turn it on later)...
Setting up internal 42-byte (default) DMP packet buffer...
Resetting FIFO and clearing INT status one last time...
Enabling DMP...
Enabling interrupt detection (Arduino external interrupt 0)...
DMP ready! Waiting for first interrupt...
ypr     117.38  -36.61  18.09
ypr     117.42  -36.60  18.04
ypr     117.46  -36.59  18.00

Output from scenario 2


Connecting to WiFi network: WifiNet
[D][WiFiGeneric.cpp:293] _eventCallback(): Event: 2 - STA_START
WifiEvent: 2
Waiting for WIFI connection...
WiFi connected! IP address: 192.168.137.12
Initializing I2C devices...
[W][esp32-hal-i2c.c:334] i2cRead(): Ack Error! Addr: 68
Testing device connections...
MPU6050 connection successful
Initializing DMP...


Resetting MPU6050...
Resetting DMP...

Disabling sleep mode...
Selecting user bank 16...
Selecting memory byte 6...
Checking hardware revision...
Revision @ user[16][6] = 4D
Resetting memory bank selection to 0...
Reading OTP bank valid flag...
OTP bank is valid!
Reading gyro offset TC values...
X gyro offset = 63
Y gyro offset = 0
Z gyro offset = 0
Setting slave 0 address to 0x7F...
Disabling I2C Master mode...
Setting slave 0 address to 0x68 (self)...
Resetting I2C Master control...
Writing DMP code to MPU memory banks (1929 bytes)
Success! DMP code written and verified.
Writing DMP configuration to MPU memory banks (192 bytes in config def)
Success! DMP configuration written and verified.
Setting clock source to Z Gyro...
Setting DMP and FIFO_OFLOW interrupts enabled...
Setting sample rate to 200Hz...
Setting external frame sync to TEMP_OUT_L[0]...
Setting DLPF bandwidth to 42Hz...
Setting gyro sensitivity to +/- 2000 deg/sec...
Setting DMP programm start address
Clearing OTP Bank flag...
Setting X/Y/Z gyro offset TCs to previous values...
Writing final memory update 1/7 (function unknown)...

Writing final memory update 2/7 (function unknown)...
Resetting FIFO...
Reading FIFO count...
Current FIFO count=0
Setting motion detection threshold to 2...
Setting zero-motion detection threshold to 156...
Setting motion detection duration to 80...
Setting zero-motion detection duration to 0...
Resetting FIFO...
Enabling FIFO...
Enabling DMP...
Resetting DMP...
Writing final memory update 3/7 (function unknown)...
Writing final memory update 4/7 (function unknown)...
Writing final memory update 5/7 (function unknown)...
Waiting for FIFO count > 2...
Current FIFO count=42
Reading FIFO data...
Reading interrupt status...
Current interrupt status=7
Reading final memory update 6/7 (function unknown)...
Waiting for FIFO count > 2...
Current FIFO count=42
Reading FIFO data...
Reading interrupt status...
Current interrupt status=3
Writing final memory update 7/7 (function unknown)...
DMP is good to go! Finally.
Disabling DMP (you turn it on later)...
Setting up internal 42-byte (default) DMP packet buffer...
Resetting FIFO and clearing INT status one last time...
Enabling DMP...

Enabling interrupt detection (Arduino external interrupt 0)...
DMP ready! Waiting for first interrupt...
ypr     101.45  -26.54  19.11
FIFO overflow!
ypr     101.54  -26.50  19.03
FIFO overflow!
ypr     101.62  -26.46  18.96
FIFO overflow!
ypr     101.72  -26.42  18.87
FIFO overflow!
ypr     101.80  -26.39  18.79
FIFO overflow!
ypr     101.89  -26.35  18.72
FIFO overflow!
ypr     101.98  -26.31  18.65
FIFO overflow!
ypr     102.06  -26.27  18.57
FIFO overflow!
ypr     102.14  -26.23  18.50
FIFO overflow!
.
.
ypr     102.71  -25.99  18.02
FIFO overflow!
[W][esp32-hal-i2c.c:334] i2cRead(): Ack Error! Addr: 68
[W][esp32-hal-i2c.c:334] i2cRead(): Ack Error! Addr: 68
Guru Meditation Error: Core  1 panic'ed (Cache disabled but cached memory region accessed)
Register dump:
PC      : 0x400d2194  PS      : 0x00060034  A0      : 0x40081624  A1      : 0x3ffc0be0
A2      : 0x00000004  A3      : 0x3ffc3614  A4      : 0x00000010  A5      : 0x400d2194
A6      : 0x00000000  A7      : 0x1200005c  A8      : 0x80080e6c  A9      : 0x80000020
A10     : 0x00000000  A11     : 0x00000000  A12     : 0x3ffc3cfc  A13     : 0x00000000
A14     : 0x3ffc3cf8  A15     : 0xffffffff  SAR     : 0x0000001a  EXCCAUSE: 0x00000007
EXCVADDR: 0x00000000  LBEG    : 0x00000000  LEND    : 0x00000000  LCOUNT  : 0x00000000

Backtrace: 0x400d2194:0x3ffc0be0 0x40081621:0x3ffc0c00 0x400823f5:0x00000000

Rebooting...
ets Jun  8 2016 00:22:57

rst:0x3 (SW_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:812
load:0x40078000,len:0
load:0x40078000,len:11404
entry 0x40078a28
Connecting to WiFi network: WifiNet
[D][WiFiGeneric.cpp:293] _eventCallback(): Event: 2 - STA_START

WifiEvent: 2
Waiting for WIFI connection...
WiFi connected! IP address: 192.168.137.12
Initializing I2C devices...
[W][esp32-hal-i2c.c:334] i2cRead(): Ack Error! Addr: 68
Testing device connections...
MPU6050 connection successful
Initializing DMP...


Resetting MPU6050...
Resetting DMP...
Disabling sleep mode...
Selecting user bank 16...
Selecting memory byte 6...
Checking hardware revision...
Revision @ user[16][6] = 4D
Resetting memory bank selection to 0...
Reading OTP bank valid flag...
OTP bank is invalid!
Reading gyro offset TC values...
X gyro offset = 63
Y gyro offset = 0
Z gyro offset = 0
Setting slave 0 address to 0x7F...
Disabling I2C Master mode...
Setting slave 0 address to 0x68 (self)...
Resetting I2C Master control...
Writing DMP code to MPU memory banks (1929 bytes)
ERROR! DMP code verification failed.
DMP Initialization failed (code 1)
[D][WiFiGeneric.cpp:293] _eventCallback(): Event: 7 - STA_GOT_IP
WifiEvent: 7
WiFi connected! IP address: 192.168.137.12
[D][WiFiGeneric.cpp:293] _eventCallback(): Event: 7 - STA_GOT_IP
WifiEvent: 7
WiFi connected! IP address: 192.168.137.12

ESP Exception 
===============================
PC: 0x400d2194: dmpDataReady() at C:/Code/MPU6050_DMP6_ESPWiFi/MPU6050_DMP6_ESPWiFi.ino line 279
EXCVADDR: 0x00000000

Decoding stack results
0x400d2194: dmpDataReady() at C:/Code/MPU6050_DMP6_ESPWiFi/MPU6050_DMP6_ESPWiFi.ino line 279
0x400823f5: spi_flash_op_block_func at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/spi_flash/./cache_utils.c line 82
===============================

Output from scenario 3

With IRAM_ATTR in interrupt
======================================
Connecting to WiFi network: WifiNet
[D][WiFiGeneric.cpp:293] _eventCallback(): Event: 2 - STA_START
WifiEvent: 2
Waiting for WIFI connection...
WiFi connected! IP address: 192.168.137.12
Initializing I2C devices...
[W][esp32-hal-i2c.c:334] i2cRead(): Ack Error! Addr: 68
Testing device connections...
MPU6050 connection successful
Initializing DMP...


Resetting MPU6050...
Resetting DMP...

Disabling sleep mode...
Selecting user bank 16...
Selecting memory byte 6...
Checking hardware revision...
Revision @ user[16][6] = 4D
Resetting memory bank selection to 0...
Reading OTP bank valid flag...
OTP bank is valid!
Reading gyro offset TC values...
X gyro offset = 63
Y gyro offset = 0
Z gyro offset = 0
Setting slave 0 address to 0x7F...
Disabling I2C Master mode...
Setting slave 0 address to 0x68 (self)...
Resetting I2C Master control...
Writing DMP code to MPU memory banks (1929 bytes)
Success! DMP code written and verified.
Writing DMP configuration to MPU memory banks (192 bytes in config def)
Success! DMP configuration written and verified.
Setting clock source to Z Gyro...
Setting DMP and FIFO_OFLOW interrupts enabled...
Setting sample rate to 200Hz...
Setting external frame sync to TEMP_OUT_L[0]...
Setting DLPF bandwidth to 42Hz...
Setting gyro sensitivity to +/- 2000 deg/sec...
Setting DMP programm start address
Clearing OTP Bank flag...

Setting X/Y/Z gyro offset TCs to previous values...
Writing final memory update 1/7 (function unknown)...
Writing final memory update 2/7 (function unknown)...
Resetting FIFO...
Reading FIFO count...
Current FIFO count=0
Setting motion detection threshold to 2...
Setting zero-motion detection threshold to 156...
Setting motion detection duration to 80...
Setting zero-motion detection duration to 0...
Resetting FIFO...
Enabling FIFO...
Enabling DMP...
Resetting DMP...
Writing final memory update 3/7 (function unknown)...
Writing final memory update 4/7 (function unknown)...
Writing final memory update 5/7 (function unknown)...
Waiting for FIFO count > 2...
Current FIFO count=42
Reading FIFO data...
Reading interrupt status...
Current interrupt status=7
Reading final memory update 6/7 (function unknown)...
Waiting for FIFO count > 2...
Current FIFO count=42
Reading FIFO data...
Reading interrupt status...
Current interrupt status=3
Writing final memory update 7/7 (function unknown)...
DMP is good to go! Finally.
Disabling DMP (you turn it on later)...
Setting up internal 42-byte (default) DMP packet buffer...
Resetting FIFO and clearing INT status one last time...
Enabling DMP...
Enabling interrupt detection (Arduino external interrupt 0)...
DMP ready! Waiting for first interrupt...
ypr     105.20  -29.69  19.56
FIFO overflow!
ypr     105.27  -29.71  19.50
FIFO overflow!
ypr     105.34  -29.69  19.43

FIFO overflow!
ypr     105.44  -29.65  19.36
FIFO overflow!
ypr     105.53  -29.59  19.27
FIFO overflow!
ypr     105.62  -29.52  19.18
FIFO overflow!
ypr     105.72  -29.44  19.10
FIFO overflow!
ypr     105.81  -29.37  19.02
FIFO overflow!
ypr     105.89  -29.36  18.95
FIFO overflow!
ypr     105.95  -29.40  18.90
FIFO overflow!
ypr     106.02  -29.42  18.85
FIFO overflow!
ypr     106.10  -29.37  18.78
FIFO overflow!
ypr     106.20  -29.29  18.70
FIFO overflow!
ypr     106.29  -29.21  18.61
FIFO overflow!
ypr     106.37  -29.15  18.54
FIFO overflow!
ypr     106.45  -29.13  18.47
FIFO overflow!
[W][esp32-hal-i2c.c:334] i2cRead(): Ack Error! Addr: 68
[W][esp32-hal-i2c.c:334] i2cRead(): Ack Error! Addr: 68
ypr     106.45  -29.13  18.47
[D][WiFiGeneric.cpp:293] _eventCallback(): Event: 7 - STA_GOT_IP
WifiEvent: 7
WiFi connected! IP address: 192.168.137.12
[D][WiFiGeneric.cpp:293] _eventCallback(): Event: 7 - STA_GOT_IP
WifiEvent: 7
WiFi connected! IP address: 192.168.137.12
[W][esp32-hal-i2c.c:334] i2cRead(): Ack Error! Addr: 68
[E][esp32-hal-i2c.c:161] i2cWrite(): Busy Timeout! Addr: 68
[W][esp32-hal-i2c.c:280] i2cRead(): Busy Timeout! Addr: 68
[E][esp32-hal-i2c.c:161] i2cWrite(): Busy Timeout! Addr: 68
[W][esp32-hal-i2c.c:280] i2cRead(): Busy Timeout! Addr: 68
ypr     106.45  -29.13  18.47
[E][esp32-hal-i2c.c:161] i2cWrite(): Busy Timeout! Addr: 68
[W][esp32-hal-i2c.c:280] i2cRead(): Busy Timeout! Addr: 68
[E][esp32-hal-i2c.c:161] i2cWrite(): Busy Timeout! Addr: 68
[W][esp32-hal-i2c.c:280] i2cRead(): Busy Timeout! Addr: 68
[E][esp32-hal-i2c.c:161] i2cWrite(): Busy Timeout! Addr: 68
[W][esp32-hal-i2c.c:280] i2cRead(): Busy Timeout! Addr: 68
ypr     106.45  -29.13  18.47
[E][esp32-hal-i2c.c:161] i2cWrite(): Busy Timeout! Addr: 68
[W][esp32-hal-i2c.c:280] i2cRead(): Busy Timeout! Addr: 68

@stickbreaker
Copy link
Contributor

@echoGee Switch to the stickbreaker-i2c branch of this repo. And add the IRAM_ATTR to:

void IRAM_ATTR dmpDataReady() {
    mpuInterrupt = true;
}

The main branch I2C subsystem is not very durable.

Chuck.

@echoGee
Copy link
Author

echoGee commented Apr 25, 2018

Attempting to use the stickbreaker-i2c branch on PlatformIO. I haven't been able to find a good way to do this yet using PlatformIO !! :(

@lbernstone
Copy link
Contributor

There's only five files that need to be replaced. https://desire.giesecke.tk/index.php/2018/04/20/how-to-use-stickbreakers-i2c-improved-code/ . The location should be ~/.platformio/packages/framework-arduinoespressif32

@echoGee
Copy link
Author

echoGee commented Apr 26, 2018

This works. However, I get an occassional log for i2c_isr_handler_default() . Is this an issue ?

ypr     20.02   21.79   -23.26
ypr     20.04   21.79   -23.25
ypr     20.07   21.78   -23.24
ypr     20.09   21.76   -23.22
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0
ypr     20.11   21.75   -23.20
ypr     20.13   21.74   -23.17
ypr     20.15   21.73   -23.16
ypr     20.17   21.72   -23.14
ypr     20.21   21.72   -23.13
ypr     20.23   21.71   -23.12
ypr     20.25   21.70   -23.11
ypr     20.28   21.69   -23.10
ypr     20.30   21.68   -23.07
ypr     20.32   21.68   -23.06
ypr     20.35   21.67   -23.03
ypr     20.38   21.68   -23.01
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0
ypr     20.41   21.68   -23.00

Corresponding code that logs this is in esp32-hal-i2c.c

static void IRAM_ATTR i2c_isr_handler_default(void* arg)
{
    i2c_t* p_i2c = (i2c_t*) arg; // recover data
    uint32_t activeInt = p_i2c->dev->int_status.val&0x1FFF;

    //portBASE_TYPE HPTaskAwoken = pdFALSE,xResult;

    if(p_i2c->stage==I2C_DONE) { //get Out
        log_e("eject int=%p, ena=%p",activeInt,p_i2c->dev->int_ena.val);
        p_i2c->dev->int_ena.val = 0;
        p_i2c->dev->int_clr.val = activeInt; //0x1FFF;
        return;
    }
.
.
.

@stickbreaker
Copy link
Contributor

That error is saying a i2c interrupt has been triggered before the ISR is correctly configured. So the ISR cleared the interrupt and exited.

[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0

int=0x0 is stating that no interrupt reason exists, and the ena=0x0 says no interrupts are enabled?

What version of my code are you using?

look in i2cProcQueue() for the code that attaches the i2c interrupt to i2c_isr_handler_default(). It should look like this:

    if(!i2c->intr_handle) { // create ISR for either peripheral
        // log_i("create ISR %d",i2c->num);
        uint32_t ret = 0;
        uint32_t flags = ESP_INTR_FLAG_EDGE |  //< Edge-triggered interrupt
          ESP_INTR_FLAG_IRAM |  //< ISR can be called if cache is disabled
          ESP_INTR_FLAG_LOWMED;   //< Low and medium prio interrupts. These can be handled in C.

        if(i2c->num) {
            ret = esp_intr_alloc_intrstatus(ETS_I2C_EXT1_INTR_SOURCE, flags, (uint32_t)&i2c->dev->int_status.val, 0x1FFF, &i2c_isr_handler_default,i2c, &i2c->intr_handle);
        } else {
            ret = esp_intr_alloc_intrstatus(ETS_I2C_EXT0_INTR_SOURCE, flags, (uint32_t)&i2c->dev->int_status.val, 0x1FFF, &i2c_isr_handler_default,i2c, &i2c->intr_handle);
        }

Chuck.

@echoGee
Copy link
Author

echoGee commented Apr 27, 2018

I am using the latest code on https://github.com/espressif/arduino-esp32/tree/stickbreaker-i2c

What do you mean by no interrupt reason exists?

int=0x0 is stating that no interrupt reason exists, and the ena=0x0 says no interrupts are enabled?

The code snippet looks like this for me :

    if(!i2c->intr_handle) { // create ISR for either peripheral
        // log_i("create ISR %d",i2c->num);
        uint32_t ret = 0;
        uint32_t flags = ESP_INTR_FLAG_EDGE |  //< Edge-triggered interrupt
          ESP_INTR_FLAG_IRAM |  //< ISR can be called if cache is disabled
          ESP_INTR_FLAG_LOWMED;   //< Low and medium prio interrupts. These can be handled in C.

        if(i2c->num) {
            ret = esp_intr_alloc_intrstatus(ETS_I2C_EXT1_INTR_SOURCE, flags, (uint32_t)&i2c->dev->int_status.val, 0x1FFF, &i2c_isr_handler_default,i2c, &i2c->intr_handle);
        } else {
            ret = esp_intr_alloc_intrstatus(ETS_I2C_EXT0_INTR_SOURCE, flags, (uint32_t)&i2c->dev->int_status.val, 0x1FFF, &i2c_isr_handler_default,i2c, &i2c->intr_handle);
        }

        if(ret!=ESP_OK) {
            log_e("install interrupt handler Failed=%d",ret);
            I2C_MUTEX_UNLOCK();
            return I2C_ERROR_MEMORY;
        }
    }

@stickbreaker
Copy link
Contributor

stickbreaker commented Apr 27, 2018

What do you mean by no interrupt reason exists?
int=0x0 is stating that no interrupt reason exists, and the ena=0x0 says no interrupts are enabled?

int= is displaying the bit flags for which of the i2c interrupt condition was the source for this cycle.
This is a copy of int_status from i2c_struct.h

  union {
        struct {
            uint32_t rx_fifo_full:     1;            /*The masked interrupt status for rx_fifo_full_int interrupt.*/
            uint32_t tx_fifo_empty:    1;            /*The masked interrupt status for tx_fifo_empty_int interrupt.*/
            uint32_t rx_fifo_ovf:      1;            /*The masked interrupt status for rx_fifo_ovf_int interrupt.*/
            uint32_t end_detect:       1;            /*The masked interrupt status for end_detect_int interrupt.*/
            uint32_t slave_tran_comp:  1;            /*The masked interrupt status for slave_tran_comp_int interrupt.*/
            uint32_t arbitration_lost: 1;            /*The masked interrupt status for arbitration_lost_int interrupt.*/
            uint32_t master_tran_comp: 1;            /*The masked interrupt status for master_tran_comp_int interrupt.*/
            uint32_t trans_complete:   1;            /*The masked interrupt status for trans_complete_int interrupt.*/
            uint32_t time_out:         1;            /*The masked interrupt status for time_out_int interrupt.*/
            uint32_t trans_start:      1;            /*The masked interrupt status for trans_start_int interrupt.*/
            uint32_t ack_err:          1;            /*The masked interrupt status for ack_err_int interrupt.*/
            uint32_t rx_rec_full:      1;            /*The masked interrupt status for rx_rec_full_int interrupt.*/
            uint32_t tx_send_empty:    1;            /*The masked interrupt status for tx_send_empty_int interrupt.*/
            uint32_t reserved13:      19;
        };
        uint32_t val;
} int_status;

It should be a non Zero value in the range of 0x0001 to 0x1fff. somehow a interrupt is being generated without a corresponding source.

Possibly my ISR is servicing the interrupt before the interrupt is generated. My ISR services all pending interrupts before is exits. It cycles through a while() loop as long as uint32_t activeInt = p_i2c->dev->int_status.val&0x1FFF;
activeInt != 0. So, possibly, one interrupt triggered the ISR, and while that interrupt source was being serviced, another interruptible condition was generated. But since the Interrupt is currently being serviced, the actual interrupt was differed until this call completed.

at the Bottom of i2c_isr_default_handler():

   activeInt = p_i2c->dev->int_status.val; // start all over if another interrupt happened

Here

comment out this line. That will make the ISR only handle pre-existing events.

See if commenting out that line prevents that error message.

I coded it this way to increase performance, I found that it was faster to service multiple interrupts at the same time, than to do each one separately.

See if commenting out that line changes the behavior, I'll have to do some more thinking and testing.
Chuck.

@echoGee
Copy link
Author

echoGee commented Apr 28, 2018

@stickbreaker , tried commenting at the Bottom of i2c_isr_default_handler():

activeInt = p_i2c->dev->int_status.val; // start all over if another interrupt happened 

There are many(around 1 a sec) errors

Error 1

areal -8 -436 160
[E][esp32-hal-i2c.c:1038] i2cProcQueue(): Gross Timeout Dead start=0x3fd, end=0x3fd, =0, max=50 error=1
[E][esp32-hal-i2c.c:1419] i2cDumpI2c(): i2c=0x3ffc1038
[E][esp32-hal-i2c.c:1420] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): lock=0x3ffd9f38
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): event=0x3ffda02c bits=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): intr_handle=0x3ffd9888
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): dq=0x3ffd9d58
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): byteCnt=2
[E][esp32-hal-i2c.c:1390] i2cDumpDqData(): [0] d0 W STOP buf@=0x3ffc33fe, len=1, pos=1, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1408] i2cDumpDqData(): 0x0000: r 72
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): enable Core Debug Level "Error"
areal 23 -447 208
areal 69 -408 240

Error 2

areal 377 -736 -339
[E][esp32-hal-i2c.c:1038] i2cProcQueue(): Gross Timeout Dead start=0xf6d, end=0xf6d, =0, max=51 error=1
[E][esp32-hal-i2c.c:1419] i2cDumpI2c(): i2c=0x3ffc1038
[E][esp32-hal-i2c.c:1420] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): lock=0x3ffd9f38
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): event=0x3ffda02c bits=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): intr_handle=0x3ffd9888
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): dq=0x3ffda7d0
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): byteCnt=30
[E][esp32-hal-i2c.c:1390] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc3378, len=42, pos=30, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1408] i2cDumpDqData(): 0x0000: ;.....Fg......`....f...8...>.... 3b f2 ac 86 f6 e9 46 67 eb 91 94 86 fe 84 60 0f 00 01 d5 66 00 01 0c 38 ff fe 14 3e 14 da a1 16
[E][esp32-hal-i2c.c:1408] i2cDumpDqData(): 0x0020: ..)......j f5 16 29 7f 16 dd 80 a9 b2 6a
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): enable Core Debug Level "Error"
areal 384 -735 -337
areal 391 -738 -357
areal 401 -733 -374
areal 406 -723 -380
areal 407 -723 -385
areal 392 -735 -398
[E][esp32-hal-i2c.c:1038] i2cProcQueue(): Gross Timeout Dead start=0x102d, end=0x102d, =0, max=50 error=1
[E][esp32-hal-i2c.c:1419] i2cDumpI2c(): i2c=0x3ffc1038
[E][esp32-hal-i2c.c:1420] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): lock=0x3ffd9f38
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): event=0x3ffda02c bits=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): intr_handle=0x3ffd9888
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): dq=0x3ffda7d0
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): byteCnt=3
[E][esp32-hal-i2c.c:1390] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc3378, len=2, pos=0, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1408] i2cDumpDqData(): 0x0000: .L 00 4c
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): enable Core Debug Level "Error"
FIFO overflow!
areal 389 -819 -306

Error 3

[E][esp32-hal-i2c.c:1038] i2cProcQueue(): Gross Timeout Dead start=0x1a96, end=0x1a96, =0, max=51 error=1
[E][esp32-hal-i2c.c:1419] i2cDumpI2c(): i2c=0x3ffc1038
[E][esp32-hal-i2c.c:1420] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): lock=0x3ffd9f38
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): event=0x3ffda02c bits=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): intr_handle=0x3ffd9888
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): dq=0x3ffcd0a8
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): byteCnt=30
[E][esp32-hal-i2c.c:1390] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc3378, len=42, pos=30, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1408] i2cDumpDqData(): 0x0000: ?.h..b*o..UK.....^c...<d.0.V..iz 3f 80 68 84 fb 62 2a 6f f9 8c 55 4b 00 c7 c4 90 00 5e 63 0a 00 ae 3c 64 00 30 a2 56 0a 0f 69 7a
[E][esp32-hal-i2c.c:1408] i2cDumpDqData(): 0x0020: ... .;...j f4 89 09 20 10 3b 07 a7 b2 6a
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): enable Core Debug Level "Error"
areal 950 -1742 -3784
areal 1396 -2779 -1836
areal 1841 -3038 -967
areal 2203 -3006 -413
[E][esp32-hal-i2c.c:1038] i2cProcQueue(): Gross Timeout Dead start=0x1b4a, end=0x1b4a, =0, max=51 error=1
[E][esp32-hal-i2c.c:1419] i2cDumpI2c(): i2c=0x3ffc1038
[E][esp32-hal-i2c.c:1420] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): lock=0x3ffd9f38
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): event=0x3ffda02c bits=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): intr_handle=0x3ffd9888
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): dq=0x3ffcd0a8
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): byteCnt=30
[E][esp32-hal-i2c.c:1390] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc3378, len=42, pos=30, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1408] i2cDumpDqData(): 0x0000: ?..w..h...v......$R.. .-..a..|.g 3f cd fb 77 fc db 68 0a fc 1d 76 0b ff ff 90 1b 00 24 52 a2 00 20 be 2d ff b3 61 af 0d 7c 0e 67
[E][esp32-hal-i2c.c:1408] i2cDumpDqData(): 0x0020: ......(Z.j f0 d4 a6 88 1d f2 28 5a b2 6a
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): enable Core Debug Level "Error"

@stickbreaker
Copy link
Contributor

stickbreaker commented Apr 29, 2018

@echoGee increase you log level to info, and post. I'm getting confused. The Gross timeout error seem to be wrong.

[E][esp32-hal-i2c.c:1038] i2cProcQueue(): Gross Timeout Dead start=0x1b4a, end=0x1b4a, =0, max=51 error=1

start= and end= are millisecond markers, this message is saying the i2c process started at 0x1b4a and took less than 1ms, Maximum before timeout should have occurred is 51ms (50ms as default timeout, 1ms calculated for this data block).

FOUND ERROR in stickbreaker-i2c,
inside i2cProcQueue()

   i2c->dev->ctr.trans_start=1; // go for it

    uint32_t eBits = xEventGroupWaitBits(i2c->i2c_event,EVENT_DONE,pdFALSE,pdTRUE,ticksTimeOut);

    //log_e("after WaitBits=%x @tick=%d",eBits,xTaskGetTickCount());

#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
    portTickType tBefore=xTaskGetTickCount();
    portTickType tAfter=xTaskGetTickCount();
#endif

See that #ifdef ?
me-no-dev optimized it incorrectly from my code. Change it to this:

   i2c->dev->ctr.trans_start=1; // go for it

#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
    portTickType tBefore=xTaskGetTickCount();
#endif

    uint32_t eBits = xEventGroupWaitBits(i2c->i2c_event,EVENT_DONE,pdFALSE,pdTRUE,ticksTimeOut);

    //log_e("after WaitBits=%x @tick=%d",eBits,xTaskGetTickCount());

#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
    portTickType tAfter=xTaskGetTickCount();
#endif

That will fix the error message, But, It won't fix your problem.

Chuck.

@echoGee
Copy link
Author

echoGee commented Apr 29, 2018

Attached is the INFO level logs with the changes
Error 1

ypr 110.71 -3.56 12.57
ypr 110.75 -3.56 12.56
[E][esp32-hal-i2c.c:1042] i2cProcQueue(): Gross Timeout Dead start=0x2cd5, end=0x2d08, =51, max=51 error=1
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): i2c=0x3ffc10ac
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): lock=0x3ffda538
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): event=0x3ffda458 bits=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): intr_handle=0x3ffd9e88
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): dq=0x3ffda428
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1437] i2cDumpI2c(): byteCnt=43
[E][esp32-hal-i2c.c:1394] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc33fc, len=42, pos=30, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1412] i2cDumpDqData(): 0x0000: ....$+..4J.........t..9....0..<. 05 a1 f3 d3 24 2b f2 aa 34 4a f7 9c 04 9e aa e5 00 02 18 74 00 02 39 fb ff fd d1 30 fc 03 3c 16
[E][esp32-hal-i2c.c:1412] i2cDumpDqData(): 0x0020: .....3...j 08 86 b9 9b e1 33 1f a4 b2 6a
[E][esp32-hal-i2c.c:1447] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [01] 0x0001 0x0002 0x0001 0x0000 0x00002cd5
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00002cd5
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [03] 0x001e 0x0040 0x0000 0x0000 0x00002cd6
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [04] 0x0001 0x0041 0x0000 0x001e 0x00002cd6
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [05] 0x000c 0x0040 0x0000 0x0000 0x00002cd7
ypr 110.79 -3.57 12.55
[E][esp32-hal-i2c.c:1042] i2cProcQueue(): Gross Timeout Dead start=0x2d96, end=0x2dc8, =50, max=50 error=1
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): i2c=0x3ffc10ac
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): lock=0x3ffda538
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): event=0x3ffda458 bits=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): intr_handle=0x3ffd9e88
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): dq=0x3ffda428
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1437] i2cDumpI2c(): byteCnt=2
[E][esp32-hal-i2c.c:1394] i2cDumpDqData(): [0] d0 W STOP buf@=0x3ffc3482, len=1, pos=1, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1412] i2cDumpDqData(): 0x0000: r 72
[E][esp32-hal-i2c.c:1447] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [01] 0x0001 0x0002 0x0002 0x0000 0x00002d96
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00002d96
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [03] 0x0002 0x0040 0x0000 0x0000 0x00002d97
FIFO overflow!
FIFO overflow!
ypr 112.07 -3.62 12.27
ypr 112.10 -3.63 12.27

Error 2

ypr 115.11 -3.67 11.84
[E][esp32-hal-i2c.c:1042] i2cProcQueue(): Gross Timeout Dead start=0x3198, end=0x31ca, =50, max=50 error=1
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): i2c=0x3ffc10ac
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): lock=0x3ffda538
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): event=0x3ffda458 bits=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): intr_handle=0x3ffd9e88
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): dq=0x3ffda428
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1437] i2cDumpI2c(): byteCnt=2
[E][esp32-hal-i2c.c:1394] i2cDumpDqData(): [0] d0 W STOP buf@=0x3ffc3482, len=1, pos=1, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1412] i2cDumpDqData(): 0x0000: r 72
[E][esp32-hal-i2c.c:1447] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [01] 0x0001 0x0002 0x0002 0x0000 0x00003198
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00003198
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [03] 0x0002 0x0040 0x0000 0x0000 0x00003198
ypr 115.14 -3.68 11.83
ypr 115.19 -3.67 11.83
ypr 115.22 -3.68 11.82
ypr 115.25 -3.69 11.82
ypr 115.29 -3.69 11.82
[E][esp32-hal-i2c.c:1042] i2cProcQueue(): Gross Timeout Dead start=0x3256, end=0x3288, =50, max=50 error=1
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): i2c=0x3ffc10ac
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): lock=0x3ffda538
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): event=0x3ffda458 bits=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): intr_handle=0x3ffd9e88
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): dq=0x3ffda428
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1437] i2cDumpI2c(): byteCnt=2
[E][esp32-hal-i2c.c:1394] i2cDumpDqData(): [0] d0 W STOP buf@=0x3ffc3482, len=1, pos=1, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1412] i2cDumpDqData(): 0x0000: r 72
[E][esp32-hal-i2c.c:1447] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [01] 0x0001 0x0002 0x0002 0x0000 0x00003256
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00003256
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [03] 0x0002 0x0040 0x0000 0x0000 0x00003256
FIFO overflow!
[E][esp32-hal-i2c.c:1042] i2cProcQueue(): Gross Timeout Dead start=0x32f5, end=0x3327, =50, max=50 error=1
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): i2c=0x3ffc10ac
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): lock=0x3ffda538
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): event=0x3ffda458 bits=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): intr_handle=0x3ffd9e88
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): dq=0x3ffda428
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1437] i2cDumpI2c(): byteCnt=3
[E][esp32-hal-i2c.c:1394] i2cDumpDqData(): [0] d0 W STOP buf@=0x3ffc3482, len=2, pos=2, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1412] i2cDumpDqData(): 0x0000: j. 6a c4
[E][esp32-hal-i2c.c:1447] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x000032f5
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000032f5
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x000032f5
FIFO overflow!
ypr 116.40 -3.69 11.72
ypr 116.44 -3.69 11.72
ypr 116.47 -3.69 11.72
ypr 116.51 -3.69 11.71
[E][esp32-hal-i2c.c:1042] i2cProcQueue(): Gross Timeout Dead start=0x33b1, end=0x33e3, =50, max=50 error=1
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): i2c=0x3ffc10ac
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): lock=0x3ffda538
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): event=0x3ffda458 bits=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): intr_handle=0x3ffd9e88
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): dq=0x3ffda428
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1437] i2cDumpI2c(): byteCnt=2
[E][esp32-hal-i2c.c:1394] i2cDumpDqData(): [0] d0 W STOP buf@=0x3ffc3482, len=1, pos=1, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1412] i2cDumpDqData(): 0x0000: r 72
[E][esp32-hal-i2c.c:1447] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [01] 0x0001 0x0002 0x0002 0x0000 0x000033b1
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000033b1
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [03] 0x0002 0x0040 0x0000 0x0000 0x000033b1
FIFO overflow!
FIFO overflow!
ypr 117.65 -3.71 11.63

@stickbreaker
Copy link
Contributor

stickbreaker commented Apr 29, 2018

@echoGee thanks for the debug output, Let me think about what is going wrong, The dumpInts() sequence is weird:

[E][esp32-hal-i2c.c:1042] i2cProcQueue(): Gross Timeout Dead start=0x2cd5, end=0x2d08, =51, max=51 error=1
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): i2c=0x3ffc10ac
[E][esp32-hal-i2c.c:1424] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1426] i2cDumpI2c(): lock=0x3ffda538
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): event=0x3ffda458 bits=0
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): intr_handle=0x3ffd9e88
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): dq=0x3ffda428
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1437] i2cDumpI2c(): byteCnt=43
[E][esp32-hal-i2c.c:1394] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc33fc, len=42, pos=30, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1412] i2cDumpDqData(): 0x0000: ....$+..4J.........t..9....0..<. 05 a1 f3 d3 24 2b f2 aa 34 4a f7 9c 04 9e aa e5 00 02 18 74 00 02 39 fb ff fd d1 30 fc 03 3c 16
[E][esp32-hal-i2c.c:1412] i2cDumpDqData(): 0x0020: .....3...j 08 86 b9 9b e1 33 1f a4 b2 6a
[E][esp32-hal-i2c.c:1447] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [01] 0x0001 0x0002 0x0001 0x0000 0x00002cd5
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00002cd5
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [03] 0x001e 0x0040 0x0000 0x0000 0x00002cd6
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [04] 0x0001 0x0041 0x0000 0x001e 0x00002cd6
[E][esp32-hal-i2c.c:1451] i2cDumpInts(): [05] 0x000c 0x0040 0x0000 0x0000 0x00002cd7

Ok, decoding this dump, A Wire.requestFrom(0x68,42,true) Calculated to take 1ms to process with a 51ms timeout.
The dumpInts():
[01] fill txFifo with 1 character(0x68+read) 0xD1 at tick 0x2cd5
[02] Start I2C communications at tick 0x2cd5
[03] moved 31 bytes, 1 out, 30 into rxFifo at tick 0x2cd6 (time of last character receive)
[04] receive 1 more character into rxFifo, and trigger rxFifoFull, empty 31 characters from rxFifo at tick 0x2cd6
[05] moved 12 more bytes into rxFifo at tick 0x2cd7 (2ms after starting?)

There should be more interrupts, either some Timeouts, or the Stop (0x80).

Are you using long critical sections in your code? Something shutdown interrupts for a long time.

Something is either wrong in stickbreaker-i2c.
Chuck.

@echoGee
Copy link
Author

echoGee commented Apr 29, 2018

Are you using long critical sections in your code? Something shutdown interrupts for a long time.

None that I have implemented. I'm virtually using the code given in #1352 (comment)

Is anything related to the Wifi call or any interrupt requests from Wifi the troublemaker ? Just reminding that connectToWifi() is what weirdifies the i2c read.

@stickbreaker
Copy link
Contributor

@echoGee More debug:
at the end of i2cProcQueue():

   } else { // GROSS timeout, shutdown ISR , report Timeout
        i2c->stage = I2C_DONE;
        i2c->dev->int_ena.val =0;
        i2c->dev->int_clr.val = 0x1FFF;
        if((i2c->queuePos==0)&&(i2c->byteCnt==0)) { // Bus Busy no bytes Moved
            reason = I2C_ERROR_BUSY;
            eBits = eBits | EVENT_ERROR_BUS_BUSY|EVENT_ERROR|EVENT_DONE;
#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
            log_e(" Busy Timeout start=0x%x, end=0x%x, =%d, max=%d error=%d",tBefore,tAfter,(tAfter-tBefore),ticksTimeOut,i2c->error);
            i2cDumpI2c(i2c);
            i2cDumpInts(i2c->num);
#endif
        } else { // just a timeout, some data made it out or in.
            reason = I2C_ERROR_TIMEOUT;
            eBits = eBits | EVENT_ERROR_TIMEOUT|EVENT_ERROR|EVENT_DONE;

#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
            log_e(" Gross Timeout Dead start=0x%x, end=0x%x, =%d, max=%d error=%d",tBefore,tAfter,(tAfter-tBefore),ticksTimeOut,i2c->error);
            i2cDumpI2c(i2c);
            i2cDumpInts(i2c->num);
#endif
        }
    }

add
dumpCmdQueue(i2c); after i2cDumpInts(i2c->num);

Chuck.

@stickbreaker
Copy link
Contributor

@echoGee Try increasing the timeout with Wire.setTimeOut(1000); give it 1 second instead of the default 50ms.

chuck.

@stickbreaker
Copy link
Contributor

@echoGee Maybe the Wifi is disabling interrupts longer than 50ms and there is an interrupt pending.

    uint32_t eBits = xEventGroupWaitBits(i2c->i2c_event,EVENT_DONE,pdFALSE,pdTRUE,ticksTimeOut);

times out and shuts down the ISR before it can receive the last interrupt and complete the transaction. The i2c hardware has successfully completed the data transfer, but the ISR has not processed the STOP.

Chuck.

@stickbreaker
Copy link
Contributor

stickbreaker commented Apr 29, 2018

@echoGee That would make sense with the original problem of no 'interrupt source'.

  • WiFi disabled interrupts,
  • i2c hardware triggered an interrupt, but since interrupts are disabled, it is held pending the WiFi re-enabling interrupts
  • i2cProcQueue() timed out, cleared interrupt status, disabled new i2c Interrupts,
  • WiFi re-enabled interrupts
  • i2c_isr_handler_default()receives the interrupt, but the interrupt status value is already cleared, it has nothing to do and exits.

See if increasing the TimeOut fixes this problem.

Chuck.

@echoGee
Copy link
Author

echoGee commented Apr 29, 2018

Why would WiFi disable interrupts? If any, it would run an ISR that would take too long to complete. That what you mean ?

@echoGee
Copy link
Author

echoGee commented Apr 29, 2018

Debugs with the i2cDumpI2c function . Note that the timeout has not been increased yet.

ypr 119.91 -18.79 8.98
ypr 119.94 -18.79 8.96
[E][esp32-hal-i2c.c:997] i2cProcQueue(): TimeoutRecovery: expected=0ms, actual=50ms
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1110
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffda628
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffda56c bits=0
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffd9f78
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffda5f4
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=3
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc345c, len=2, pos=2, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: .* 00 2a
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0001 0x0000 0x000009a4
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000009a4
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x000009a4
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0002 0x000009a4
[E][esp32-hal-i2c.c:997] i2cProcQueue(): TimeoutRecovery: expected=0ms, actual=50ms
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1110
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffda628
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffda56c bits=0
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffd9f78
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffda5f4
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=2
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] d0 W STOP buf@=0x3ffc34e2, len=1, pos=1, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: t 74
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0002 0x0000 0x00000a46
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000a46
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [03] 0x0002 0x0040 0x0000 0x0000 0x00000a46
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x00000a46
[E][esp32-hal-i2c.c:997] i2cProcQueue(): TimeoutRecovery: expected=1ms, actual=51ms
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1110
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffda628
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffda56c bits=0
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffd9f78
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffda5f4
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=43
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc345c, len=42, pos=42, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: .............c.j......&.7....O.& af a8 f4 84 06 96 06 a6 ee 0e e3 18 f5 63 b2 6a 0b 8d 06 e1 1e 85 26 c4 37 0d 16 92 ff 4f fe 26
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0020: ...G..E(.. 00 02 0d 47 00 02 45 28 ff fd
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0001 0x0000 0x00000ae8
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000ae8
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [03] 0x001e 0x0040 0x0000 0x0000 0x00000ae9
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [04] 0x0001 0x0041 0x0000 0x001e 0x00000ae9
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [05] 0x000c 0x0040 0x0000 0x0000 0x00000ae9
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [06] 0x0001 0x0080 0x0000 0x000c 0x00000ae9
ypr -12.31 -25.85 -5.61
[E][esp32-hal-i2c.c:997] i2cProcQueue(): TimeoutRecovery: expected=0ms, actual=50ms
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1110
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffda628
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffda56c bits=0
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffd9f78
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffda5f4
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=2
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] d0 W STOP buf@=0x3ffc34e2, len=1, pos=1, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: : 3a
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0002 0x0000 0x00000baf
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000baf
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [03] 0x0002 0x0040 0x0000 0x0000 0x00000baf
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x00000baf
FIFO overflow!
ypr 121.87 -18.34 8.25
ypr 121.89 -18.34 8.24
ypr 121.92 -18.33 8.24
ypr 121.95 -18.32 8.23
ypr 121.97 -18.32 8.22
ypr 122.00 -18.32 8.21
[E][esp32-hal-i2c.c:997] i2cProcQueue(): TimeoutRecovery: expected=0ms, actual=4ms
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1110
[D][WiFiGeneric.cpp:293] _eventCallback(): Event: 4 - STA_CONNECTED
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
WifiEvent: [E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffda628
4[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffda56c bits=10
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffd9f78
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffda518
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=2
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] d0 W STOP buf@=0x3ffc34e2, len=1, pos=1, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: : 3a
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0002 0x0000 0x00000c91
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000c91
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [03] 0x0002 0x0040 0x0000 0x0000 0x00000c91
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x00000c91
ypr 122.03 -18.31 8.20
ypr 122.05 -18.31 8.20

ypr 123.38 -18.10 7.90
[E][esp32-hal-i2c.c:1041] i2cProcQueue(): Gross Timeout Dead start=0xe99, end=0xecb, =50, max=50 error=1
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1110
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffda628
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffda56c bits=0
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffd9f78
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffdae2c
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=3
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc345c, len=2, pos=0, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: .. 03 03
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0001 0x0000 0x00000e99
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000e99
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x00000e99
ypr 123.40 -18.09 7.89
ypr 123.43 -18.09 7.89
ypr 123.45 -18.09 7.88
ypr 123.48 -18.08 7.88
ypr 123.50 -18.08 7.88
[E][esp32-hal-i2c.c:997] i2cProcQueue(): TimeoutRecovery: expected=0ms, actual=2ms
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1110
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffda628
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffda56c bits=10
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffd9f78
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffdae2c
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=2
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc345c, len=1, pos=1, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: . 01
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0001 0x0000 0x00000f59
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000f59
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [03] 0x0002 0x0040 0x0000 0x0000 0x00000f59
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0001 0x00000f59
FIFO overflow!
FIFO overflow!
ypr 124.24 -18.00 7.77

@echoGee
Copy link
Author

echoGee commented Apr 29, 2018

@stickbreaker Confirming that increasing the timeout to 1000ms has NOT removed the error.

@stickbreaker
Copy link
Contributor

This error is showing that the ISR was unable to notify i2cProcQueue() that it completed successfully.
the dumpints() [04] shows the transaction was completed within 1ms, but ISR was not able to notify i2cProcQueue() via the EventGroup.

[E][esp32-hal-i2c.c:997] i2cProcQueue(): TimeoutRecovery: expected=0ms, actual=50ms
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1110
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffda628
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffda56c bits=0
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffd9f78
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffda5f4
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=3
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] d1 R STOP buf@=0x3ffc345c, len=2, pos=2, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: .* 00 2a
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0001 0x0000 0x000009a4
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000009a4
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x000009a4
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0002 0x000009a4

Set your timeout to 1000, and set the debug level back to Error. The timeout Recovery message is just an Info level output. It is not actually an error.

Chuck.

@echoGee
Copy link
Author

echoGee commented Apr 30, 2018

@stickbreaker , commenting at the Bottom of i2c_isr_default_handler() is part of the fix, correct?

activeInt = p_i2c->dev->int_status.val; // start all over if another interrupt happened 

@stickbreaker
Copy link
Contributor

Na, put that line back in. I think the only problem was too short of timeout.

@copercini
Copy link
Contributor

Fixed on #1767 =)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants