Fix g_time3() overflow

[metalefty]

CC: @moobyfr

g_time3() returns epoch time in msec. However, return type is int. The maximum value of signed int is 2147483647. Current epoch time is around 1522431329. Only 30% room remained. epoch time * 1000 overflows. To handle epoch time in msec properly, the container should have 64 bit size.

First of all, I made a test for g_time*() function.

How to test:

$ ./bootstrap && ./configure && make 
$ tests/common/os_calls/g_time

Expected

$ tests/common/os_calls/g_time
g_time1()        =       1522431329 [ sec] (epoch time)
g_time1() * 1000 =    1522431329000 [msec] (epoch time)
g_time2()        =       1011875170 [msec] (since machine was started)
g_time3()        =    1522431329792 [msec] (epoch time in msec)

Testing...
All tests passed!

Actual

$ tests/common/os_calls/g_time
g_time1()        =       1522431461 [ sec] (epoch time)
g_time1() * 1000 =    1522431461000 [msec] (epoch time)
g_time2()        =       1012043250 [msec] (since machine was started)
g_time3()        =       2013038323 [msec] (epoch time in msec)

Testing...
Assertion failed: (gTime3 >= gTime1 * 1000), function main, file g_time.c, line 58.
zsh: abort (core dumped)  tests/common/os_calls/g_time

Fix

g_time*() should be long long. I'll make a fix in addition to this PR branch. Please review the test code first.

[jsorg71]

I think in tests/common/os_calls/g_time.c, before include os_calls.h you need to include config_ac.h

[metalefty]

Indeed, thanks.

[metalefty]

Fixed Travis CI.

[metalefty]

@jsorg71 @speidy @moobyfr
Done. Now unit tests, only g_time so var, is run by Travis. Can you review?
g_time1() still returns signed int.

[speidy]

i'm not sure about that change. while it "solves" the truncation issue its not precise enough.
sizeof(time_t) == 4 on x86 machines, i belive it is also the case on mips, ppc archs.
sizeof(time_t) == 8 on x86-64 machines.

while sizeof(long long) == 8 anywhere.

we shall count seconds using time_t and just store the remainder in micro seconds using useconds_t. This keeps our sources 100% portable.

anyhow i'm not sure if we care about the resolution anywhere.

[metalefty]

Please note g_time3() is used almost only for logs. Just for recording timestamps in msec to the log (to stdout). I intend to record the correct timestamps in the log, not to cause overflow. Other use case of g_time3() is to get time diff in trans_connect() in common/trans.c

We already using timeval structure, time_t for seconds and suseconds_t for microseconds, in most places. Do you mean time diff in trans_connect() should be measured using timeval like done in xorg/tests/xdemo/xdemo.c?

/* xorg/tests/xdemo/xdemo.c: */
uint32_t time_elapsed_ms(struct timeval tv)
{
    struct timeval  tv_now;
    uint32_t        dur;

    gettimeofday(&tv_now, NULL);
    dur = ((tv_now.tv_sec - tv.tv_sec) * 1000) + ((tv_now.tv_usec - tv.tv_usec) / 1000);
    return dur;
}

uint32_t time_elapsed_us(struct timeval tv)
{
    struct timeval  tv_now;
    uint32_t        dur;

    gettimeofday(&tv_now, NULL);
    dur = ((tv_now.tv_sec - tv.tv_sec) * 1000000) + (tv_now.tv_usec - tv.tv_usec);
    return dur;
}

[moobyfr]

About the PR itself, i'm ok.
For my initial need, I must fill utmp with a time_t entry. I'm not sure casting time_t to long long to time_t is the best way. But basically, the precision for utmp isn't probably needed to be the microsecond. so I can still use g_time3 or make a g_time4() which return a time_t

[speidy]

make a g_time4() which return a time_t

i don't think you should return non primitive type from os_calls.c

[jsorg71]

@metalefty The timex() functions are returning a time val in mssec or sec that is used to compare to a later call to timex() or just to log a time value. Also the names are just ugly. Free free to name new functions that can be accurate and return uint64_t if that is better. We can depreciate these.

[matt335672]

Just came across this one.

I think I addressed all of this in #3328. g_time3() has been replaced with g_get_elapsed_ms(). Rather than making this a 64-bit value, I've guaranteed that subtracting one of these values from another always gives a sensible value for elapsed time, provided no more than 50 days elapse between the calls. There's a comment to this effect in the header file:-

xrdp/common/os_calls.h

Lines 410 to 427 in aac4946

	/**
	* Gets elapsed milliseconds since some arbitrary point in the past
	*
	* The returned value is unaffected by leap-seconds or time zone changes.
	*
	* @return elaped ms since some arbitrary point
	*
	* Calculate the duration of a task by calling this routine before and
	* after the task, and subtracting the two values.
	*
	* The value wraps every so often (every 49.7 days on a 32-bit system),
	* but as we are using unsigned arithmetic, the difference of any of these
	* two values can be used to calculate elapsed time, whether-or-not a wrap
	* occurs during the interval - provided of course the time being measured
	* is less than the total wrap-around interval.
	*/
	unsigned int
	g_get_elapsed_ms(void);

Does that cover everything, or have I missed something?

[metalefty]

Thanks. It's been a long time so I don't remember that g_time3() overflow affects what. g_get_elapsed_ms() is not in v0.10 but I'm fine with closing this if the overflow in v0.10 is not severe.

[matt335672]

The changes I made in #3228 for g_get_elapsed_ms() :-

1. use the guarantees that C offers about unsigned values to ensure that behaviour in the event of an overflow is well-defined.
2. Ensure that the timer scaling down to unsigned int is well-behaved when an overflow occurs.

For v0.10.x we're using signed values. Overflow of these is implementation-defined. We've had no reports of any problems in v0.10, so in practice I think we're OK.

The other big change in #3228 was removing int g_time1() which is not year 2038 compliant. The fix is to use the POSIX 'time()' call instead. I don't think people will be running v0.10.x in 2038 so again, no change is needed there.