What in the world? Some randomness with millis() and subtraction

The code below and the output dont make sense at all to me. Anyone know what is happening here?

i.e. how could those 90k values for now and old ever get there?

Serial Out:

61482
96771
60980
35791
502
skipping delay
61985
61984
96771
4294932509
4294932510
skipping delay
62486
97775
61984
35791
502
skipping delay

Relevant Code:

int try_process () {
    unsigned long now = millis();
    unsigned long odiff = now - old;

    if (odiff > 2000UL) {
        connect();
        Particle.process();
        unsigned long diff = millis() - old;

        Serial.println(millis());
        Serial.println(now);
        Serial.println(old);
        Serial.println(odiff);
        Serial.println(diff);

        old = now;
        if (diff > my_delay) {
            Serial.println("skipping delay");
            return 0;
        }
        return 1;
    }

    return 1;
}

Don’t you want old to be a persistent variable by declaring it static? Or something like that?

3 Likes

For the lifetime of the program I figured it would be in scope (since I declare it outside of a proper function). Maybe this is me being naive.
What happens in my case if it is not static? Does it get assigned to a random unsigned int block of memory thus making it something unpredictable?

so if old is global… right it’s persistent, but then what does the rest of your code look like?

What system version are you using?
There were some fixes about making millis() and micros() atomic in some recent update.

Also try using Serial.printlnf("varName: %u", varName); for clarity what output stands for what.

BTW: that 4294932509 looks very much like a unsigned long overrun - what type is old of?

1 Like

I initialize like so

//int debug_led = D7;
int tmp = 0;
int up = 1;
int mode = 1;
int my_delay = 500;
unsigned long old = 0;

When the default 0.5.3 firware selection on the web ide gave me this trouble I tried 0.6.0-rc2 but that failed to flash. So at the moment I am 0.6.0-rc1.

for you, you might have a keen understanding of the numbers you see on the Serial output. But, you may also benefit from (as others may too) giving a little description of what all the numbers mean!

something like this:

int try_process () 
{
  unsigned long now = millis();
  static unsigned long lastMillis = 0;
  if (now - lastMillis > 2000UL) 
  {
    connect();
    Particle.process();
    unsigned long functionMillis = millis();
    Serial.printlnf("Currrent millis() = %u", functionMillis);
    Serial.printlnf("Entered function at %u millis", now);
    Serial.printlnf("Functions took %u milliseconds", functionMillis - now);
    Serial.printlnf("Last ran function at %u millis", lastMillis);
    Serial.printlnf("Total elapsed millis betweeen calls = %u", now - lastMillis);
    lastMillis = now;
    if ((now - lastMillis) > my_delay) 
    {
      Serial.println("skipping delay");
      return 0;
    }
    // return 1; //eliminate as superfluous 
  }
  return 1;
}

As a side note, you may also benefit from using more meaningful variable names… and meaningful scope. in my edited code, I think that lastMillis is only used in try_process() and make that known by keeping it within the scope of that function. Making a variable global implies that it may be affected/used in multiple places. That may be the case in your (yet to be disclosed) code, but worth mentioning nonetheless.

To me, it looks like one of your unsigned subtractions is wrapping to a number less than zero… but I don’t know what number I am looking at!!!

1 Like

Yeah old is global and only used in this function. I like scoping it this way too… I was just running some quick tests hence the global and the variable names.

Yeah of course, but looking at the code… why/how.

“lastMillis/old” is always set to what “now” was. “lastMilliis” is then always set to millis() the next time try_process is called. So how would “lastMillis” ever me greater than now? At absolute worst “now” and “lastMillis” would be equal. But the condition where “lastMillis > now” seems wonkey to me.

All of that (besides me potentially tampering with “old” outside of try_process) is visible in try_process.

It should not really be relevant but maybe I missed something stupid thus the code is here http://pastebin.com/u4yujmLW

Welp this is kinda promising, the docs state that math with UL and other types produces undefined behavior:
fastled-test.cpp:69:20: warning: comparison between signed and unsigned integer expressions [-Wsign-compare]

int try_process () {
    static unsigned long old = 0;
    unsigned long now = millis();
    unsigned long odiff = now - old;

But “odiff” “now” and “old” are all unsigned longs. Anyone know what is up here?

Have you tried the fixed-width integer type uint32_t instead of unsigned long? The uint32_t type would be guaranteed to overflow at 2^32.

1 Like