Garbled I2C unless printf is used

[snoopy20]

Hi,

I have a very odd problem but one which is consistent.

As part of my lcd library I send several ''packets' of data interleaved with spacing from a timer. It typically looks like -

6 bytes - 50us - 6 bytes - 50us - 6 bytes ...

A second timer works in counter mode and is used to stop the transmission once the requisite amount of bytes are sent. It works well.

Now, the command that kicks such a process off (the data is held in a buffer) is this -

void lcdTransactionEnd (void) {
  
  if (dmaBuffer.writeBuffer->writeLocked) {
    dmaBuffer.writeBuffer->writeLocked = 0;
  }
  if (dmaBuffer.transferBuffer->size && ! dmaBuffer.transferBuffer->txLocked) {
    printf("transfering \n");
    __startTransfer();
  }
}

and startTransfer is

static void __startTransfer (void) {

  dmaBuffer.transferBuffer->txLocked = 1;
  CFG_TWIM_LCD_TX->TXD.PTR = (uint32_t) &dmaBuffer.transferBuffer->data[0];
  CFG_TWIM_LCD_TX->TXD.MAXCNT = dmaBuffer.transferBuffer->packetSize;
  CFG_TIMER_LCD_COUNTER->CC[0] = dmaBuffer.transferBuffer->size / dmaBuffer.transferBuffer->packetSize;
  //printf("tx %d, %d \n", dmaBuffer.transferBuffer->size, dmaBuffer.transferBuffer->packetSize);
  CFG_TWIM_LCD_TX->TASKS_STARTTX = 1;
}

Now here's the thing. In the ledTransactionEnd there is a printf statement. If I remove this statement I get garbage (or data corruption) over I2C. I thought maybe I have a timing issue, so I replaced it with various nrf_delay_ms values and that had no effect. I have absolutely no idea how using printf can cause this to happen but it's repeating every time.

Any ideas most welcome!

[awneil]

snoopy20 said:

6 bytes - 50us - 6 bytes - 50us - 6 bytes ...

What's the point of the delay?

Why 50us? Have you verified that you are actually getting 50us?

snoopy20 said:

If I remove this statement I get garbage

sounds like a timing issue.

What happens if you increase your "50us" ?

[snoopy20]

The LCD has a I2C piggyback on it, it's a timing requirement between commands.

I've tried all sorts of timing increases and decreases but after a few days at it I've found the TWIM will randomly begin producing garbage and end in a hard fault.

Yet using printf("here \n") in that above statement causes it to behave. I'm unsure if printf (via swagger) stalls the CPU in a different way to nrf_delay burning cycles. I'm specifically interested in whether the clock to the TWIM peripheral is being stalled, which seems more likely.

[awneil]

snoopy20 said:

the TWIM will randomly begin producing garbage

Do you mean it's transmitting garbage, or just that the LCD is showing garbage?

Do you have an analyser to see what's happening on the wires?

snoopy20 said:

end in a hard fault

That points to a bug in the code; eg, buffer overrun, stack corruption, memory leaks ...

What debugging have you done to find what's causing the Hard Fault?

You should get some diagnsotics.

snoopy20 said:

via swagger

has that been a victim of autocorrect?

[snoopy20]

If it helps here's the code doing the timing. It should all be hardware based and is as far as I can tell.

The timing for the space is 1600/16000000 or 100us well within the 52us required.

Then 50 cycles are allowed for the counter timer to shut down the first timer before the next starttx is called.

  NRF_GPIO->PIN_CNF[CFG_PIN_LCD_SCL] = LCD_I2C_PIN_INIT_CONF;
  NRF_GPIO->PIN_CNF[CFG_PIN_LCD_SDA] = LCD_I2C_PIN_INIT_CONF;
  #ifdef CFG_PIN_LCD_VDD
  NRF_GPIO->PIN_CNF[CFG_PIN_LCD_VDD] = ((GPIO_PIN_CNF_SENSE_Disabled << GPIO_PIN_CNF_SENSE_Pos) | (GPIO_PIN_CNF_DRIVE_S0H1 << GPIO_PIN_CNF_DRIVE_Pos) | (GPIO_PIN_CNF_INPUT_Disconnect << GPIO_PIN_CNF_INPUT_Pos) | (GPIO_PIN_CNF_DIR_Output << GPIO_PIN_CNF_DIR_Pos));
  NRF_GPIO->OUTSET = 1 << CFG_PIN_LCD_VDD;
  #endif

  CFG_TIMER_LCD_SPACE->BITMODE = TIMER_BITMODE_BITMODE_32Bit << TIMER_BITMODE_BITMODE_Pos;
  CFG_TIMER_LCD_SPACE->PRESCALER = 0;
  CFG_TIMER_LCD_SPACE->CC[0] = LCD_TICKS_BETWEEN_DATA - 50;
  CFG_TIMER_LCD_SPACE->CC[1] = LCD_TICKS_BETWEEN_DATA;
  CFG_TIMER_LCD_SPACE->SHORTS = TIMER_SHORTS_COMPARE1_STOP_Enabled << TIMER_SHORTS_COMPARE1_STOP_Pos | TIMER_SHORTS_COMPARE1_CLEAR_Enabled << TIMER_SHORTS_COMPARE1_CLEAR_Pos;

  CFG_TIMER_LCD_COUNTER->BITMODE = TIMER_BITMODE_BITMODE_32Bit << TIMER_BITMODE_BITMODE_Pos;
  CFG_TIMER_LCD_COUNTER->PRESCALER = 0;
  CFG_TIMER_LCD_COUNTER->MODE = TIMER_MODE_MODE_LowPowerCounter << TIMER_MODE_MODE_Pos;
  CFG_TIMER_LCD_COUNTER->SHORTS = TIMER_SHORTS_COMPARE0_CLEAR_Enabled << TIMER_SHORTS_COMPARE0_CLEAR_Pos;
  CFG_TIMER_LCD_COUNTER->INTENSET = TIMER_INTENSET_COMPARE0_Enabled << TIMER_INTENSET_COMPARE0_Pos;
 
  CFG_TWIM_LCD_TX->ADDRESS = LCD_I2C_ADDRESS;
  CFG_TWIM_LCD_TX->FREQUENCY = TWIM_FREQUENCY_FREQUENCY_K100 << TWIM_FREQUENCY_FREQUENCY_Pos;
  CFG_TWIM_LCD_TX->PSEL.SCL = (TWIM_PSEL_SCL_CONNECT_Connected << TWIM_PSEL_SCL_CONNECT_Pos) | CFG_PIN_LCD_SCL;
  CFG_TWIM_LCD_TX->PSEL.SDA = (TWIM_PSEL_SDA_CONNECT_Connected << TWIM_PSEL_SDA_CONNECT_Pos) | CFG_PIN_LCD_SDA;
  CFG_TWIM_LCD_TX->SHORTS = TWIM_SHORTS_LASTTX_STOP_Enabled << TWIM_SHORTS_LASTTX_STOP_Pos;
  CFG_TWIM_LCD_TX->TXD.LIST = TWIM_TXD_LIST_LIST_ArrayList << TWIM_TXD_LIST_LIST_Pos;
  CFG_TWIM_LCD_TX->ENABLE = TWIM_ENABLE_ENABLE_Enabled << TWIM_ENABLE_ENABLE_Pos;

  NRF_PPI->CH[CFG_PPI_LCD_CHANNEL_TWIM_SPACE].EEP = (uint32_t) &CFG_TWIM_LCD_TX->EVENTS_LASTTX; // wire timer compare
  NRF_PPI->CH[CFG_PPI_LCD_CHANNEL_TWIM_SPACE].TEP = (uint32_t) &CFG_TIMER_LCD_SPACE->TASKS_START; 
  NRF_PPI->CH[CFG_PPI_LCD_CHANNEL_SPACE_COUNT].EEP = (uint32_t) &CFG_TIMER_LCD_SPACE->EVENTS_COMPARE[0]; // wire timer compare
  NRF_PPI->CH[CFG_PPI_LCD_CHANNEL_SPACE_COUNT].TEP = (uint32_t) &CFG_TIMER_LCD_COUNTER->TASKS_COUNT;
  NRF_PPI->CH[CFG_PPI_LCD_CHANNEL_SPACE_START].EEP = (uint32_t) &CFG_TIMER_LCD_SPACE->EVENTS_COMPARE[1]; // wire timer compare
  NRF_PPI->CH[CFG_PPI_LCD_CHANNEL_SPACE_START].TEP = (uint32_t) &CFG_TWIM_LCD_TX->TASKS_STARTTX;
  NRF_PPI->CH[CFG_PPI_LCD_CHANNEL_COUNTER_RESET].EEP = (uint32_t) &CFG_TIMER_LCD_COUNTER->EVENTS_COMPARE[0]; // wire timer compare
  NRF_PPI->CH[CFG_PPI_LCD_CHANNEL_COUNTER_RESET].TEP = (uint32_t) &CFG_TIMER_LCD_SPACE->TASKS_STOP;
  NRF_PPI->FORK[CFG_PPI_LCD_CHANNEL_COUNTER_RESET].TEP = (uint32_t) &CFG_TIMER_LCD_SPACE->TASKS_CLEAR;
  NRF_PPI->CHENSET = 1 << CFG_PPI_LCD_CHANNEL_TWIM_SPACE | 1 << CFG_PPI_LCD_CHANNEL_SPACE_COUNT | 1 << CFG_PPI_LCD_CHANNEL_SPACE_START | 1 << CFG_PPI_LCD_CHANNEL_COUNTER_RESET;  // enable ppi channel

The hard fault occurs because the TWIM has given up and eventually the circular buffer overruns itself. Not part of the problem as it works fine while the TWIM is operational.

After a random amount of time, with consistent and identical data packets sent over I2C, the TWIM faults and causes the cascading failure.

Swagger  = Segger. :)

[snoopy20]

Could there be a race between the counter shutting down the first timer and the first timer reaching the second CC and triggering the TWIM? I allocated 50 cycles (of 16MHz), perhaps the propagation of the PPI is quite a bit slower than this?

[ovrebekk]

Hi 

The only case where the PPI propagation could be delayed is if the 16MHz peripheral clock is suspended, but unless you enter sleep mode and have disabled all peripherals that require the peripheral clock (such as the UART or a timer in timer mode) this will not be the case. Then the delay of the PPI should be consistent, and only about a clock cycle long. 

Are you going to sleep in between events by the way?

Best regards
Torbjørn

[snoopy20]

I've had to abandon it, the consistency wasn't there.

Regards, Andrew

[ovrebekk]

Hi Andrew

Thanks for the update. 

I feel this issue is one that we should be able to solve, but it will probably take some time to figure out what is happening. It is understandable if you want to focus your efforts elsewhere. 

Best regards
Torbjørn