Skip to content

6X slowdown in 1.0.6 loop() #2367

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
dmd opened this issue Oct 15, 2014 · 3 comments
Closed

6X slowdown in 1.0.6 loop() #2367

dmd opened this issue Oct 15, 2014 · 3 comments
Assignees
Labels
Component: HardwareSerial The hardware serial functionality of the core libraries Type: Regression Something that used to work and now doesn't
Milestone

Comments

@dmd
Copy link

dmd commented Oct 15, 2014

I'm seeing a 6X slowdown in arduino 1.0.6 loop() as compared to 1.0.5.

To reproduce, run the following sketch under 1.0.5, and note the printed values, which represent the delay in microseconds between the end of one iteration of the loop and the beginning of the next. Then try it again under 1.0.6.

Using 1.0.5 I get 12 uS
Using 1.0.6 I get 72 uS

This is on an ATmega2560.

unsigned long before, howlong, iters;

void setup() {
    Serial1.begin(57600);
}

void loop() {
    howlong = micros() - before;
    iters++;

    if (iters == 10000) {
        iters = 0;
        Serial1.println(howlong);
    }

    before = micros();
}
@cmaglie
Copy link
Member

cmaglie commented Oct 16, 2014

Hi @dmd !

Your test is not really measuring the time to perform 10000 loops (it measure just the latest one) BTW a slight rewrite reveals that there is indeed a problem:

unsigned long before, howlong, iters;

void setup() {
    Serial.begin(57600);
    iters = 0;
    before = micros();
}

void loop() {
    iters++;

    if (iters == 10000) {
        howlong = micros() - before;
        Serial.println(howlong);
        delay(500); // Wait for serial buffer to be emptied

        // Start a new count
        iters = 0;
        before = micros();
    }
}

Tested on a Mega1280, 1.0.5 gives 88000 and 1.0.6 480000.

With a git bisection I've found the following commit as the cause of the bug: f40e471
This change was introduced with #2057.

@matthijskooijman do you think we can revert it? There is a better solution to avoid the cast?

@cmaglie cmaglie added Component: HardwareSerial The hardware serial functionality of the core libraries Version: 1.0.x Type: Regression Something that used to work and now doesn't labels Oct 16, 2014
@cmaglie cmaglie added this to the Release 1.0.7 milestone Oct 16, 2014
@cmaglie cmaglie self-assigned this Oct 16, 2014
@matthijskooijman
Copy link
Collaborator

In that commit, it's not the type of the return expression that's cast to (unsigned) int, but it's the first operand to the modulo. I guess that doing modulo on a signed expression is significantly slower than doing it on an unsigned expression for some reason. The reason that this shows up is probably because Serialx.available() is called every loop to trigger serialEvent().

I guess we can just convert this commit, since it it doesn't actually do what it says - the cast isn't about the return type. Perhaps it would be good to add some parenthesis to emphasize this fact?

@cmaglie
Copy link
Member

cmaglie commented Oct 21, 2014

Fixed for 1.0.7.
Thanks @dmd!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Component: HardwareSerial The hardware serial functionality of the core libraries Type: Regression Something that used to work and now doesn't
Projects
None yet
Development

No branches or pull requests

3 participants