Concurrent I2C access

[dflogeras]

I'm playing around with reading an accelerometer which is connected to I2C1 of my STM32L1, and writing data to an I2C LCD screen on the other (I2C2) bus. I have threaded the two operations, so that they may happen concurrently.

What I am seeing is that even though the i2cMasterTransmitTimeout() function will set up DMA, it then seems to busy poll waiting for the transaction to complete. In my logic analyzer I can see that the two busses are still being accessed one after the other.

Is there any way with the current drivers to use the two busses in concurrently? Am approaching the problem completely wrong?

Thanks,
Dave

[Giovanni]

The two busses should be used concurrently unless you are using mutual exclusion in your code.

If you have delays in your threads probably it simply never happens that the use is concurrent because timings.

Giovanni

[dflogeras]

Hmm, no I shouldn't have blocked myself. The code is something like this:

main thread:

Code: Select all

timeout = MS2ST( 100 );
while(1) {
  // Tell the other thread it is OK to start writing to the LCD
  chBSemSignal( &write_lcd_sem );
  i2cAcquireBus( &I2CD2 );
  i2cMasterTimeoutWrite( &I2CD2, 0x1c, &tx[0], 1, &rx[0], 192, timeout );
  i2cMasterTimeoutWrite( .... );
  ...
  i2cReleaseBus( &I2CD2 );
  // Wait for the LCD thread to signal it is finished writing the last string
  chBSemWait( &lcd_write_done_sem );
  // Render a new string from the data just collected.
  process_data_and_render_string();
  // eventually implement standyby/stop mode here and wait for next interrupt to wake up
}

lcd thread:

Code: Select all

while(1) {
  chBSemWait( &lcd_write_done_sem );
  i2cAcquireBus( &I2CD1 );
  i2cMasterTimeoutWrite( .... );
  i2cMasterTimeoutWrite( .... );
  ...
  i2cReleaseBus( &I2CD1 );
}

The attached screenshot shows the timing, and I would have guessed that since the main thread spends almost 20ms in transmitting/receiving data that at least one context switch would occur during that time. The bottom SDA/SCL pair are the sensor being read, and the top SDA/SCL pair are the LCD being written to.

Does this shed any more light?

[Giovanni]

You should examine the trace buffer and see what happens exactly.

Giovanni

[dflogeras]

I have not used this feature before, thanks for making me aware!

I might need some help interpreting it. I have attached the output of printing dbg_trace_buffer inside gdb. I assume this is a circular buffer since the oldest timestamp seems to be in the middle?

I didn't explain this earlier, but the mma_sem semaphore is used for my EXTI interrupt handler to signal that new data is available for the main thread.

Any help reading this output is greatly appreciated. My first questions would be
* Is se_tp the thread that is currently running?
* Is se_wtobjp the semaphore that woke the currently running thread, or is it the head of a pending semaphore list?

Let's start with the two entries at time se_time 3049. Do I interpret that the first one is saying: the lcd_thread is in state 3 (Waiting on a sem) and that the mma_sem has been signaled at this point? Then the second entry is back to the idle thread, but se_wtobjp is now the update_lcd_sem semaphore. I'm not sure what this means in the context of the idle thread.

It then seems like at se_time 3072 the main thread runs (collecting data on I2C bus 2), then ~20ms later the lcd_thread runs at se_time 3091. This agrees with the logic analyzer output but I still don't know why it didn't context switch before then.

Code: Select all

tb_size = 64 , 
  tb_ptr = 0x2000165c <dbg_trace_buffer+168> , 
tb_buffer = { {
      se_time = 3094 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3094 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3095 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3095 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3095 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3095 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3095 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' 
    }
, {
      se_time = 3095 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3095 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3095 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x20001cc8 <update_lcd_sem> , se_state = 3 '\003' }
, {
      se_time = 3030 , se_tp = 0x20001588 <mainthread> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3030 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3030 , se_tp = 0x20001588 <mainthread> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3030 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3048 , se_tp = 0x20001588 <mainthread> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3049 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x20001ac0 <mma_sem> , se_state = 3 '\003' }
, {
      se_time = 3049 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x20001cc8 <update_lcd_sem> , se_state = 3 '\003' }
, {
      se_time = 3072 , se_tp = 0x20001588 <mainthread> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3072 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3072 , se_tp = 0x20001588 <mainthread> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3072 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3090 , se_tp = 0x20001588 <mainthread> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3091 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x20001ac0 <mma_sem> , se_state = 3 '\003' }
, {
      se_time = 3091 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3091 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3091 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3091 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3091 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3091 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3091 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3091 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3091 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3091 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3091 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3091 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3092 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3092 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3092 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3092 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3092 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3092 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3092 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3092 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3092 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3092 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3092 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3093 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3093 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3093 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3093 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3093 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3093 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3093 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3093 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3093 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3093 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3094 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3094 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3094 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3094 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3094 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3094 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }
, {
      se_time = 3094 , se_tp = 0x20001ce0 <lcd_thread_working_area> , 
      se_wtobjp = 0x0 , se_state = 0 '\000' }
, {
      se_time = 3094 , se_tp = 0x200014c8 <_idle_thread_wa> , 
      se_wtobjp = 0x0 , se_state = 2 '\002' }

} }

[Giovanni]

Hi,

The ChibiOS Eclipse plugin in ChibiStudio can decode the trace and produce a readable table.

Giovanni

[dflogeras]

While waiting for java and eclipse to download (I don't normally use these tools), I found the source of my issue. I simply had some logic reversed in the semaphores and should have seen it when I was typing my pseudo-code earlier. The trace makes much more sense to me now - even without the plugin.

As usual, thank you for the help and at the very least I now know how to debug these types of issues for the future

Dave