Does micros(); LAG??? Very interesting phenomenon!

Hi, I was just playing with my arduino uno r3 board.

I was using micros(); function.

At first, I wanted to see the time Serial.println("HI"); takes, then turned out that it varies alot!
From 5000us~8us!!!!

Then I started doing some experiments. For example, I gave delay(1); to the end of the code. Thinking that this wouldn't affect the time measurement because it is not between time measurement as you can see down here!!
Actually the first result is showing the affect of how many time you read the data(you'll see!)

-->>

void setup(){

Serial.begin(9600);//I set the baud rate to be 9600

}

int i=0;

unsigned long count1,count2=0;

void loop(){

for(int i=0;i<15;i++){//To test the result for 15 times!

count1=micros();

Serial.print("HI ");

Serial.print(micros()-count1);//This, prints the time interval

Serial.print(" ");

Serial.println(i);

delay(1);//This is where I gave a delay.
}

delay(100000);
}// END!!

================================================
Guess what??? the result was like this
HI 36 0
HI 36 1
HI 36 2
HI 36 3
HI 40 4
HI 32 5
HI 32 6
HI 2108 7
HI 2108 8
HI 2108 9
HI 2108 10
HI 2108 11
HI 2108 12
HI 2108 13
HI 2108 14

---> You can clearly see that the time interval increases dramatically(x50)!! from 8th reading...!

Also, when there is no delay~(under)

HI 36 0 HI 32 1 HI 32 2 HI 36 3 HI 40 4 HI 32 5 HI 2640 6 HI 3116 7 HI 3116 8 HI 3116 9 HI 3116 10 HI 3116 11 HI 3116 12 HI 3116 13 HI 3116 14

=> Isn't that so interesting and confusing at the same time???

Sorry for such a messy post!! I'll conclude in 2 questions.

1.Why would time interval dramatically increase from certain point? Is it lag?? How is it possible?

2.Why would delay(1) almost exactly decrease the lagging time(?) by 1000???? How is it have an effect on it???

Thanks for reading my post, I'm a newbie so anyone who is watching this can write their thoughts and I'll be amazed...!!!

Looking forward for kind replys~

By the way, have a nice day, being happy is the best!! :D

From Junwoo HWANG(very confused :( )

Why would time interval dramatically increase from certain point? Is it lag?? How is it possible?

Because the output buffer becomes full, and Serial.print becomes blocking.

AWOL:
Because the output buffer becomes full, and Serial.print becomes blocking.

Ok! I'll check out what 'output-buffer' is!! Thanks for replying!

Your problem is the Serial.print. Change the baudrate to 115200

HI 36   0
HI 32   1
HI 36   2
HI 32   3
HI 32   4
HI 36   5
HI 32   6
HI 32   7
HI 32   8
HI 36   9
HI 32   10
HI 32   11
HI 36   12
HI 36   13
HI 36   14

The reason is that Serial.print starts blocking when the serial tx buffer (63 bytes) is full. At 9600, a byte takes roughly 1 ms. Your pumping 12 bytes per loop cycle so after roughly 6 calls to loop the buffer is full.

sterretje:
Your problem is the Serial.print. Change the baudrate to 115200

HI 36   0

HI 32  1
HI 36  2
HI 32  3
HI 32  4
HI 36  5
HI 32  6
HI 32  7
HI 32  8
HI 36  9
HI 32  10
HI 32  11
HI 36  12
HI 36  13
HI 36  14




The reason is that Serial.print starts blocking when the serial tx buffer (63 bytes) is full. At 9600, a byte takes roughly 1 ms. Your pumping 12 bytes per loop cycle so after roughly 6 calls to loop the buffer is full.

Thank you so much for replying!!
I am having trouble understanding what you exactly mean!!
So my question is...

  1. Then does it slow down after 6 calls even if buffer is full? doesn't it push away the old data??

  2. 9600 byte/s =>1 byte per 1ms?? how was that calculation done?

"Thank you again!"

  1. Then does it slow down after 6 calls even if buffer is full? doesn't it push away the old data??

  2. 9600 byte/s =>1 byte per 1ms?? how was that calculation done?

Eight data bits, one stop, one start, no parity = 10 bits.
1/960 = 1.04ms

I don't know what you mean by " doesn't it push away the old data??" (there's something wrong with your '?' key, BTW).
It takes over 1ms to shift out one character, so that's the fastest data can leave the buffer, oldest data first.

AWOL:
Eight data bits, one stop, one start, no parity = 10 bits.
1/960 = 1.04ms

I don't know what you mean by " doesn't it push away the old data??" (there's something wrong with your '?' key, BTW).
It takes over 1ms to shift out one character, so that's the fastest data can leave the buffer, oldest data first.

OH! then how does the numbers less then 1000 comes out??(really curious)

and what I meant on the number 2 was 'Doesn't old data get pushed and erased(I did a quick research and found out that tx buffer is round-type or something so it can continue it's work even if it's full it pushes away the old one) as the new data comes in??'

So I was just asking why serial.println() would block the transmission... Even though it seems there is no problem...

then how does the numbers less then 1000 comes out??(really curious)

Because until the output buffer is full, Serial.print returns almost immediately, because pretty much all it has to do is an array write, and an index update. (you have the source, why don't you take a look?).
Once it is full, each write to the buffer must wait until there is space for it, i.e. it must wait until the oldest character in the buffer is written to the tx register.

(I did a quick research and found out that tx buffer is round-type or something so it can continue it's work even if it's full it pushes away the old one)

I suspect you're confusing your tx with your rx.

(please give your keyboard a shake)

While you seem to think it would be perfectly fine if serial.print() threw away characters, the arduino thinks that if you want to print something it should print.

The serial system can print 63 characters in the background. Once you have more than that, serial.print() has no choice but to wait for a character to be sent before it can add a character to the buffer.

Think of a bathroom with a bunch of stalls. The first people that get there can go right in. But once all the stalls are full, the next person has to wait until a stall empties to use one.

. . . and you don't want a buffer overflow incident in that case.