Problem Serial.print change my timing

Hi everyone and sorry for my poor English. I’m working on a prototype to measure very high currents (until 80kA) through a shunt. The pulse can be very short, so I’ve decided to use a 12bits ADC, faster than the Arduino.
I can get the ADC working, but I have a problem ;

byte i=0; //compteur
//stockage des données
int courant[250]; 
int tension[250];
//valeurs maximum
int i_courant_max;  
int i_courant_min;  
int i_tension_max;
int i_tension_min;
float t_courant_max;
//octets provisoires
byte courant_low;
byte courant_high;
byte tension_low;
byte tension_high;

void setup() {
  //initialisation de la communication série
  Serial.begin(115200);
  //déclaration des entrées/sorties

  //entrées du CAN
  pinMode(0,INPUT);     //poids faible
  pinMode(1,INPUT);
  pinMode(2,INPUT);
  pinMode(3,INPUT);
  pinMode(4,INPUT);
  pinMode(5,INPUT);
  pinMode(6,INPUT);
  pinMode(7,INPUT); 
  pinMode(A0,INPUT);
  pinMode(A1,INPUT);
  pinMode(A2,INPUT);
  pinMode(A3,INPUT);    //poids fort
  //pilotage du CAN
  pinMode(10,OUTPUT);   //Startconv, PORTB2
  pinMode(9,OUTPUT);    //CS, PORTB1
  pinMode(8,OUTPUT);    //RD, PORTB0
}

void loop() {
  i = 0;
  do{
    //boucle d'acquisition
    bitSet(PORTB,2);  //génération d'un front montant sur startconv
    ///////////////////////////////////////////////////////////////
    //opérations durant le temps de conversion (1,45µs)
    bitClear(PORTB,2);  ////réinitialisation de la demande d'acquisition
    bitClear(PORTB,1);  //changement d'adc
    bitSet(PORTB,0);    //réinitialisation de la demande lecture
    tension[i] = word(tension_high,tension_low);
    courant[i] = word(courant_high,courant_low);
    ////////////////////////////////////////////////////////////////
    bitClear(PORTB,0); //demande de lecture
    tension_low = PIND;
    tension_high = PINC;
    bitSet(PORTB,1);    //changement d'adc
    courant_low = PIND;
    courant_high = PINC;
  }while(i++ < 250);
  Serial.print(tension[40]/2048.0*5.0);
  Serial.print(" V\n");
  Serial.print(tension[40]);
  Serial.print("\n");
  Serial.print(t_courant_max);
  Serial.print(" µs\n\n");
  delay(1000);
}

Here is my code. If I comment the 6 lines “Serial.print()”, my WHILE loop is done in 2µs ; very good, that’s the speed I need!
If I uncomment the 6 lines “Serial.print()”, my WHILE loop slow down, about 2.8 or 3µs if I remember well.
And If I add a function to find the maximum value, it’s worse. I’ve looked at that with my oscilloscope.

I don’t understand because this code is not INSIDE my loop. I don’t understand how it can slow down my loop (I need it to be FAST). I’ve tried to stop the interruptions during the loop, but nothing changes.

My purpose is to send the datas to a PLC with MODBUS TCP after that, so if my loop slow down each time I add a line :smiley:

What’s wrong with my work? Would you help me?

Thank you very much!
Tristan.

  Serial.print(t_courant_max);
  Serial.print(" µs\n\n");

How are you determining the time it takes?

t_courant_max is initially 0.0 and remains unchanged.

BTW that’s a DO loop as you might put it, not a WHILE. Shouldn’t make a difference, just a bit odd to see.

Since those are the only print statements, removing them all might cause some difference to the compiled code. Grasping at straws…

Put a

serial.println("bonjour mon ami!");

in setup() so this might not happen. As an experiment, trés facile!

a7

Hi and thank you for your answer.

Indeed, “t_courant_max” was defined in another function which find the maximum current and determine the time to reach this current by his position in the array. I’ve delete this function (for the moment) to understand interactions with my speed problem.

I determine the time by putting a probe directly on the pin of the ADC, which is wired with an ARDUINO output. So I can see the timing of the differents signals. I try to do things that take time during the adc conversion, wich is “dead time” if I don’t use it.

For the DO/WHILE, yes you’re right, i’m going to change that, it’s less readable.

I’ll test to put a Serial.print in the setup tomorrow :slight_smile:
Thank you for your help!

Tristan.

Serial prints take time if the TX buffer fills up
Check out my tutorial on Arduino Serial I/O for the Real World
for how to add a non-blocking Serial output buffer

The data that is transfered is small, the baudrate is 115200 and there is a delay of a second; I doubt that your suggestion helps :wink:

Hi and thank you everyone for your help.
This morning I’ve checked some things.

  • If I don’t put any Serial.print in my code, my loop takes 2µs.
  • If I put a Serial.print(“blabla”), so only text, my loop timing doesn’t change.
  • If I put a Serial.print(tension[40]/2048.0*5.0), MY TIME CHANGES TO 3.2µs!
    -If I do the same calculation outside of the Serial.print, the time is the same, 3.2µs.

So, the Serial.print doesn’t change anything, but if I do some maths…
I don’t understand what happens? Is it possible that the compiler needs some place in the register and takes some time to move the results?

I only need the program to be fast inside this loop. Next, it will find the maximum and minimum in the Array and then send these values to the PLC through MODBUS TCP.

I hope my English is well enough.
Tristan.

PS :

I’ve tried to not put any maths in my code BUT to declare tension as a VOLATILE variable. The time rise from 2 to 3.2µs. So I think it’s a memory “problem”.
I would need to do my loop with a non-volatile variable and the other stuff with volatile variables if needed.

Tell me if I’m wrong!

Floating point calculations are slow. You might want to consider to modify it to integer calculations.

  int32_t t = tension[40] * 100L / 2048 * 5;
  Serial.println(t);

That value will now be 100 times too big. So you can e.g. divide the result by 100

  Serial.print(t/100);
  Serial.print(".");
  int tmod = t%100;
  if(tmod < 10)
  {
    Serial.print("0");
  }
  Serial.println(tmod);

Note that modulo (%) might also be slow but give it a shot.

Not tested, just to give you the idea.

True that.

But the OP claims to be measuring the time in the while loop, which has no floating point or serial comms…

Can you (@betasub) use an extra output pin to produce a pulse that is HIGH during the while loop and LOW for the floating point calcs and printing (and delay)? Rather than the way you do it now, which you have explained only briefly.

Again, an experiment and sanity check.

a7

Hi! Waiting for help and letting me some time to think a little bit, I’ve done the part which send the data to the PLC via Modbus TCP. That’s working :smiley:
I come back on the timing problem tomorrow I think.
I’ll tell you. Thank you all again.

Tristan.

Another way to speed up the code execution is to precalculate any values used in a formula so it is only done once. A second speed up is to use shift and add or shift and subtract when dealing with computing something using a single digit.
Paul

I’m trying all these ideas and measuring tomorrow or friday, to understand.
Then, I will have several options ;
-Do maths in the PLC (better for scaling ans calibrating my shunt, 0,1mohm!).
-Try to be smart :slight_smile:
-Perhaps one point each 3us is enough to find the maximum with precision, because the wave is a half sinus, so the maximum is more “flat” (Rising time of the slowest current generators is 100ms, I will have to slow the acquisition, rising time of the fastest is 100us).
-Change for an Arduino Due!

Il reach my limits in English :slight_smile:

While wanting to get on with what you are trying to accomplish is understandable, I express hope that the basic mystery

why does printing and maths in one part of a program slow down a loop that uses neither?

gets resolved somewhere along the way.

It may not matter here, but if your timing measurements are valid, there’s something going on that could be good to know about.

If you have time and a spare pin, I would be curious to see if a simple output pulse HIGH during that 2 or sometimes more uS changes, that is to say I still don’t know for sure how you are obtaining these data and suspect that you are not actually measuring what you think.

a7

By default, the Serial output is interrupt driven, and I suspect that your timing change is due to a uart interrupt occurring inside your loop. (It’s not a large enough time difference to be caused by the serial.write() blocking, as other people are trying to claim.)

You can maybe fix this by disabling interrupts around your time-critical section, perhaps using atomic_block: avr-libc: <util/atomic.h> Atomically and Non-Atomically Executed Code Blocks

Perhaps. I don’t have a handle on this at such a level.

But my understanding of interrupt-driven serial output is that following Serial.printing at 115200 baud with a 1000 mS delay should mean that the answer lay elsewhere.

So I hope @betasub can take a moment for either or both of the proposed experiments.

And I’m off to see if i can find serial.print code doing its thing…

edit/add it occurs to me that if @westfw’s idea has merit, it can be investigated anywhere, as the actual function of the while loop would be unimportant. I don’t think I’ll be able to resist.

a7

Ah. I didn’t notice the delay(). You’re right; serial interrupts should be all done by the time your do loop executes again.

Could you post the exact “faster” code?

If I remove ALL the print statements that reference tension, it looks like the compiler optimizes away the stores to that array.

  do {
    //boucle d'acquisition
    bitSet(PORTB, 2); //g<C3><A9>n<C3><A9>ration d'un front montant sur startconv
 674:   2a 9a           sbi     0x05, 2 ; 5
    //op<C3><A9>rations durant le temps de conversion (1,45<C2><B5>s)
    bitClear(PORTB, 2); ////r<C3><A9>initialisation de la demande d'acquisition
 676:   2a 98           cbi     0x05, 2 ; 5
    bitClear(PORTB, 1); //changement d'adc
 678:   29 98           cbi     0x05, 1 ; 5
    bitSet(PORTB, 0);   //r<C3><A9>initialisation de la demande lecture
 67a:   28 9a           sbi     0x05, 0 ; 5
    //*******************************************
    tension[i] = word(tension_high, tension_low);
    courant[i] = word(courant_high, courant_low);
    //  NO CODE IS GENERATED FOR THOSE STATEMENTS !!!

    bitClear(PORTB, 0); //demande de lecture
 67c:   28 98           cbi     0x05, 0 ; 5
    tension_low = PIND;
 67e:   89 b1           in      r24, 0x09       ; 9
 680:   80 93 c3 01     sts     0x01C3, r24     ; 0x8001c3 <tension_low>
    tension_high = PINC;
 684:   86 b1           in      r24, 0x06       ; 6
 686:   80 93 c2 01     sts     0x01C2, r24     ; 0x8001c2 <tension_high>
    bitSet(PORTB, 1);   //changement d'adc
 68a:   29 9a           sbi     0x05, 1 ; 5
    courant_low = PIND;
 68c:   89 b1           in      r24, 0x09       ; 9
 68e:   80 93 c1 01     sts     0x01C1, r24     ; 0x8001c1 <courant_low>
    courant_high = PINC;
 692:   86 b1           in      r24, 0x06       ; 6
 694:   80 93 c0 01     sts     0x01C0, r24     ; 0x8001c0 <courant_high>
  } while (i++ < 250);
 698:   80 91 c4 01     lds     r24, 0x01C4     ; 0x8001c4 <i>
 69c:   91 e0           ldi     r25, 0x01       ; 1
 69e:   98 0f           add     r25, r24
 6a0:   90 93 c4 01     sts     0x01C4, r25     ; 0x8001c4 <i>
 6a4:   8a 3f           cpi     r24, 0xFA       ; 250
 6a6:   30 f3           brcs    .-52            ; 0x674 <main+0x170>

(the code needed to store tension[i] is actually relatively substantial:

    tension[i] = word(tension_high, tension_low);
 8d6:   e0 91 2b 03     lds     r30, 0x032B     ; 0x80032b <i>
 8da:   f0 e0           ldi     r31, 0x00       ; 0
 8dc:   ee 0f           add     r30, r30
 8de:   ff 1f           adc     r31, r31
 8e0:   eb 5c           subi    r30, 0xCB       ; 203
 8e2:   fe 4f           sbci    r31, 0xFE       ; 254
 8e4:   80 91 29 03     lds     r24, 0x0329     ; 0x800329 <tension_high>
 8e8:   90 91 2a 03     lds     r25, 0x032A     ; 0x80032a <tension_low>
 8ec:   89 27           eor     r24, r25
 8ee:   98 27           eor     r25, r24
 8f0:   89 27           eor     r24, r25
 8f2:   91 83           std     Z+1, r25        ; 0x01
 8f4:   80 83           st      Z, r24

word() does not seem to be very optimal, nor does it get very optimized :frowning:

It looks like things will improve substantially if you make some of the variables local to loop:

void loop() {
  byte i = 0;
  byte courant_low;
  byte courant_high;
  byte tension_low;
  byte tension_high;

The loop code goes from ~84 bytes to 30 bytes!

Hi everyone and thanks for your suggestions. I’m not going to answer to everyone but I’m trying to synthesize what you’ve said until here.
I’ve already tried to disable the interrupts during my loop.

I said in another post :

PS :

I’ve tried to not put any maths in my code BUT to declare tension as a VOLATILE variable. The time rise from 2 to 3.2µs. So I think it’s a memory “problem”.
I would need to do my loop with a non-volatile variable and the other stuff with volatile variables if needed.

Tell me if I’m wrong!

And yes, I think today it’s a problem of memory/variable declaration.

@alto777 , it’s a professional project and i’m an electrical engineer, so don’t worry my way to measure the loop is correct :slight_smile:

With the program given in the first post and without maths or print, we have that ; 2µs


The signal is the pin “Startconversion” ; the ADC start his conversion on a rising edge.

Now, if I add a calculation (Serial.print is not the problem finally). 3,2µs

And if I add a function to find the maximum values… 4,1µs!

Then I’ve read what @westfw was saying, it’s very interesting! So I’ve done new measures, with the complete project (find maximum, send datas with modbus…)

Nothing changes! 4,1µs


In Yellow we have “Start conversion”, in blue, “end of conversion” and in purple it’s the “read” command (I read on low level). Falling edge of “read” must be after “end of conversion”.

If I listen to @westfw and try to declare variable as local and not global, it’s way better! 2,9µs

Could you tell me what is the soft you use to have the assembly code? I think you not decode directly HEXA, it’s long!

I still have many things to learn, but thanks to you, I’ve already improved my code :slight_smile:
Tristan.

avr-objdump -SC sketch.elf

Objdump is in the same directory as avr-gcc, and the .elf file is … somewhere. Both will show up in verbose output from a compile.