Re: [PATCH 2/2] V3: cyclictest: report large measured clock latency

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

 




On Mon, 13 Aug 2012, Frank Rowand wrote:

Hi Frank - I added the extra comment to your patch as you requested
"One issue with using warn() and info() instead of fprintf() is that
the compiler no longer warns about format mismatches."

Another thing about using the warn function - I'm not sure I like that
WARN: printed out when you use your -R

./cyclictest -R
WARN: reported clock resolution: 1 nsec
WARN: measured clock resolution approximately: 699 nsec

Nice patch though.
Signed-off-by: John Kacur <jkacur@xxxxxxxxxx>
> 
> V3: Use src/lib/error.c functions instead of fprintf.
>     Fix printf format warnings for 32 bit vs 64 bit systems with cast.
>     Fix bad continuation line white space prefix.
>     Remove unused variable zero_diff.
> 
> cyclictest: ARM panda clock resolution will be ~30 usec unless
> CONFIG_OMAP_32K_TIMER=n, resulting in a poor latency report.
> 
> This patch does _not_ fix the problem, it merely provides the
> instrumentation to make it visible.  The value of measured
> resolution is useful information for any system.
> 
> Signed-off-by: Frank Rowand <frank.rowand@xxxxxxxxxxx>
> ---
>  src/cyclictest/cyclictest.c |  109 	108 +	1 -	0 !
>  1 file changed, 108 insertions(+), 1 deletion(-)
> 
> Index: b/src/cyclictest/cyclictest.c
> ===================================================================
> --- a/src/cyclictest/cyclictest.c
> +++ b/src/cyclictest/cyclictest.c
> @@ -174,6 +174,8 @@ static int use_nsecs = 0;
>  static int refresh_on_max;
>  static int force_sched_other;
>  static int priospread = 0;
> +static int check_clock_resolution;
> +static int ct_debug;
>  
>  static pthread_cond_t refresh_on_max_cond = PTHREAD_COND_INITIALIZER;
>  static pthread_mutex_t refresh_on_max_lock = PTHREAD_MUTEX_INITIALIZER;
> @@ -944,6 +946,9 @@ static void display_help(int error)
>  	       "-q       --quiet           print only a summary on exit\n"
>  	       "-Q       --priospread       spread priority levels starting at specified value\n"
>  	       "-r       --relative        use relative timer instead of absolute\n"
> +	       "-R       --resolution      check clock resolution, calling clock_gettime() many\n"
> +	       "                           times.  list of clock_gettime() values will be\n"
> +	       "                           reported with -X\n"
>  	       "-s       --system          use sys_nanosleep and sys_setitimer\n"
>  	       "-S       --smp             Standard SMP testing: options -a -t -n and\n"
>  	       "                           same priority of all threads\n"
> @@ -960,6 +965,7 @@ static void display_help(int error)
>  	       "                           format: n:c:v n=tasknum c=count v=value in us\n"
>  	       "-w       --wakeup          task wakeup tracing (used with -b)\n"
>  	       "-W       --wakeuprt        rt task wakeup tracing (used with -b)\n"
> +	       "-X       --dbg_cyclictest  print info useful for debugging cyclictest\n"
>  	       "-y POLI  --policy=POLI     policy of realtime thread, POLI may be fifo(default) or rr\n"
>  	       "                           format: --policy=fifo(default) or --policy=rr\n",
>  	       tracers
> @@ -1076,6 +1082,7 @@ static void process_options (int argc, c
>  			{"quiet",            no_argument,       NULL, 'q'},
>  			{"priospread",       no_argument,       NULL, 'Q'},
>  			{"relative",         no_argument,       NULL, 'r'},
> +			{"resolution",       no_argument,       NULL, 'R'},
>  			{"system",           no_argument,       NULL, 's'},
>  			{"smp",              no_argument,       NULL, 'S'},
>  			{"threads",          optional_argument, NULL, 't'},
> @@ -1085,11 +1092,12 @@ static void process_options (int argc, c
>  			{"verbose",          no_argument,       NULL, 'v'},
>  			{"wakeup",           no_argument,       NULL, 'w'},
>  			{"wakeuprt",         no_argument,       NULL, 'W'},
> +			{"dbg_cyclictest",   no_argument,       NULL, 'X'},
>  			{"policy",           required_argument, NULL, 'y'},
>  			{"help",             no_argument,       NULL, '?'},
>  			{NULL, 0, NULL, 0}
>  		};
> -		int c = getopt_long(argc, argv, "a::b:Bc:Cd:D:e:Efh:H:i:Il:MnNo:O:p:PmqQrsSt::uUvD:wWT:y:",
> +		int c = getopt_long(argc, argv, "a::b:Bc:Cd:D:e:Efh:H:i:Il:MnNo:O:p:PmqQrRsSt::uUvD:wWXT:y:",
>  				    long_options, &option_index);
>  		if (c == -1)
>  			break;
> @@ -1158,6 +1166,7 @@ static void process_options (int argc, c
>  		case 'q': quiet = 1; break;
>  		case 'Q': priospread = 1; break;
>  		case 'r': timermode = TIMER_RELTIME; break;
> +		case 'R': check_clock_resolution = 1; break;
>  		case 's': use_system = MODE_SYS_OFFSET; break;
>  		case 'S':  /* SMP testing */
>  			if (numa)
> @@ -1202,6 +1211,7 @@ static void process_options (int argc, c
>  		case 'v': verbose = 1; break;
>  		case 'w': tracetype = WAKEUP; break;
>  		case 'W': tracetype = WAKEUPRT; break;
> +		case 'X': ct_debug = 1; break;
>  		case 'y': handlepolicy(optarg); break;
>  
>  		case '?': display_help(0); break;
> @@ -1483,6 +1493,103 @@ int main(int argc, char **argv)
>  	if (check_timer())
>  		warn("High resolution timers not available\n");
>  
> +	if (check_clock_resolution) {
> +		int clock;
> +		uint64_t diff;
> +		int k;
> +		uint64_t min_non_zero_diff = UINT64_MAX;
> +		struct timespec now;
> +		struct timespec prev;
> +		uint64_t reported_resolution = UINT64_MAX;
> +		struct timespec res;
> +		struct timespec *time;
> +		int times;
> +
> +		clock = clocksources[clocksel];
> +
> +		if (clock_getres(clock, &res)) {
> +			warn("clock_getres failed");
> +		} else {
> +			reported_resolution = (NSEC_PER_SEC * res.tv_sec) + res.tv_nsec;
> +		}
> +
> +
> +		/*
> +		 * Calculate how many calls to clock_gettime are needed.
> +		 * Then call it that many times.
> +		 * Goal is to collect timestamps for ~ 0.001 sec.
> +		 * This will reliably capture resolution <= 500 usec.
> +		 */
> +		times = 1000;
> +		clock_gettime(clock, &prev);
> +		for (k=0; k < times; k++) {
> +			clock_gettime(clock, &now);
> +		}
> +
> +		diff = calcdiff_ns(now, prev);
> +		if (diff == 0) {
> +			/*
> +			 * No clock rollover occurred.
> +			 * Use the default value for times.
> +			 */
> +			times = -1;
> +		} else {
> +			int call_time;
> +			call_time = diff / times;         /* duration 1 call */
> +			times = NSEC_PER_SEC / call_time; /* calls per second */
> +			times /= 1000;                    /* calls per msec */
> +			if (times < 1000)
> +				times = 1000;
> +		}
> +		/* sanity check */
> +		if ((times <= 0) || (times > 100000))
> +			times = 100000;
> +
> +		time = calloc(times, sizeof(*time));
> +
> +		for (k=0; k < times; k++) {
> +			clock_gettime(clock, &time[k]);
> +		}
> +
> +		if (ct_debug) {
> +			info("For %d consecutive calls to clock_gettime():\n", times);
> +			info("time, delta time (nsec)\n");
> +		}
> +
> +		prev = time[0];
> +		for (k=1; k < times; k++) {
> +
> +			diff = calcdiff_ns(time[k], prev);
> +			prev = time[k];
> +
> +			if (diff && (diff < min_non_zero_diff)) {
> +				min_non_zero_diff = diff;
> +			}
> +
> +			if (ct_debug)
> +				info("%ld.%06ld  %5llu\n",
> +				     time[k].tv_sec, time[k].tv_nsec,
> +				     (unsigned long long)diff);
> +		}
> +
> +		free(time);
> +
> +
> +		if (verbose ||
> +		    (min_non_zero_diff && (min_non_zero_diff > reported_resolution))) {
> +		    	/*
> +			 * Measured clock resolution includes the time to call
> +			 * clock_gettime(), so it will be slightly larger than
> +			 * actual resolution.
> +			 */
> +			warn("reported clock resolution: %llu nsec\n",
> +			     (unsigned long long)reported_resolution);
> +			warn("measured clock resolution approximately: %llu nsec\n",
> +			     (unsigned long long)min_non_zero_diff);
> +		}
> +
> +	}
> +
>  	mode = use_nanosleep + use_system;
>  
>  	sigemptyset(&sigset);
> 
> 
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html


[Index of Archives]     [RT Stable]     [Kernel Newbies]     [IDE]     [Security]     [Git]     [Netfilter]     [Bugtraq]     [Yosemite]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Linux ATA RAID]     [Samba]     [Video 4 Linux]     [Device Mapper]

  Powered by Linux