[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: non-monotonic do_gettimeofday?



Quoting Akshay Adhikari <akshay@xxxxxxx.com>:

> Hi, 
> I tried the patch, but I still get decreasing timestamps sometimes. 

Can you send a list of timestamp where this happens, so I can see 
how large difference it is and if there is any pattern+

> Is it possible to copy over time.c from 2.4.19 and use it in 2.4.14,
> or are there any other dependencies? 

You probably need include/asm-cris/timex.h as well, but I'm currently
not able to test it.

> also, how do you test for non-monotonicity? Is it by by calling
> gettimeofday in a loop from user space? I have never noticed
> non-monotonic timestamps when I do that. 

Yes, I could verify the bug and the fix in 2.4.5(?) with it.

>Could you make your test
> program(s) available? 

It's at the end of this mail (sorry for the long post)

> The only time it happens is under moderately high
> network(and hence CPU) load, when I compare a user space send
> timestamp
> for a UDP packet, and a kernel space receive timestamp (obtained via
> do_gettimeofday) for that packet: the receive timestamp is sometimes
> smaller than the send. 
> 
> ofcourse, if timer interrupts _can_ be missed, then there is not much
> that can be done about it....

Even if we missed an interrupt we should be able to keep the 
time monotonic, just need som more/better code somewhere...
 
> Thanks, 
> akshay
> 

Best regards
/Johan



/*!***************************************************************************
*!
*! FILE NAME  : timetest.c
*!
*! DESCRIPTION: Test timer resolution.
*!
*! FUNCTIONS  : 
*! (EXTERNAL)
*!
*! FUNCTIONS  : 
*! (LOCAL)
*!
*! ---------------------------------------------------------------------------
*! HISTORY
*!
*! DATE         NAME               CHANGES
*! ----         ----               -------
*! Nov  1 2001  Johan Adolfsson    Initial version
*! $Log: timetest.c,v $
*! Revision 1.2  2002/03/05 13:18:44  johana
*! Added histogram of how the time differs. Increased the amount of tests.
*! Added number of zero diff.
*!
*! Revision 1.1  2001/11/01 16:00:37  johana
*! Testprogram to test gettimeofday() resolution and if clock goes backword
*! etc.
*!
*!
*! ---------------------------------------------------------------------------
*! (C) Copyright 2001, Axis Communications AB, LUND, SWEDEN
*!***************************************************************************/
/* $Id: timetest.c,v 1.2 2002/03/05 13:18:44 johana Exp $ */

/****************** INCLUDE FILES SECTION ***********************************/

#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <time.h>
#include <unistd.h>
#include <sys/time.h>

/****************** CONSTANT AND MACRO SECTION ******************************/
const char usage[] = 
"usage: timetest [-print-all]\n"
;
#define NUM_TV 8192
#define MAX_DIFF 10000
/****************** TYPE DEFINITION SECTION *********************************/

/****************** LOCAL FUNCTION DECLARATION SECTION **********************/

/****************** GLOBAL VARIABLE DECLARATION SECTION *********************/

/****************** LOCAL VARIABLE DECLARATION SECTION **********************/
struct timeval tvs[NUM_TV];

unsigned short diff_count_histogram[MAX_DIFF+1];


/****************** FUNCTION DEFINITION SECTION *****************************/
int main(int argc, char **argv)
{
  int i,j;
  long diff_usec;
  long min_diff_usec;
  long max_diff_usec;
  unsigned long going_back = 0;
  long sum_diff = 0;
  long zero_diff_count = 0;
  short max_count = 0;
  
  min_diff_usec = 1000000;
  max_diff_usec = 0;

  gettimeofday(&tvs[0], NULL);
  for (i=1; i< NUM_TV; i++)
  {
    do
    {
      gettimeofday(&tvs[i], NULL);
      zero_diff_count++;
    } while( tvs[i].tv_usec == tvs[i-1].tv_usec);
    zero_diff_count--;
  }
  memset(diff_count_histogram, 0, sizeof(diff_count_histogram));
  
  for (i=1; i< NUM_TV; i++)
  {
    diff_usec = (tvs[i].tv_sec - tvs[i-1].tv_sec)*1000000+tvs[i].tv_usec - tvs
[i-1].tv_usec;
    if (diff_usec > max_diff_usec)
      max_diff_usec = diff_usec;
    if (abs(diff_usec) < min_diff_usec)
      min_diff_usec = diff_usec;
    if (diff_usec < 0)
    {
      going_back++;
      printf("%lu.%06lu to %lu.%06lu diff %li\n", 
             tvs[i-1].tv_sec, tvs[i-1].tv_usec, 
             tvs[i].tv_sec, tvs[i].tv_usec, diff_usec);
    }
    else
    {
      if (diff_usec < MAX_DIFF)
      {
        diff_count_histogram[diff_usec]++;
      }
      else
      {
        diff_count_histogram[MAX_DIFF]++;
      }
    }
    sum_diff += diff_usec;
  }
  for (i=0; i <= MAX_DIFF; i++)
  {
    if (diff_count_histogram[i] > max_count)
    {
      max_count = diff_count_histogram[i];
    }
  }
  for (i=0; i <= MAX_DIFF; i++)
  {
    if (diff_count_histogram[i] > 0)
    {
      printf("%4i us %4i ", i, diff_count_histogram[i]);
      for(j=0; j<(65*diff_count_histogram[i]/max_count); j++)
      {
        printf("#");
      }
      printf("\n");
      
    }
  }
  
  printf("zero_diff_count: %lu\n", zero_diff_count);
  printf("min_diff: %lu us\n", min_diff_usec);
  printf("max_diff: %lu us\n", max_diff_usec);
  printf("mean_diff: %lu/%i = %lu us\n", sum_diff, NUM_TV, sum_diff/NUM_TV);
  printf("Clock going backwords: %lu\n", going_back);
  if (argc > 1)
  {
    for (i=0; i< NUM_TV; i++)
    {
      diff_usec = (tvs[i].tv_sec - tvs[i-1].tv_sec)*1000000+tvs[i].tv_usec - tvs
[i-1].tv_usec;
      printf("%lu.%06lu  diff %li\n", 
             tvs[i].tv_sec, tvs[i].tv_usec, diff_usec);
    }
  }
  
    return 0;
}