i2c speed dropping down

[xiruilin]

My i2c device is support high speed to 1MHz, it works good in 100kHz.
When update to new Wire library, it only work down to 50kHz, Why?

[stickbreaker]

@xiruilin What problems are you seeing? Error Messages? What is your Circuit? I need more Info before I can diagnose your problem.

Chuck.

[xiruilin]

Error Messages:
[E][esp32-hal-i2c.c:1032] i2cProcQueue(): Busy Timeout start=0xcfed, end=0xd01f, =50, max=50 error=5
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1030
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffb2e24
[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=5
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffb2eac bits=100
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffb9b50
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffb9ae8
[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=0
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] 7c W STOP buf@=0x3ffc363a, len=2, pos=2, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: .. 01 02
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x0000cfed
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x0000cfed
[W][esp32-hal-i2c.c:1097] i2cCheckLineState(): invalid state sda=0, scl=1

[E][esp32-hal-i2c.c:1113] i2cCheckLineState(): Bus Invalid State, TwoWire() Can't init
[E][esp32-hal-i2c.c:1032] i2cProcQueue(): Busy Timeout start=0xd090, end=0xd0c2, =50, max=50 error=5
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1030
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffb2e24
[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=5
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffb2eac bits=100
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffb9b50
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffb9ae8
[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=0
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] 7d R STOP buf@=0x3ffc35b4, len=2, pos=0, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: .. ff ff
[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 0x0000d090
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0002 0x0200 0x0000 0x0000 0x0000d090
[W][esp32-hal-i2c.c:1097] i2cCheckLineState(): invalid state sda=0, scl=1

[E][esp32-hal-i2c.c:1113] i2cCheckLineState(): Bus Invalid State, TwoWire() Can't init
Working Status:FFFF
[E][esp32-hal-i2c.c:1032] i2cProcQueue(): Busy Timeout start=0xd136, end=0xd168, =50, max=50 error=5
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1030
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffb2e24
[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=5
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffb2eac bits=100
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffb9b50
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffb9ae8
[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=0
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] 7c W STOP buf@=0x3ffc363a, len=2, pos=2, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: .. 01 02
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x0000d136
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0002 0x0200 0x0000 0x0000 0x0000d136
[W][esp32-hal-i2c.c:1097] i2cCheckLineState(): invalid state sda=0, scl=1

[E][esp32-hal-i2c.c:1113] i2cCheckLineState(): Bus Invalid State, TwoWire() Can't init
[E][esp32-hal-i2c.c:1032] i2cProcQueue(): Busy Timeout start=0xd1da, end=0xd20c, =50, max=50 error=5
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1030
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffb2e24
[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=5
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffb2eac bits=100
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffb9b50
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffb9ae8
[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=0
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] 7d R STOP buf@=0x3ffc35b4, len=2, pos=0, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: .. ff ff
[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 0x0000d1da
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0002 0x0200 0x0000 0x0000 0x0000d1da
[W][esp32-hal-i2c.c:1097] i2cCheckLineState(): invalid state sda=0, scl=1

[E][esp32-hal-i2c.c:1113] i2cCheckLineState(): Bus Invalid State, TwoWire() Can't init

[stickbreaker]

@xiruilin ok,

Error Messages:
[E][esp32-hal-i2c.c:1032] i2cProcQueue(): Busy Timeout start=0xcfed, end=0xd01f, =50, max=50 error=5
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc1030
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffb2e24
[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=5
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffb2eac bits=100
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffb9b50
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffb9ae8
[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=0
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] 7c W STOP buf@=0x3ffc363a, len=2, pos=2, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: .. 01 02
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x0000cfed
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x0000cfed
[W][esp32-hal-i2c.c:1097] i2cCheckLineState(): invalid state sda=0, scl=1

[E][esp32-hal-i2c.c:1113] i2cCheckLineState(): Bus Invalid State, TwoWire() Can't init

This sequence of error messages is telling you:

[E][esp32-hal-i2c.c:1032] i2cProcQueue(): Busy Timeout start=0xcfed, end=0xd01f, =50, max=50 error=5

The i2c hardware peripheral saw someone else using the bus, it waited 50ms, but the bus was never released.

[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=0
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] 7c W STOP buf@=0x3ffc363a, len=2, pos=2, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: .. 01 02

You were sending a Write command equivalent to:

Wire.beginTransmission(0x3e);
Wire.write(0x01);
Wire.write(0x02);
Wire.endTransmission(true);

[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x0000cfed
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x0000cfed

This is the interrupt sequence received by the ISR handler:
First it received one TX_FIFO_EMPTY irq: [01] 0x0001 0x0002
and it move three bytes into the TX Fifo: 0x0003
this happened at millisecond: 0x0000cfed

Then it received a second interrupt, the START at millisecond: 0x0000cfed: [02] 0x0001 0x0200 0x0000 0x0000 0x0000cfed

Then the default 50ms timeout expired, and it exited with a Bus Busy error.

It then tried to clear the bus by manually stimulating it:

[W][esp32-hal-i2c.c:1097] i2cCheckLineState(): invalid state sda=0, scl=1

[E][esp32-hal-i2c.c:1113] i2cCheckLineState(): Bus Invalid State, TwoWire() Can't init

but failed. the SDA gpio pin was held LOW and did not respond to the manual bus clearing cycle.

This is the code from /cores/esp32/esp32-hal-i2c.c:

static bool i2cCheckLineState(int8_t sda, int8_t scl){
    if(sda < 0 || scl < 0){
        return true;//return true since there is nothing to do
    }
    // if the bus is not 'clear' try the recommended recovery sequence, START, 9 Clocks, STOP
    digitalWrite(sda, HIGH);
    digitalWrite(scl, HIGH);
    pinMode(sda, PULLUP|OPEN_DRAIN|OUTPUT|INPUT);
    pinMode(scl, PULLUP|OPEN_DRAIN|OUTPUT|INPUT);

    if(!digitalRead(sda) || !digitalRead(scl)) { // bus in busy state
        log_w("invalid state sda=%d, scl=%d\n", digitalRead(sda), digitalRead(scl));
        digitalWrite(sda, HIGH);
        digitalWrite(scl, HIGH);
        delayMicroseconds(5);
        digitalWrite(sda, LOW);
        for(uint8_t a=0; a<9; a++) {
            delayMicroseconds(5);
            digitalWrite(scl, LOW);
            delayMicroseconds(5);
            digitalWrite(scl, HIGH);
        }
        delayMicroseconds(5);
        digitalWrite(sda, HIGH);
    }

    if(!digitalRead(sda) || !digitalRead(scl)) { // bus in busy state
        log_e("Bus Invalid State, TwoWire() Can't init");
        return false; // bus is busy
    }
    return true;
}

These error message are telling me that you have a hardware fault, the SDA pin is LOW.

Chuck.

[xiruilin]

Thanks @stickbreaker for your detailed answers.

The same device，use old Wire library, it works good at 100kHz,
use new Wire library, it only works good at 50kHz.

Because our application needs to transmit a lot of data through i2c, so the speed of using 50kHz is much slower than that of 100kHz. May I trouble you to see if there is any solution?

Thanks again!

[stickbreaker]

@xiruilin what i2c device are you using?
Post the code you are using.
I'll see if i can identify the problem.

Chuck.

[copercini]

Fixed with #1767 =)