[PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Bhavesh Davda]

From: Bhavesh Davda <bhavesh@vmware.com>

Add a new command line option '-g' (long option '--of_max') to cap how many
outliers are tracked per thread. 

Signed-off-by: Bhavesh Davda <bhavesh@vmware.com>
---
Here's my attempt at addressing Frank's suggestions. Please correct me if I've misunderstood what you were suggesting.

checkpatch.pl reported:

total: 2 errors, 5 warnings, 76 lines checked

but the warnings and errors seem consistent with existing cyclictest practice.
---
 src/cyclictest/cyclictest.c |   24 +++++++++++++++++-------
 1 files changed, 17 insertions(+), 7 deletions(-)

diff --git a/src/cyclictest/cyclictest.c b/src/cyclictest/cyclictest.c
index 824544f..a728c14 100644
--- a/src/cyclictest/cyclictest.c
+++ b/src/cyclictest/cyclictest.c
@@ -171,6 +171,7 @@ static int lockall = 0;
 static int tracetype = NOTRACE;
 static int histogram = 0;
 static int histofall = 0;
+static int of_max = 0;
 static int duration = 0;
 static int use_nsecs = 0;
 static int refresh_on_max;
@@ -854,7 +855,7 @@ void *timerthread(void *param)
 		if (histogram) {
 			if (diff >= histogram) {
 				stat->hist_overflow++;
-                                if (stat->num_outliers < histogram)
+				if (stat->num_outliers < of_max)
 					stat->outliers[stat->num_outliers++] = stat->cycles;
 			}
 			else
@@ -930,6 +931,7 @@ static void display_help(int error)
 	       "                           to modify value to minutes, hours or days\n"
 	       "-E       --event           event tracing (used with -b)\n"
 	       "-f       --ftrace          function trace (when -b is active)\n"
+	       "-g MAX   --of_max=MAX      Report cycle instances (up to MAX) for histogram overflows\n"
 	       "-h       --histogram=US    dump a latency histogram to stdout after the run\n"
                "                           (with same priority about many threads)\n"
 	       "                           US is the max time to be be tracked in microseconds\n"
@@ -1059,6 +1061,8 @@ static void process_options (int argc, char *argv[])
 			{"distance", required_argument, NULL, 'd'},
 			{"event", no_argument, NULL, 'E'},
 			{"ftrace", no_argument, NULL, 'f'},
+			{"ftrace", no_argument, NULL, 'f'},
+			{"of_max", required_argument, NULL, 'g'},
 			{"histogram", required_argument, NULL, 'h'},
 			{"histofall", required_argument, NULL, 'H'},
 			{"interval", required_argument, NULL, 'i'},
@@ -1090,8 +1094,8 @@ static void process_options (int argc, char *argv[])
 			{"priospread", no_argument, NULL, 'Q'},
 			{NULL, 0, NULL, 0}
 		};
-		int c = getopt_long(argc, argv, "a::b:Bc:Cd:Efh:H:i:Il:MnNo:O:p:PmqQrsSt::uUvD:wWT:y:e:",
-				    long_options, &option_index);
+		int c = getopt_long(argc, argv, "a::b:Bc:Cd:Efg:h:H:i:Il:MnNo:O:p:PmqQrsS"
+				    "t::uUvD:wWT:y:e:", long_options, &option_index);
 		if (c == -1)
 			break;
 		switch (c) {
@@ -1116,6 +1120,7 @@ static void process_options (int argc, char *argv[])
 		case 'd': distance = atoi(optarg); break;
 		case 'E': enable_events = 1; break;
 		case 'f': tracetype = FUNCTION; ftrace = 1; break;
+		case 'g': of_max = atoi(optarg); break;
 		case 'H': histofall = 1; /* fall through */
 		case 'h': histogram = atoi(optarg); break;
 		case 'i': interval = atoi(optarg); break;
@@ -1563,13 +1568,18 @@ int main(int argc, char **argv)
 		/* allocate the histogram if requested */
 		if (histogram) {
 			int bufsize = histogram * sizeof(long);
-
 			stat->hist_array = threadalloc(bufsize, node);
-			stat->outliers = threadalloc(bufsize, node);
-			if (stat->hist_array == NULL || stat->outliers == NULL)
+			if (stat->hist_array == NULL)
 				fatal("failed to allocate histogram of size %d on node %d\n",
 				      histogram, i);
 			memset(stat->hist_array, 0, bufsize);
+		}
+		if (of_max) {
+			int bufsize = of_max * sizeof(long);
+			stat->outliers = threadalloc(bufsize, node);
+			if (stat->outliers == NULL)
+				fatal("failed to allocate outliers of size %d on node %d\n",
+				      histogram, i);
 			memset(stat->outliers, 0, bufsize);
 		}
 
@@ -1688,7 +1698,7 @@ int main(int argc, char **argv)
 		print_hist(parameters, num_threads);
 		for (i = 0; i < num_threads; i++) {
 			threadfree(statistics[i]->hist_array, histogram*sizeof(long), parameters[i]->node);
-			threadfree(statistics[i]->outliers, histogram*sizeof(long), parameters[i]->node);
+			threadfree(statistics[i]->outliers, of_max*sizeof(long), parameters[i]->node);
 		}
 	}
 
-- 
1.7.1

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Frank Rowand]

On 11/14/12 14:18, Bhavesh Davda wrote:
> From: Bhavesh Davda <bhavesh@vmware.com>
> 
> Add a new command line option '-g' (long option '--of_max') to cap how many
> outliers are tracked per thread. 
> 
> Signed-off-by: Bhavesh Davda <bhavesh@vmware.com>
> ---
> Here's my attempt at addressing Frank's suggestions. Please correct me if I've misunderstood what you were suggesting.

It addresses the issues related to the size of stat->outliers.  But does
not address my other suggestions.

If you want to ignore my other suggestions, that is ok.

More comments inline below.

> 
> checkpatch.pl reported:
> 
> total: 2 errors, 5 warnings, 76 lines checked
> 
> but the warnings and errors seem consistent with existing cyclictest practice.

Patch is not against the current git repository, so fails:

patching file src/cyclictest/cyclictest.c
Hunk #2 succeeded at 888 (offset 33 lines).
Hunk #3 succeeded at 965 with fuzz 2 (offset 34 lines).
Hunk #4 FAILED at 1061.
Hunk #5 FAILED at 1092.
Hunk #6 succeeded at 1168 with fuzz 1 (offset 50 lines).
Hunk #7 succeeded at 1707 (offset 141 lines).
Hunk #8 succeeded at 1837 (offset 141 lines).

> ---
>  src/cyclictest/cyclictest.c |   24 +++++++++++++++++-------
>  1 files changed, 17 insertions(+), 7 deletions(-)
> 
> diff --git a/src/cyclictest/cyclictest.c b/src/cyclictest/cyclictest.c
> index 824544f..a728c14 100644
> --- a/src/cyclictest/cyclictest.c
> +++ b/src/cyclictest/cyclictest.c
> @@ -171,6 +171,7 @@ static int lockall = 0;
>  static int tracetype = NOTRACE;
>  static int histogram = 0;
>  static int histofall = 0;
> +static int of_max = 0;
>  static int duration = 0;
>  static int use_nsecs = 0;
>  static int refresh_on_max;
> @@ -854,7 +855,7 @@ void *timerthread(void *param)
>  		if (histogram) {
>  			if (diff >= histogram) {
>  				stat->hist_overflow++;
> -                                if (stat->num_outliers < histogram)
> +				if (stat->num_outliers < of_max)
>  					stat->outliers[stat->num_outliers++] = stat->cycles;
>  			}
>  			else
> @@ -930,6 +931,7 @@ static void display_help(int error)
>  	       "                           to modify value to minutes, hours or days\n"
>  	       "-E       --event           event tracing (used with -b)\n"
>  	       "-f       --ftrace          function trace (when -b is active)\n"
> +	       "-g MAX   --of_max=MAX      Report cycle instances (up to MAX) for histogram overflows\n"
>  	       "-h       --histogram=US    dump a latency histogram to stdout after the run\n"
>                 "                           (with same priority about many threads)\n"
>  	       "                           US is the max time to be be tracked in microseconds\n"
> @@ -1059,6 +1061,8 @@ static void process_options (int argc, char *argv[])
>  			{"distance", required_argument, NULL, 'd'},
>  			{"event", no_argument, NULL, 'E'},
>  			{"ftrace", no_argument, NULL, 'f'},
> +			{"ftrace", no_argument, NULL, 'f'},

ftrace already exists in previous line.

> +			{"of_max", required_argument, NULL, 'g'},
>  			{"histogram", required_argument, NULL, 'h'},
>  			{"histofall", required_argument, NULL, 'H'},
>  			{"interval", required_argument, NULL, 'i'},
> @@ -1090,8 +1094,8 @@ static void process_options (int argc, char *argv[])
>  			{"priospread", no_argument, NULL, 'Q'},
>  			{NULL, 0, NULL, 0}
>  		};
> -		int c = getopt_long(argc, argv, "a::b:Bc:Cd:Efh:H:i:Il:MnNo:O:p:PmqQrsSt::uUvD:wWT:y:e:",
> -				    long_options, &option_index);
> +		int c = getopt_long(argc, argv, "a::b:Bc:Cd:Efg:h:H:i:Il:MnNo:O:p:PmqQrsS"
> +				    "t::uUvD:wWT:y:e:", long_options, &option_index);

nit: I don't see the point of splitting the constant string.  The line is over long both before
and after the change.  If adding one character makes the string too long, I would suggest
moving it to a new line, indented to match "long_options, &option_index);".

>  		if (c == -1)
>  			break;
>  		switch (c) {
> @@ -1116,6 +1120,7 @@ static void process_options (int argc, char *argv[])
>  		case 'd': distance = atoi(optarg); break;
>  		case 'E': enable_events = 1; break;
>  		case 'f': tracetype = FUNCTION; ftrace = 1; break;
> +		case 'g': of_max = atoi(optarg); break;
>  		case 'H': histofall = 1; /* fall through */
>  		case 'h': histogram = atoi(optarg); break;
>  		case 'i': interval = atoi(optarg); break;

Should ensure that of_max is not negative.


> @@ -1563,13 +1568,18 @@ int main(int argc, char **argv)
>  		/* allocate the histogram if requested */
>  		if (histogram) {
>  			int bufsize = histogram * sizeof(long);
> -
>  			stat->hist_array = threadalloc(bufsize, node);
> -			stat->outliers = threadalloc(bufsize, node);
> -			if (stat->hist_array == NULL || stat->outliers == NULL)
> +			if (stat->hist_array == NULL)
>  				fatal("failed to allocate histogram of size %d on node %d\n",
>  				      histogram, i);
>  			memset(stat->hist_array, 0, bufsize);
> +		}
> +		if (of_max) {
> +			int bufsize = of_max * sizeof(long);
> +			stat->outliers = threadalloc(bufsize, node);
> +			if (stat->outliers == NULL)
> +				fatal("failed to allocate outliers of size %d on node %d\n",
> +				      histogram, i);
>  			memset(stat->outliers, 0, bufsize);
>  		}
>  
> @@ -1688,7 +1698,7 @@ int main(int argc, char **argv)
>  		print_hist(parameters, num_threads);
>  		for (i = 0; i < num_threads; i++) {
>  			threadfree(statistics[i]->hist_array, histogram*sizeof(long), parameters[i]->node);
> -			threadfree(statistics[i]->outliers, histogram*sizeof(long), parameters[i]->node);
> +			threadfree(statistics[i]->outliers, of_max*sizeof(long), parameters[i]->node);
>  		}
>  	}
>  

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Bhavesh Davda]

Add a new command line option '-g' (long option '--of_max') to cap how many
outliers are tracked per thread.

$ sudo ./cyclictest -p 99 -m -n -a -h 5 -g 50 -t4 -D 30

policy: fifo: loadavg: 0.04 0.05 0.01 1/422 13994

T: 0 (13938) P:99 I:1000 C:  29996 Min:      2 Act:    3 Avg:    2 Max:      75
T: 1 (13939) P:99 I:1000 C:  29994 Min:      2 Act:    5 Avg:    3 Max:      12
T: 2 (13940) P:99 I:1000 C:  29991 Min:      2 Act:    4 Avg:    3 Max:       8
T: 3 (13941) P:99 I:1000 C:  29989 Min:      2 Act:    4 Avg:    3 Max:       8
  Histogram
000000 000000   000000  000000  000000
000001 000000   000000  000000  000000
000002 010425   000019  000012  000029
000003 017252   005100  008867  018353
000004 002277   021146  021048  011549
  Total: 000029954 000026265 000029927 000029931
  Min Latencies: 00002 00002 00002 00002
  Avg Latencies: 00002 00003 00003 00003
  Max Latencies: 00075 00012 00008 00008
  Histogram Overflows: 00046 03733 00069 00063
  Histogram Overflow at cycle number:
  Thread 0: 00475 00476 01311 01818 03183 03311 05569 08003 08741 08743 08745 08760 08761 09311 13922 14890 15476 15562 15563 17243 17250 17253 17254 17255 17256 17257 17258 17259 17270 17271 17272 18026 18752 19115 19700 20668 21031 21311 21813 22311 24782 26234 26960 28291 29259 29622
  Thread 1: 00000 00001 00002 00003 00004 00014 00024 00034 00035 00044 00045 00054 00055 00064 00065 00074 00075 00084 00085 00095 00105 00115 00125 00135 00145 00146 00149 00155 00156 00165 00166 00175 00176 00185 00186 00188 00195 00196 00206 00216 00226 00233 00236 00246 00256 00257 00266 00267 00276 00277 # 03683 others
  Thread 2: 00000 00001 00002 00228 00471 01301 02471 02472 02912 03301 03472 05301 05307 05314 05565 06472 07301 07472 08472 08711 08737 08738 08740 08757 09301 10228 11301 13301 14472 15301 15472 15566 17241 17247 17249 17250 17251 17252 17253 17254 17255 17256 17257 17262 17266 17267 17268 17301 17472 18472 # 00019 others
  Thread 3: 00000 00469 01296 02469 02470 03296 05296 05562 06554 06555 07296 07308 08736 08737 08738 08739 08740 08741 08742 08743 08744 08745 08746 08747 08748 08749 08750 08751 08752 08753 08754 09296 09308 11296 13296 14470 15296 15308 15470 15564 16554 16555 17245 17246 17248 17249 17253 17254 17265 17296 # 00013 others

Signed-off-by: Bhavesh Davda <bhavesh@vmware.com>

---
> > Here's my attempt at addressing Frank's suggestions. Please correct
> > me if I've misunderstood what you were suggesting.
> 
> It addresses the issues related to the size of stat->outliers.  But
> does
> not address my other suggestions.
> 
> If you want to ignore my other suggestions, that is ok.

I would like to address all your suggestions. Which ones did I miss?

> More comments inline below.
> 
> 
> Patch is not against the current git repository, so fails:
> 
> patching file src/cyclictest/cyclictest.c
> Hunk #2 succeeded at 888 (offset 33 lines).
> Hunk #3 succeeded at 965 with fuzz 2 (offset 34 lines).
> Hunk #4 FAILED at 1061.
> Hunk #5 FAILED at 1092.
> Hunk #6 succeeded at 1168 with fuzz 1 (offset 50 lines).
> Hunk #7 succeeded at 1707 (offset 141 lines).
> Hunk #8 succeeded at 1837 (offset 141 lines).

Yikes! After all these years, I'm still a n00b when it comes to git things. Really sorry about that! It took me a couple of hours just to get my git tree back in shape, after messing it up in strange ways.

> >  			{"ftrace", no_argument, NULL, 'f'},
> > +			{"ftrace", no_argument, NULL, 'f'},
> 
> ftrace already exists in previous line.
> 

Fixed. Sorry.

> > +		int c = getopt_long(argc, argv,
> > "a::b:Bc:Cd:Efg:h:H:i:Il:MnNo:O:p:PmqQrsS"
> > +				    "t::uUvD:wWT:y:e:", long_options, &option_index);
> 
> nit: I don't see the point of splitting the constant string.  The
> line is over long both before
> and after the change.  If adding one character makes the string too
> long, I would suggest
> moving it to a new line, indented to match "long_options,
> &option_index);".

Like you said, the string was too long to being with, so I left it as is, with my addition.

> Should ensure that of_max is not negative.

Done.

---
 src/cyclictest/cyclictest.c |   27 ++++++++++++++++++++++-----
 1 files changed, 22 insertions(+), 5 deletions(-)

diff --git a/src/cyclictest/cyclictest.c b/src/cyclictest/cyclictest.c
index abf3e8b..bfd1324 100644
--- a/src/cyclictest/cyclictest.c
+++ b/src/cyclictest/cyclictest.c
@@ -91,6 +91,7 @@ extern int clock_nanosleep(clockid_t __clock_id, int __flags,
 #define NSEC_PER_SEC           1000000000

 #define HIST_MAX               1000000
+#define OF_MAX                  1000000

 #define MODE_CYCLIC            0
 #define MODE_CLOCK_NANOSLEEP   1
@@ -171,6 +172,7 @@ static int lockall = 0;
 static int tracetype = NOTRACE;
 static int histogram = 0;
 static int histofall = 0;
+static int of_max = 0;
 static int duration = 0;
 static int use_nsecs = 0;
 static int refresh_on_max;
@@ -887,7 +889,7 @@ void *timerthread(void *param)
                if (histogram) {
                        if (diff >= histogram) {
                                stat->hist_overflow++;
-                                if (stat->num_outliers < histogram)
+                                if (stat->num_outliers < of_max)
                                        stat->outliers[stat->num_outliers++] = stat->cycles;
                        }
                        else
@@ -964,6 +966,7 @@ static void display_help(int error)
               "-e       --latency=PM_QOS  write PM_QOS to /dev/cpu_dma_latency\n"
               "-E       --event           event tracing (used with -b)\n"
               "-f       --ftrace          function trace (when -b is active)\n"
+              "-g MAX   --of_max=MAX      Report cycle instances (up to MAX) for histogram overflows\n"
               "-h       --histogram=US    dump a latency histogram to stdout after the run\n"
               "                           (with same priority about many threads)\n"
               "                           US is the max time to be be tracked in microseconds\n"
@@ -1102,6 +1105,7 @@ static void process_options (int argc, char *argv[])
                        {"latency",          required_argument, NULL, 'e'},
                        {"event",            no_argument,       NULL, 'E'},
                        {"ftrace",           no_argument,       NULL, 'f'},
+                       {"of_max",           required_argument, NULL, 'g'},
                        {"histogram",        required_argument, NULL, 'h'},
                        {"histofall",        required_argument, NULL, 'H'},
                        {"interval",         required_argument, NULL, 'i'},
@@ -1133,7 +1137,7 @@ static void process_options (int argc, char *argv[])
                        {"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:PmqQrRsSt::uUvD:wWXT:y:",
+               int c = getopt_long(argc, argv, "a::b:Bc:Cd:D:e:Efg:h:H:i:Il:MnNo:O:p:PmqQrRsSt::uUvD:wWXT:y:",
                                    long_options, &option_index);
                if (c == -1)
                        break;
@@ -1166,6 +1170,7 @@ static void process_options (int argc, char *argv[])
                        break;
                case 'E': enable_events = 1; break;
                case 'f': tracetype = FUNCTION; ftrace = 1; break;
+               case 'g': of_max = atoi(optarg); break;
                case 'H': histofall = 1; /* fall through */
                case 'h': histogram = atoi(optarg); break;
                case 'i': interval = atoi(optarg); break;
@@ -1290,6 +1295,12 @@ static void process_options (int argc, char *argv[])
        if (histogram > HIST_MAX)
                histogram = HIST_MAX;

+       if (of_max < 0)
+               error = 1;
+
+       if (of_max > OF_MAX)
+               of_max = OF_MAX;
+
        if (histogram && distance != -1)
                warn("distance is ignored and set to 0, if histogram enabled\n");
        if (distance == -1)
@@ -1706,11 +1717,17 @@ int main(int argc, char **argv)
                        int bufsize = histogram * sizeof(long);

                        stat->hist_array = threadalloc(bufsize, node);
-                       stat->outliers = threadalloc(bufsize, node);
-                       if (stat->hist_array == NULL || stat->outliers == NULL)
+                       if (stat->hist_array == NULL)
                                fatal("failed to allocate histogram of size %d on node %d\n",
                                      histogram, i);
                        memset(stat->hist_array, 0, bufsize);
+               }
+               if (of_max) {
+                       int bufsize = of_max * sizeof(long);
+                       stat->outliers = threadalloc(bufsize, node);
+                       if (stat->outliers == NULL)
+                               fatal("failed to allocate outliers of size %d on node %d\n",
+                                     histogram, i);
                        memset(stat->outliers, 0, bufsize);
                }

@@ -1829,7 +1846,7 @@ int main(int argc, char **argv)
                print_hist(parameters, num_threads);
                for (i = 0; i < num_threads; i++) {
                        threadfree(statistics[i]->hist_array, histogram*sizeof(long), parameters[i]->node);
-                       threadfree(statistics[i]->outliers, histogram*sizeof(long), parameters[i]->node);
+                       threadfree(statistics[i]->outliers, of_max*sizeof(long), parameters[i]->node);
                }
        }

--
1.7.1

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Frank Rowand]

On 11/14/12 18:17, Bhavesh Davda wrote:
> Add a new command line option '-g' (long option '--of_max') to cap how many
> outliers are tracked per thread.
> 
> $ sudo ./cyclictest -p 99 -m -n -a -h 5 -g 50 -t4 -D 30
> 
> policy: fifo: loadavg: 0.04 0.05 0.01 1/422 13994
> 
> T: 0 (13938) P:99 I:1000 C:  29996 Min:      2 Act:    3 Avg:    2 Max:      75
> T: 1 (13939) P:99 I:1000 C:  29994 Min:      2 Act:    5 Avg:    3 Max:      12
> T: 2 (13940) P:99 I:1000 C:  29991 Min:      2 Act:    4 Avg:    3 Max:       8
> T: 3 (13941) P:99 I:1000 C:  29989 Min:      2 Act:    4 Avg:    3 Max:       8
>   Histogram
> 000000 000000   000000  000000  000000
> 000001 000000   000000  000000  000000
> 000002 010425   000019  000012  000029
> 000003 017252   005100  008867  018353
> 000004 002277   021146  021048  011549
>   Total: 000029954 000026265 000029927 000029931
>   Min Latencies: 00002 00002 00002 00002
>   Avg Latencies: 00002 00003 00003 00003
>   Max Latencies: 00075 00012 00008 00008
>   Histogram Overflows: 00046 03733 00069 00063
>   Histogram Overflow at cycle number:
>   Thread 0: 00475 00476 01311 01818 03183 03311 05569 08003 08741 08743 08745 08760 08761 09311 13922 14890 15476 15562 15563 17243 17250 17253 17254 17255 17256 17257 17258 17259 17270 17271 17272 18026 18752 19115 19700 20668 21031 21311 21813 22311 24782 26234 26960 28291 29259 29622
>   Thread 1: 00000 00001 00002 00003 00004 00014 00024 00034 00035 00044 00045 00054 00055 00064 00065 00074 00075 00084 00085 00095 00105 00115 00125 00135 00145 00146 00149 00155 00156 00165 00166 00175 00176 00185 00186 00188 00195 00196 00206 00216 00226 00233 00236 00246 00256 00257 00266 00267 00276 00277 # 03683 others
>   Thread 2: 00000 00001 00002 00228 00471 01301 02471 02472 02912 03301 03472 05301 05307 05314 05565 06472 07301 07472 08472 08711 08737 08738 08740 08757 09301 10228 11301 13301 14472 15301 15472 15566 17241 17247 17249 17250 17251 17252 17253 17254 17255 17256 17257 17262 17266 17267 17268 17301 17472 18472 # 00019 others
>   Thread 3: 00000 00469 01296 02469 02470 03296 05296 05562 06554 06555 07296 07308 08736 08737 08738 08739 08740 08741 08742 08743 08744 08745 08746 08747 08748 08749 08750 08751 08752 08753 08754 09296 09308 11296 13296 14470 15296 15308 15470 15564 16554 16555 17245 17246 17248 17249 17253 17254 17265 17296 # 00013 others
> 
> Signed-off-by: Bhavesh Davda <bhavesh@vmware.com>
> 
> ---
>>> Here's my attempt at addressing Frank's suggestions. Please correct
>>> me if I've misunderstood what you were suggesting.
>>
>> It addresses the issues related to the size of stat->outliers.  But
>> does
>> not address my other suggestions.
>>
>> If you want to ignore my other suggestions, that is ok.
> 
> I would like to address all your suggestions. Which ones did I miss?

| Add a line to the histogram overflow cycle report that merges all
| threads into a single time line.  This is controlled by the -H
| option which already serves a similar purpose for histograms.

The merged data line is an enhancement.  If there is no strong request
from anyone for the feature then no need to include.  But it seems
useful to me.


| Removed leading zeros from cycle values reported in the histogram
| overflow cycle report to make the values more readable.

I should have also mentioned that many programs interpret numbers
with leading zeros as octal.

(Note that the existing histogram code uses the same printf()
format creating data with leading zeros.  I should submit a
separate patch, independent of the overflow instance tracking,
to fix that.)


| Removed extra blank line printed at end of Histogram output.

Some graphing programs are sensitive to extraneous blank lines,
so I try to avoid adding additional blank lines.


| One further thought...  The histogram overflow cycle report shows
| what cycle the overflow occurred in, not the actual time.  Adding
| the merged for all threads cycle times works because the histogram
| turns off the "different intervals for different threads" option:
| 
|                 if (!histogram) /* same interval on CPUs */
|                         interval += distance;
| 
| but if that ever changes then cycle is not a useful value to be
| reporting.
| 
| So it seems like it would be useful to convert cycle to a time
| in the report.  This is something that would have to be done
| anyway in post processing when trying to make use of the report.

This was probably the most important comment.


>> More comments inline below.

< snip >

This version of the patch addressed all of my inline comments.

But this version of the patch seems to have tabs converted to spaces, so
it doesn't apply.  My email servers sometimes alter white space in patches
so I double checked the patch on a list server at:

   http://marc.info/?l=linux-rt-users&m=135294583618844&q=raw

If the problem really is just at my end then don't worry about it
(what matters most is that John gets a clean version).

When force applied, the patch compiles and generates output
as expected.

-Frank

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Bhavesh Davda]

From: Bhavesh Davda <bhavesh@vmware.com>

Add a new command line option '-g' (long option '--of_max') to cap how many
outliers are tracked per thread.

$ sudo ./cyclictest -p 99 -m -n -a -h 5 -g 50 -t4 -D 30
  /dev/cpu_dma_latency set to 0us
policy: fifo: loadavg: 0.14 0.15 0.09 1/396 11018

T: 0 (10978) P:99 I:1000 C:  29997 Min:      2 Act:    4 Avg:    3 Max:       7
T: 1 (10979) P:99 I:1000 C:  29995 Min:      2 Act:    4 Avg:    3 Max:      54
T: 2 (10980) P:99 I:1000 C:  29993 Min:      2 Act:    3 Avg:    3 Max:      10
T: 3 (10981) P:99 I:1000 C:  29991 Min:      2 Act:    3 Avg:    3 Max:       8
  Histogram
000000 000000	000000	000000	000000
000001 000000	000000	000000	000000
000002 000050	000031	000009	000037
000003 015205	016327	014673	018062
000004 014619	010466	012414	011863
  Total: 000029874 000026824 000027096 000029962
  Min Latencies: 00002 00002 00002 00002
  Avg Latencies: 00003 00003 00003 00003
  Max Latencies: 00007 00054 00010 00008
  Histogram Overflows: 00126 03174 02900 00032
  Histogram Overflow at time (ms):
  Thread 0: 1152 1653 3027 3152 3650 5152 5653 7027 7037 7047 7058 7068 7078 7088 7098 7108 7118 7128 7138 7148 7152 7158 7169 7179 7189 7199 7209 7219 7229 7239 7249 7259 7269 7279 7290 7300 7310 7320 7330 7340 7350 7360 7370 7380 7390 7401 7403 7404 7411 7412 # 76 others
  Thread 1: 0 1 2 4 14 24 34 45 55 56 65 75 85 95 105 115 125 126 135 145 153 155 166 176 186 196 206 216 226 236 246 256 266 277 287 297 307 317 327 337 347 357 367 377 388 398 408 418 428 438 # 3124 others
  Thread 2: 0 1 2 12 22 32 42 52 62 72 82 92 102 113 123 133 143 153 173 183 193 203 224 234 244 254 264 284 294 304 314 324 334 345 355 365 375 395 405 415 425 435 445 456 466 476 486 496 516 526 # 2850 others
  Thread 3: 0 1137 1149 3137 5137 7137 7405 8395 8396 8397 9137 11137 12643 12644 13137 15137 17137 17406 18395 18396 19137 21137 21227 21228 21229 23137 25137 27137 27406 28395 28396 29137

Signed-off-by: Bhavesh Davda <bhavesh@vmware.com>

---

> | Add a line to the histogram overflow cycle report that merges all
> | threads into a single time line.  This is controlled by the -H
> | option which already serves a similar purpose for histograms.
> 
> The merged data line is an enhancement.  If there is no strong
> request
> from anyone for the feature then no need to include.  But it seems
> useful to me.

I agree this is a useful feature request, but harder to implement, since I'll have to merge sort from the per-thread outliers to produce a single line merged outlier output. I hope it's okay if I punt on this one.

> | Removed leading zeros from cycle values reported in the histogram
> | overflow cycle report to make the values more readable.
> 
> I should have also mentioned that many programs interpret numbers
> with leading zeros as octal.

Fixed.

> | Removed extra blank line printed at end of Histogram output.
> 
> Some graphing programs are sensitive to extraneous blank lines,
> so I try to avoid adding additional blank lines.
> 

Fixed.

> | One further thought...  The histogram overflow cycle report shows
> | what cycle the overflow occurred in, not the actual time.  Adding
> | the merged for all threads cycle times works because the histogram
> | turns off the "different intervals for different threads" option:
> | 
> |                 if (!histogram) /* same interval on CPUs */
> |                         interval += distance;
> | 
> | but if that ever changes then cycle is not a useful value to be
> | reporting.
> | 
> | So it seems like it would be useful to convert cycle to a time
> | in the report.  This is something that would have to be done
> | anyway in post processing when trying to make use of the report.
> 
> This was probably the most important comment.

Gotcha. I've attempted to change the outliers reported from the cycle count they occurred at to the time (in ms) that they occurred at. Please take a look.

> This version of the patch addressed all of my inline comments.
> 
> But this version of the patch seems to have tabs converted to spaces,
> so
> it doesn't apply.  My email servers sometimes alter white space in
> patches
> so I double checked the patch on a list server at:

It's not you, it's me :) I had used a different mailer and a different method to copy-paste the patch inline, which munged the tabs to spaces. Sorry about that. Hopefully it's back to tabs in this version.

---
 src/cyclictest/cyclictest.c |   34 +++++++++++++++++++++++++---------
 1 files changed, 25 insertions(+), 9 deletions(-)

diff --git a/src/cyclictest/cyclictest.c b/src/cyclictest/cyclictest.c
index abf3e8b..0701ef9 100644
--- a/src/cyclictest/cyclictest.c
+++ b/src/cyclictest/cyclictest.c
@@ -91,6 +91,7 @@ extern int clock_nanosleep(clockid_t __clock_id, int __flags,
 #define NSEC_PER_SEC		1000000000
 
 #define HIST_MAX		1000000
+#define OF_MAX                  1000000
 
 #define MODE_CYCLIC		0
 #define MODE_CLOCK_NANOSLEEP	1
@@ -171,6 +172,7 @@ static int lockall = 0;
 static int tracetype = NOTRACE;
 static int histogram = 0;
 static int histofall = 0;
+static int of_max = 0;
 static int duration = 0;
 static int use_nsecs = 0;
 static int refresh_on_max;
@@ -887,7 +889,7 @@ void *timerthread(void *param)
 		if (histogram) {
 			if (diff >= histogram) {
 				stat->hist_overflow++;
-                                if (stat->num_outliers < histogram)
+                                if (stat->num_outliers < of_max)
 					stat->outliers[stat->num_outliers++] = stat->cycles;
 			}
 			else
@@ -964,6 +966,7 @@ static void display_help(int error)
 	       "-e       --latency=PM_QOS  write PM_QOS to /dev/cpu_dma_latency\n"
 	       "-E       --event           event tracing (used with -b)\n"
 	       "-f       --ftrace          function trace (when -b is active)\n"
+	       "-g MAX   --of_max=MAX      Report time in ms (up to MAX) for histogram overflows\n"
 	       "-h       --histogram=US    dump a latency histogram to stdout after the run\n"
 	       "                           (with same priority about many threads)\n"
 	       "                           US is the max time to be be tracked in microseconds\n"
@@ -1102,6 +1105,7 @@ static void process_options (int argc, char *argv[])
 			{"latency",          required_argument, NULL, 'e'},
 			{"event",            no_argument,       NULL, 'E'},
 			{"ftrace",           no_argument,       NULL, 'f'},
+			{"of_max",           required_argument, NULL, 'g'},
 			{"histogram",        required_argument, NULL, 'h'},
 			{"histofall",        required_argument, NULL, 'H'},
 			{"interval",         required_argument, NULL, 'i'},
@@ -1133,7 +1137,7 @@ static void process_options (int argc, char *argv[])
 			{"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:PmqQrRsSt::uUvD:wWXT:y:",
+		int c = getopt_long(argc, argv, "a::b:Bc:Cd:D:e:Efg:h:H:i:Il:MnNo:O:p:PmqQrRsSt::uUvD:wWXT:y:",
 				    long_options, &option_index);
 		if (c == -1)
 			break;
@@ -1166,6 +1170,7 @@ static void process_options (int argc, char *argv[])
 			break;
 		case 'E': enable_events = 1; break;
 		case 'f': tracetype = FUNCTION; ftrace = 1; break;
+		case 'g': of_max = atoi(optarg); break;
 		case 'H': histofall = 1; /* fall through */
 		case 'h': histogram = atoi(optarg); break;
 		case 'i': interval = atoi(optarg); break;
@@ -1290,6 +1295,12 @@ static void process_options (int argc, char *argv[])
 	if (histogram > HIST_MAX)
 		histogram = HIST_MAX;
 
+	if (of_max < 0)
+		error = 1;
+
+	if (of_max > OF_MAX)
+		of_max = OF_MAX;
+
 	if (histogram && distance != -1)
 		warn("distance is ignored and set to 0, if histogram enabled\n");
 	if (distance == -1)
@@ -1451,16 +1462,15 @@ static void print_hist(struct thread_param *par[], int nthreads)
 		printf(" %05lu", alloverflows);
 	printf("\n");
 
-	printf("# Histogram Overflow at cycle number:\n");
+	printf("# Histogram Overflow at time (ms):\n");
 	for (i = 0; i < nthreads; i++) {
 		printf("# Thread %d:", i);
 		for (j = 0; j < par[i]->stats->num_outliers; j++)
-			printf(" %05lu", par[i]->stats->outliers[j]);
+			printf(" %lu", par[i]->stats->outliers[j] * par[i]->interval / 1000);
 		if (par[i]->stats->num_outliers < par[i]->stats->hist_overflow)
-			printf(" # %05lu others", par[i]->stats->hist_overflow - par[i]->stats->num_outliers);
+			printf(" # %lu others", par[i]->stats->hist_overflow - par[i]->stats->num_outliers);
 		printf("\n");
 	}
-	printf("\n");
 }
 
 static void print_stat(struct thread_param *par, int index, int verbose)
@@ -1706,11 +1716,17 @@ int main(int argc, char **argv)
 			int bufsize = histogram * sizeof(long);
 
 			stat->hist_array = threadalloc(bufsize, node);
-			stat->outliers = threadalloc(bufsize, node);
-			if (stat->hist_array == NULL || stat->outliers == NULL)
+			if (stat->hist_array == NULL)
 				fatal("failed to allocate histogram of size %d on node %d\n",
 				      histogram, i);
 			memset(stat->hist_array, 0, bufsize);
+		}
+		if (of_max) {
+			int bufsize = of_max * sizeof(long);
+			stat->outliers = threadalloc(bufsize, node);
+			if (stat->outliers == NULL)
+				fatal("failed to allocate outliers of size %d on node %d\n",
+				      histogram, i);
 			memset(stat->outliers, 0, bufsize);
 		}
 
@@ -1829,7 +1845,7 @@ int main(int argc, char **argv)
 		print_hist(parameters, num_threads);
 		for (i = 0; i < num_threads; i++) {
 			threadfree(statistics[i]->hist_array, histogram*sizeof(long), parameters[i]->node);
-			threadfree(statistics[i]->outliers, histogram*sizeof(long), parameters[i]->node);
+			threadfree(statistics[i]->outliers, of_max*sizeof(long), parameters[i]->node);
 		}
 	}
 
-- 
1.7.1

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Bhavesh Davda]

From: Bhavesh Davda <bhavesh@vmware.com>

Add a new command line option '-g' (long option '--of_max') to cap how many
outliers are tracked per thread.

$ sudo ./cyclictest -p 99 -m -n -a -h 5 -g 50 -t4 -D 30
  /dev/cpu_dma_latency set to 0us
policy: fifo: loadavg: 0.14 0.15 0.09 1/396 11018

T: 0 (10978) P:99 I:1000 C:  29997 Min:      2 Act:    4 Avg:    3 Max:       7
T: 1 (10979) P:99 I:1000 C:  29995 Min:      2 Act:    4 Avg:    3 Max:      54
T: 2 (10980) P:99 I:1000 C:  29993 Min:      2 Act:    3 Avg:    3 Max:      10
T: 3 (10981) P:99 I:1000 C:  29991 Min:      2 Act:    3 Avg:    3 Max:       8
  Histogram
000000 000000	000000	000000	000000
000001 000000	000000	000000	000000
000002 000050	000031	000009	000037
000003 015205	016327	014673	018062
000004 014619	010466	012414	011863
  Total: 000029874 000026824 000027096 000029962
  Min Latencies: 00002 00002 00002 00002
  Avg Latencies: 00003 00003 00003 00003
  Max Latencies: 00007 00054 00010 00008
  Histogram Overflows: 00126 03174 02900 00032
  Histogram Overflow at time (ms):
  Thread 0: 1152 1653 3027 3152 3650 5152 5653 7027 7037 7047 7058 7068 7078 7088 7098 7108 7118 7128 7138 7148 7152 7158 7169 7179 7189 7199 7209 7219 7229 7239 7249 7259 7269 7279 7290 7300 7310 7320 7330 7340 7350 7360 7370 7380 7390 7401 7403 7404 7411 7412 # 76 others
  Thread 1: 0 1 2 4 14 24 34 45 55 56 65 75 85 95 105 115 125 126 135 145 153 155 166 176 186 196 206 216 226 236 246 256 266 277 287 297 307 317 327 337 347 357 367 377 388 398 408 418 428 438 # 3124 others
  Thread 2: 0 1 2 12 22 32 42 52 62 72 82 92 102 113 123 133 143 153 173 183 193 203 224 234 244 254 264 284 294 304 314 324 334 345 355 365 375 395 405 415 425 435 445 456 466 476 486 496 516 526 # 2850 others
  Thread 3: 0 1137 1149 3137 5137 7137 7405 8395 8396 8397 9137 11137 12643 12644 13137 15137 17137 17406 18395 18396 19137 21137 21227 21228 21229 23137 25137 27137 27406 28395 28396 29137

Signed-off-by: Bhavesh Davda <bhavesh@vmware.com>
---
Argh! Missed one tabs v/s spaces issue from a previous commit as found by checkpatch!
---
 src/cyclictest/cyclictest.c |   34 +++++++++++++++++++++++++---------
 1 files changed, 25 insertions(+), 9 deletions(-)

diff --git a/src/cyclictest/cyclictest.c b/src/cyclictest/cyclictest.c
index abf3e8b..141e79f 100644
--- a/src/cyclictest/cyclictest.c
+++ b/src/cyclictest/cyclictest.c
@@ -91,6 +91,7 @@ extern int clock_nanosleep(clockid_t __clock_id, int __flags,
 #define NSEC_PER_SEC		1000000000
 
 #define HIST_MAX		1000000
+#define OF_MAX                  1000000
 
 #define MODE_CYCLIC		0
 #define MODE_CLOCK_NANOSLEEP	1
@@ -171,6 +172,7 @@ static int lockall = 0;
 static int tracetype = NOTRACE;
 static int histogram = 0;
 static int histofall = 0;
+static int of_max = 0;
 static int duration = 0;
 static int use_nsecs = 0;
 static int refresh_on_max;
@@ -887,7 +889,7 @@ void *timerthread(void *param)
 		if (histogram) {
 			if (diff >= histogram) {
 				stat->hist_overflow++;
-                                if (stat->num_outliers < histogram)
+				if (stat->num_outliers < of_max)
 					stat->outliers[stat->num_outliers++] = stat->cycles;
 			}
 			else
@@ -964,6 +966,7 @@ static void display_help(int error)
 	       "-e       --latency=PM_QOS  write PM_QOS to /dev/cpu_dma_latency\n"
 	       "-E       --event           event tracing (used with -b)\n"
 	       "-f       --ftrace          function trace (when -b is active)\n"
+	       "-g MAX   --of_max=MAX      Report time in ms (up to MAX) for histogram overflows\n"
 	       "-h       --histogram=US    dump a latency histogram to stdout after the run\n"
 	       "                           (with same priority about many threads)\n"
 	       "                           US is the max time to be be tracked in microseconds\n"
@@ -1102,6 +1105,7 @@ static void process_options (int argc, char *argv[])
 			{"latency",          required_argument, NULL, 'e'},
 			{"event",            no_argument,       NULL, 'E'},
 			{"ftrace",           no_argument,       NULL, 'f'},
+			{"of_max",           required_argument, NULL, 'g'},
 			{"histogram",        required_argument, NULL, 'h'},
 			{"histofall",        required_argument, NULL, 'H'},
 			{"interval",         required_argument, NULL, 'i'},
@@ -1133,7 +1137,7 @@ static void process_options (int argc, char *argv[])
 			{"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:PmqQrRsSt::uUvD:wWXT:y:",
+		int c = getopt_long(argc, argv, "a::b:Bc:Cd:D:e:Efg:h:H:i:Il:MnNo:O:p:PmqQrRsSt::uUvD:wWXT:y:",
 				    long_options, &option_index);
 		if (c == -1)
 			break;
@@ -1166,6 +1170,7 @@ static void process_options (int argc, char *argv[])
 			break;
 		case 'E': enable_events = 1; break;
 		case 'f': tracetype = FUNCTION; ftrace = 1; break;
+		case 'g': of_max = atoi(optarg); break;
 		case 'H': histofall = 1; /* fall through */
 		case 'h': histogram = atoi(optarg); break;
 		case 'i': interval = atoi(optarg); break;
@@ -1290,6 +1295,12 @@ static void process_options (int argc, char *argv[])
 	if (histogram > HIST_MAX)
 		histogram = HIST_MAX;
 
+	if (of_max < 0)
+		error = 1;
+
+	if (of_max > OF_MAX)
+		of_max = OF_MAX;
+
 	if (histogram && distance != -1)
 		warn("distance is ignored and set to 0, if histogram enabled\n");
 	if (distance == -1)
@@ -1451,16 +1462,15 @@ static void print_hist(struct thread_param *par[], int nthreads)
 		printf(" %05lu", alloverflows);
 	printf("\n");
 
-	printf("# Histogram Overflow at cycle number:\n");
+	printf("# Histogram Overflow at time (ms):\n");
 	for (i = 0; i < nthreads; i++) {
 		printf("# Thread %d:", i);
 		for (j = 0; j < par[i]->stats->num_outliers; j++)
-			printf(" %05lu", par[i]->stats->outliers[j]);
+			printf(" %lu", par[i]->stats->outliers[j] * par[i]->interval / 1000);
 		if (par[i]->stats->num_outliers < par[i]->stats->hist_overflow)
-			printf(" # %05lu others", par[i]->stats->hist_overflow - par[i]->stats->num_outliers);
+			printf(" # %lu others", par[i]->stats->hist_overflow - par[i]->stats->num_outliers);
 		printf("\n");
 	}
-	printf("\n");
 }
 
 static void print_stat(struct thread_param *par, int index, int verbose)
@@ -1706,11 +1716,17 @@ int main(int argc, char **argv)
 			int bufsize = histogram * sizeof(long);
 
 			stat->hist_array = threadalloc(bufsize, node);
-			stat->outliers = threadalloc(bufsize, node);
-			if (stat->hist_array == NULL || stat->outliers == NULL)
+			if (stat->hist_array == NULL)
 				fatal("failed to allocate histogram of size %d on node %d\n",
 				      histogram, i);
 			memset(stat->hist_array, 0, bufsize);
+		}
+		if (of_max) {
+			int bufsize = of_max * sizeof(long);
+			stat->outliers = threadalloc(bufsize, node);
+			if (stat->outliers == NULL)
+				fatal("failed to allocate outliers of size %d on node %d\n",
+				      histogram, i);
 			memset(stat->outliers, 0, bufsize);
 		}
 
@@ -1829,7 +1845,7 @@ int main(int argc, char **argv)
 		print_hist(parameters, num_threads);
 		for (i = 0; i < num_threads; i++) {
 			threadfree(statistics[i]->hist_array, histogram*sizeof(long), parameters[i]->node);
-			threadfree(statistics[i]->outliers, histogram*sizeof(long), parameters[i]->node);
+			threadfree(statistics[i]->outliers, of_max*sizeof(long), parameters[i]->node);
 		}
 	}
 
-- 
1.7.1

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Frank Rowand]

On 11/15/12 17:56, Bhavesh Davda wrote:
> From: Bhavesh Davda <bhavesh@vmware.com>
> 
> Add a new command line option '-g' (long option '--of_max') to cap
> how many outliers are tracked per thread.

< snip >

> ---
> 
>> | Add a line to the histogram overflow cycle report that merges
>> all | threads into a single time line.  This is controlled by the
>> -H | option which already serves a similar purpose for histograms.
>> 
>> The merged data line is an enhancement.  If there is no strong 
>> request from anyone for the feature then no need to include.  But
>> it seems useful to me.
> 
> I agree this is a useful feature request, but harder to implement,
> since I'll have to merge sort from the per-thread outliers to produce
> a single line merged outlier output. I hope it's okay if I punt on
> this one.

It is ok to punt.  But the code to do it was in my patch if you want it.
It is the block of code inside of "if (histofall && nthreads > 1) { ... }".
The code is a little bit ugly, but not totally terrible.

< snip >

I'll look over and test the rest of the patch in a moment (well
actually the next version, which you already sent), as soon
as I finish debugging an email problem.

-Frank

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Frank Rowand]

On 11/15/12 16:11, Frank Rowand wrote:

< snip >

>> I would like to address all your suggestions. Which ones did I miss?
> 
> | Add a line to the histogram overflow cycle report that merges all
> | threads into a single time line.  This is controlled by the -H
> | option which already serves a similar purpose for histograms.
> 
> The merged data line is an enhancement.  If there is no strong request
> from anyone for the feature then no need to include.  But it seems
> useful to me.

After adding in timestamps instead of cycle numbers, and playing
around with some actual data, I think that this feature is not
needed.  It adds code complexity.  The same result can be
achieved by sorting the data outside of cyclictest.

-Frank

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Frank Rowand]

On 11/16/12 18:31, Frank Rowand wrote:

< snip >
 
> I graphed the results with the msec data and with the nanosecond
> timestamps for an artificial test (two test runs for each case):
> 
>   nanosecond:  junk7.gif    junk10.gif
>   msec:        junk8_d.gif  junk9_d.gif
> 
> The cyclictest latency disruptions seem more visible to me in the
> nanosecond data graphs.  But that is just a first impression
> without playing around with a lot of different data sets.

John, Bhavesh,

OK, so after all of that, I'm going on vacation for a week.
I hope the rest of you are taking some time off too.

My conclusion after my data creation and graphing exercise is that
it might be good if people could play around with collecting and
analyzing real histogram overflow data and see what data formats
provide useful information.

I think we should not rush the patch into John's tree so that we
aren't stuck with a format or type of data that is not optimal.

Bhavesh, if you created this feature based on a real world need
(instead of just a brilliant mind exercise), it would be great
if you could apply the latest iteration (or iterations in the
near future) to your actual data collection and provide a real
world example of how this feature makes cyclictest better.

Thanks,

Frank

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Frank Rowand]

On 11/16/12 18:41, Frank Rowand wrote:
> On 11/16/12 18:31, Frank Rowand wrote:
> 
> < snip >
>  
>> I graphed the results with the msec data and with the nanosecond
>> timestamps for an artificial test (two test runs for each case):
>>
>>   nanosecond:  junk7.gif    junk10.gif
>>   msec:        junk8_d.gif  junk9_d.gif
>>
>> The cyclictest latency disruptions seem more visible to me in the
>> nanosecond data graphs.  But that is just a first impression
>> without playing around with a lot of different data sets.
> 
> John, Bhavesh,
> 
> OK, so after all of that, I'm going on vacation for a week.
> I hope the rest of you are taking some time off too.

I'm back...  Bhavesh, have you had a chance to think about my last
several emails (my comments on your latest patch, my proposed patch,
and the email I'm responding to)?  Any comments?

> 
> My conclusion after my data creation and graphing exercise is that
> it might be good if people could play around with collecting and
> analyzing real histogram overflow data and see what data formats
> provide useful information.
> 
> I think we should not rush the patch into John's tree so that we
> aren't stuck with a format or type of data that is not optimal.
> 
> Bhavesh, if you created this feature based on a real world need
> (instead of just a brilliant mind exercise), it would be great
> if you could apply the latest iteration (or iterations in the
> near future) to your actual data collection and provide a real
> world example of how this feature makes cyclictest better.
> 
> Thanks,
> 
> Frank

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Bhavesh Davda]

> On 11/16/12 18:41, Frank Rowand wrote:
> > On 11/16/12 18:31, Frank Rowand wrote:
> > 
> > < snip >
> >  
> >> I graphed the results with the msec data and with the nanosecond
> >> timestamps for an artificial test (two test runs for each case):
> >>
> >>   nanosecond:  junk7.gif    junk10.gif
> >>   msec:        junk8_d.gif  junk9_d.gif
> >>
> >> The cyclictest latency disruptions seem more visible to me in the
> >> nanosecond data graphs.  But that is just a first impression
> >> without playing around with a lot of different data sets.
> > 
> > John, Bhavesh,
> > 
> > OK, so after all of that, I'm going on vacation for a week.
> > I hope the rest of you are taking some time off too.
> 
> I'm back...  Bhavesh, have you had a chance to think about my last
> several emails (my comments on your latest patch, my proposed patch,
> and the email I'm responding to)?  Any comments?

Hello Frank. Welcome back. I was out for the long weekend and am just getting back in the swing of things too, so sorry about the delay.

I do have real use cases for this "outlier" mode, that I've used effectively to identify sources of high latencies of cyclictest running in a Linux-rt kernel based VM on our VMware ESXi hypervisor. The patterns in the outliers, for various thresholds (e.g. 50 us) have helped me identify timers and callbacks in the hypervisor kernel (vmkernel) which have caused time to be "stolen" away from scheduling the virtual CPUs of the VM to do various housekeeping tasks, and to either move those timers out to other physical CPUs or to limit the time spend in those timers and callbacks to have a smaller impact on the cyclictest latencies.

I'm hoping that others in the community find similar uses of this "outlier" feature of cyclictest.

That said, I realize that not every use cases might fit my exact mould and might require either different formatting, or different granularities of the "outliers" output. So I'm open to suggestions in that regard.

I'm going to respond to your proposed patch next.

Thanks

- Bhavesh

> 
> > 
> > My conclusion after my data creation and graphing exercise is that
> > it might be good if people could play around with collecting and
> > analyzing real histogram overflow data and see what data formats
> > provide useful information.
> > 
> > I think we should not rush the patch into John's tree so that we
> > aren't stuck with a format or type of data that is not optimal.
> > 
> > Bhavesh, if you created this feature based on a real world need
> > (instead of just a brilliant mind exercise), it would be great
> > if you could apply the latest iteration (or iterations in the
> > near future) to your actual data collection and provide a real
> > world example of how this feature makes cyclictest better.
> > 
> > Thanks,
> > 
> > Frank
> 
> 
> 

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Bhavesh Davda]

> > I'm back...  Bhavesh, have you had a chance to think about my last
> > several emails (my comments on your latest patch, my proposed
> > patch,
> > and the email I'm responding to)?  Any comments?
> 
> Hello Frank. Welcome back. I was out for the long weekend and am just
> getting back in the swing of things too, so sorry about the delay.
> 
> I do have real use cases for this "outlier" mode, that I've used
> effectively to identify sources of high latencies of cyclictest
<snip> 
> I'm hoping that others in the community find similar uses of this
> "outlier" feature of cyclictest.
> 
<snip>
> I'm going to respond to your proposed patch next.

Hello Frank,

I'm sorry I can't find your e-mail with a proposed patch on top of my patch posted on 

Date:       2012-11-16 2:04:07

with

Message-ID: 1465858638.1880820.1353031447623.JavaMail.root () vmware ! com

Can you please tell me which e-mail contained your proposed patch on top of this patch?

Thanks

- Bhavesh

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Frank Rowand]

On 11/29/12 09:28, Bhavesh Davda wrote:
>>> I'm back...  Bhavesh, have you had a chance to think about my last
>>> several emails (my comments on your latest patch, my proposed
>>> patch,
>>> and the email I'm responding to)?  Any comments?
>>
>> Hello Frank. Welcome back. I was out for the long weekend and am just
>> getting back in the swing of things too, so sorry about the delay.
>>
>> I do have real use cases for this "outlier" mode, that I've used
>> effectively to identify sources of high latencies of cyclictest
> <snip> 
>> I'm hoping that others in the community find similar uses of this
>> "outlier" feature of cyclictest.
>>
> <snip>
>> I'm going to respond to your proposed patch next.
> 
> Hello Frank,
> 
> I'm sorry I can't find your e-mail with a proposed patch on top of my patch posted on 
> 
> Date:       2012-11-16 2:04:07
> 
> with
> 
> Message-ID: 1465858638.1880820.1353031447623.JavaMail.root () vmware ! com
> 
> Can you please tell me which e-mail contained your proposed patch on top of this patch?
> 
> Thanks
> 
> - Bhavesh

Strange, I don't find it in any of the archives I looked at.  I'll send it again.

-Frank

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Frank Rowand]

On 11/26/12 13:37, Bhavesh Davda wrote:
>> On 11/16/12 18:41, Frank Rowand wrote:
>>> On 11/16/12 18:31, Frank Rowand wrote:
>>> 
>>> < snip >
>>> 
>>>> I graphed the results with the msec data and with the
>>>> nanosecond timestamps for an artificial test (two test runs for
>>>> each case):
>>>> 
>>>> nanosecond:  junk7.gif    junk10.gif msec:        junk8_d.gif
>>>> junk9_d.gif
>>>> 
>>>> The cyclictest latency disruptions seem more visible to me in
>>>> the nanosecond data graphs.  But that is just a first
>>>> impression without playing around with a lot of different data
>>>> sets.
>>> 
>>> John, Bhavesh,
>>> 
>>> OK, so after all of that, I'm going on vacation for a week. I
>>> hope the rest of you are taking some time off too.
>> 
>> I'm back...  Bhavesh, have you had a chance to think about my last 
>> several emails (my comments on your latest patch, my proposed
>> patch, and the email I'm responding to)?  Any comments?
> 
> Hello Frank. Welcome back. I was out for the long weekend and am just
> getting back in the swing of things too, so sorry about the delay.
> 
> I do have real use cases for this "outlier" mode, that I've used
> effectively to identify sources of high latencies of cyclictest
> running in a Linux-rt kernel based VM on our VMware ESXi hypervisor.
> The patterns in the outliers, for various thresholds (e.g. 50 us)
> have helped me identify timers and callbacks in the hypervisor kernel
> (vmkernel) which have caused time to be "stolen" away from scheduling
> the virtual CPUs of the VM to do various housekeeping tasks, and to
> either move those timers out to other physical CPUs or to limit the
> time spend in those timers and callbacks to have a smaller impact on
> the cyclictest latencies.
> 
> I'm hoping that others in the community find similar uses of this
> "outlier" feature of cyclictest.
> 
> That said, I realize that not every use cases might fit my exact
> mould and might require either different formatting, or different
> granularities of the "outliers" output. So I'm open to suggestions in
> that regard.
> 
> I'm going to respond to your proposed patch next.
> 
> Thanks
> 
> - Bhavesh

ping....

Thanks,

Frank

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Bhavesh Davda]

> > I'm going to respond to your proposed patch next.
> > 
> > Thanks
> > 
> > - Bhavesh
> 
> ping....
> 
> Thanks,
> 
> Frank

Hello Frank,

Extremely sorry about the tardiness in reviewing your proposed change!

Your change looks good to me. Again, did you want me to fold your proposed change into my original patch, or were you proposing applying your patch (of course without the #if 0's) on top of mine?

Thanks for spending so much time reviewing my patches, trying them out, and suggesting ways to make it better!

- Bhavesh

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Frank Rowand]

On 12/17/12 10:24, Bhavesh Davda wrote:
>>> I'm going to respond to your proposed patch next.
>>> 
>>> Thanks
>>> 
>>> - Bhavesh
>> 
>> ping....
>> 
>> Thanks,
>> 
>> Frank
> 
> Hello Frank,
> 
> Extremely sorry about the tardiness in reviewing your proposed
> change!

No problem.  Life is busy, we progress as we can.

> Your change looks good to me. Again, did you want me to fold your
> proposed change into my original patch, or were you proposing
> applying your patch (of course without the #if 0's) on top of mine?

It would be great if you could add my changes on top of your original patch
since John hasn't committed your original patch yet.  That way everything
will be coordinated from one person.  And yes, without the "#if 0's".

It would probably be good to submit it to John as a series of two patches,
your original patch, followed by my additions.

For my patch, you can add: Signed-off-by: Frank Rowand <frank.rowand@am.sony.com>

My patch did not address one other comment I made, which is:

  default of -g to zero means histogram overflows will be printed even
  if "-g" not specified (same as "-g 0").  The output of histogram
  overflows should only occur if of_max > 0.


> Thanks for spending so much time reviewing my patches, trying them
> out, and suggesting ways to make it better!

Your welcome!

-Frank

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Bhavesh Davda]

> It would be great if you could add my changes on top of your original
> patch
> since John hasn't committed your original patch yet.  That way
> everything
> will be coordinated from one person.  And yes, without the "#if 0's".
> 
> It would probably be good to submit it to John as a series of two
> patches,
> your original patch, followed by my additions.
> 
> For my patch, you can add: Signed-off-by: Frank Rowand
> <frank.rowand@am.sony.com>
> 
> My patch did not address one other comment I made, which is:
> 
>   default of -g to zero means histogram overflows will be printed
>   even
>   if "-g" not specified (same as "-g 0").  The output of histogram
>   overflows should only occur if of_max > 0.


I'll see if I can address that in a potentially 3rd part of a 3 patch series.

One thing I noticed when actually creating the 2nd patch, in your change:

@@ -890,7 +904,7 @@ void *timerthread(void *param)
                        if (diff >= histogram) {
                                stat->hist_overflow++;
                                if (stat->num_outliers < of_max)
-                                       stat->outliers[stat->num_outliers++] = stat->cycles;
+                                       stat->outliers[stat->num_outliers++] = next;
                        }
                        else
                                stat->hist_array[diff]++;

Should that be:
+                                       stat->outliers[stat->num_outliers++] = now;

instead?

Also, not your fault, but I fixed another white space issue here:

@@ -151,7 +153,7 @@ struct thread_stat {
        double avg;
        long *values;
        long *hist_array;
-        long *outliers;
+        struct timespec *outliers;
        pthread_t thread;
        int threadstarted;
        int tid;

And finally, as far as output format for the outliers is concerned, I'm slightly worried it takes too much screen real estate by printing one line per outlier per thread. But that's quite subjective and I wouldn't be opposed to living with it for a while and seeing if it starts to get annoying :)

Thanks

- Bhavesh

Re: [PATCH RT-TESTS] cyclictest: new command line switch for histogram overflow instance tracking

[Frank Rowand]

On 12/17/12 14:17, Bhavesh Davda wrote:
> 
>> It would be great if you could add my changes on top of your original
>> patch
>> since John hasn't committed your original patch yet.  That way
>> everything
>> will be coordinated from one person.  And yes, without the "#if 0's".
>>
>> It would probably be good to submit it to John as a series of two
>> patches,
>> your original patch, followed by my additions.
>>
>> For my patch, you can add: Signed-off-by: Frank Rowand
>> <frank.rowand@am.sony.com>
>>
>> My patch did not address one other comment I made, which is:
>>
>>   default of -g to zero means histogram overflows will be printed
>>   even
>>   if "-g" not specified (same as "-g 0").  The output of histogram
>>   overflows should only occur if of_max > 0.
> 
> 
> I'll see if I can address that in a potentially 3rd part of a 3 patch series.
> 
> One thing I noticed when actually creating the 2nd patch, in your change:
> 
> @@ -890,7 +904,7 @@ void *timerthread(void *param)
>                         if (diff >= histogram) {
>                                 stat->hist_overflow++;
>                                 if (stat->num_outliers < of_max)
> -                                       stat->outliers[stat->num_outliers++] = stat->cycles;
> +                                       stat->outliers[stat->num_outliers++] = next;
>                         }
>                         else
>                                 stat->hist_array[diff]++;
> 
> Should that be:
> +                                       stat->outliers[stat->num_outliers++] = now;
> 
> instead?

Both next and now are valid choices.  If one was to get totally carried away both
values could be reported.  I don't think it is critical which one is used, as
long as it is clearly documented.  For those reading along at home:

  next is the beginning time stamp of the delay (when execution should have occurred)

  now is the ending time stamp of the delay (when execution did occur)

Different causes of periodic latency causes might be more apparent with one time or
the other.  I suspect that whichever one is used that I will on occasion modify
cyclictest to report the other one.


> Also, not your fault, but I fixed another white space issue here:
> 
> @@ -151,7 +153,7 @@ struct thread_stat {
>         double avg;
>         long *values;
>         long *hist_array;
> -        long *outliers;
> +        struct timespec *outliers;
>         pthread_t thread;
>         int threadstarted;
>         int tid;

There are still a handful of white space issues if you want to kill
them all with one patch (just look for a space in the first or last
column).  I was just going to wait to everything else settled out to
submit a patch for that.


> And finally, as far as output format for the outliers is concerned, I'm slightly worried it takes too much screen real estate by printing one line per outlier per thread. But that's quite subjective and I wouldn't be opposed to living with it for a while and seeing if it starts to get annoying :)

Agreed.  Two different use cases argue for different output format.  I'm used to
processing large batches of data and frequently graph the data to make it more
manageable.  But if you are looking at the raw data on a screen then many values
per line is more effective use of real estate.  It isn't too hard to convert back
and forth.  So given my use case, my one vote (for whatever that is worth) is for
the screen real estate wasting format.

-Frank