[Bug?] ElapsedMilliseconds() jumps to the past ...

[PureLust]

In one on my projects, I needed a little 3 seconds progress-bar and I used ElapsedMilliseconds() to realize it.

I developed the code on my Laptop with Win10 and anything was working fine.
When I tested it on the destination machine with WinXP, I was wondering, why the progress-bar was not working right.

After some tests, I find out, that ElapsedMilliseconds() jumps to the past (to lower values) randomly after a few seconds.

To proof this, I wrote a little test-code, which reports, if a new ElapsedMilliseconds()-value is lower than the one before.

Code: Select all

Repeat
  ActTimer = ElapsedMilliseconds()
  If ActTimer < OldTimer
    Debug "ERROR at "+FormatDate("%hh:%ii:%ss", Date())+" -  old Timer ->  "+Str(OldTimer)+" / "+Str(ActTimer)+"  <- new Timer   ("+Str(ActTimer-OldTimer)+"ms)"
  EndIf
  OldTimer = ActTimer
  Delay(100)
Until 0

And here are some results:

Code: Select all

ERROR at 12:38:49 -  old Timer ->  1153164 / 1148576  <- new Timer   (-4588ms)
ERROR at 12:38:58 -  old Timer ->  1162498 / 1157910  <- new Timer   (-4588ms)
ERROR at 12:39:07 -  old Timer ->  1190624 / 1186036  <- new Timer   (-4588ms)
ERROR at 12:39:17 -  old Timer ->  1199980 / 1195392  <- new Timer   (-4588ms)
ERROR at 12:39:22 -  old Timer ->  1200026 / 1186064  <- new Timer   (-13962ms)
ERROR at 12:39:26 -  old Timer ->  1190658 / 1186071  <- new Timer   (-4587ms)
ERROR at 12:39:36 -  old Timer ->  1199966 / 1195399  <- new Timer   (-4567ms)
ERROR at 12:39:40 -  old Timer ->  1199998 /  178184  <- new Timer   (-1021814ms)
ERROR at 12:39:50 -  old Timer ->   187446 /  178191  <- new Timer   (-9255ms)
ERROR at 12:39:59 -  old Timer ->   187449 /  178173  <- new Timer   (-9276ms)
ERROR at 12:40:08 -  old Timer ->   187446 /  178170  <- new Timer   (-9276ms)
ERROR at 12:40:27 -  old Timer ->   224927 /  215652  <- new Timer   (-9275ms)
ERROR at 12:40:37 -  old Timer ->   224987 /  215712  <- new Timer   (-9275ms)
ERROR at 12:40:46 -  old Timer ->   224965 /  215690  <- new Timer   (-9275ms)
ERROR at 12:41:05 -  old Timer ->   262405 /  253160  <- new Timer   (-9245ms)

As you can see, ElapsedMilliseconds() jumps to lower values at irregular intervals.
Sometimes it falls back only a few seconds, sometimes more than 17 Minuten (1199998 > 178184).
The only consistency I can see is, that the 'fallback-time' is ~4.6 Seconds or a multiplication of it.
Anyone an idea why or how this could happen?

Maybe some of you could run the test-code and give me some feedback if this phenomenon appears on your machine as well.
Attention: Because it's an endless routine, you need to break it manually.

I've testet it with PB 5.5 on several WinXP-PCs, and run into this problems on all of them.
All PCs do have the same configuration: WinXP-Pro SP3, an older AMD Geode single-core Processor and 512MB Ram.

[Keya]

so your Win10 was ok but XP not? are they both 32 or 64bit or different or? which PB are you using, and have you tried an older build of PB? I just had it running on XP32 with 5.42 x86 for over 40 minutes, no problem

[bosker]

ElapsedMilliseconds returns a Quad.
Using an Int could result in all kinds of mayhem depending on what the absolute values happen to be.

[Keya]

ElapsedMilliseconds returns a Quad.

The docs don't specify the return type, which suggests it's an Integer, so 32bits on x86. I just checked my XP32 and the current Debug Hex(ElapsedMs(), #PB_Quad) = FFFFFFFFF9684E8E which is within 32bit, and in 30.7 hours i'll be able to check how it rolls over

ps. PureLust do you get the same problem from calling GetTickCount_() ?

[Mistrel]

ElapsedMilliseconds() used to call Win32 GetTickCount() unless this has changed. This function returns an unsigned int (PureBasic long) which rolls over after 49.7 days. Because PureBasic only has signed longs then this number will flip to the past in half that time unless you explicitly use a bitwise AND with your comparison to treat it as unsigned.

[bosker]

Well, my 5.50 help file certainly does specify return type.

ElapsedMilliseconds()

Syntax

Result.q = ElapsedMilliseconds()
Description

Returns the number of milliseconds that have elapsed since a specific time in the past.

[bosker]

Have a look at this thread...
http://www.purebasic.fr/english/viewtop ... lliseconds

[netmaestro]

ElapsedMilliseconds() and Delay() both use QueryPerformanceCounter now, hence the quad return value. Rollover is no longer a consideration. (not that rollover was happening here, this is most likely overflow in a too-small variable type.)

[Mistrel]

.. this is most likely overflow in a too-small variable type.

This does sound accurate. I'm still in the habit of storing ElapsedMilliseconds() in an integer. I didn't realize that it had been changed to quad on x86; although I do recall of a feature request for it.

I don't think 64-bit granularity for this function is necessary as it's typically used for very short timers. The issue with its use is that it's reliant upon system uptime and not application uptime.

I think it would have been more useful as such:

Code: Select all

Result.l = ElapsedMilliseconds(*WrapCount=0)

.. where elapsed time begins at 0 since program start and WrapCount increments if this value ever loops. You won't have to ever account for it unless you plan on writing something that stays resident for a while. Moving to 64-bits is just replacing one problem with another (as this thread demonstrates).

[PureLust]

Using quads does not help.
But GetTickCount_() does the trick and works fine ... thanks Keya.

I thought, ElapsedMilliseconds() was just a mapped GetTickCount_(), but as netmaestro mentioned, PB uses QueryPerformanceCounter now.
So it looks like that the new routine, PB uses for ElapsedMilliseconds() works fine on an actual CPU, but may produce some problems on older platforms?

[Mistrel]

Sounds like you would have to do some further testing with the API in question directly to be sure. It doesn't appear that we will be able to duplicate this in our environment if it is indeed a hardware issue.

[PureLust]

Sounds like you would have to do some further testing with the API in question directly to be sure. It doesn't appear that we will be able to duplicate this in our environment if it is indeed a hardware issue.

Yes, I agree. It's difficult to locate a problem if it does not occur on you hardware.

But it looks like that you have to consider some anomalies when implementing QueryPerformanceCounter.

I did find these information on that:
=> https://blogs.msdn.microsoft.com/oldnew ... 0/?p=20963
=> https://blogs.msdn.microsoft.com/oldnew ... 33/#461129

The author of this article describes the problem quite good, although it's about Gecko and not PB.
=> http://www.janbambas.cz/usage-of-queryp ... -in-gecko/

Also the following article describes, that QueryPerformanceCounter could cause great Problems on older hardware:
=> http://computerperformancebydesign.com/ ... ilization/
(Scroll down around 60% of the page or search for 'it is a problem that only occurs on older hardware'.)

Even though it will not be fixed, this behavior should be mentioned in the Doc with a hint to use GetTickCount_() instead.