Skip to content
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

xtimer_core: reduce idle time #8990

Closed
wants to merge 1 commit into from
Closed

Conversation

Josar
Copy link
Contributor

@Josar Josar commented Apr 20, 2018

The idle wait time for the xtimer can be reduced with this PR.
This is a improvement for platforms with slow cpu frequency, as the shoot overhead can be taken into account. It also can help to ensure that the iddle wait time in the timer ISR is as short as possible.

Following figures show the time which the xtimer core routine idles until the time is reached to shoot.
As shown it is reduced, see timing at the right side.

before_xtimer
after_xtimer

@jnohlgard
Copy link
Member

I don't remember right now and I am too tired to examine this in detail, I believe there was some reason behind the ordering we currently have. Are there any races in the code here?

@Josar
Copy link
Contributor Author

Josar commented Apr 20, 2018

@gebart how to test for race condition, and which timer calls exactly?

I added a testcase, with different test. The periodic wakeup was firering to early.

Result is still better as before, let me know if it has any benefit.
Timings at the left side are the time from entering timer interrupt till ending in sleeping thread.
First one is when using xtimer_tsleep32 or xtimer_usleep the second one when using xtimer_periodic_wakeup and adjusting the start time and the last is with xtimer_periodic_wakeup used as it meant to be, with fixed periode.

before_xtimer
after_xtimer

Before:

Slept for 1028 ticks (expected: 1000 ticks)
Slept for 2373 ticks (expected: 2345 ticks)
Slept for 65564 ticks (expected: 65536 ticks)
Slept for 50028 ticks (expected: 50000 ticks)
Slept for 100028 ticks (expected: 100000 ticks)
Slept for 1028 ticks (expected: 1000 ticks)
Slept for 2373 ticks (expected: 2345 ticks)
Slept for 65564 ticks (expected: 65536 ticks)
Slept for 50028 ticks (expected: 50000 ticks)
Slept for 100028 ticks (expected: 100000 ticks)
Intervall 1000 ticks, start 718443 ticks, now 719462 ticks, slept 1019 ticks
Intervall 2345 ticks, start 721908 ticks, now 724272 ticks, slept 2364 ticks
Intervall 65536 ticks, start 726718 ticks, now 792273 ticks, slept 65555 ticks
Intervall 50000 ticks, start 794784 ticks, now 844803 ticks, slept 50019 ticks
Intervall 100000 ticks, start 847314 ticks, now 947333 ticks, slept 100019 ticks
Intervall 2345 ticks, now 952273 ticks, diff 19 ticks
Intervall 2345 ticks, now 954618 ticks, diff 19 ticks
Intervall 2345 ticks, now 956963 ticks, diff 19 ticks
Intervall 2345 ticks, now 959308 ticks, diff 19 ticks
Intervall 2345 ticks, now 961653 ticks, diff 19 ticks
Test ran for 5577616 us

After:

Slept for 1000 ticks (expected: 1000 ticks)
Slept for 2345 ticks (expected: 2345 ticks)
Slept for 65537 ticks (expected: 65536 ticks)
Slept for 50000 ticks (expected: 50000 ticks)
Slept for 100001 ticks (expected: 100000 ticks)
Slept for 1001 ticks (expected: 1000 ticks)
Slept for 2346 ticks (expected: 2345 ticks)
Slept for 65536 ticks (expected: 65536 ticks)
Slept for 50001 ticks (expected: 50000 ticks)
Slept for 100001 ticks (expected: 100000 ticks)
Intervall 1000 ticks, start 705777 ticks, now 706781 ticks, slept 1004 ticks
Intervall 2345 ticks, start 709227 ticks, now 711576 ticks, slept 2349 ticks
Intervall 65536 ticks, start 714022 ticks, now 779562 ticks, slept 65540 ticks
Intervall 50000 ticks, start 782073 ticks, now 832077 ticks, slept 50004 ticks
Intervall 100000 ticks, start 834588 ticks, now 934592 ticks, slept 100004 ticks
Intervall 2345 ticks, now 939517 ticks, diff 4 ticks
Intervall 2345 ticks, now 941862 ticks, diff 4 ticks
Intervall 2345 ticks, now 944207 ticks, diff 4 ticks
Intervall 2345 ticks, now 946552 ticks, diff 4 ticks
Intervall 2345 ticks, now 948897 ticks, diff 4 ticks
Test ran for 5574456 us

@smlng
Copy link
Member

smlng commented Apr 20, 2018

on first sight: this PR does severals things at once, at least the following:

  • changing xtimer behaviour
  • code clean up in xtimer
  • changing atmega periph timer implementation
  • adapting board configuration of jiminy

Though all these changes might serve the same purpose, I guess fixing (x)timer on jiminy (?), it would IMHO be better to single them out into separate PRs.

@smlng smlng added the State: WIP State: The PR is still work-in-progress and its code is not in its final presentable form yet label Apr 20, 2018
@Josar
Copy link
Contributor Author

Josar commented Apr 20, 2018

@smlng thats right.

First i just wanted put the xtimer changes into this PR.
But then i added the whole test setup if someone wants to have a closer look and test it.

@Josar Josar force-pushed the pr/xtimer_core branch 9 times, most recently from 308b2c2 to 4958b02 Compare April 26, 2018 19:46
@Josar
Copy link
Contributor Author

Josar commented Apr 26, 2018

@smlng tried to only include relevant changes to this PR.

@Josar Josar force-pushed the pr/xtimer_core branch 4 times, most recently from 85148a4 to f11a0d6 Compare April 26, 2018 23:09
@Josar Josar force-pushed the pr/xtimer_core branch 6 times, most recently from bccdf46 to 1f3c0dc Compare April 30, 2018 12:16
@Josar Josar force-pushed the pr/xtimer_core branch 2 times, most recently from 80d2173 to 413845b Compare May 15, 2018 12:55
@Josar
Copy link
Contributor Author

Josar commented May 15, 2018

@gebart @smlng i think this is ready for a review.

@cladmi
Copy link
Contributor

cladmi commented Jun 1, 2018

Using #8865 for timing:

iotlab-m3: offset 14 us (same as before)
iotlab-a8-m3: offset 14 us (same as before)
wsn430-v1_3b: offset 127us (instead of 135 us)
arduino-zero (samd21 cpu): offset 42us (instead of 50us)
samr21-xpro: offset 42us (instead of 44us)

I am running the other xtimer_* tests you mentionned.

@cladmi
Copy link
Contributor

cladmi commented Jun 1, 2018

Using #8865 for timing:

iotlab-m3: offset 14 us (same as before)
iotlab-a8-m3: offset 14 us (same as before)
wsn430-v1_3b: offset 127us (instead of 135 us)
arduino-zero (samd21 cpu): offset 42us (instead of 50us)
samr21-xpro: offset 42us (instead of 44us)

I am running the other xtimer_* tests you mentioned with #8865 #9037 #9108

I only get errors for xtimer_usleep_short

  • On samr21-xpro I always get too long timer
going to sleep 15 us
Slept for      48 us
Timeout longer than expected margin.
  • On arduino-zero (samd cpu not avr) I get sometime
going to sleep 16 us
Slept for      65580 us
Timeout longer than expected margin.

https://gist.github.com/cladmi/3accb8837ad6d76d4c67570f42698103

@cladmi
Copy link
Contributor

cladmi commented Jun 1, 2018

Now when I run xtimer_usleep_short with this PR it gets stuck for both boards.
I needed to patch xtimer_usleep_short test a bit to get a better output check.

  • samr21-xpro stuck on going to sleep 14 us
  • arduino-zero: this one I got stuck with
Timeout longer than expected margin.
going to sleep 16 us
Slept for      262188 us
Timeout longer than expected margin.
going to sleep 15 us

xtimer stuck when trying to sleep 15 us
[FAILED]

Copy link
Contributor

@cladmi cladmi left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Currently breaking both samr21-xpro and arduino-zero with xtimer_usleep_short test. Using an updated version of #9037

@Josar
Copy link
Contributor Author

Josar commented Jun 1, 2018

For the failed tests this can be caused by xtimer bug fixed in #9211 .

For the long offsets, did you follow the procedure descriped in the readme?

@cladmi
Copy link
Contributor

cladmi commented Jun 1, 2018

@Josar No I missed the xtimer_configure… my bad, I will do it before.

If boards get stuck with this PR but is resolved by #9211, it means that this PR cannot be merged without it.

However, both boards manage to execute the xtimer_hang test without problem with this PR and also without the fix so xtimer_hang may not be enough to find it.

@Josar
Copy link
Contributor Author

Josar commented Jun 1, 2018

Xtimer_hang accepts an error of 10%, thus masks the problems sometimes.

@Josar
Copy link
Contributor Author

Josar commented Jun 1, 2018

@cladmi #9211 fixes an error which could have been found with this test but was not as the test just skip the relevant parts. Thus the error is Masked. If this changes make the boards hang then it just reveals this problems. But its ok to merge this after the other as the other is much more crucial.

@Josar
Copy link
Contributor Author

Josar commented Jun 7, 2018

@smlng and @cladmi could you have a second look?

@cladmi
Copy link
Contributor

cladmi commented Jul 5, 2018

@Josar in order to try to get some of the xtimer changes included for the release I will need some help from you. I spend most of my time not understanding where I am and if I am testing the right thing. To simplify reviewing and merging all the xtimer related PRs, could you do an issue where you describe all the PRs and dependencies, on implementation and testing. This would help me reviewing in the right order, because right now I am lost. Then keep the first message up to date by updating it.

I think you should separate the "uncrustify" PRs, they are easy to review and merge and then simplify reviewing the "hard" stuff.

Regarding this PR, I would like to split this PR in parts. The uncrustify/style related changes, the PR adding the new variables, the xtimer_configuration in a third one.
They would of course need to include the previous PR. This requires a lot of rebase on your side, but allows reviewing and merging independent parts earlier.

Also it would be great if, by default, the behavior is kept the same as before so there is no need to test every boards before merging.
I think it would mean setting XTIMER_BACKOFF_OVERHEAD by default to 0 but I am not sure.

@Josar
Copy link
Contributor Author

Josar commented Jul 6, 2018

@cladmi I will rework this and try to make it so that it can be better understood. After #9211 is merged.

I think the default is kept as before.

@cladmi
Copy link
Contributor

cladmi commented Jul 6, 2018

@Josar Thank you :) I will re-read to understand the XTIMER_BACKOFF_OVERHEAD changes.

@Josar
Copy link
Contributor Author

Josar commented Nov 8, 2018

@cladmi rebased and heavily reworked this PR trying to solve some more issues with the xtimer implemetation. Would you mind to have a closer look?

This is still WIP, but i could not provoke issues. Maybe there are some more ideas for hardening the xtimer implementation from your side!

Please read the readme of test/xtimer_configuration and adjust the board values before running it.

1. Make it interrupt save.
2. Make periodic_wakeup to skip lost wakeups, solving a priodic race.
3. Remove xtimer_spin_until as this may lead to hanging conditions.
4. Improve/reduce delay of sleeps by introducing XTIMER_SHOOT_OVERHEAD, XTIMER_BACKOFF_OVERHEAD.
5. Implement a tests\xtimer_configuration whcih helps to properly set the values for the xtimer.

6. Introduce a second pin for tests/xtimer_hang to distinguish between worker 1 and 2.
@cladmi
Copy link
Contributor

cladmi commented Nov 12, 2018

@cladmi rebased and heavily reworked this PR trying to solve some more issues with the xtimer implemetation. Would you mind to have a closer look?

Then I would take this PR as a big PR that will get split per issue fix, which is good to give an overview of final changes but not merge-able as is.

As this is quite tricky to review with all platforms and parallel context (with the low timer always running and other tasks) I prefer to review the smallest possible atomic changes.
Even more as I do not currently have an understanding of all problems.

And in case of an issue with one PR, one commit could be reverted which is not the case when everything is packed together.

Copy link
Contributor

@cladmi cladmi left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did not look in the code details and implementation but just the general change direction.

I do not like the global change with _xtimer_set_absolute, it follows the current code implementation but for me goes in the wrong direction. As was done before, you still try to spin in the calling function (which was for me already wrong) and do the irq handling in the calling function too, so you duplicate the handling in both calling functions. If you need it twice, why not putting it with a function that your reuse, so putting it common for both ?

And this is what _xtimer_set_absolute should be for. With a more robust implementation of course but it would even remove the _spin in _xtimer_set and _xtimer_periodic_wakeup.

It is working around the bad implementation of _xtimer_set_absolute when it should be fixed to use without needing specific setup before calling it.

So basically I would prefer the changes inside the function than outside.

@Josar Josar mentioned this pull request Nov 15, 2018
@stale
Copy link

stale bot commented Aug 10, 2019

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. If you want me to ignore this issue, please mark it with the "State: don't stale" label. Thank you for your contributions.

@stale stale bot added the State: stale State: The issue / PR has no activity for >185 days label Aug 10, 2019
@stale stale bot closed this Sep 10, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
State: stale State: The issue / PR has no activity for >185 days State: WIP State: The PR is still work-in-progress and its code is not in its final presentable form yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants