[zookeeper]

I see there's at least two common ways to get the current mission time, Missiontime and timestamp(). However, they don't produce the same values or even almost the same; the longer the mission runs, the more the values they return diverge from each other. Initially timestamp() returns a very slightly bigger value, but Missiontime overtakes it in less than a second and then consistently stays higher afterwards. However, I don't know which one of them returns the correct value.

So... what's going on? Is this a bug? Or am I missing something? Should one of them not be used for getting the current time? Both seem to be used for that purpose in many places.

Here's a simple test case. Just run the game and check the output from fs2_open.log:

Code: [Select]

Index: freespace.cpp
===================================================================
--- freespace.cpp (revision 8006)
+++ freespace.cpp (working copy)
@@ -4420,6 +4420,8 @@
 
 
  game_simulation_frame();
+
+ mprintf(("Difference between Missiontime and timestamp(): %f seconds\n", f2fl(Missiontime) - (float)timestamp()/1000.0f));
 
  // if not actually in a game play state, then return.  This condition could only be true in
  // a multiplayer game.


[Eli2]

my guess is, that the float used in timestamp() accumulates rounding errors.

[jr2]

Possible to sync timestamp to mission time every so often? (say, every 10s or so?) Or is that not desirable?

[Goober5000]

Hmm.  This could explain why the times of messages in the mission log differ from the times they were sent in-mission.

[z64555]

How are each of them calculated?

Edit: eh? Missiontime is a long while timestamp is an int.

Overflow?

[Eli2]

There should have never been a float version of the time in the first place.

[Eli2]

Possible to sync timestamp to mission time every so often? (say, every 10s or so?) Or is that not desirable?

That is _not_ a solution!
 

[jr2]

No.  It's a dirty hack.  However, if for some reason timestamp() must remain inaccurate, at least you could partially mitigate the inaccuracy by syncing once in a while..  right?

[Sushi]

No.  It's a dirty hack.  However, if for some reason timestamp() must remain inaccurate, at least you could partially mitigate the inaccuracy by syncing once in a while..  right?

If you're willing to accept time effectively going backwards every once in a while when it syncs. I'm sure you can imagine the kinds of chaos that would cause.

[Eli2]

If anyone is willing to review a huge patch,
i will try to fix the time issues and inconsistencies.

[Valathil]

my guess would be timestamp is a real time clock and missiontime is a accumulated value that has the frametimetime added to it every frame when the game is not paused. too lazy to check tho. i probably wouldnt recommend fixing it tho issues like pausing the game waiting for a few secs and then unpausing resulting in ships just skipping to position+velocity*pausedtime could crop up

[The E]

That just means we have to be careful when testing any patch

Personally, I'd rather have a timer system that doesn't suffer from float inaccuracies.

[FUBAR-BDHR]

You should see the divergence between host and client if you want to see time divergence. 

[Eli2]

The divergence might be caused because the frametime is converted to float and back.
Ill fix that as soon as my cleanups hit trunk.

[Eli2]

Ok, here is a minimal invasive patch to fix this issue.
I hope this does not have any side effects. 

EDIT: rebased against latest trunk
EDIT2: the patch was the wrong way around

Code: [Select]

Index: code/freespace2/freespace.cpp
===================================================================
--- code/freespace2/freespace.cpp
+++ code/freespace2/freespace.cpp
@@ -4420,8 +4420,7 @@ void game_frame(int paused)
  if ((Game_mode & GM_MULTIPLAYER) && (Netgame.game_state == NETGAME_STATE_SERVER_TRANSFER)){
  return;
  }
-
-
+
  game_simulation_frame();
 
  // if not actually in a game play state, then return.  This condition could only be true in
@@ -4808,10 +4807,7 @@ fix game_get_overall_frametime()
 // This is called from game_do_frame(), and from navmap_do_frame()
 void game_update_missiontime()
 {
- // TODO JAS: Put in if and move this into game_set_frametime,
- // fix navmap to call game_stop/start_time
- //if ( !timer_paused )
- Missiontime += Frametime;
+ Missiontime = fixTimeFromMs(timestamp());
 }
 
 void game_do_frame()
Index: code/math/fix.h
===================================================================
--- code/math/fix.h
+++ code/math/fix.h
@@ -21,6 +21,20 @@ fix fixmul(fix a, fix b);
 fix fixdiv(fix a, fix b);
 fix fixmuldiv(fix a, fix b, fix c);
 
+static inline uint32_t fixTimeToMs(const fix time) {
+ uint64_t temp = time;
+ temp = temp * 1000;
+ temp = temp >> 16;
+ return (uint32_t) temp;
+}
+
+static inline fix fixTimeFromMs(const uint32_t ms) {
+ uint64_t temp = ms;
+ temp = temp << 16;
+ temp = temp / 1000;
+ return (fix) temp;
+}
+
 #define f2i(a) ((int)((a)>>16))
 #define i2f(a) ((fix)((a)<<16))

[Goober5000]

What are the tests you've run using this patch?

[zookeeper]

Urgh, I promised to test that today, but got stuck on other things. Tomorrow it is, then.

[Eli2]

Simple 2 minute play test.

What are the tests you've run using this patch?

[Goober5000]

Simple 2 minute play test.

Well, considering how much code this can potentially affect, you'll need to test it more than this.   Fly several missions with the fix enabled, paying particular attention to the times when things happen.  See if they work.  Compare playthroughs of the same mission with and without the fix.  Also, look through the message and event logs and check to see if the fix causes events and messages to match up properly with the HUD time at which they took place.

[karajorma]

Or post a test build and let others do it.