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

steady time overflow issue #86

Closed
wjwwood opened this issue Feb 1, 2018 · 3 comments · Fixed by #87
Closed

steady time overflow issue #86

wjwwood opened this issue Feb 1, 2018 · 3 comments · Fixed by #87
Labels
bug Something isn't working help wanted Extra attention is needed

Comments

@wjwwood
Copy link
Member

wjwwood commented Feb 1, 2018

As reported by @serge-nikulin, this test code will eventually produce unexpected output on Windows (I do not think it affects Linux/macOS):

int main()
{
  rcutils_time_point_value_t last_time_ns;
  rcutils_time_point_value_t this_time_ns;
  rcutils_steady_time_now(&last_time_ns);
  for (uint64_t count = 0ULL; ; ++count)
  {
    rcutils_steady_time_now(&this_time_ns);
    uint64_t delta_ns = this_time_ns - last_time_ns;
    if (delta_ns > 100000000ULL) {
      std::cout << "****** Unexpected delta: " << delta_ns << "*********\n";
    }
    if ((count % 1000000000ULL) == 0ULL) {
      std::ostringstream ss;
      ss.imbue(std::locale(""));
      ss << count;
      std::cout << ss.str() << "\n";
    }
    last_time_ns = this_time_ns;
  }
  return 0;
}

Something like this (after about 30 minutes or so):

41,000,000,000
42,000,000,000
43,000,000,000
44,000,000,000
45,000,000,000
****** Unexpected delta: 18446738826622249502*********
46,000,000,000
47,000,000,000
48,000,000,000

The theory is that this is due to an overflow of an intermediate calculation which uses the performance ticks on a computer with a GHz speed processor.

@serge-nikulin said:

The culprit is rcutils_steady_time_now: multiplication by 10^9 periodically overflows uint64_t (max ~10^19).
With GHZ frequencies (10^9) it should be a matter of time to get an overflow condition:

  // Convert to nanoseconds before converting from ticks to avoid precision loss.
  rcutils_time_point_value_t intermediate = RCUTILS_S_TO_NS(performance_count.QuadPart);
  *now = intermediate / cpu_frequency.QuadPart;

I already have brushed this bug in #79 (comment).

@wjwwood wjwwood added bug Something isn't working help wanted Extra attention is needed labels Feb 1, 2018
@serge-nikulin
Copy link

@wjwwood, I see two solutions:

  1. Use adaptive scaling factor instead of 10^9, e.g.:
    • Before the division left-shift intermediate by all available non-1 bits. After the division right-shift the result by the same amount of bits.
  2. Use 128-bit math. It could take some code to do division right, though.

I can do the first fix if you want. Do you have any destination date for it?
I would welcome help in creating a non-time consuming test, though.

@wjwwood
Copy link
Member Author

wjwwood commented Feb 1, 2018

Since it only affects Windows we might be able to use something like this:

https://msdn.microsoft.com/en-us/library/windows/desktop/hh802933(v=vs.85).aspx

  1. Use adaptive scaling factor instead of 10^9, e.g.:
  • Before the division left-shift intermediate by all available non-1 bits. After the division right-shift the result by the same amount of bits.

I think this is basically what the above function does (or one of it's related functions).

We'd welcome a patch, but that's up to you.

I'll think about what we could do to more quickly reproduce the issue as a test.

@serge-nikulin
Copy link

serge-nikulin commented Feb 1, 2018

@wjwwood,
I did not know about these that API, thanks!

Please review, is this the solution?

// Division by invariant multiplication:
*now = UnsignedMultiplyExtract128(performance_count.QuadPart, ((UULONG_MAX / cpu_frequency.QuadPart) + 1ULL)), 64U);

No, the above is not. Please ignore.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working help wanted Extra attention is needed
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants