[owagner]

Platform: Ubuntu 8.10 on Athlon X2 6000+, SVN 16927

Hi,

I've just noticed a lot of those in the debug log, stemming from an .avi playback session:

Code:

20:23:14 T:3051738944 M:793210880 WARNING: QueryPerformanceCounter moving backwords by 27080 ticks with freq of 1000000000
20:24:33 T:3051738944 M:796422144 WARNING: QueryPerformanceCounter moving backwords by 62160 ticks with freq of 1000000000
20:24:59 T:3051738944 M:797814784 WARNING: QueryPerformanceCounter moving backwords by 41160 ticks with freq of 1000000000
20:25:12 T:3051738944 M:797814784 WARNING: QueryPerformanceCounter moving backwords by 34280 ticks with freq of 1000000000
20:25:48 T:3051738944 M:797052928 WARNING: QueryPerformanceCounter moving backwords by 10600 ticks with freq of 1000000000

I've looked into the implementation of QueryPerformanceCounter(), and it seems to call through to clock_gettime with CLOCK_MONOTONIC, which is documented to not go backward, ever, so this looks slightly worrying.

Best Regards,
Olli

[davidw]

If have the same in my log while I play an .mpg file.
SVN17520 ; Ubuntu 8.10 AMDx2 ATI HD3450.

The video jumps a bit every few seconds.

cheers,
david

[Maxim]

I have no further input on this matter other than "backwards" is spelled incorrectly. Sorry.

[gnif]

This occurs on computers with more then one core, the reason is that the tick counter in each cpu is not always exactly in sync, and there is no way to ever achieve this.

I have been playing around with fixing this problem, and I think I have found a way to solve it, just need to do some more testing.

If I create two threads on my dual core pc that are querying clock_gettime, I can replicate the badness. What needs to be done, is set the affinity to both threads to the run on the same CPU core, so they retrieve the tick count from the same CPU every time.

What I am thinking of doing is starting a thread that is bound to the single CPU for timing, using a mutex to lock a global variable that contains the time that is continually updated by the thread.

Anyway, I will play more over the weekend with it and see if I can solve this issue, I dont like my logs filling with this crap.

[gnif]

I have come up with a work around that works really well...

If I create a thread that does the single task of waiting for a signal on a condition so it does not chew up the CPU, then fetching the time, and signaling a 2nd condition to let the callback function know that the data is ready.

Using the pthread_setaffinity_np function the thread is locked to one core, so it will only ever fetch that core's counter.

The clock_gettime function is wrapped to setup the parameters, signal the thread, the thread then does the work, while we wait for a 2nd condition to be signalled, which, once it is, we can read the clock and unlock the mutex so the whole process can be repeated.

Using this method in a small test program, I am no longer seeing the time go backwards!!!! this is a unique soluition to this problem as google has yielded nobody that has solved this problem in any application.

I will post some sample code in the next reply

[gnif]

Note, this is sample code and could be better, (eg: pthread_setaffinity_np should use the CPU_SET macros)

Code:

pthread_cond_t  thread_time_cond1       = PTHREAD_COND_INITIALIZER;
pthread_mutex_t thread_time_mutex1      = PTHREAD_MUTEX_INITIALIZER;
pthread_cond_t  thread_time_cond2       = PTHREAD_COND_INITIALIZER;
pthread_mutex_t thread_time_mutex2      = PTHREAD_MUTEX_INITIALIZER;

struct timespec *thread_time_data;
clockid_t       thread_time_clk_id;
int             thread_time_ret;

void* thread_time_func(void *data) {
        /* Set our affinity to one core so the time never goes backwards */
        unsigned long mask = 1;
        pthread_setaffinity_np(pthread_self(), sizeof(mask), (cpu_set_t*)&mask);

        /* Lock the primary mutex for our condition */
        pthread_mutex_lock(&thread_time_mutex1);
        while(1) {
                /* Wait until someone wants the current time */
                pthread_cond_wait(&thread_time_cond1, &thread_time_mutex1);
                thread_time_ret = clock_gettime(thread_time_clk_id, thread_time_data);

                /* Lock the 2nd mutex, signal the 2nd cond, and unlock */
                pthread_mutex_lock(&thread_time_mutex2);
                pthread_cond_signal(&thread_time_cond2);
                pthread_mutex_unlock(&thread_time_mutex2);
        }

        pthread_exit(NULL);
        return NULL;
}

int clock_gettime_core(clockid_t clk_id, struct timespec *tp) {
        int ret;

        /* Lock the mutex so we dont change things in the thread mid stride */
        pthread_mutex_lock(&thread_time_mutex1);
        pthread_mutex_lock(&thread_time_mutex2);

        thread_time_clk_id      = clk_id;
        thread_time_data        = tp;

        /* Signal the thread to run  */
        pthread_cond_signal(&thread_time_cond1);
        pthread_mutex_unlock(&thread_time_mutex1);

        /* Wait for the thread to tell us our data is ready */
        pthread_cond_wait(&thread_time_cond2, &thread_time_mutex2);
        ret = thread_time_ret;

        /* Finally unlock the mutex so this function can be called again */
        pthread_mutex_unlock(&thread_time_mutex2);
        return ret;
}

[gnif]

The problem was found and fixed (Committed in r17646), see thread:
http://forum.xbmc.org/showthread.php?tid=45194

Was not due to dual core, but a thread race condition