I was just reading over another thread where they reiterated, again, that it's not a good idea to use serial.print inside an ISR for several reasons including the fact that you never want to spend too much time inside the ISR. Well I started thinking that sometimes, for debugging reasons, you may want an easy way to have a visual indicator (Serial Monitor) that your interrupt took place.
So I was wondering if anyone sees any drawback to just sending a single character out to serial monitor while inside the ISR by directly writing to the Transmit register ie UDR0 = '*' ?
Looking over the datasheet, it appears that it's non blocking and only takes one machine cycle. The only drawback I see is that if the interrupt happens while you're already sending data out serially it will overwrite one character. But as long as you know this, and again for strictly debugging purposes, I don't see why you couldn't do something like this. Here's a little example sketch, it's using Timer2 to generate an interrupt every couple of milliseconds and then printing an asterisk each time in the ISR. You can see how the output overwrites the current serial data.
void setup()
{
Serial.begin(115200);
TCNT2 = 0x00;
TCCR2A = 0x00;
TCCR2B = 0x00; //set to zero so timer does not start counting yet
TCNT2 = 0x00; //reset counter back to zero
ASSR &= ~(1<<AS2);
TIMSK2 |= (1<<TOIE2);
TIMSK2 &= ~((1<<OCIE2A)|(1<<OCIE2B));
sei();
TCCR2B = 0x05; //start timer counting
}
void loop()
{
Serial.println("Testing the feasibility of printing inside an interrupt");
delay(50);
}
ISR(TIMER2_OVF_vect)
{
UDR0 = '*'; //load character into transmit buffer and transmit
}
OUTPUT
************************Testing the feasibility of *printing inside an interrupt
************************Testing the feasibility of printing inside an interrupt
*************************Testing the feas*ibility of printing inside an interrupt
*************************Testing the feasibility of printing inside an interrupt
************************Testing the feasibility of printing inside an interrupt
************************Testing the feasibility of printing inside an interrupt
I'm going to try and do some timing checks later to verify this is as easy as it looks. Maybe it could be added to the Serial class for easier use...something like Serial.ISR()
Do the changes to Serial output in IDE 1.0 make any difference to this? As it is now asynchronous, does that reduce the overhead enough to make the use viable?
As it is now asynchronous, does that reduce the overhead enough to make the use viable?
My first thought was yes, it does. But, the "asynchronous" nature depends on a buffer. Once the output buffer is full, then serial printing blocks until there is room in the buffer. So, even outside of the ISR, you need to be careful about how much data you are sending, so there is always room in the buffer for the ISR's serial data.
If you were only sending single characters, at a high baud rate, it might be enough to spot an error.
As long as you aren't flooding the serial port with data from outside the ISR, then, yes the small amount of serial data output in the ISR could be used to spot errors. Sometimes people get carried away, though.
So I was hoping that printing the one character would be as fast as incrementing a single variable but it's not as it turns out it's actually FASTER.
Here's the sketch I used to test the timing:
volatile uint8_t test = 0;
volatile uint8_t timerCount = 0;
void setup()
{
Serial.begin(115200);
TCNT2 = 0x00;
TCCR2A = 0x00;
TCCR2B = 0x00; //set to zero so timer does not start counting yet
TCNT2 = 0x00; //reset counter back to zero
ASSR &= ~(1<<AS2);
TIMSK2 |= (1<<TOIE2);
TIMSK2 &= ~((1<<OCIE2A)|(1<<OCIE2B));
sei();
TCCR2B = 0x01; //start timer counting
}
void loop()
{
Serial.println(TCNT2,DEC);
}
ISR(TIMER2_OVF_vect)
{
// test++;
// timerCount++;
// UDR0 = '*'; //load character into trasmit buffer and transmit
// Serial.print("*");
TCCR2B = 0x00;
}
As you can see Timer2 is set to no prescaler so it's running at the highest rate possible. Once inside the ISR timer2 stops counting after the overflow interrupt is called. The time left in timer2 should be the overhead from the rollover and the call to the ISR. Running this sketch prints a value of 17 counts (~1.06us) and we'll use this number as a baseline. Now I repeated the test including one variable increment, then two, then just UDR0 and finally just a Serial print and here are the results:
It was 2 counts faster. So interestingly enough it might actually be more beneficial using this method for debugging instead. I'm going to repeat the test on 1.0 to see the time difference.
You'll have to disregard my previous results as I didn't take into account the the timer overflowing. I modified the sketch to do the timing outside the ISR but factor in the timer rollovers. The results were pretty much the same (different baseline) but when it came to 1.0 the times shot up significantly. Here's the sketch and the results:
uint8_t test = 0;
uint8_t test2 = 0;
volatile uint8_t timerCount = 0;
void setup()
{
Serial.begin(115200);
TCCR2A = 0x00;
TCCR2B = 0x00; //set to zero so timer does not start counting yet
TCNT2 = 0x00; //reset counter back to zero
ASSR &= ~(1<<AS2);
TIMSK2 |= (1<<TOIE2);
TIMSK2 &= ~((1<<OCIE2A)|(1<<OCIE2B));
sei();
}
void loop()
{
timerCount = 0;
TCCR2B = 0x01; //start timer counting
// test++;
// test2++;
// UDR0 = '*'; //load character into trasmit buffer and transmit
// Serial.print("*");
// Serial.write("*");
TCCR2B = 0x00; //stop timer counting
Serial.println(TCNT2 + (timerCount*256),DEC);
while(1);
}
ISR(TIMER2_OVF_vect)
{
timerCount++;
}
I applied the fix to Hardwareserial and the results for Serial.print and Serial.write came down dramatically to 422 and 384 respectively. It is, however, still three times slower than 022.
Here's something else I learned, apparently it's quite faster setting a variable then incrementing one. Incrementing the variable returned a 7 every time while setting the value ( test = 1) came back at 4 every time. So setting a variable is much faster than incrementing one. Also each successive print using UDR0 only adds 3 counts to the timer each time so you can print a few characters in a short time.
wayneft:
1.0 has even worse results. I thought serial.print was non blocking? I added Serial.write also and here's what I got:
...
I wonder why serial communication would be slower on 1.0 ?
Having spent a lot of time yesterday looking at HardwareSerial on 1.0 I feel qualified to comment ...
As far as I can make out, and it isn't the easiest code in the world to read, writing to the serial port on 1.0 relies totally on interrupts. And as I also noticed, the USART interrupts are somewhat lower priority than timer interrupts.
This is what HardwareSerial::write does:
size_t HardwareSerial::write(uint8_t c)
{
int i = (_tx_buffer->head + 1) % SERIAL_BUFFER_SIZE;
// If the output buffer is full, there's nothing for it other than to
// wait for the interrupt handler to empty it a bit
// ???: return 0 here instead?
while (i == _tx_buffer->tail)
;
_tx_buffer->buffer[_tx_buffer->head] = c;
_tx_buffer->head = i;
sbi(*_ucsrb, _udrie);
return 1;
}
Notice that it makes no attempt to actually output the byte, even if it was able to do so. It gets placed into the buffer and then interrupts (Data Register Empty Interrupt Enable) turned on (even if they already are, sigh). Later on, when the interrupt fires, that byte will be removed from the buffer and output. Compare to version 0022:
void HardwareSerial::write(uint8_t c)
{
while (!((*_ucsra) & (1 << _udre)))
;
*_udr = c;
}
Clearly, 0022 will be faster in the cases where a byte is able to be written immediately.
If I may suggest, the techniques I documented here will give fast, reliable results:
Using the "debug SPI slave" posted there, and this test sketch for the "sketch under test":
#define DEBUG
#include <SPI.h>
#include "pins_arduino.h"
const byte LED = 9;
ISR (TIMER1_COMPA_vect)
{
static boolean state = false;
state = !state; // toggle
digitalWrite (LED, state ? HIGH : LOW);
#ifdef DEBUG
digitalWrite(SS, LOW);
SPI.transfer ('*');
digitalWrite(SS, HIGH);
#endif
}
void setup() {
#ifdef DEBUG
SPI.begin ();
SPI.setClockDivider(SPI_CLOCK_DIV8);
#endif
pinMode (LED, OUTPUT);
// set up Timer 1
TCCR1A = 0; // normal operation
TCCR1B = _BV(WGM12) | _BV(CS10); // CTC, no prescaling
OCR1A = 1000; // compare A register value (1000 * clock speed)
TIMSK1 = _BV (OCIE1A); // interrupt on Compare A Match
} // end of setup
void loop() { }
This is using a timer to fire every 62.5 uS (1000 * clock speed). It outputs an asterisk as an indicator inside the ISR. Screen shot of the results:
As you can see, the debugging byte only took 3.75 uS to be sent, well inside the time we have available in the ISR. Meanwhile, sending a single byte at 115200 baud takes 1/11520 seconds, namely 86.8 uS, a lot longer.
Now of course, loading up UDR0 is even faster (because you don't wait for it to be sent) but the second time around you either have to wait, or you lost a debug byte.
You can make SPI even faster by taking out the setClockDivider line. Then the transfer time is 1.833 uS. However tests show that the receiving end won't keep up with very rapid transfers at that rate. For bursts it could be OK.
Now of course, loading up UDR0 is even faster (because you don't wait for it to be sent) but the second time around you either have to wait, or you lost a debug byte.
Actually I was able to do 3 successive prints with no data loss, maybe I'll have to try more and see where it overflows.
Clearly, 0022 will be faster in the cases where a byte is able to be written immediately.
You appear to be correct. I ran a test and checked the speeds between 1 character and 26 character printouts and the results are very strange. You can see the chart here (http://dsscircuits.com/images/images/1vs022.jpg) I tried attaching the image but it said the server was full or something.
022 is faster when printing one byte. 1.0 is faster when printing 2 - 12 bytes but then is only slightly faster after that. The "patched version" is also faster but only from 2 - 8 bytes and then the speed follows 022. It's strange because you would think you could take advantage of the speed increase up to 32 bytes but it does not appear to be the case.
wayneft:
Actually I was able to do 3 successive prints with no data loss, maybe I'll have to try more and see where it overflows.
I think there is a single byte buffer in the output register, so you would expect at least 2, and maybe by the time you got to the third the first one had been sent.
wayneft:
Actually I was able to do 3 successive prints with no data loss, maybe I'll have to try more and see where it overflows.
I think there is a single byte buffer in the output register, so you would expect at least 2, and maybe by the time you got to the third the first one had been sent.
[/quote]I played around with it a little more and could only get a 2 byte transfer to reliably work.
You will only get 2 bytes to work without waiting for one to go which kind of defeats the purpose
The first one goes into UDRn and is immediately transfered by the hardware to the Tx shift reg. The next one also goes into UDRn to be sent in due course. Any more and you have to wait.
Unless you code is unbelievably slow (or the bit rate extremely fast) I can't see how 3 bytes would ever work.
