First cut not the deepest?

[Jim White]

Does Windows cause brain damage?

Runnng timing comparisons under Windows is always a
trifle dodgy, but the anomaly I am seeing is
particularly baffling.

The test is simple enough. Repeat some non-trivial
operation R times, report the time taken. Do that that
N times.

Using either a static or shared library built for a
Pentium 4 under MinGW, I am consistently getting a
series of times that increase fairly quickly, then
seem to stabilise at just under twice the time taken
for the first set.

For example, here the test program is mpz_mul-ing two
arguments of about 8K limbs, 1000 times a set:

> test -p 8192 -r 1000 -n 10
16:48:38  start test, ops/set = 1000, nreps = 10
16:48:47  time =  8.625000
16:48:58  time = 11.672000
16:49:11  time = 12.734000
16:49:24  time = 13.282000
16:49:38  time = 13.734000
16:49:52  time = 14.109000
16:50:06  time = 14.250000
16:50:21  time = 14.453000
16:50:35  time = 14.500000
16:50:50  time = 14.579000
16:50:50  avg  = 13.193800

The test program records the real-time clock as well
as the calculated times, because I had to convince
myself that the calculated times were right! 

This same trend is produced, regardless of whether I
hammer mpz_mul, or mpf_div, or mpfr_cos.  

Has my obtuseness become acute (so to speak!), or is
there something going on in there?

Cheers
Jim White
ANU, Canberra

-------------------------------------------
> type test.c

#include <stdio.h>
#include <time.h>
#include "gmp_static.h"

mpz_t  X1, X2, Y;
int    TSTART, TNOW;

double GetClock() {return ((double)(TNOW -
TSTART)/1000.0);}
char   timenow[32];
char  *dclock() {  // time-of-day ("hh:mm:ss")
   time_t etime; time(&etime);
   char *tnow = (char *) ctime(&etime);
   strncpy (timenow, tnow, 20);
   timenow[20] = 0;
   return (&timenow[11]);
   }
//----------------------

int main (int argc, char *argv[]) {
    int i, p;
    int k = 1;
    int r = 1000;
    int nreps = 1;

    while (k < argc) {
       if (strcmp(argv[k],"-p")  == 0) { k++;     p =
atoi(argv[k]); }
       if (strcmp(argv[k],"-r")  == 0) { k++;     r =
atoi(argv[k]); }
       if (strcmp(argv[k],"-n")  == 0) { k++; nreps =
atoi(argv[k]); }
       k++;
       }
    mpz_init2  (X1, 32*p);
    mpz_init2  (X2, 32*p);
    mpz_init2  (Y,  32*p);

    double xtime, rtime;

    // Set test operands

    mpz_set_ui (X1, 3); mpz_set_ui (X2, 3);
    while (X1->_mp_size < (p/2)) {
       mpz_add_ui (X2, X2, 2);
       mpz_mul    (X1, X1, X2);
       }
    mpz_mul    (X2, X1, X1);
    mpz_add_ui (X1, X1,  1);

    // Timing tests
    rtime = 0.0;
    printf ("%s start test, ops/set = %d, nreps =
%d\n", dclock(), r, nreps);
    for  (k = 0; k < nreps; k++) {
          TSTART = clock();
          for (i=0; i < r; i++) mpz_mul (Y, X1, X2);
          TNOW   = clock();
          xtime  = GetClock();
          rtime += xtime;
          printf ("%s time = %f\n", dclock(), xtime);
          }
    rtime /= nreps;
    printf ("%s avg  = %f\n", dclock(), rtime);
    }