cpu/samd21: i2c timing with compiler optimization

[PeterKietzmann]

The i2c driver for samd21 CPUs has timing problems with the standard compiler optimization -Os. The optimization level for this CPU was enabled in #2848. It seems that e.g. this code line is not executed which may lead to collisions on the bus. In my case I got stuck using tests/drivers_tmp006 with an Atmel samr21-xpro and an external tmp006 sensor. As a bugfix I see two alternatives (for now):

1. Disable size optimisation for samd21 again by reverting cpu/samd21: set optimization level to -Os #2848

• PRO: Who knows where else it introduced failures?
• CON: Huge code sizes

   text    data     bss     dec     hex filename
  15516     128    2792   18436    4804 ...samr21-xpro/driver_tmp006.elf

1. Stay with -Os and use puts() instead of DEBUG() at critical parts (as shown above)

• PRO: Smaller code sizes; Does not hurt in this case; Improves current situation
• CON: Seems a bit like a random solution; Probably compiler dependant?; Similar bugs in other drivers possible

   text    data     bss     dec     hex filename
  10236     128    2792   13156    3364 ...samr21-xpro/driver_tmp006.elf

BTW: I used gcc version 5.2.1 20151202 (release) [ARM/embedded-5-branch revision 231848]

What's your opinion?

[PeterKietzmann]

Pointer for @gebart

[kaspar030]

The i2c driver for samd21 CPUs has timing problems with the standard compiler optimization -Os.
It seems that e.g. this code line is not executed which may lead to collisions on the bus.

Are you sure that the line is not executed? What does the assembly say?
Maybe the register structs are not marked volatile?

[kaspar030]

Are you sure that the line is not executed?

Actually the disassembly looks like the timeout is tested for correctly.

How do these timing problems manifest?

[PeterKietzmann]

In the sensor driver i2c_read_regs() and i2c_write_regs() are called consecutively. i2c_write_regs()initially calls _start(). With -Os the i2c driver just goes over this line and the i2c signals on the bus collide. However, still with -Os enabled I replaced DEBUG() by puts here and the expected dead-time on the bus was there again, leading to expected signals on the bus. EVEN if the puts() never put something on the console...

Of course I played around with delay in the driver and evaluated parameters of the samd21 hardware with "success", but at the end the i2c driver should not start a new write operation once the previous operation is not done ore timed out.

Do you mean the register structs in the vendor header (would be somewhere here) or did I get you wrong?

[jnohlgard]

@PeterKietzmann Could you post the assembly code for both cases of -Os, with and without puts?

I don't have the board but the assembly looks OK on my side, but it's a bit convoluted so there might be a problem that I haven't spotted:

    29fe:       4a14            ldr     r2, [pc, #80]   ; (2a50 <_start.constprop.6+0x74>)

    /* Wait for response on bus. */
    while (!(dev->INTFLAG.reg & SERCOM_I2CM_INTFLAG_MB)
    2a00:       7e18            ldrb    r0, [r3, #24]
    2a02:       4228            tst     r0, r5
    2a04:       d107            bne.n   2a16 <_start.constprop.6+0x3a>
           && !(dev->INTFLAG.reg & SERCOM_I2CM_INTFLAG_SB)) {
    2a06:       7e20            ldrb    r0, [r4, #24]
    2a08:       4208            tst     r0, r1
    2a0a:       d104            bne.n   2a16 <_start.constprop.6+0x3a>
    2a0c:       3a01            subs    r2, #1
        if (++timeout_counter >= SAMD21_I2C_TIMEOUT) {
    2a0e:       2a00            cmp     r2, #0
    2a10:       d1f6            bne.n   2a00 <_start.constprop.6+0x24>
            DEBUG("STATUS_ERR_TIMEOUT\n");
            return -1;
    2a12:       2001            movs    r0, #1
    2a14:       e016            b.n     2a44 <_start.constprop.6+0x68>
    }

Changing the condition on line 380 to while ((dev->INTFLAG.reg & (SERCOM_I2CM_INTFLAG_MB | SERCOM_I2CM_INTFLAG_SB)) == 0) {
yields:

    29fa:       4913            ldr     r1, [pc, #76]   ; (2a48 <_start.constprop.6+0x6c>)

    /* Wait for response on bus. */
    while ((dev->INTFLAG.reg & (SERCOM_I2CM_INTFLAG_MB | SERCOM_I2CM_INTFLAG_SB)) == 0) {
    29fc:       7e14            ldrb    r4, [r2, #24]
    29fe:       4b10            ldr     r3, [pc, #64]   ; (2a40 <_start.constprop.6+0x64>)
    2a00:       4204            tst     r4, r0
    2a02:       d104            bne.n   2a0e <_start.constprop.6+0x32>
    2a04:       3901            subs    r1, #1
        if (++timeout_counter >= SAMD21_I2C_TIMEOUT) {
    2a06:       2900            cmp     r1, #0
    2a08:       d1f8            bne.n   29fc <_start.constprop.6+0x20>
            DEBUG("STATUS_ERR_TIMEOUT\n");
            return -1;
    2a0a:       2001            movs    r0, #1
    2a0c:       e015            b.n     2a3a <_start.constprop.6+0x5e>
    }

[PeterKietzmann]

@gebart thanks for your help. I hope that I cut the right snips out of the assembly output. As be seen, the version with puts does some instructions more

With -Os and without puts:

    124a:   4a14        ldr r2, [pc, #80]   ; (129c <_start.constprop.6+0x74>)

    /* Wait for response on bus. */
    while (!(dev->INTFLAG.reg & SERCOM_I2CM_INTFLAG_MB)
    124c:   7e18        ldrb    r0, [r3, #24]
    124e:   4228        tst r0, r5
    1250:   d107        bne.n   1262 <_start.constprop.6+0x3a>
           && !(dev->INTFLAG.reg & SERCOM_I2CM_INTFLAG_SB)) {
    1252:   7e20        ldrb    r0, [r4, #24]
    1254:   4208        tst r0, r1
    1256:   d104        bne.n   1262 <_start.constprop.6+0x3a>
    1258:   3a01        subs    r2, #1
        if (++timeout_counter >= SAMD21_I2C_TIMEOUT) {
    125a:   2a00        cmp r2, #0
    125c:   d1f6        bne.n   124c <_start.constprop.6+0x24>
            DEBUG("STATUS_ERR_TIMEOUT\n");
            return -1;
    125e:   2001        movs    r0, #1
    1260:   e016        b.n 1290 <_start.constprop.6+0x68>
    }

With -Os and with puts:

    124a:   4a16        ldr r2, [pc, #88]   ; (12a4 <_start.constprop.6+0x7c>)

    /* Wait for response on bus. */
    while (!(dev->INTFLAG.reg & SERCOM_I2CM_INTFLAG_MB)
    124c:   7e18        ldrb    r0, [r3, #24]
    124e:   4228        tst r0, r5
    1250:   d10a        bne.n   1268 <_start.constprop.6+0x40>
           && !(dev->INTFLAG.reg & SERCOM_I2CM_INTFLAG_SB)) {
    1252:   7e20        ldrb    r0, [r4, #24]
    1254:   4208        tst r0, r1
    1256:   d107        bne.n   1268 <_start.constprop.6+0x40>
    1258:   3a01        subs    r2, #1
        if (++timeout_counter >= SAMD21_I2C_TIMEOUT) {
    125a:   2a00        cmp r2, #0
    125c:   d1f6        bne.n   124c <_start.constprop.6+0x24>
            puts("STATUS_ERR_TIMEOUT\n");
    125e:   4812        ldr r0, [pc, #72]   ; (12a8 <_start.constprop.6+0x80>)
    1260:   f000 fabc   bl  17dc <puts>
            return -1;
    1264:   2001        movs    r0, #1
    1266:   e016        b.n 1296 <_start.constprop.6+0x6e>
    }

[jnohlgard]

There's really no difference except for the call to puts.
Could it be that the timeout value is too small on such a tight loop? It's only 65535 right now.
What is the wanted timeout in ms?
What is the core clock frequency of the samr21-xpro?

[PeterKietzmann]

The core frequency is 48MHz thus results in a timeout > 1ms which is dimensions longer than needed. Increasing the timeout threshold value does not change the behaviour. Also note that the puts is not printed to the console. My assumption was that it prevents from optimization at that passage.

[jnohlgard]

Could be a CPU pipeline optimization then. Try making the timeout counter variable volatile.

[PeterKietzmann]

Nice, that worked :-) ! Thanks @gebart. Will open a PR

[PeterKietzmann]

Reopened issue cause above described fix didn't work for @smlng. We found out the register type isn't volatile as well. Need to elaborate on it the next days

[kaspar030]

We found out the register type isn't volatile as well. Need to elaborate on it the next days

Isn't the component type marked __IO, which evaluates to volatile?

The counter variable shouldn't need to be volatile, and in the assembly, it is correctly set up, decremented and tested, so volatile shouldn't change anything.

[kaspar030]

The SB and MB flags - what do they actually mean? Maybe one of them is set?
@PeterKietzmann Could you try lighting an LED at the beginning of the while block (after line 381) or somehow else confirm that the loop is actually being entered?

[kaspar030]

(or, add an output whenever _start() is called and returns -1)?

[PeterKietzmann]

• funnily making the reg volatile (as described above) did it for @smlng but not for me. And the other way around for the timeout_counter
• INTFLAG is marked as _IO (compare here) which means volatile (defined here). I'm learning a lot today
• The loop is actually entered. I confirmed that with the LED
• _start_ does not return -1
• you can read about SB and MB in the reference manual section 26.8.2.6. page 556

I guess I have to rethink some conditions and assumptions I made. Happy to get more feedback from you. I'll report once I figured out more details.

[PeterKietzmann]

#5464 was merged.

[dbohn]

I'm sorry to comment this issue, although it is closed, but I'm experiencing closely related issues with an TMP006 and the samr21-xpro board as well.

I'm currently participating in a software project at FU and thus me and my group are just getting to know RIOT, so please excuse some missing knowledge about the platform.

I'm using the latest RIOT master and made sure that the fix provided in #5464 was present in the code, but still I'm unable to successfully run the tests/driver_tmp006 application unless I provide the 'CFLAGS_OPT = -O0' option to disable code optimization.

Otherwise it seems that the first reading after rebooting the system and first configuring the temperature sensor gives an adequate temperature, but afterwards it does always report the same temperature values, because the drdy value set by tmp006_read() seems to always be false, thus it always displays "conversion in progress" and does not retrieve temperature values.

[PeterKietzmann]

Thanks for reporting @dbohn. Unfortunately I don't have a fix right now. Will re-open the issue

[OlegHahm]

Any news?

[PeterKietzmann]

I can not reproduce this error. For me it works with current master and standard optimization -Os. @dbohn are you still available?

[dbohn]

hey, sry, actually I'm not really available for this anymore. This issue occured in the works for a university software project in the last semester, so I don't have the development boards around anymore and it has been quite a while now that I dived into the code.
The only thing I can do, is provide you the code we used, which lives here: https://github.com/fridalufa/smart-environment
If I remember it correctly, the code we used to read from the temperature sensor lives in here: https://github.com/fridalufa/smart-environment/blob/master/sensor/hardware.c

[PeterKietzmann]

@OlegHahm any idea how to proceed here?

[PeterKietzmann]

This issue didn't occur for quite some time, even if samr21-xpro is a widely used platform. Willl close the issue with memo label set. @dbohn if you ever face this problem again, feel free to reopen