Delay function broken?

Question

I noticed timing inconsistencies in my project, and further debugging pinpointed it to the problem below. The text should be updating every second, but the returned values are>> 1000ms.

To clarify, the text is not showing up every second. The delays between texts vary according to fluctuating start and finish values.

I'm using a Teensy 3.2. Changing the baud rate doesn't help.

Is my timing crystal busted? Is there a serial buffering issue? I don't know how to fix either of these.

example code

Any help would be appreciated!

Edit:

Here's the code if anyone wants to test. I found that adding more delay functions screws the output up in completely unlinear ways.

unsigned long start, finished, elapsed;
void setup() {
 Serial.begin(115200);
}
void loop() {
 Serial.println("Start...");
 start = millis();
 Serial.println(start);
 delay(1000);
 finished = millis();
 Serial.println(finished);
 Serial.println("Finished");
 elapsed = finished - start;
 Serial.print(elapsed);
 Serial.println(" milliseconds elapsed");
 Serial.println();
}

Edit #2:

I thought it was worth showing everyone this screenshot. It looks like delay(1000) just isn't functioning at all.

screenshot

Edit #3:

I debugged it with an LED and it blinked at exactly 1s intervals. It seems like delay(1000) works, so the problem must be related to the serial buffering. I also updated my software but that didn't help.

Edit #4:

New developments from further debugging:

• The problem is not reproducible on a different computer. The Arduino serial monitor on other computers displays correctly.
• Updating to the latest OSX, arduino IDE, and teensyduino did not help.
• Terminal 'screen' command surprisingly prints correct serial communication.
• Serial monitors from 3rd party apps, like CoolTerm and Arduino IDE do not work.

• James Waldby - jwpat7: I don't know what the problem is but recommend you try grouping all the println statements together, and likewise the start=/delay/finished=/elapsed= statements, and see if that makes any difference. If so, edit question and say so. Also, it's a good idea to include in your question code that can be cut and pasted (so people can run tests) instead of just a picture of the code.
• Nick Gammon: Yes, please edit your question and post the code into it. Indent it using Ctrl+K. I have trouble believing that 23005 -ひく 11004 =わ 1000 - as shown in your screenshot.
• Nick Gammon: Well, that is nothing to do with a crystal, right? 23005 - 11004 is not 1000, so that code couldn't have printed that.
• Nick Gammon: Looks like delay just isn't functioning at all. - on what grounds? You print at the start and end of loop so you expect the end time twice, right? Which is what you get. The next time is sometimes 1000 ms later, and sometimes 2000 ms (and once 4000 ms) which is kind of weird.
• frarugi87: Have you tried with the code everyone is suggesting (i.e put the println all together)? If not, try with void loop() { start = millis(); delay(1000); finished = millis(); Serial.print("Start "); Serial.println(start); Serial.print("Finished "); Serial.println(finished); }

Answer 1

After correcting the syntax error (missing semicolon) I tried your code on my Teensy 3.0. The results look OK to me:

Start...
1250
2250
Finished
1000 milliseconds elapsed
Start...
2250
3250
Finished
1000 milliseconds elapsed
Start...
3250
4250
Finished
1000 milliseconds elapsed
Start...
4250
5250
Finished
1000 milliseconds elapsed
Start...
5250
6250
Finished
1000 milliseconds elapsed
Start...
6250
7250
Finished
1000 milliseconds elapsed
Start...
7250
8250
Finished
1000 milliseconds elapsed
Start...
8250
9250
Finished
1000 milliseconds elapsed

---

Since the code you posted doesn't compile, can you re-test please with your posted code, assuming you add in the semicolon, and put a space before "milliseconds elapsed".

---

Further down my test I see this:

Start...
153258
154258
Finished
1000 milliseconds elapsed
Start...
154259
155259
Finished
1000 milliseconds elapsed
Start...
155259
156259
Finished
1000 milliseconds elapsed

Now are you talking about the "creep" in the start time? That doesn't totally surprise me, because the rest of the code must take some time to execute.

---

I know this isn't an "answer" per se, but I can't post this much information into a comment.

• shukmeister: I tested the posted code (w/ syntax correction), and got the same results. I'm not worried about the creep, that's to be expected.

Answer 2

Since the subtraction's result (finished - start) displays alright, it means the right number is being stored in the variable, so it's Serial that is screwing up the task of printing it. Try reducing the baud rate to 9600 and try again.

• shukmeister: Changing baud rates doesn't help :/
• SoreDakeNoKoto: Oh, must have missed that in your post...have you tried just printing numbers (at least 6 digits) instead of millis() to see if this problem applies only to millis or to all arguments
• shukmeister: It applies to all arguments. I learned that the problem is independent of the hardware and must be computer related. Check out edit #4 for more info.