From 378a3053c310be717ced22e5db9afb6340e259de Mon Sep 17 00:00:00 2001 From: Benny Prijono Date: Mon, 30 Mar 2009 18:22:16 +0000 Subject: Ticket #764: Bug with milliseconds time resolution in WinCE/Windows Mobile targets (thanks Johan Lantz for the report) - use QueryPerformanceCounter() (via pj_get_timestamp() API) to emulate the msec precision) - more strict tests in pjlib-test git-svn-id: http://svn.pjsip.org/repos/pjproject/trunk@2560 74dad513-b988-da41-8d7b-12977e46ad98 --- pjlib/include/pj/os.h | 6 ++ pjlib/src/pj/os_time_win32.c | 171 ++++++++++++++++++++++++++++++++++++- pjlib/src/pj/os_timestamp_common.c | 6 ++ pjlib/src/pjlib-test/sleep.c | 44 +++++++--- 4 files changed, 211 insertions(+), 16 deletions(-) diff --git a/pjlib/include/pj/os.h b/pjlib/include/pj/os.h index 4a5a77f8..38eb8ea6 100644 --- a/pjlib/include/pj/os.h +++ b/pjlib/include/pj/os.h @@ -1267,6 +1267,12 @@ PJ_DECL(pj_time_val) pj_elapsed_time( const pj_timestamp *start, PJ_DECL(pj_uint32_t) pj_elapsed_msec( const pj_timestamp *start, const pj_timestamp *stop ); +/** + * Variant of #pj_elapsed_msec() which returns 64bit value. + */ +PJ_DECL(pj_uint64_t) pj_elapsed_msec64(const pj_timestamp *start, + const pj_timestamp *stop ); + /** * Calculate the elapsed time in 32-bit microseconds. * This function calculates the elapsed time using highest precision diff --git a/pjlib/src/pj/os_time_win32.c b/pjlib/src/pj/os_time_win32.c index 0f28359a..6da3c23d 100644 --- a/pjlib/src/pj/os_time_win32.c +++ b/pjlib/src/pj/os_time_win32.c @@ -19,6 +19,7 @@ */ #include #include +#include #include /////////////////////////////////////////////////////////////////////////////// @@ -27,11 +28,133 @@ static LARGE_INTEGER base_time; +#if defined(PJ_WIN32_WINCE) && PJ_WIN32_WINCE +# define WINCE_TIME +#endif + +#ifdef WINCE_TIME +/* Note: + * In Windows CE/Windows Mobile platforms, the availability of milliseconds + * time resolution in SYSTEMTIME.wMilliseconds depends on the OEM, and most + * likely it won't be available. When it's not available, the + * SYSTEMTIME.wMilliseconds will contain a constant arbitrary value. + * + * Because of that, we need to emulate the milliseconds time resolution + * using QueryPerformanceCounter() (via pj_get_timestamp() API). However + * there is limitation on using this, i.e. the time returned by + * pj_gettimeofday() may be off by up to plus/minus 999 msec (the second + * part will be correct, however the msec part may be off), because we're + * not synchronizing the msec field with the change of value of the "second" + * field of the system time. + * + * Also there is other caveat which need to be handled (and they are + * handled by this implementation): + * - user may change system time, so pj_gettimeofday() needs to periodically + * checks if system time has changed. The period on which system time is + * checked is controlled by PJ_WINCE_TIME_CHECK_INTERVAL macro. + */ +static LARGE_INTEGER g_start_time; /* Time gettimeofday() is first called */ +static pj_timestamp g_start_tick; /* TS gettimeofday() is first called */ +static pj_timestamp g_last_update; /* Last time check_system_time() is + called, to periodically synchronize + with up-to-date system time (in case + user changes system time). */ +static pj_uint64_t g_update_period; /* Period (in TS) check_system_time() + should be called. */ + +/* Period on which check_system_time() is called, in seconds */ +#ifndef PJ_WINCE_TIME_CHECK_INTERVAL +# define PJ_WINCE_TIME_CHECK_INTERVAL (10) +#endif + +#endif + +#ifdef WINCE_TIME +static pj_status_t init_start_time(void) +{ + SYSTEMTIME st; + FILETIME ft; + pj_timestamp freq; + pj_status_t status; + + GetLocalTime(&st); + SystemTimeToFileTime(&st, &ft); + + g_start_time.LowPart = ft.dwLowDateTime; + g_start_time.HighPart = ft.dwHighDateTime; + g_start_time.QuadPart /= SECS_TO_FT_MULT; + g_start_time.QuadPart -= base_time.QuadPart; + + status = pj_get_timestamp(&g_start_tick); + if (status != PJ_SUCCESS) + return status; + + g_last_update.u64 = g_start_tick.u64; + + status = pj_get_timestamp_freq(&freq); + if (status != PJ_SUCCESS) + return status; + + g_update_period = PJ_WINCE_TIME_CHECK_INTERVAL * freq.u64; + + PJ_LOG(4,("os_time_win32.c", "WinCE time (re)started")); + + return PJ_SUCCESS; +} + +static pj_status_t check_system_time(pj_uint64_t ts_elapsed) +{ + enum { MIS = 5 }; + SYSTEMTIME st; + FILETIME ft; + LARGE_INTEGER cur, calc; + DWORD diff; + pj_timestamp freq; + pj_status_t status; + + /* Get system's current time */ + GetLocalTime(&st); + SystemTimeToFileTime(&st, &ft); + + cur.LowPart = ft.dwLowDateTime; + cur.HighPart = ft.dwHighDateTime; + cur.QuadPart /= SECS_TO_FT_MULT; + cur.QuadPart -= base_time.QuadPart; + + /* Get our calculated system time */ + status = pj_get_timestamp_freq(&freq); + if (status != PJ_SUCCESS) + return status; + + calc.QuadPart = g_start_time.QuadPart + ts_elapsed / freq.u64; + + /* See the difference between calculated and actual system time */ + if (calc.QuadPart >= cur.QuadPart) { + diff = (DWORD)(calc.QuadPart - cur.QuadPart); + } else { + diff = (DWORD)(cur.QuadPart - calc.QuadPart); + } + + if (diff > MIS) { + /* System time has changed */ + PJ_LOG(3,("os_time_win32.c", "WinCE system time changed detected " + "(diff=%u)", diff)); + status = init_start_time(); + } else { + status = PJ_SUCCESS; + } + + return status; +} + +#endif + // Find 1st Jan 1970 as a FILETIME -static void get_base_time(void) +static pj_status_t get_base_time(void) { SYSTEMTIME st; FILETIME ft; + pj_status_t status = PJ_SUCCESS; memset(&st,0,sizeof(st)); st.wYear=1970; @@ -42,17 +165,58 @@ static void get_base_time(void) base_time.LowPart = ft.dwLowDateTime; base_time.HighPart = ft.dwHighDateTime; base_time.QuadPart /= SECS_TO_FT_MULT; + +#ifdef WINCE_TIME + pj_enter_critical_section(); + status = init_start_time(); + pj_leave_critical_section(); +#endif + + return status; } PJ_DEF(pj_status_t) pj_gettimeofday(pj_time_val *tv) { +#ifdef WINCE_TIME + pj_timestamp tick; + pj_uint64_t msec_elapsed; +#else SYSTEMTIME st; FILETIME ft; LARGE_INTEGER li; +#endif + pj_status_t status; + + if (base_time.QuadPart == 0) { + status = get_base_time(); + if (status != PJ_SUCCESS) + return status; + } + +#ifdef WINCE_TIME + do { + status = pj_get_timestamp(&tick); + if (status != PJ_SUCCESS) + return status; + + if (tick.u64 - g_last_update.u64 >= g_update_period) { + pj_enter_critical_section(); + if (tick.u64 - g_last_update.u64 >= g_update_period) { + g_last_update.u64 = tick.u64; + check_system_time(tick.u64 - g_start_tick.u64); + } + pj_leave_critical_section(); + } else { + break; + } + } while (1); - if (base_time.QuadPart == 0) - get_base_time(); + msec_elapsed = pj_elapsed_msec64(&g_start_tick, &tick); + tv->sec = (long)(g_start_time.QuadPart + msec_elapsed/1000); + tv->msec = (long)(msec_elapsed % 1000); +#else + /* Standard Win32 GetLocalTime */ GetLocalTime(&st); SystemTimeToFileTime(&st, &ft); @@ -63,6 +227,7 @@ PJ_DEF(pj_status_t) pj_gettimeofday(pj_time_val *tv) tv->sec = li.LowPart; tv->msec = st.wMilliseconds; +#endif /* WINCE_TIME */ return PJ_SUCCESS; } diff --git a/pjlib/src/pj/os_timestamp_common.c b/pjlib/src/pj/os_timestamp_common.c index 3384baf7..293f6162 100644 --- a/pjlib/src/pj/os_timestamp_common.c +++ b/pjlib/src/pj/os_timestamp_common.c @@ -152,6 +152,12 @@ PJ_DEF(pj_uint32_t) pj_elapsed_msec( const pj_timestamp *start, return (pj_uint32_t)elapsed_msec(start, stop); } +PJ_DEF(pj_uint64_t) pj_elapsed_msec64(const pj_timestamp *start, + const pj_timestamp *stop ) +{ + return (pj_uint64_t)elapsed_msec(start, stop); +} + PJ_DEF(pj_time_val) pj_elapsed_time( const pj_timestamp *start, const pj_timestamp *stop ) { diff --git a/pjlib/src/pjlib-test/sleep.c b/pjlib/src/pjlib-test/sleep.c index 1c4986f0..eaaac88c 100644 --- a/pjlib/src/pjlib-test/sleep.c +++ b/pjlib/src/pjlib-test/sleep.c @@ -55,19 +55,35 @@ static int simple_sleep_test(void) { - enum { COUNT = 5 }; + enum { COUNT = 10 }; int i; pj_status_t rc; PJ_LOG(3,(THIS_FILE, "..will write messages every 1 second:")); for (i=0; i DURATION * (100+MIS)/100) + if (msec < duration[i] * (100-MIS)/100 || + msec > duration[i] * (100+MIS)/100) { PJ_LOG(3,(THIS_FILE, "...error: slept for %d ms instead of %d ms " "(outside %d%% err window)", - msec, DURATION, MIS)); + msec, duration[i], MIS)); return -30; } } /* Test pj_thread_sleep() and pj_get_timestamp() and friends */ - { + for (i=0; i DURATION2 * (100+MIS)/100) + if (msec < duration[i] * (100-MIS)/100 || + msec > duration[i] * (100+MIS)/100) { PJ_LOG(3,(THIS_FILE, "...error: slept for %d ms instead of %d ms " "(outside %d%% err window)", - msec, DURATION2, MIS)); + msec, duration[i], MIS)); PJ_TIME_VAL_SUB(t2, t1); PJ_LOG(3,(THIS_FILE, "...info: gettimeofday() reported duration is " -- cgit v1.2.3