I2C Comms not working in Renode

[nwdepatie]

Kinda broad ticket that is high priority and blocks a lot of the emulation: Currently I'm suspecting that the I2C module provided by renode doesn't work. Specifically, it feels like a similar problem to this ticket submitted in Renode. https://github.com/renode/renode/issues/114 So, we need to try the proposed changes in this ticket and see if it fixes it. Specifically, we just need to get I2C communication initialized for Renode.

So far, I've been evaluating the call stack provided by Renode's output and it seems like it gets stuck infinitely during the I2C1 initialization, but oddly only the I2C1 bus.

[nwdepatie]

Okay so it actually seems like the modules initialize fine, but still both I2C lines are stuck in an infinite timeout loop per this log when trying to read an I2C address defined with 0x80:

15:20:01.2797 [INFO] cpu: Entering function HAL_I2C_Mem_Read (entry) at 0x80018F8
15:20:01.2798 [INFO] cpu: Entering function HAL_GetTick (entry) at 0x80013C4
15:20:01.2799 [INFO] cpu: Entering function HAL_I2C_Mem_Read at 0x800190C
15:20:01.2800 [INFO] cpu: Entering function HAL_I2C_Mem_Read at 0x8001922
15:20:01.2801 [INFO] cpu: Entering function I2C_WaitOnFlagUntilTimeout (entry) at 0x8001402
15:20:01.2802 [INFO] cpu: Entering function I2C_WaitOnFlagUntilTimeout at 0x800145A
15:20:01.2802 [INFO] cpu: Entering function I2C_WaitOnFlagUntilTimeout at 0x800143C
15:20:01.2803 [INFO] i2c2: [cpu: 0x800143C] ReadUInt32 from 0x18 (Status2), returned 0x0.
15:20:01.2804 [INFO] cpu: Entering function I2C_WaitOnFlagUntilTimeout at 0x8001478
15:20:01.2805 [INFO] cpu: Entering function HAL_I2C_Mem_Read at 0x8001930
15:20:01.2805 [INFO] cpu: Entering function HAL_I2C_Mem_Read at 0x8001936
15:20:01.2806 [INFO] cpu: Entering function HAL_I2C_Mem_Read at 0x8001940
15:20:01.2807 [INFO] i2c2: [cpu: 0x8001940] ReadUInt32 from 0x0 (Control1), returned 0x1.
15:20:01.2808 [INFO] cpu: Entering function HAL_I2C_Mem_Read at 0x8001958
15:20:01.2808 [INFO] i2c2: [cpu: 0x8001958] ReadUInt32 from 0x0 (Control1), returned 0x1.
15:20:01.2809 [INFO] i2c2: [cpu: 0x8001958] WriteUInt32 to 0x0 (Control1), value 0x1.
15:20:01.2810 [INFO] cpu: Entering function I2C_RequestMemoryRead (entry) at 0x800157C
15:20:01.2810 [INFO] i2c2: [cpu: 0x800157E] ReadUInt32 from 0x0 (Control1), returned 0x1.
15:20:01.2811 [INFO] i2c2: [cpu: 0x800157E] WriteUInt32 to 0x0 (Control1), value 0x401.
15:20:01.2812 [INFO] i2c2: [cpu: 0x800157E] ReadUInt32 from 0x0 (Control1), returned 0x401.
15:20:01.2813 [INFO] i2c2: [cpu: 0x800157E] WriteUInt32 to 0x0 (Control1), value 0x501.
15:20:01.2813 [INFO] cpu: Entering function I2C_WaitOnFlagUntilTimeout (entry) at 0x8001402
15:20:01.2814 [INFO] cpu: Entering function I2C_WaitOnFlagUntilTimeout at 0x800145A
15:20:01.2815 [INFO] cpu: Entering function I2C_WaitOnFlagUntilTimeout at 0x8001462
15:20:01.2816 [INFO] i2c2: [cpu: 0x8001462] ReadUInt32 from 0x14 (Status1), returned 0x1.
15:20:01.2817 [INFO] cpu: Entering function I2C_WaitOnFlagUntilTimeout at 0x8001450
15:20:01.2817 [INFO] cpu: Entering function I2C_WaitOnFlagUntilTimeout at 0x8001478
15:20:01.2818 [INFO] cpu: Entering function I2C_RequestMemoryRead at 0x80015B4
15:20:01.2819 [INFO] cpu: Entering function I2C_RequestMemoryRead at 0x80015B6
15:20:01.2820 [INFO] i2c2: [cpu: 0x80015B6] WriteUInt32 to 0x10 (Data), value 0x80.
15:20:01.2821 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout (entry) at 0x800147E
15:20:01.2822 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x8001508
15:20:01.2822 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x8001510
15:20:01.2823 [INFO] i2c2: [cpu: 0x8001510] ReadUInt32 from 0x14 (Status1), returned 0x400.
15:20:01.2824 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x80014F6
15:20:01.2824 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x80014F8
15:20:01.2825 [INFO] i2c2: [cpu: 0x80014F8] ReadUInt32 from 0x14 (Status1), returned 0x0.
15:20:01.2826 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x8001502
15:20:01.2827 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x80014BA
15:20:01.2828 [INFO] cpu: Entering function HAL_GetTick (entry) at 0x80013C4
15:20:01.2829 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x80014BE
15:20:01.2829 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x80014C6
15:20:01.2830 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x8001508
15:20:01.2832 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x8001510
15:20:01.2833 [INFO] i2c2: [cpu: 0x8001508] ReadUInt32 from 0x14 (Status1), returned 0x0.
15:20:01.2834 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x80014F6
15:20:01.2835 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x80014F8
15:20:01.2835 [INFO] i2c2: [cpu: 0x8001508] ReadUInt32 from 0x14 (Status1), returned 0x0.
15:20:01.2836 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x8001502
15:20:01.2837 [INFO] cpu: Entering function I2C_WaitOnMasterAddressFlagUntilTimeout at 0x80014BA
15:20:01.2838 [INFO] cpu: Entering function HAL_GetTick (entry) at 0x80013C4

[nwdepatie]

Okay interesting discovery here, it seems like Renode time operates at 1ms per second. The code here waits about 10 seconds before breaking out of the loop, and HAL_GetTick should return a ms value:

MX_GPIO_Init();
  MX_CAN1_Init();
  MX_I2C1_Init();
  MX_I2C2_Init();
  uint32_t test;
  uint32_t start = HAL_GetTick();
  while(1)
  {
    test = HAL_GetTick();
    if (test > start + 10)
      break;
  }
  MX_SPI1_Init();
  MX_SPI2_Init();
  MX_ADC1_Init();

[nwdepatie]

https://github.com/renode/renode/issues/325 https://renode.readthedocs.io/en/latest/advanced/time_framework.html ^ For weird time behavior, I might make a PR for this issue specifically, kinda makes using the system take WAY too much time

[nwdepatie]

More docs on wtf is happening, I added prints for every step of the callstack, seems like it calls these functions in a cycle:

ReadDouble!
WriteDouble!
StopWrite!
StartWrite!
PeripheralEnableWrite!
ReadDouble!
WriteDouble!
StopWrite!
StartWrite!
PeripheralEnableWrite!
ReadDouble!
WriteDouble!
StopWrite!
StartWrite!
Update!
PeripheralEnableWrite!
ReadDouble!
WriteDouble!
DataWrite!
Update!
ReadDouble!
Update!
ReadDouble!
ReadDouble!
ReadDouble!
ReadDouble!
ReadDouble!
ReadDouble!
ReadDouble!
ReadDouble!
ReadDouble!
...

Note: This behavior only shows itself if the I2C address listed in the .resc is wrong, important to note that Renode actually bitshifts the address right by 1, meaning an address of 0x80 becomes 0x40 internally in Renode, meaning that (I think) the address in in .resc has to be the whatever address we query with in the C code bitshifted right 1. When the I2C address is correct, it just goes into a bunch of ReadDouble!s

[timmyhoa]

Heya, just for future reference and saving your time in the future, renode stm32f4 i2c does not implement multiple byte continuous read, so if you try to read multiple byte consecutively (i.e for lsm6dso reading acceleration), it would not work. They also have a bug where they forget to call finish transmission on the slave.

I had patched multiple byte read and finish transmission, but 2 byte read is not yet patched (prob will do that soon). Heres the patched file: https://github.com/timmyhoa/renode-infrastructure/blob/4099ca698014b4997855d76c1e93621b19edd0a7/src/Emulator/Peripherals/Peripherals/Sensors/MRT_LSM6DSO_IMU.cs

P/s: its crazy how we have pretty much the same situation in term of we want to do :v. Design team + devops. Feel free to reach out if you need help, since I'm working on the same platform too (stm32f4xx) and some common sensors (lsm6dso). Also renode support debugging, where you can run it in debug mode and see all variable and internal state, what save me a lot of time is to run gdb debugging and renode debugging at the same time and let them bounce between each other.