WITH_LOCK( Wire ) - Seems like it's not working

We’ve built a fairly complex, modular expansion system, built on the I²C bus, but we recently started having a lot of trouble with the bus locking up on us. I thought we’d had everything sorted out by tracing the problem to updating a certain I²C component using a timer. I added WITH_LOCK( Wire ) all over the place, and it seemed to get much better. However, I still have a couple customers with problems.

It seems like I still have communication that seems to be overlapping, as shown by the log outputs here.

Correct Sequence:

I2C_DEBUG -> ReadBytes() for 0x60: 0xA5CE00204D, Status = 3
I2C_DEBUG -> WriteByte() for 0x71: 0x0F, Status = 3, Stop = 1
I2C_DEBUG -> WriteBytes() for 0x60: 0x0000, Status = 3
I2C_DEBUG -> ReadBytes() for 0x60: 0xA5CE00204D, Status = 3
I2C_DEBUG -> WriteByte() for 0x71: 0x00, Status = 3, Stop = 1
PCA9698_DEBUG -> Write (20), Status = 0 -> 889DFF00
PCA9698_DEBUG -> Write (20), Status = 0 -> 980000DF
PCA9698_DEBUG -> Write (20), Status = 0 -> 2A03
I2C_DEBUG -> WriteBytes() for 0x48: 0x014483, Status = 3
I2C_DEBUG -> WriteByte() for 0x48: 0x00, Status = 3, Stop = 1
I2C_DEBUG -> ReadBytes() for 0x48: 0x0000, Status = 3
I2C_DEBUG -> WriteBytes() for 0x48: 0x015483, Status = 3
I2C_DEBUG -> WriteByte() for 0x48: 0x00, Status = 3, Stop = 1

Overlapping Sequence (*** added to try to highlight discrete messages):

I2C_DEBUG -> WriteByte() for 0x2D: 0x23, Status = 3, Stop = 0
I2C_DEBUG -> ReadBytes() for 0x2D: 0x0300, Status = 3
I2C_DEBUG -> WriteByte() for 0x71: 0x08, Status = 3, Stop = 1
I2C_DEBUG -> WriteBytes() for 0x60: 0x0527, Status = 3
I2C_DEBUG -> Re****PCA9698_DEBUG -> Write (20), Status = 0 -> 8899FF00****
adBytes() for 0x60: 0xA5CE00204D, Status = 0
I2C_DEBUG -> WriteByte() for 0x71: 0x09, Status = 3, Stop = 1
I2C_DEBUG -> WriteBytes() for 0x60: 0x06****PCA9698_DEBUG -> Write (20), Status = 0 -> 980000DF
PCA9698_DEBUG -> Write (2****57, Status = 3
I2C_DEBUG -> ReadBytes() for 0x60: 0xA5CE00204D, Status = 0
****0), Status = 0 -> 2A03****
I2C_DEBUG -> WriteByte() for 0x71: 0x0A, Status = 3, Stop = 1
I2C_DEBUG -> WriteBytes() for 0x60: 0x0000, Status = 3
I2C_DEBUG -> ReadBytes() for 0x60: 0xA5CE00204D, Status = 3
I2C_DEBUG -> WriteByte() for 0x71: 0x0B, Status = 3, Stop = 1
I2C_DEBUG -> WriteBytes() for 0x60: 0x0000, Status = 3
I2C_DEBUG -> ReadBytes() for 0x60: 0xA5CE00204D, Status = 3

The error statuses are because I’m on a dev board that only has the PCA9698 on the bus, but I think that shouldn’t be a problem. I’d also chalk up the overlapping outputs to a serial write issue, but when it occurs, you can actually see it reports status 0 from endTransmission() on 0x60, which doesn’t actually exist on the bus physically. So it seems like something is happening to the actual I²C communication.

Here are some code snippets with the locking in place. Is there something I’m doing wrong?

void PCA9698::writeBytes( uint8_t* data, size_t length )
{
    WITH_LOCK( Wire )
    {
        if ( !Wire.isEnabled() )
        {
            Wire.begin();
        }

        Wire.beginTransmission( _address );
        Wire.write( data, length );
        uint8_t status = Wire.endTransmission();

#ifdef PCA9698_DEBUG
        Serial.printlnf( "PCA9698_DEBUG -> Write (%02X), Status = %i -> %s", _address, status, getHexStringFromBytes( data, length ).c_str() );
#endif
    }
}
uint8_t I2CService::ReadByte()
{
    uint8_t data = 0;

    WITH_LOCK( Wire )
    {
        if ( !Wire.isEnabled() )
        {
            Wire.begin();
        }

        Wire.requestFrom( _address, (uint8_t) 1 );

        data = Wire.read();

#ifdef I2C_DEBUG
        Serial.printlnf( "I2C_DEBUG -> ReadByte() for 0x%02X: 0x%02X", _address, data );
#endif
    }

    return data;
}

void I2CService::ReadBytes( uint8_t* buffer, size_t length )
{
    WITH_LOCK( Wire )
    {
        if ( !Wire.isEnabled() )
        {
            Wire.begin();
        }

        Wire.requestFrom( _address, length );

        for ( size_t i = 0; i < length && Wire.available(); i++ )
        {
            buffer[i] = Wire.read();
        }

#ifdef I2C_DEBUG
        Serial.printlnf( "I2C_DEBUG -> ReadBytes() for 0x%02X: 0x%s, Status = %i", _address, getHexStringFromBytes( buffer, length ).c_str(), Wire.endTransmission() );
#else
        Wire.endTransmission();
#endif
    }
}

bool I2CService::WriteByte( uint8_t data, bool stop )
{
    uint8_t status;

    WITH_LOCK( Wire )
    {
        if ( !Wire.isEnabled() )
        {
            Wire.begin();
        }

        Wire.beginTransmission( _address );
        Wire.write( data );

        status = Wire.endTransmission( stop );

#ifdef I2C_DEBUG
        Serial.printlnf( "I2C_DEBUG -> WriteByte() for 0x%02X: 0x%02X, Status = %i, Stop = %i", _address, data, status, stop );
#endif
    }

    return status == 0;
}

bool I2CService::WriteBytes( uint8_t* data, size_t length )
{
    uint8_t status;

    WITH_LOCK( Wire )
    {
        if ( !Wire.isEnabled() )
        {
            Wire.begin();
        }

        Wire.beginTransmission( _address );

        for ( size_t i = 0; i < length; i++ )
        {
            Wire.write( data[i] );
        }

        status = Wire.endTransmission();

#ifdef I2C_DEBUG
        Serial.printlnf( "I2C_DEBUG -> WriteBytes() for 0x%02X: 0x%s, Status = %i", _address, getHexStringFromBytes( data, length ).c_str(), status );
#endif
    }

    return status == 0;
}

It’s hard to tell for sure, but I think you have the locking at too low of a level to work properly.

As soon as the WITH_LOCK exits another thread can take over the I2C bus. But the way you have the locks organized above, it looks like the following scenario could occur:

Many I2C transactions require multiple operations. For example, reading a register on the PCA9698 requires a write (stop = false) to specify the register you want to read, then a read of the register data. You need to have a lock surrounding the whole operation. Not the individual write and read.

With the locking at too low of a level, one thread can do the write (stop = false) and another thread can then take over the I2C bus before the read, and things will be hopelessly confused.

1 Like

Yeah, I definitely have been combing through looking for those write/read scenarios too. In this particular case, I’m only writing to the PCA9698. In the less common scenario where we read from it, we use this:

uint8_t PCA9698::readBank( uint8_t index )
{
    uint8_t data = 0x00;

    WITH_LOCK( Wire )
    {
        if ( !Wire.isEnabled() )
        {
            Wire.begin();
        }

        Wire.beginTransmission( _address );
        Wire.write( index );
        Wire.endTransmission();

        Wire.beginTransmission( _address );
        Wire.requestFrom( _address, (uint8_t) 1 );
        data = Wire.read();
        Wire.endTransmission();
    }

    return data;
}

I was looking at that code yesterday and noticed we’re sending a stop in between, which doesn’t seem right, but it’s also always worked to my knowledge. However, this code isn’t involved in my original example either.