Modulo on unsigned long storing millis() and Serial.print unexpected behavior

Hi,

I am trying to do something every second (I know, this could be coded another way like shown here http://forum.arduino.cc/index.php?topic=247117.0).

To evaluate whether one second has elapsed, I read the current time via millis() and evaluate whether its modulo by 1000 returns 0.

My sketch is however behaving strangely. Here is my code:

void setup() {
  // put your setup code here, to run once:
  Serial.begin(115200);
  while(!Serial) {
    ;
  }
}

void loop() {
  const unsigned long currentTime = millis();
  //Serial.println(currentTime);                          // first serial.print
  if (currentTime % 1000 == 0) {                          
    // Serial.println(currentTime);
    Serial.println("********* - *********");     // second serial.print
    // do something interesting
  }
}

If I do not print anything to serial, it prints every seconds 5 lines with "********* - ".
If I uncomment the second serial.print to print the value stored in currentTime, currentTime and "
- " are printed 5 times to the console and currentTime seems to have been rounded (down, I guess) to the nearest multiple of 1000.
If I uncomment the first serial.print, it prints a lot of currentTime (as expected, but contaminating my serial console), but the line with "
- *********" is printed once every second (which is precisely what I was expecting).

This was tested on an ESP32.

Any reason for this strange behavior? Does the modulo of an unsigned long rounds the unsigned long which is being divided?

Many thanks

Once per second, the condition test in the 'if' statement will be true for an entire millisecond. How many times do you think the loop() function will run during that millisecond?

If you know it can be coded another way, why are you using modulo? That is a very expensive test and must be used in conjunction with a flag so that it only occurs once. After that, the flag must be reset for the next second. A very convoluted means of executing a very simple task.

I usually use something like:

const unsigned long ONE_TICK = 1000UL;

unsigned long last_tick = 0UL;
unsigned long total_ticks = 0UL;

void setup() {
  Serial.begin(115200);
  Serial.println("Start!");
}

void loop() {
  
  if ((millis() - last_tick) >= ONE_TICK) {
    // this block executes once per tick
    last_tick += ONE_TICK;
    total_ticks++;
    Serial.print("This is tick number ");
    Serial.println(total_ticks);
  }
  
}

Well, use that now.

Sorry odo, thought you were OP.

@fgalvo, thank you, I would agree with you (the loop() function might run several times in one millisecond) but when I uncomment the first Serial.print(), I only print ONCE the “********* - *********” line to the console.

So, taking your comment into account, my question could be formulated otherwise: why does the loop() function run only ONCE per milliseconds when I Serial.print() before the if and 5 times when I Serial.print() in the if?

@DKWatson, thank you so much for your nice reply. I really appreciate your concern for my resource usage. However relax, the point was not to have the most optimal code ever (I mentioned that I know that there are other ways to code this, but my question was not to look for optimisation suggestion; maybe I should have mentioned that I had already done my homework and googled the modulo function before posting my question and know that modulo eats up a lot of resources. But I tried to stay concise. Please @DKWatson, forgive me, I am just trying to apply your signature: “Learn as if you were to live forever.” 8) :smiling_imp: ).

The point was to UNDERSTAND WHY, when changing the position of the Serial.print(), the modulo works as expected when it does not when the Serial.print() is positioned after evaluating the condition.

@odometer, thank you, this is a very elegant way to code this.

Vrex:
So, taking your comment into account, my question could be formulated otherwise: why does the loop() function run only ONCE per milliseconds when I Serial.print() before the if and 5 times when I Serial.print() in the if?

My guess is that it only looks like that's what's happening. Let's say for argument's sake that your loop executes 5000 times per second and that after you uncomment the first 'Serial.println(currentTime);' it takes 10 characters to print the (unsigned long) 'currentTime'. That means you're trying to put 50,000 characters into the print buffer every second.

Now, at 115,200 baud, the serial hardware will be pulling 11,520 characters out of the buffer every second.

See problem with that situation? Once the buffer (50 characters, I believe) becomes full, the 'Serial.println()' function will block until enough characters are removed to allow placing the next string into it. So, I'm guessing some of the 'currentTime % 1000 == 0' cases are simply being missed.

gfvalvo:
My guess is that it only looks like that's what's happening. Let's say for argument's sake that your loop executes 5000 times per second and that after you uncomment the first 'Serial.println(currentTime);' it takes 10 characters to print the (unsigned long) 'currentTime'. That means you're trying to put 50,000 characters into the print buffer every second.

Now, at 115,200 baud, the serial hardware will be pulling 11,520 characters out of the buffer every second.

See problem with that situation? Once the buffer (50 characters, I believe) becomes full, the 'Serial.println()' function will block until enough characters are removed to allow placing the next string into it. So, I'm guessing some of the 'currentTime % 1000 == 0' cases are simply being missed.

Thank you very much. Very clear answer. Get it now.