Serial.write command execution time variations

Hi, I'm writing a module for spatial orientation using Arduino UNO. I came across a weird behaviour of Serial.write lately (I send pretty big amount of data through serial and I need it to be send fast, that's why Serial.print is useless). It worked fine until today, when I checked the sampling time of my sketch (micros() before first and after last command at loop() section) and found out that the execution time of Serial.write varies from 1600 us to even 15000us! I can't understand where did this come from, especially that when I checked it previouselly (before writing libraries for the project, about week before) the sampling times were very stable (about 30 us variation). I need program execution time to be constant and possibly shortest as I use numeric integration acions in my computations. I send 60 bytes of data through the serial in every loop realisation. What may cause the execution time variations? Why did this parameter change? How can I fix this?
Below I attach a simplified sketch of my program.

Regards
Gr4jp3r

#include <Wire.h>
#include <math.h>
#include <CompassHMC6352.h>
#include <ITG3200Gyroscope.h>

#define TP_MICROS 12000
#define TP_SECONDS 0.012

unsigned int startTime = 0;
unsigned int stopTime = 0;

byte frame[60]; 
byte frameIncrement = 0; 
\\...\\
void setup() 
{
  Serial.begin(57600);
  Wire.begin(); 
    
  \\...\\
}

void loop() 
{
  startTime = micros();  
  kompas.LeaveSleepMode();
  gyro.UpdateVelocities();
  gyro.UpdateAngles();
  kompas.DownloadAngle();
  BMAReadAccel(); 
  
  AngleFusion(zeta,w0,fusionRoll,bmaAccRoll,gyro.GetPrevVelocity(0));
  AngleFusion(zeta,w0,fusionPitch,bmaAccPitch,gyro.GetPrevVelocity(1));
  AngleFusion(zeta,w0,fusionYaw,kompas.GetAngle(),gyro.GetPrevVelocity(2));

  SetFrameReady(); 
  unsigned int t9 = micros();
  Serial.write(frame, frameIncrement);
  stopTime = micros(); 
  delayMicroseconds(TP_MICROS-(stopTime-startTime));
  // Serial.println(stopTime-t9); //This varies from 1.6ms to 15ms!
}

inline void ConvertIntToByte(unsigned int intToConvert, byte *tempByte)
{
  tempByte[0] = (byte)intToConvert;
  tempByte[1] = (byte)(intToConvert>>8);  
}

void SetFrameReady(void)
{
  frameIncrement = 0;
  byte tempByteArray[2]; 
  
  ConvertIntToByte(11111,tempByteArray); 
  frame[frameIncrement++] = tempByteArray[0];
  frame[frameIncrement++] = tempByteArray[1];
  
  \\...\\
  
  ConvertIntToByte(kompas.GetAngle()*100 +5000,tempByteArray);
  frame[frameIncrement++] = tempByteArray[0];
  frame[frameIncrement++] = tempByteArray[1];

  \\...\\

}

The first thing we'd need to know is what version of the IDE you are using.

In 1.0, the write method just loads the buffer, and then it uses interrupts to actually send the data. If the buffer is full, it waits until everything has finished transmitting (which takes comparatively long time).

Hi, I'm using IDE 1.0 (I tought that everyone use this version now, sory) Yesterday I noticed, that reducing the frame length to 50 bytes stabilizes the execution time at a little bit over 1.3ms and that time was not fluctuating (time variation was about 30us, like previously) . Today however, the same code generated Serial.write execution time 1.3ms to 3.2ms. Yesterday I tought that dividing the frame to 2 smaller ones will solve the problem but today the issue is back again. What is going on? Why do those times vary so significantly?

@WizenedEE
What did you mean by

WizenedEE:
it waits until everything has finished transmitting

? I use UART only to send this frame, communication with the sensors is realised by I2C.

The Serial.print() and Serial.write() methods in 1.0 now use interrupts to send serial data. The data is stored in a buffer, and the Serial.print()/Serial.write() commands return immediately - unless the outgoing buffer is full. If it is, the functions block until there is room in the buffer for the data they are trying to place in the buffer.

To do a real timing test, you need to call Serial.flush() after buffering the packet. Serial.flush() does nothing but block until the buffer is empty.

That way, every packet send time is consistent. Otherwise, some packets fit in the buffer, and some do not. Hence, some packets cause blocking, and some do not. In which case, you will not get consistent times.

So i need to call Serial.flush() after every Serial.write() right? It dramatically increased the frame sending time but it's more consistent for sure. Is there any other way to decrease the sending time but to provide its consistency at the same time?

So i need to call Serial.flush() after every Serial.write() right?

Maybe. Maybe not. You need to call Serial.flush() after the last Serial.write() for the packet. If the whole packet is written in one step, then yes. Otherwise, no.

It dramatically increased the frame sending time but it's more consistent for sure.

Sure, because you now ensure that Elvis has left the building before continuing.

Is there any other way to decrease the sending time but to provide its consistency at the same time?

Aside from the obvious (pick up the speed, send less data)? No.

Thanks for the anwser, I'm curious about one more thing: the buffer we are talking about is the UART buffer right? Sending the package without flushing took about 5 times less time to realise than with flushing on. What other data is stored in that buffer? Would decreasing the size of the buffer to the size of frame decrease the time needed to send the package?

the buffer we are talking about is the UART buffer right?

Yes.

What other data is stored in that buffer?

Nothing, nada, zip, zilch.

Would decreasing the size of the buffer to the size of frame decrease the time needed to send the package?

No. Writing 8 letters on a sheet of paper takes the same amount of time, regardless of the size of the paper, doesn't it? Writing 8 bytes into the buffer, and then waiting for the buffer to empty takes the same amount of time if the buffer is 10 characters as it does if the buffer is 64 characters.

PaulS:

Would decreasing the size of the buffer to the size of frame decrease the time needed to send the package?

No. Writing 8 letters on a sheet of paper takes the same amount of time, regardless of the size of the paper, doesn't it? Writing 8 bytes into the buffer, and then waiting for the buffer to empty takes the same amount of time if the buffer is 10 characters as it does if the buffer is 64 characters.

Since I'm sending always the same amount of bits (1 frame) to the buffer and than flush it immediately after calling Serial.write(), than filling and emptying of the buffer takes the same amount of time. Why does Serial.write() + Serial.flush() take more time than calling Serial.write() only? Shouldn't it be contrary? Sending only 1 frame and flushing it should take less time than filling the whole buffer with frames and than emptying it, right?

Sending only 1 frame and flushing it should take less time than filling the whole buffer with frames and than emptying it, right?

Yes, but that is not what you were measuring, before. You were measuring the time to just write to the buffer, sometimes, and the time needed to write some data to the buffer and the time needed to wait for the buffer to partially drain, other times.

Thanks, I think everything is clear right now!
PaulS, where do you get all those anwsers from?

Regards
Gr4jp3r

PaulS, where do you get all those anwsers from?

I make them up as I go along. When that fails, I read the source code.