smbus read_i2c_block_data Fails on Latest Kernel

[DexterInd]

Hey folks, noticed a problem when we went to update to the latest kernel on June 17 2017. I tried to isolate it as best I could with the following description. The smbus call read_i2c_block_data fails to do a block read. A couple of quick bullet

• This does not seem to affect the write function or the single byte read function on smbus.
• The clock speed of I2C has not changed.
• I'm able to reproduce the problem using the same hardware (Pi3), a voltage level converter, and an atmega chip.
• The I2C function clearly works with kernel 4.4.50-v7+
• The I2C function fails when I update to kernel 4.9.24-v7+

I did the following to test and isolate the problem with the firmware, I created the following python script (pasted below). First, running on Jessi Lite 2017.01.11 I checked the kernel version, the updated Jessi Lite with the necessary support

#   sudo apt-get install python-pip python-smbus
#   sudo pip install future
#   sudo raspi-config to enable i2c

Running with the older firmware, I get a healthy response from the function read_i2c_block_data.

Then, updating to the latest firmware 4.9+ I run the same python script, and get a failure to read.

Below is the python code you can use to replicate the problem.

# Start with raspbian jessi lite 2017.01.11
# Prep with 
#   sudo apt-get install python-pip python-smbus
#   sudo pip install future
#   sudo raspi-config to enable i2c

#   This works at first using FW version    -   Linux raspberrypi 4.4.50-v7+

#   Update the firmware with sudo apt-get update && sudo apt-get install raspberrypi-kernel
#   sudo reboot
#   To not working with version FW          -   Linux raspberrypi 4.9.24-v7+ #993

from __future__ import print_function
from __future__ import division
from builtins import input

import time
import smbus
import time
import math
import RPi.GPIO as GPIO
import struct
import operator
import pickle

# This allows us to be more specific about which commands contain unused bytes
unused = 0

rev = GPIO.RPI_REVISION
if rev == 2 or rev == 3:
	bus = smbus.SMBus(1)
else:
	bus = smbus.SMBus(0)

# I2C Address of Arduino
address = 0x06

# Command Format
# analogRead() command format header
aRead_cmd = [3]

def read_sensor():
    time.sleep(1)
    try:
        bus.write_i2c_block_data(address, 1, aRead_cmd + [unused, unused, unused])
        number = bus.read_i2c_block_data(address, 1)
        return number[0]* 256 + number[1],number[2]* 256 + number[3],number[4]* 256 + number[5],number[6]* 256 + number[7],number[8]* 256 + number[9]
        time.sleep(.05)
    except IOError:
        return -1,-1,-1,-1,-1

while True:
    print(read_sensor())`

[DexterInd]

Sorry, one more piece of info on this: If I roll back the kernel version to kernel 4.4.50-v7+ the python function begins to read properly again.

[P33M]

In the second (broken) trace, the transfer diverges at the third Start bus state. The second transfer looks like it's doing a repeated start but terminating after a byte, whereas the first transfer does a stop then start and continues normally.

What is the output of lsmod on both 4.4 and 4.9?

[pelwell]

Can you try adding dtoverlay=i2c1_bcm2708? This reverts to using the old downstream I2C driver.

[DexterInd]

@P33M Re output of lsmod:

For 4.4.50-v7+

Module                  Size  Used by
bnep                   10340  2
bluetooth             326105  5 bnep
lirc_dev                8310  0
rc_core                16468  1 lirc_dev
sg                     18319  0
brcmfmac              186403  0
brcmutil                5661  1 brcmfmac
cfg80211              428871  1 brcmfmac
rfkill                 16037  4 cfg80211,bluetooth
snd_bcm2835            20447  2
snd_pcm                75762  1 snd_bcm2835
snd_timer              19288  1 snd_pcm
snd                    51908  7 snd_bcm2835,snd_timer,snd_pcm
bcm2835_gpiomem         2976  2
spi_bcm2835             6678  0
bcm2835_wdt             3225  0
uio_pdrv_genirq         3164  0
uio                     8000  1 uio_pdrv_genirq
i2c_dev                 5859  0
i2c_bcm2708             4834  0
fuse                   84037  5
ipv6                  347620  61

After an upgrade . . .
For 4.9.28-v7+

Module                  Size  Used by
bnep                   12051  2
hci_uart               19956  1
btbcm                   7916  1 hci_uart
bluetooth             365511  22 hci_uart,bnep,btbcm
sg                     20825  0
brcmfmac              222874  0
brcmutil                9092  1 brcmfmac
cfg80211              543027  1 brcmfmac
rfkill                 20851  4 bluetooth,cfg80211
snd_bcm2835            24427  0
snd_pcm                98501  1 snd_bcm2835
snd_timer              23904  1 snd_pcm
snd                    70032  3 snd_timer,snd_bcm2835,snd_pcm
i2c_bcm2835             7167  0
bcm2835_gpiomem         3940  0
fixed                   3285  0
uio_pdrv_genirq         3923  0
uio                    10204  1 uio_pdrv_genirq
i2c_dev                 6913  0
ipv6                  406751  33

[DexterInd]

@pelwell to test this, I pasted dtoverlay=i2c1_bcm2708 in /boot/config.txt and rebooted. I am still seeing the same behavior. Was there anything else I was supposed to do?

When I do that I see:

pi@raspberrypi:~ $ lsmod
Module                  Size  Used by
bnep                   12051  2
hci_uart               19956  1
btbcm                   7916  1 hci_uart
bluetooth             365511  22 hci_uart,bnep,btbcm
sg                     20825  0
brcmfmac              222874  0
brcmutil                9092  1 brcmfmac
cfg80211              543027  1 brcmfmac
rfkill                 20851  4 bluetooth,cfg80211
snd_bcm2835            24427  0
i2c_bcm2835             7167  0
snd_pcm                98501  1 snd_bcm2835
snd_timer              23904  1 snd_pcm
snd                    70032  3 snd_timer,snd_bcm2835,snd_pcm
bcm2835_gpiomem         3940  0
fixed                   3285  0
uio_pdrv_genirq         3923  0
uio                    10204  1 uio_pdrv_genirq
i2c_dev                 6913  0
ipv6                  406751  34

[DexterInd]

@pelwell also just tried to change that line to dtoverlay=i2c1_bcm2708,sda1_pin=2,scl1=3,pin_func=6 (I am not sure where to find the numbering for the GPIO's). This didn't change the i2c behavior.

Output of lsmod is:

pi@raspberrypi:~ $ lsmod
Module                  Size  Used by
bnep                   12051  2
hci_uart               19956  1
btbcm                   7916  1 hci_uart
bluetooth             365511  22 hci_uart,bnep,btbcm
sg                     20825  0
brcmfmac              222874  0
brcmutil                9092  1 brcmfmac
cfg80211              543027  1 brcmfmac
rfkill                 20851  4 bluetooth,cfg80211
snd_bcm2835            24427  0
bcm2835_gpiomem         3940  0
snd_pcm                98501  1 snd_bcm2835
i2c_bcm2835             7167  0
snd_timer              23904  1 snd_pcm
snd                    70032  3 snd_timer,snd_bcm2835,snd_pcm
uio_pdrv_genirq         3923  0
fixed                   3285  0
uio                    10204  1 uio_pdrv_genirq
i2c_dev                 6913  0
ipv6                  406751  32

[pelwell]

Ah yes, that's because the overlay no longer does what you might think from its name.

Download an updated overlay here that changes the compatible string - if you copy it into /boot/overlays and reboot you should find that the old driver (i2c_bcm2708) is loaded instead. You can then retry your test.

My theory is that the I2C device you are trying to control does not support repeated starts. If you find that everything springs into life with the old driver, try repeating your test after turning on the "combined" module parameter:

sudo sh -c '/bin/echo Y > /sys/module/i2c_bcm2708/parameters/combined'

[DexterInd]

@pelwell , thanks! I replaced i2c_bcm2708 (i2c1_bcm2708) and update config.txt. Unfortunately this did not seem to solve the problem. Could it be anything else? Is there a way to tell when the Kernel i2c was changed?

[pelwell]

1. Does sudo vcdbg log msg |& grep -v HDMI include any errors?
2. What does lsmod | grep i2c show?

[DexterInd]

@pelwell thanks for hanging in there with us!

1. Here are the results:

pi@raspberrypi:~ $ sudo vcdbg log msg |& grep -v HDMI
001089.526: gpioman: gpioman_get_pin_num: pin WL_LPO_CLK not defined
001089.550: gpioman: gpioman_get_pin_num: pin BT_ON not defined
001089.569: gpioman: gpioman_get_pin_num: pin WL_ON not defined
001289.249: *** Restart logging
001293.787: Read command line from file 'cmdline.txt'
dwc_otg.lpm_enable=0 console=serial0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
001584.432: Loading 'kernel.img' to 0x8000 size 0x42ce30
001588.091: No kernel trailer (run mkknlimg to fix) - assuming DT-capable
001590.856: Loading 'bcm2708-rpi-b-plus.dtb' to 0x434e30 size 0x3c60
001671.507: dtparam: i2c_arm=on
001677.350: dtparam: audio=on
001705.465: Failed to load overlay 'i2c1_bcm2708'
001773.647: Device tree loaded to 0x1bfebe00 (size 0x4174)
001774.899: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined
004226.826: vchiq_core: vchiq_init_state: slot_zero = 0x5b580000, is_master = 1

2. Here are the results of lsmod | grep i2c

pi@raspberrypi:~ $ lsmod | grep i2c
i2c_bcm2835             6433  0
i2c_dev                 6642  0

[DexterInd]

Looks like there's a failure here: 001705.465: Failed to load overlay 'i2c1_bcm2708'

[DexterInd]

Just to see if I had entered in the config.txt info wrong, I changed the line to dtoverlay=i2c1_bcm2708.dtbo
The output was:

pi@raspberrypi:~ $ sudo vcdbg log msg |& grep -v HDMI
001036.946: gpioman: gpioman_get_pin_num: pin WL_LPO_CLK not defined
001036.970: gpioman: gpioman_get_pin_num: pin BT_ON not defined
001036.989: gpioman: gpioman_get_pin_num: pin WL_ON not defined
001236.661: *** Restart logging
001240.994: Read command line from file 'cmdline.txt'
dwc_otg.lpm_enable=0 console=serial0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
001531.743: Loading 'kernel.img' to 0x8000 size 0x42ce30
001535.412: No kernel trailer (run mkknlimg to fix) - assuming DT-capable
001538.180: Loading 'bcm2708-rpi-b-plus.dtb' to 0x434e30 size 0x3c60
001618.152: dtparam: i2c_arm=on
001624.038: dtparam: audio=on
001641.290: Failed to load overlay 'i2c1_bcm2708.dtbo'
001709.634: Device tree loaded to 0x1bfebe00 (size 0x4174)
001710.886: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined
004172.407: vchiq_core: vchiq_init_state: slot_zero = 0x5b580000, is_master = 1

[pelwell]

Ah - although the module is called i2c_bcm2708, the overlay uses a hyphen - i2c1-bcm2708. Try:

dtoverlay=i2c1-bcm2708

[DexterInd]

@pelwell that worked! We're reading I2C again! Thanks!

Just to repeat the entire process . . . .

1. Download the old module here.
2. Copy this file into /boot/overlays.
3. In /boot/config.txt add the line dtoverlay=i2c1-bcm2708 at the end.

Does that sound about right?

Again, THANK YOU SO MUCH FOR YOUR HELP WITH THIS!

[pelwell]

Now that you have a workaround you can help to diagnose the real problem by trying with the combined module parameter enabled:

sudo sh -c '/bin/echo Y > /sys/module/i2c_bcm2708/parameters/combined'

I am expecting your test to fail again, in which case we would need to find a way to disable combined (repeated start) transactions for i2c_bcm2835.

[DexterInd]

@pelwell should this be run on a fresh Jessie Lite without the workaround on it, or on the one we've applied the workaround to?

[pelwell]

This test requires the workaround - you need the overlay to get the old driver loaded, and only the old driver has that parameter.

[DexterInd]

Ok, so after applying the workaround, and then running the command

sudo sh -c '/bin/echo Y > /sys/module/i2c_bcm2708/parameters/combined'

the example code does not work. However, after a reboot, the i2c readings returned to normal and gave expected readings.

So what do you make of that? Strange or expected?

[pelwell]

It is what I was expecting - and hoping for, really. Now I'm sure what the problem is, finding a solution should just be a matter of having some time to work on it - either to find an existing way of disabling combined transaction, or to add one.

[pelwell]

By the way, rebooting should not be necessary to get back to a working system, just:

sudo sh -c '/bin/echo N > /sys/module/i2c_bcm2708/parameters/combined'

[DexterInd]

That's great to hear. Should I leave this open?

[pelwell]

Yes - until a proper fix is found, it's better to keep the history in a single thread.

[pelwell]

I've been looking at this for quite a while now, and I can't find a satisfactory solution.

Linux expects to be able to use a repeated START when issuing a read from a device. If your device doesn't support that then I think it is broken - the I2C protocol seems pretty clear that a repeated start should be accepted. Fortunately there seem to be two workarounds:

1. Issue a write with no data and a read with no address (using the I2C_M_NOSTART flag).
2. Some bus controller drivers understand the I2C_M_STOP flag that forces a stop in situations where a repeated start would otherwise be used, but it doesn't seem to be widely supported.

Normally these flags are passed with each transfer using the I2C_RDWR ioctl. However, the SMBus API doesn't have these flags, and the Python SMBus module adds yet another abstraction layer.

Preventing an entire I2C interface from using a repeated start just because a particular device doesn't support it is a kludge, but I can't see a better way while continuing to use the Python smbus module. I did find an alternative Python library using I2C_RDWR - https://github.com/quick2wire/quick2wire-python-api/blob/master/quick2wire/i2c.py - perhaps that might be worth a try. Otherwise, you're going to have to continue to use the modified i2c1_bcm2708 overlay.

[pelwell]

I think I answered this one when I said:

I'll push a patch adding a new parameter to the standard overlay allowing combined transactions to be turned off.

I'll post here when the updated overlay is available.

[MrCollor]

Yes, you did. Thanks !

[pelwell]

The patched overlay (actually overlays - I changed i2c0-bcm2708 as well) is in the source tree and will be picked up by the next firmware build.

Usage: dtoverlay=i2c1-bcm2708,combine=no (or =off).

[roncapat]

Has the overlay thing been properly fixed in the last FW release?

[popcornmix]

Yes, "combine" option was added in 4.14.37.
Latest stable apt kernel is 4.14.52.
So if you've apt upgraded in the last month you should have this.

[roncapat]

Why this issue is still open? :)

[JamesH65]

Well, we haven't had third party confirmation it's actually fixed, but reading back it does seem that it can be closed. @pelwell happy to close?