Re: measuring elapsed time on mingw
On 04/04/2010 04:41 AM, Bruno Haible wrote: Hi, Just a side note about how to measure elapsed time on mingw. (I needed this in order to evaluate how to implement nanosleep on mingw.) Summary: - GetSystemTimeAsFileTime, _ftime, gettimeofday (from newer mingw runtimes) all have about 15.6 ms resolution. Actually, they have a resolution that is variable length. It defaults to 15.6 ms, but you can get it down to 1 ms with other tricks, although it has performance ramifications across all processes running on the machine (whether or not those other processes needed the extra resolution). - QueryPerformanceCounter [1] has a resolution of 0.5 ms or higher. Yes, this is probably the best call to use for raw resolution, but if you use it, then you run into the issues of file timestamp mismatch (cygwin currently has a known issue where, because it uses QueryPerformanceCounter instead of GetSystemTimeAsFileTime for implementing utimensat(UTIME_NOW), a file can not only appear newer than what a corresponding file system operation would be, but also time can appear to travel backwards when following a utimensat(UTIME_NOW) operation by a normal file system operation). As a result, all of the gnulib tests that inspect sub-second resolution of file timestamps have to insert the equivalent of usleep(2) to ensure that events are far enough apart to be observable without time apparently traveling in reverse. -- Eric Blake ebl...@redhat.com+1-801-349-2682 Libvirt virtualization library http://libvirt.org signature.asc Description: OpenPGP digital signature
Re: measuring elapsed time on mingw
Hi Eric, - QueryPerformanceCounter [1] has a resolution of 0.5 ms or higher. ... if you use it, then you run into the issues of file timestamp mismatch (cygwin currently has a known issue where, because it uses QueryPerformanceCounter instead of GetSystemTimeAsFileTime for implementing utimensat(UTIME_NOW), a file can not only appear newer than what a corresponding file system operation would be, but also time can appear to travel backwards when following a utimensat(UTIME_NOW) operation by a normal file system operation). This matches the difficulties that are described in [1]. But I would think the difficulties come in only when you try to combine the GetSystemTimeAsFileTime and QueryPerformanceCounter results? When you use only QueryPerformanceCounter, you should be fine (except for [2])? Bruno [1] http://msdn.microsoft.com/en-us/magazine/cc163996.aspx [2] http://support.microsoft.com/kb/274323/en-us/
Re: measuring elapsed time on mingw
On 04/05/2010 08:56 AM, Bruno Haible wrote: Hi Eric, - QueryPerformanceCounter [1] has a resolution of 0.5 ms or higher. ... if you use it, then you run into the issues of file timestamp mismatch (cygwin currently has a known issue where, because it uses QueryPerformanceCounter instead of GetSystemTimeAsFileTime for implementing utimensat(UTIME_NOW), a file can not only appear newer than what a corresponding file system operation would be, but also time can appear to travel backwards when following a utimensat(UTIME_NOW) operation by a normal file system operation). This matches the difficulties that are described in [1]. But I would think the difficulties come in only when you try to combine the GetSystemTimeAsFileTime and QueryPerformanceCounter results? When you use only QueryPerformanceCounter, you should be fine (except for [2])? As I see it, using QueryPerformanceCounter in isolation is fine; the problems only come when you try to correlate between two different counters of two different resolutions. So if all you are trying to do is measure elapsed time, rather than setting timestamps of files that will match the system's notion of file timestamps, I don't think we are running into obvious problems. It's just that it is always worth an extra bit of caution when dealing with subsecond resolutions, because the ramifications are not always immediately apparant. -- Eric Blake ebl...@redhat.com+1-801-349-2682 Libvirt virtualization library http://libvirt.org signature.asc Description: OpenPGP digital signature
measuring elapsed time on mingw
Hi,
Just a side note about how to measure elapsed time on mingw.
(I needed this in order to evaluate how to implement nanosleep on mingw.)
Summary:
- GetSystemTimeAsFileTime, _ftime, gettimeofday (from newer mingw runtimes)
all have about 15.6 ms resolution.
- QueryPerformanceCounter [1] has a resolution of 0.5 ms or higher.
There is an explanation how to implement the equivalent of gettimeofday with
a combination of GetSystemTimeAsFileTime and QueryPerformanceCounter [2],
but it appears quite complex, and overkill for gnulib.
As witness, here's a test program that busy-loops for a certain time and
then outputs the time difference, measured according to different system calls:
gettime-res.c
#include sys/time.h
#include sys/timeb.h
#include stdio.h
#include stdlib.h
#include windows.h
int main (int argc, char *argv[])
{
int count = atoi(argv[1]);
FILETIME ft_before, ft_after;
struct _timeb tb_before, tb_after;
struct timeval tv_before, tv_after;
LARGE_INTEGER pcfreq;
LARGE_INTEGER pc_before, pc_after;
int i, j;
if (!QueryPerformanceFrequency (pcfreq))
printf (QueryPerformanceFrequency failed\n);
GetSystemTimeAsFileTime (ft_before);
_ftime (tb_before);
gettimeofday (tv_before, NULL);
if (!QueryPerformanceCounter (pc_before))
printf (QueryPerformanceCounter failed\n);
for (i = 0; i count; i++)
for (j = 0; j 1; j++)
;
GetSystemTimeAsFileTime (ft_after);
_ftime (tb_after);
gettimeofday (tv_after, NULL);
if (!QueryPerformanceCounter (pc_after))
printf (QueryPerformanceCounter failed\n);
printf (GetSystemTimeAsFileTime %ld *0.1us\n
_ftime %ld ms\n
gettimeofday %ld us\n
QueryPerformanceCounter %ld (freq %ld) = %g s\n,
(ft_after.dwHighDateTime - ft_before.dwHighDateTime) * 0x1 +
ft_after.dwLowDateTime - ft_before.dwLowDateTime,
(tb_after.time - tb_before.time) * 1000 + tb_after.millitm -
tb_before.millitm,
(tv_after.tv_sec - tv_before.tv_sec) * 100 + tv_after.tv_usec -
tv_before.tv_usec,
(long) (pc_after.QuadPart - pc_before.QuadPart), (long)
pcfreq.QuadPart, (double)(pc_after.QuadPart - pc_before.QuadPart) / (double)
pcfreq.QuadPart);
return 0;
}
===
And its results on Windows XP:
$ ./gettime-res 100
GetSystemTimeAsFileTime 156250 *0.1us
_ftime 16 ms
gettimeofday 15625 us
QueryPerformanceCounter 18631 (freq 3579545) = 0.00520485 s
$ ./gettime-res 200
GetSystemTimeAsFileTime 156250 *0.1us
_ftime 16 ms
gettimeofday 15625 us
QueryPerformanceCounter 36574 (freq 3579545) = 0.0102175 s
$ ./gettime-res 300
GetSystemTimeAsFileTime 156250 *0.1us
_ftime 15 ms
gettimeofday 15625 us
QueryPerformanceCounter 54852 (freq 3579545) = 0.0153237 s
$ ./gettime-res 400
GetSystemTimeAsFileTime 156250 *0.1us
_ftime 16 ms
gettimeofday 15625 us
QueryPerformanceCounter 72040 (freq 3579545) = 0.0201255 s
$ ./gettime-res 400
GetSystemTimeAsFileTime 156250 *0.1us
_ftime 16 ms
gettimeofday 15625 us
QueryPerformanceCounter 72194 (freq 3579545) = 0.0201685 s
$ ./gettime-res 400
GetSystemTimeAsFileTime 156250 *0.1us
_ftime 15 ms
gettimeofday 15625 us
QueryPerformanceCounter 72201 (freq 3579545) = 0.0201704 s
$ ./gettime-res 400
GetSystemTimeAsFileTime 156250 *0.1us
_ftime 16 ms
gettimeofday 15625 us
QueryPerformanceCounter 73738 (freq 3579545) = 0.0205998 s
$ ./gettime-res 500
GetSystemTimeAsFileTime 312500 *0.1us
_ftime 31 ms
gettimeofday 31250 us
QueryPerformanceCounter 90478 (freq 3579545) = 0.0252764 s
$ ./gettime-res 500
GetSystemTimeAsFileTime 312500 *0.1us
_ftime 31 ms
gettimeofday 31250 us
QueryPerformanceCounter 91936 (freq 3579545) = 0.0256837 s
Bruno
[1] http://msdn.microsoft.com/en-us/library/ms644904(VS.85).aspx
[2] http://msdn.microsoft.com/en-us/magazine/cc163996.aspx
