Changeset 2560


Ignore:
Timestamp:
Mar 30, 2009 6:22:16 PM (16 years ago)
Author:
bennylp
Message:

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
Location:
pjproject/trunk/pjlib
Files:
4 edited

Legend:

Unmodified
Added
Removed
  • pjproject/trunk/pjlib/include/pj/os.h

    r2481 r2560  
    12691269 
    12701270/** 
     1271 * Variant of #pj_elapsed_msec() which returns 64bit value. 
     1272 */ 
     1273PJ_DECL(pj_uint64_t) pj_elapsed_msec64(const pj_timestamp *start, 
     1274                                       const pj_timestamp *stop ); 
     1275 
     1276/** 
    12711277 * Calculate the elapsed time in 32-bit microseconds. 
    12721278 * This function calculates the elapsed time using highest precision 
  • pjproject/trunk/pjlib/src/pj/os_time_win32.c

    r2394 r2560  
    2020#include <pj/os.h> 
    2121#include <pj/string.h> 
     22#include <pj/log.h> 
    2223#include <windows.h> 
    2324 
     
    2829static LARGE_INTEGER base_time; 
    2930 
     31#if defined(PJ_WIN32_WINCE) && PJ_WIN32_WINCE 
     32#   define WINCE_TIME 
     33#endif 
     34 
     35#ifdef WINCE_TIME 
     36/* Note: 
     37 *  In Windows CE/Windows Mobile platforms, the availability of milliseconds 
     38 *  time resolution in SYSTEMTIME.wMilliseconds depends on the OEM, and most 
     39 *  likely it won't be available. When it's not available, the  
     40 *  SYSTEMTIME.wMilliseconds will contain a constant arbitrary value. 
     41 * 
     42 *  Because of that, we need to emulate the milliseconds time resolution 
     43 *  using QueryPerformanceCounter() (via pj_get_timestamp() API). However  
     44 *  there is limitation on using this, i.e. the time returned by  
     45 *  pj_gettimeofday() may be off by up to plus/minus 999 msec (the second 
     46 *  part will be correct, however the msec part may be off), because we're  
     47 *  not synchronizing the msec field with the change of value of the "second" 
     48 *  field of the system time. 
     49 * 
     50 *  Also there is other caveat which need to be handled (and they are  
     51 *  handled by this implementation): 
     52 *   - user may change system time, so pj_gettimeofday() needs to periodically 
     53 *     checks if system time has changed. The period on which system time is 
     54 *     checked is controlled by PJ_WINCE_TIME_CHECK_INTERVAL macro. 
     55 */ 
     56static LARGE_INTEGER g_start_time;  /* Time gettimeofday() is first called  */ 
     57static pj_timestamp  g_start_tick;  /* TS gettimeofday() is first called  */ 
     58static pj_timestamp  g_last_update; /* Last time check_system_time() is  
     59                                       called, to periodically synchronize 
     60                                       with up-to-date system time (in case 
     61                                       user changes system time).           */ 
     62static pj_uint64_t   g_update_period; /* Period (in TS) check_system_time() 
     63                                         should be called.                  */ 
     64 
     65/* Period on which check_system_time() is called, in seconds                */ 
     66#ifndef PJ_WINCE_TIME_CHECK_INTERVAL 
     67#   define PJ_WINCE_TIME_CHECK_INTERVAL (10) 
     68#endif 
     69 
     70#endif 
     71 
     72#ifdef WINCE_TIME 
     73static pj_status_t init_start_time(void) 
     74{ 
     75    SYSTEMTIME st; 
     76    FILETIME ft; 
     77    pj_timestamp freq; 
     78    pj_status_t status; 
     79 
     80    GetLocalTime(&st); 
     81    SystemTimeToFileTime(&st, &ft); 
     82 
     83    g_start_time.LowPart = ft.dwLowDateTime; 
     84    g_start_time.HighPart = ft.dwHighDateTime; 
     85    g_start_time.QuadPart /= SECS_TO_FT_MULT; 
     86    g_start_time.QuadPart -= base_time.QuadPart; 
     87 
     88    status = pj_get_timestamp(&g_start_tick); 
     89    if (status != PJ_SUCCESS) 
     90        return status; 
     91 
     92    g_last_update.u64 = g_start_tick.u64; 
     93 
     94    status = pj_get_timestamp_freq(&freq); 
     95    if (status != PJ_SUCCESS) 
     96        return status; 
     97 
     98    g_update_period = PJ_WINCE_TIME_CHECK_INTERVAL * freq.u64; 
     99 
     100    PJ_LOG(4,("os_time_win32.c", "WinCE time (re)started")); 
     101 
     102    return PJ_SUCCESS; 
     103} 
     104 
     105static pj_status_t check_system_time(pj_uint64_t ts_elapsed) 
     106{ 
     107    enum { MIS = 5 }; 
     108    SYSTEMTIME st; 
     109    FILETIME ft; 
     110    LARGE_INTEGER cur, calc; 
     111    DWORD diff; 
     112    pj_timestamp freq; 
     113    pj_status_t status; 
     114 
     115    /* Get system's current time */ 
     116    GetLocalTime(&st); 
     117    SystemTimeToFileTime(&st, &ft); 
     118     
     119    cur.LowPart = ft.dwLowDateTime; 
     120    cur.HighPart = ft.dwHighDateTime; 
     121    cur.QuadPart /= SECS_TO_FT_MULT; 
     122    cur.QuadPart -= base_time.QuadPart; 
     123 
     124    /* Get our calculated system time */ 
     125    status = pj_get_timestamp_freq(&freq); 
     126    if (status != PJ_SUCCESS) 
     127        return status; 
     128 
     129    calc.QuadPart = g_start_time.QuadPart + ts_elapsed / freq.u64; 
     130 
     131    /* See the difference between calculated and actual system time */ 
     132    if (calc.QuadPart >= cur.QuadPart) { 
     133        diff = (DWORD)(calc.QuadPart - cur.QuadPart); 
     134    } else { 
     135        diff = (DWORD)(cur.QuadPart - calc.QuadPart); 
     136    } 
     137 
     138    if (diff > MIS) { 
     139        /* System time has changed */ 
     140        PJ_LOG(3,("os_time_win32.c", "WinCE system time changed detected " 
     141                                      "(diff=%u)", diff)); 
     142        status = init_start_time(); 
     143    } else { 
     144        status = PJ_SUCCESS; 
     145    } 
     146 
     147    return status; 
     148} 
     149 
     150#endif 
     151 
    30152// Find 1st Jan 1970 as a FILETIME  
    31 static void get_base_time(void) 
    32 { 
    33     SYSTEMTIME st; 
    34     FILETIME ft; 
     153static pj_status_t get_base_time(void) 
     154{ 
     155    SYSTEMTIME st; 
     156    FILETIME ft; 
     157    pj_status_t status = PJ_SUCCESS; 
    35158 
    36159    memset(&st,0,sizeof(st)); 
     
    43166    base_time.HighPart = ft.dwHighDateTime; 
    44167    base_time.QuadPart /= SECS_TO_FT_MULT; 
     168 
     169#ifdef WINCE_TIME 
     170    pj_enter_critical_section(); 
     171    status = init_start_time(); 
     172    pj_leave_critical_section(); 
     173#endif 
     174 
     175    return status; 
    45176} 
    46177 
    47178PJ_DEF(pj_status_t) pj_gettimeofday(pj_time_val *tv) 
    48179{ 
     180#ifdef WINCE_TIME 
     181    pj_timestamp tick; 
     182    pj_uint64_t msec_elapsed; 
     183#else 
    49184    SYSTEMTIME st; 
    50185    FILETIME ft; 
    51186    LARGE_INTEGER li; 
    52  
    53     if (base_time.QuadPart == 0) 
    54         get_base_time(); 
    55  
     187#endif 
     188    pj_status_t status; 
     189 
     190    if (base_time.QuadPart == 0) { 
     191        status = get_base_time(); 
     192        if (status != PJ_SUCCESS) 
     193            return status; 
     194    } 
     195 
     196#ifdef WINCE_TIME 
     197    do { 
     198        status = pj_get_timestamp(&tick); 
     199        if (status != PJ_SUCCESS) 
     200            return status; 
     201 
     202        if (tick.u64 - g_last_update.u64 >= g_update_period) { 
     203            pj_enter_critical_section(); 
     204            if (tick.u64 - g_last_update.u64 >= g_update_period) { 
     205                g_last_update.u64 = tick.u64; 
     206                check_system_time(tick.u64 - g_start_tick.u64); 
     207            } 
     208            pj_leave_critical_section(); 
     209        } else { 
     210            break; 
     211        } 
     212    } while (1); 
     213 
     214    msec_elapsed = pj_elapsed_msec64(&g_start_tick, &tick); 
     215 
     216    tv->sec = (long)(g_start_time.QuadPart + msec_elapsed/1000); 
     217    tv->msec = (long)(msec_elapsed % 1000); 
     218#else 
     219    /* Standard Win32 GetLocalTime */ 
    56220    GetLocalTime(&st); 
    57221    SystemTimeToFileTime(&st, &ft); 
     
    64228    tv->sec = li.LowPart; 
    65229    tv->msec = st.wMilliseconds; 
     230#endif  /* WINCE_TIME */ 
    66231 
    67232    return PJ_SUCCESS; 
  • pjproject/trunk/pjlib/src/pj/os_timestamp_common.c

    r2394 r2560  
    153153} 
    154154 
     155PJ_DEF(pj_uint64_t) pj_elapsed_msec64(const pj_timestamp *start, 
     156                                      const pj_timestamp *stop ) 
     157{ 
     158    return (pj_uint64_t)elapsed_msec(start, stop); 
     159} 
     160 
    155161PJ_DEF(pj_time_val) pj_elapsed_time( const pj_timestamp *start, 
    156162                                     const pj_timestamp *stop ) 
  • pjproject/trunk/pjlib/src/pjlib-test/sleep.c

    r2394 r2560  
    5656static int simple_sleep_test(void) 
    5757{ 
    58     enum { COUNT = 5 }; 
     58    enum { COUNT = 10 }; 
    5959    int i; 
    6060    pj_status_t rc; 
     
    6363     
    6464    for (i=0; i<COUNT; ++i) { 
     65        pj_time_val tv; 
     66        pj_parsed_time pt; 
     67 
    6568        rc = pj_thread_sleep(1000); 
    6669        if (rc != PJ_SUCCESS) { 
     
    6871            return -10; 
    6972        } 
    70         PJ_LOG(3,(THIS_FILE, "...wake up..")); 
     73 
     74        rc = pj_gettimeofday(&tv); 
     75        if (rc != PJ_SUCCESS) { 
     76            app_perror("...error: pj_gettimeofday()", rc); 
     77            return -11; 
     78        } 
     79 
     80        pj_time_decode(&tv, &pt); 
     81 
     82        PJ_LOG(3,(THIS_FILE,  
     83                  "...%04d-%02d-%02d %02d:%02d:%02d.%03d", 
     84                  pt.year, pt.mon, pt.day, 
     85                  pt.hour, pt.min, pt.sec, pt.msec)); 
     86 
    7187    } 
    7288 
     
    7692static int sleep_duration_test(void) 
    7793{ 
    78     enum { MIS = 20, DURATION = 1000, DURATION2 = 500 }; 
     94    enum { MIS = 20}; 
     95    unsigned duration[] = { 2000, 1000, 500, 200, 100 }; 
     96    unsigned i; 
    7997    pj_status_t rc; 
    8098 
     
    82100 
    83101    /* Test pj_thread_sleep() and pj_gettimeofday() */ 
    84     { 
     102    for (i=0; i<PJ_ARRAY_SIZE(duration); ++i) { 
    85103        pj_time_val start, stop; 
    86104        pj_uint32_t msec; 
     
    94112 
    95113        /* Sleep */ 
    96         rc = pj_thread_sleep(DURATION); 
     114        rc = pj_thread_sleep(duration[i]); 
    97115        if (rc != PJ_SUCCESS) { 
    98116            app_perror("...error: pj_thread_sleep()", rc); 
     
    110128 
    111129        /* Check if it's within range. */ 
    112         if (msec < DURATION * (100-MIS)/100 || 
    113             msec > DURATION * (100+MIS)/100) 
     130        if (msec < duration[i] * (100-MIS)/100 || 
     131            msec > duration[i] * (100+MIS)/100) 
    114132        { 
    115133            PJ_LOG(3,(THIS_FILE,  
    116134                      "...error: slept for %d ms instead of %d ms " 
    117135                      "(outside %d%% err window)", 
    118                       msec, DURATION, MIS)); 
     136                      msec, duration[i], MIS)); 
    119137            return -30; 
    120138        } 
     
    123141 
    124142    /* Test pj_thread_sleep() and pj_get_timestamp() and friends */ 
    125     { 
     143    for (i=0; i<PJ_ARRAY_SIZE(duration); ++i) { 
    126144        pj_time_val t1, t2; 
    127145        pj_timestamp start, stop; 
     
    141159 
    142160        /* Sleep */ 
    143         rc = pj_thread_sleep(DURATION2); 
     161        rc = pj_thread_sleep(duration[i]); 
    144162        if (rc != PJ_SUCCESS) { 
    145163            app_perror("...error: pj_thread_sleep()", rc); 
     
    163181 
    164182        /* Check if it's within range. */ 
    165         if (msec < DURATION2 * (100-MIS)/100 || 
    166             msec > DURATION2 * (100+MIS)/100) 
     183        if (msec < duration[i] * (100-MIS)/100 || 
     184            msec > duration[i] * (100+MIS)/100) 
    167185        { 
    168186            PJ_LOG(3,(THIS_FILE,  
    169187                      "...error: slept for %d ms instead of %d ms " 
    170188                      "(outside %d%% err window)", 
    171                       msec, DURATION2, MIS)); 
     189                      msec, duration[i], MIS)); 
    172190            PJ_TIME_VAL_SUB(t2, t1); 
    173191            PJ_LOG(3,(THIS_FILE,  
Note: See TracChangeset for help on using the changeset viewer.