Using stdio streams with I2C on AVR

[HwAoRrDk]

In my current project - because the usual UART pins are used up - I am using the I2C pins to output debug information in the same manner as I would otherwise with a serial console. I have an Arduino board hooked up as an I2C slave device that is running a simple sketch (based on Nick Gammon's example here) that simply copies anything it receives via I2C and spits it out the serial connection.

So I can conveniently use printf(), etc. in my debug output, I have used fdev_setup_stream() with a custom 'put' handler function that writes each character given out over I2C to the slave. However, it is quite a quick-and-dirty implementation, and I think it could be more efficient. At the moment, it is going through the whole start/write/stop I2C transaction cycle for each and every character given to it. That's highly inefficient, no? It would probably be much better to only do start/stop per line of output.

I'm thinking of implementing a buffer, so that all characters given to the 'put' function instead get stuffed in the buffer, which then only gets flushed out to I2C when CR/LF is encountered or the buffer is full.

Any comments on that, or is there a better way to do this?

[Buriedcode]

I have never used I2C for spitting out debug data, although I tend to avoid I2C unless I need it (as in, for comms where I have the option of serial, SPI, or I2C, I'll go for serial or SPI any day). 

It would indeed be better to send out chunks rather than start/write/stop for each character, but I just wanted to ask, is I2C your only option? If you have a spare SPI port, that of course would be easier with the penalty of one extra IO for chip select (not strictly needed, but best for synchronizing).

A software UART is less than ideal of course, but depending on what device you're using, and the fact its output only, an interrupt driven UART could only take a few instructions per bit using a timer. I used to use these at a pushm even have two or three of them running off the same timer interrupt and was surprised at how little CPU time it took on PIC's and AVR.

[HwAoRrDk]

Yeah, I2C is pretty much my only option. I had resigned myself to not having serial UART for debugging because I was using those pins, but then my circuit design happened to end up with two pins free on PORTC of the AVR, so I figured that if I re-arranged things there a little, I could have both SCL and SDA pins free and use I2C for debug output.

I had a look briefly into doing software-driven serial, and for reference took a look at the implementation of Arduino's SoftwareSerial library, but there seemed to be an painful amount of faffing around in the code to get timings exactly right. Looked like too much trouble, so I stuck with the idea of I2C.

Here's the buffered implementation I came up with, in case anyone cares to comment:

Code: [Select]

FILE streamI2C;

int main(void) {
initI2CDebug();

printf_P(PSTR("Foo bar %d"), foo);

// ...
}

void initI2CDebug() {
DDRC &= ~(_BV(DDC4) | _BV(DDC5));
PORTC |= _BV(PORTC4) | _BV(PORTC5);

i2c_init_clock(I2C_CLOCK_FREQ_HZ);

fdev_setup_stream(&streamI2C, putCharI2C, NULL, _FDEV_SETUP_WRITE);
stdout = &streamI2C;
}

int putCharI2C(char c, FILE *stream) {
const uint8_t BUF_MAX = 50;
static char buf[BUF_MAX];
static uint8_t buf_len = 0;

buf[buf_len++] = c;

if(buf_len >= BUF_MAX || c == '\n') {
i2c_start((I2C_DEBUG_SLAVE_ADDR << 1) | I2C_WRITE);
for(uint8_t i = 0; i < buf_len; i++) {
i2c_write(buf[i]);
}
buf_len = 0;
i2c_stop();
}

    return 0;
}

As an aside, I had an odd problem when I initially went to use the FDEV_SETUP_STREAM macro to initialise the stream at point of variable declaration. But when compiling, I just got an error or "sorry, unimplemented: non-trivial designated initializers not supported". Not sure what that's all about.

[HwAoRrDk]

I've encountered a slight hiccup with my debug output over I2C. It largely works pretty well, with the exception that frequently it appears as though something is eating my line feed characters. The effect is that a line of output on my serial terminal will have overwritten the line before it; exactly like it's getting a CR, but no LF. For example, if there are output these two lines:

First line. Blah blah blah blah blah blah.
Second line. AAAAAA

When the problem occurs I'll get this:

Second line. AAAAAAah blah blah blah blah.

I can't find what's causing it. So far I've eliminated the following:

- Double-checked all the printf() strings in my code to make sure they include proper "\r\n" termination, which they do.
- Tried a different serial terminal at the PC end - it happens both with the Arduino IDE's Serial Monitor and PuTTY.
- I'm fairly certain that the full bytes of each line are being written out to the I2C bus. But I have no way of verifying for sure (don't have an oscilloscope with serial decode).
- I don't think it's a general data corruption issue on the I2C bus, as the problem occurs in an extremely specific way.

So, I can only think it's either some really obscure issue, or perhaps a bug in the code running as the I2C/UART 'bridge' on the Arduino.

As I mentioned before, the code I'm running on the Arduino is based on that published by Nick Gammon, so one would assume it is proven code, but you never know. And I have made some slight modifications. I'll post it here in case anyone can spot any bugs:

Code: [Select]

#include <Wire.h>

#define I2C_SCL_FREQ 32000UL
#define I2C_ADDRESS 100
#define BLINK_LED_PERIOD_MS 200

char buf[1000];
volatile unsigned int inpoint = 0, outpoint = 0;
volatile bool blinkLed = false;
volatile unsigned int blinkLedCounter = 0;

void setup(void) {
pinMode(LED_BUILTIN, OUTPUT);

// Co-opt Timer0 that fires once per millisecond (used for millis(), etc), and use the
// output compare unit to throw an interrupt whenever the timer value reaches a
// certain point.
OCR0A = 0x7F; // Mid-range of timer (127).
TIMSK0 |= _BV(OCIE0A);

Serial.begin(115200);

Serial.println();
Serial.print(F("I2C slave address is 0x"));
Serial.print(I2C_ADDRESS, HEX);
Serial.print(F(", clock freq. is "));
Serial.print(I2C_SCL_FREQ, DEC);
Serial.println(F("Hz"));
Serial.println(F("Commencing debugging session..."));
Serial.println(F("----------------------------------------"));
Serial.println();

Wire.begin(I2C_ADDRESS);
Wire.setClock(I2C_SCL_FREQ);
Wire.onReceive(receiveEvent);
}

ISR(TIMER0_COMPA_vect) {
// While the LED is on, continue to increment the timing counter once
// every millisecond until it reaches the defined limit. At that point,
// signal that the LED should be turned off and reset counter.
if(blinkLed && ++blinkLedCounter >= BLINK_LED_PERIOD_MS) {
blinkLed = false;
blinkLedCounter = 0;
}
}

void receiveEvent(int howMany) {
blinkLed = true;

while(Wire.available() > 0) {
char c = Wire.read();
unsigned int next = inpoint + 1;  // next insert point

// wrap-around at end of buffer
if(next >= sizeof buf) next = 0;
 
// caught up with removal point?
if(next == outpoint) continue; // give up

// insert at insertion point
buf[inpoint] = c;
inpoint = next;  // advance to next
}
}

void loop(void) {
digitalWrite(LED_BUILTIN, (blinkLed ? HIGH : LOW));

// insertion and removal point the same, nothing there
noInterrupts();  // atomic test of a 16-bit variable
if(outpoint == inpoint) {
interrupts();
return;
}
interrupts();

// display anything found in the circular buffer
Serial.print(buf[outpoint]);

noInterrupts();
if(++outpoint >= sizeof buf)
outpoint = 0;  // wrap around
interrupts();
}

Any help most appreciated. It's a pain when your debug facilities themselves have bugs in them!

[f1rmb]

I would suggest you  to put a '\0' at the end of the string in buf[] before sending it, overwriting the '\n'.

Cheers.

[FreddyVictor]

if you just want output & speed is not a problem, then you can use the SoftSerial Arduino code to print from any pin:

Code: [Select]

// borrowed from Arduino SoftUsart
// 1000000 / 9600  = 104 microseconds at 9600 baud.
#define BIT_DELAY 102
void Print(uint8_t i)
{
uint8_t mask;
USART_TX = 0;
_delay_us(BIT_DELAY);

for (mask = 0x01; mask; mask <<= 1)
{
if (i & mask) USART_TX = 1; //switch ON digital PIN 0
else USART_TX = 0; // switch OFF digital PIN 0   

_delay_us(BIT_DELAY);
}
USART_TX = 1; // switch ON digital PIN 0
_delay_us(BIT_DELAY);
}

[Psi]

Yep, as above. Timing is only an issue for very fast soft serial comms.
You could implement a bi-directional 2400 baud uart easily without any timing issues.
Soft serial is definitely the way to go.

Note: if you use the print function above it's best to use a fast baudrate to reduce the hard delays.  115200 should work fine for TX only.

[bktemp]

Soft UART TXD is easy, but any interrupt occuring during the transmission will affect the bittiming, because the time spend for processing the interrupt code gets added to the delay!
Depending on how much CPU time is used for interrupts you may need to disable interrupts while transmitting.

[HwAoRrDk]

I would suggest you  to put a '\0' at the end of the string in buf[] before sending it, overwriting the '\n'.

Sorry, I don't quite understand - are you talking about my previous I2C sending code?

How will that help? Nothing further downstream cares about null-termination of strings.

if you just want output & speed is not a problem, then you can use the SoftSerial Arduino code to print from any pin:

Thanks for that. I didn't think it could be made quite as simple as that. I'll have to give it a try.

Soft UART TXD is easy, but any interrupt occuring during the transmission will affect the bittiming, because the time spend for processing the interrupt code gets added to the delay!
Depending on how much CPU time is used for interrupts you may need to disable interrupts while transmitting.

Hmm, the only things interrupt-wise that may interfere with timing are that I'm using a couple of timer interrupts to execute some code regularly; Timer0 as a 1KHz system 'clock', and Timer2 at 4KHz for buzzer output. With regard to the latter, I'm frequently printf()-ing in conjunction with a beep or two, so Timer2 would be running at the same time as the UART bit-banging code. Would that would be enough to throw the timing off?

Actually, speaking of timer interrupts, I've just realised I'm not using Timer1 anywhere in my code. I suppose I could set it up to trigger at the appropriate rate and use that ISR to bit-bang the serial data transmission. Is that a better approach than using _delay_us()?

[f1rmb]

I would suggest you  to put a '\0' at the end of the string in buf[] before sending it, overwriting the '\n'.

Sorry, I don't quite understand - are you talking about my previous I2C sending code?

How will that help? Nothing further downstream cares about null-termination of strings.

if you just want output & speed is not a problem, then you can use the SoftSerial Arduino code to print from any pin:

Thanks for that. I didn't think it could be made quite as simple as that. I'll have to give it a try.

Soft UART TXD is easy, but any interrupt occuring during the transmission will affect the bittiming, because the time spend for processing the interrupt code gets added to the delay!
Depending on how much CPU time is used for interrupts you may need to disable interrupts while transmitting.

Hmm, the only things interrupt-wise that may interfere with timing are that I'm using a couple of timer interrupts to execute some code regularly; Timer0 as a 1KHz system 'clock', and Timer2 at 4KHz for buzzer output. With regard to the latter, I'm frequently printf()-ing in conjunction with a beep or two, so Timer2 would be running at the same time as the UART bit-banging code. Would that would be enough to throw the timing off?

Actually, speaking of timer interrupts, I've just realised I'm not using Timer1 anywhere in my code. I suppose I could set it up to trigger at the appropriate rate and use that ISR to bit-bang the serial data transmission. Is that a better approach than using _delay_us()?

Sorry, you posted various code (in putCharI2C() ), stored in char array. If you don't terminate your strings, print() will won't work as expected (and sometimes worse than that).

Cheers.
---
Daniel

[bktemp]

Hmm, the only things interrupt-wise that may interfere with timing are that I'm using a couple of timer interrupts to execute some code regularly; Timer0 as a 1KHz system 'clock', and Timer2 at 4KHz for buzzer output. With regard to the latter, I'm frequently printf()-ing in conjunction with a beep or two, so Timer2 would be running at the same time as the UART bit-banging code. Would that would be enough to throw the timing off?

It is impossible to tell without analysing how long it takes to execute the interrupt code.
The error on the clock speed for UART should be less than 2-3%, so if the interrupt uses more than 3% CPU load, the timing will be to far off for working reliably. Maybe you could compensate the lost cycles in the delay, but it requires manual tweaking to get the timing right.

Actually, speaking of timer interrupts, I've just realised I'm not using Timer1 anywhere in my code. I suppose I could set it up to trigger at the appropriate rate and use that ISR to bit-bang the serial data transmission. Is that a better approach than using _delay_us()?

That is much better, because it provides a fixes time base, therefore the timing errors will not accumulate.
But there is still one problem left: If any other interrupt is active at the time the soft uart timer irq fires, it will delay the bit. If all interrupts are short enough (maybe last less than 15% of the uart bit duration) then it is ok. Otherwise you may get bit errors when receiving the uart data.

I would prefer I2C or SPI for debugging if there is no UART available, because I2C and SPI provide their own clock, and therefore don't care if the transmission gets interrupted by an interrupt.
For speeding up your I2C transmission, you could implement a simple state machine:
If the I2C code receives a character and there is no active transmission, it initiates own. It keeps using the I2C bus until it receives an end of line character. Then it stops and gives the bus free. You don't need any buffering, because you can send each character immediately.
This will occupy the I2C bus for quite some time, but if you have only one I2C bus master it doesn't care.

[HwAoRrDk]

Sorry, you posted various code (in putCharI2C() ), stored in char array. If you don't terminate your strings, print() will won't work as expected (and sometimes worse than that).

I still don't see how that's relevant to the buffer array I'm using in that putChar() function - it should not care about null-termination; it's just being handed a character at a time, and tracks its own accumulated length. Now, you're right that it's the library functions calling putChar() that needs to worry about null-terminated strings (i.e. so it knows when to stop passing chars to putChar()). However, all my strings being passed to printf() calls are ultimately string literals, so they're already null-terminated. (Or to be more precise, I am using printf_P() with string literals wrapped with PSTR()). If they weren't, I'm pretty sure I'd have a different problem - that being garbage extra characters output.

Although, you've given me a thought... I wonder if somewhere in my code there is an off-by-one error with an snprintf() length param or something similar which is sometimes missing my '\n' at the end of a string, leaving it as '\0', which means that the printf() call is only ever giving a '\r' to putChar(). I shall have to take a very close look in the debugger.

I would prefer I2C or SPI for debugging if there is no UART available, because I2C and SPI provide their own clock, and therefore don't care if the transmission gets interrupted by an interrupt.

Hence why I went down the road of I2C to start with - let the hardware handle everything!

For speeding up your I2C transmission, you could implement a simple state machine:
If the I2C code receives a character and there is no active transmission, it initiates own. It keeps using the I2C bus until it receives an end of line character. Then it stops and gives the bus free. You don't need any buffering, because you can send each character immediately.
This will occupy the I2C bus for quite some time, but if you have only one I2C bus master it doesn't care.

A nice idea. Perhaps I will consider that so I can get rid of the buffer if I am running short on memory.

[f1rmb]

Sorry, you posted various code (in putCharI2C() ), stored in char array. If you don't terminate your strings, print() will won't work as expected (and sometimes worse than that).

I still don't see how that's relevant to the buffer array I'm using in that putChar() function - it should not care about null-termination; it's just being handed a character at a time, and tracks its own accumulated length. Now, you're right that it's the library functions calling putChar() that needs to worry about null-terminated strings (i.e. so it knows when to stop passing chars to putChar()). However, all my strings being passed to printf() calls are ultimately string literals, so they're already null-terminated. (Or to be more precise, I am using printf_P() with string literals wrapped with PSTR()). If they weren't, I'm pretty sure I'd have a different problem - that being garbage extra characters output.

Although, you've given me a thought... I wonder if somewhere in my code there is an off-by-one error with an snprintf() length param or something similar which is sometimes missing my '\n' at the end of a string, leaving it as '\0', which means that the printf() call is only ever giving a '\r' to putChar(). I shall have to take a very close look in the debugger.

I would prefer I2C or SPI for debugging if there is no UART available, because I2C and SPI provide their own clock, and therefore don't care if the transmission gets interrupted by an interrupt.

Hence why I went down the road of I2C to start with - let the hardware handle everything!

For speeding up your I2C transmission, you could implement a simple state machine:
If the I2C code receives a character and there is no active transmission, it initiates own. It keeps using the I2C bus until it receives an end of line character. Then it stops and gives the bus free. You don't need any buffering, because you can send each character immediately.
This will occupy the I2C bus for quite some time, but if you have only one I2C bus master it doesn't care.

A nice idea. Perhaps I will consider that so I can get rid of the buffer if I am running short on memory.

Sorry to be picky, but in one of your post, you wrote:

First line. Blah blah blah blah blah blah.
Second line. AAAAAA

When the problem occurs I'll get this:

Second line. AAAAAAah blah blah blah blah.

and this is a typical example of non NULL terminated string, whatever PROGMEM printf and fmt used.

But, it would be better if you post the full code, to have a real overview.

Cheers.
---
Daniel

[HwAoRrDk]

Sorry to be picky, but in one of your post, you wrote:

First line. Blah blah blah blah blah blah.
Second line. AAAAAA

When the problem occurs I'll get this:

Second line. AAAAAAah blah blah blah blah.

and this is a typical example of non NULL terminated string, whatever PROGMEM printf and fmt used.

No, sorry, but I think you are flogging a dead horse here with irrelevant talk about null-terminated strings. Those examples were supposed to illustrate what I am seeing on the final serial console output. Like I said before, I am 99.9% certain that each line is being separately written out to the I2C bus.

In fact, I just had a brainwave whilst writing this post. I realised I can get PuTTY to log all the raw data being received over the COM port. I just did a test run with logging enabled, and was lucky (or should that be unlucky?) enough to have the problem happen right away, after only a couple of lines of debug output. So if you don't believe me, take a look at the following screenshots:




There is an instance of overlapping lines, but both lines were received, with the first line missing its LF and having CR only. So it definitely is just as I first thought!

[f1rmb]

Sorry to be picky, but in one of your post, you wrote:

First line. Blah blah blah blah blah blah.
Second line. AAAAAA

When the problem occurs I'll get this:

Second line. AAAAAAah blah blah blah blah.

and this is a typical example of non NULL terminated string, whatever PROGMEM printf and fmt used.

No, sorry, but I think you are flogging a dead horse here with irrelevant talk about null-terminated strings. Those examples were supposed to illustrate what I am seeing on the final serial console output. Like I said before, I am 99.9% certain that each line is being separately written out to the I2C bus.

In fact, I just had a brainwave whilst writing this post. I realised I can get PuTTY to log all the raw data being received over the COM port. I just did a test run with logging enabled, and was lucky (or should that be unlucky?) enough to have the problem happen right away, after only a couple of lines of debug output. So if you don't believe me, take a look at the following screenshots:




There is an instance of overlapping lines, but both lines were received, with the first line missing its LF and having CR only. So it definitely is just as I first thought!

Okay okay. But relying on CR/LF isn't that clean. '\0' as string separator, and double '\0' as terminator would be better.
Anyway, your implementation for your needs.

Cheers.
---
Daniel

[HwAoRrDk]

But relying on CR/LF isn't that clean. '\0' as string separator, and double '\0' as terminator would be better.

String separators? What? I'm not trying to put multiple strings into one buffer array... anywhere, at all... I'm pretty sure at this point you've got completely the wrong end of the stick.

Let's not muddy the waters any further by talking about whether or not I'm properly null-terminating my strings.

[HwAoRrDk]

Alrighty, I found my problem!

Convinced that the problem lay in the code that was running on the Arduino acting as a 'bridge' between I2C and serial, I starting examining it closely, which included also digging in to what the Arduino Wire library does. Something caught my eye; the following code that's part of the ISR in the lower-level TWI library that Wire is wrapping:

Code: [Select]

    case TW_SR_STOP: // stop or repeated start condition received
      // ack future responses and leave slave receiver state
      twi_releaseBus();
      // put a null char after data if there's room
      if(twi_rxBufferIndex < TWI_BUFFER_LENGTH){
        twi_rxBuffer[twi_rxBufferIndex] = '\0';
      }
      // callback to user defined callback
      twi_onSlaveReceive(twi_rxBuffer, twi_rxBufferIndex);
      // since we submit rx buffer to "wire" library, we can reset it
      twi_rxBufferIndex = 0;
      break;

Hmm, maybe there's a bug with tracking of the index and it's overwriting my trailing LF with that null character it's adding? What size is TWI_BUFFER_LENGTH, anyway? It's 32 characters? How long are the lines I'm transmitting? Heyyyy... wait a minute... the 'cut-off' point in lines of output where this problem occurs happens to be at exactly 32 characters!

My eyes strayed further up to where there was another reference to TWI_BUFFER_LENGTH:

Code: [Select]

    case TW_SR_DATA_ACK:       // data received, returned ack
    case TW_SR_GCALL_DATA_ACK: // data received generally, returned ack
      // if there is still room in the rx buffer
      if(twi_rxBufferIndex < TWI_BUFFER_LENGTH){
        // put byte in buffer and ack
        twi_rxBuffer[twi_rxBufferIndex++] = TWDR;
        twi_reply(1);
      }else{
        // otherwise nack
        twi_reply(0);
      }
      break;

Doh! It's NACK-ing when its receive buffer is full! And at the master side, in my code, I'm handling that by simply skipping transmission of the rest of my buffer. Dammit, I would have noticed that immediately if I had some way of examining what was going across the wire. And why do they have to have such a small receive buffer?

Anyway, looks like I have a couple of ways of fixing the problem:

- Override the definition of TWI_BUFFER_LENGTH in the Arduino code and make the buffer larger.
- Reduce the size of my transmit buffer to 32 characters.
- Implement some kind of transmission retry mechanism?

For the latter, what would be the proper way to go about that? Should I have a short pause, then do a repeated start and carry on transmitting the remaining bytes in my send buffer? Perhaps some kind of retry counter as well so that it gives up after too many NACKs?

[HwAoRrDk]

Well, this sucks. The only thing that seemed to solve the problem once-and-for-all is to reduce the size of my I2C transmit buffer to 32 characters.

I tried redefining TWI_BUFFER_LENGTH in the code running on the Arduino, but no success because the Wire library has it's own 32-character buffer with a length definition that you can't override.

I also implemented a retry mechanism in my transmit code, but that didn't seem to help either. I made it so that if it encounters a NACK when writing a data byte, it issues a repeated start plus slave address, then continues writing data bytes from the point where it failed. If my interpretation of twi.c is correct, this repeated start should have made it issue the callback to the Wire library to get it to copy out the received data, just as if it had received a stop. However... there is the following code within TwoWire::onReceiveService() that I think may be messing things up:

Code: [Select]

  // don't bother if rx buffer is in use by a master requestFrom() op
  // i know this drops data, but it allows for slight stupidity
  // meaning, they may not have read all the master requestFrom() data yet
  if(rxBufferIndex < rxBufferLength){
    return;
  }

I think a race condition is occurring. Because my Arduino code may not have finished reading out the received data by the time onReceiveService() is called a second time, so rxBufferIndex will not be equal to rxBufferLength, and this if statement will cause it bail out, and so I lose the data anyway.

Perhaps if I do as I thought earlier and put a delay in before the repeated start, it may work around this issue.