Hard Light Productions Forums

Modding, Mission Design, and Coding => FS2 Open Coding - The Source Code Project (SCP) => Topic started by: zookeeper on November 18, 2011, 10:23:13 am

Title: Why do Missiontime and timestamp() diverge?
Post by: zookeeper on November 18, 2011, 10:23:13 am
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.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Eli2 on November 18, 2011, 10:42:28 am
my guess is, that the float used in timestamp() accumulates rounding errors.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: jr2 on November 18, 2011, 11:38:41 am
Possible to sync timestamp to mission time every so often? (say, every 10s or so?) Or is that not desirable?
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Goober5000 on November 18, 2011, 11:52:13 am
Hmm.  This could explain why the times of messages in the mission log differ from the times they were sent in-mission.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: z64555 on November 18, 2011, 12:33:15 pm
How are each of them calculated?

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

Overflow?
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Eli2 on November 18, 2011, 01:06:10 pm
There should have never been a float version of the time in the first place.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Eli2 on November 18, 2011, 01:07:50 pm
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!
 :shaking:
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: jr2 on November 18, 2011, 01:50:52 pm
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?
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Sushi on November 18, 2011, 03:56:59 pm
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.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Eli2 on November 18, 2011, 05:12:41 pm
If anyone is willing to review a huge patch,
i will try to fix the time issues and inconsistencies.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Valathil on November 18, 2011, 05:25:22 pm
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
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: The E on November 18, 2011, 05:27:35 pm
That just means we have to be careful when testing any patch :P

Personally, I'd rather have a timer system that doesn't suffer from float inaccuracies.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: FUBAR-BDHR on November 18, 2011, 05:29:58 pm
You should see the divergence between host and client if you want to see time divergence. 
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Eli2 on November 19, 2011, 08:40:42 am
The divergence might be caused because the frametime is converted to float and back.
Ill fix that as soon as my cleanups hit trunk.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Eli2 on December 13, 2011, 07:35:20 pm
Ok, here is a minimal invasive patch to fix this issue.
I hope this does not have any side effects.  :nervous:

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))
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Goober5000 on December 14, 2011, 08:37:12 am
What are the tests you've run using this patch?
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: zookeeper on December 14, 2011, 03:52:51 pm
Urgh, I promised to test that today, but got stuck on other things. Tomorrow it is, then.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Eli2 on December 14, 2011, 04:03:43 pm
Simple 2 minute play test.

What are the tests you've run using this patch?
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Goober5000 on December 14, 2011, 08:47:14 pm
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.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: karajorma on December 15, 2011, 03:39:35 am
Or post a test build and let others do it.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: zookeeper on December 16, 2011, 03:24:59 am
Here's windows trunk builds (release and debug, SSE2) with the above patch applied. (http://hotfile.com/dl/137643928/c45fc9b/eli_timer_test_build.7z.html)

EDIT: Forgot to mention that I added this to fix.h make it compile on MSVC++ 2010 Express:

Code: [Select]
#ifdef _MSC_VER
#include "globalincs/msvc/stdint.h"
#else
#include <stdint.h>
#endif
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Eli2 on December 16, 2011, 04:12:20 pm
Ok, here is another patch, so that scripting gets its time from the better source.

Code: [Select]
Index: code/parse/lua.cpp
===================================================================
--- code/parse/lua.cpp
+++ code/parse/lua.cpp
@@ -11907,7 +11907,9 @@ ADE_FUNC(getMissionTime, l_Mission, NULL, "Game time in seconds since the missio
  if(!(Game_mode & GM_IN_MISSION))
  return ade_set_error(L, "f", 0.0f);
 
- return ade_set_args(L, "x", Missiontime);
+ double time = (double)timestamp() / 1000.0;
+
+ return ade_set_args(L, "d", time);
 }
 
 //WMC - These are in freespace.cpp
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: zookeeper on February 25, 2012, 09:49:18 am
I've been testing this patch for months now myself, so at least for me it works just fine. Since this fix is needed by FotG ASAP, I'd like to get this in unless there's any particular objections.
Title: Re: Why do Missiontime and timestamp() diverge?
Post by: Goober5000 on February 25, 2012, 01:48:58 pm
Now why couldn't I find this thread when I was looking all over for it yesterday? :sigh:

Jg18 was on the #scp channel in IRC yesterday and he was experiencing some problems that may have been due to this.  I'll point him over this way.