aboutsummaryrefslogtreecommitdiffstats
path: root/kernel/trace
diff options
context:
space:
mode:
authorSteven Rostedt <srostedt@redhat.com>2009-06-17 17:01:09 -0400
committerSteven Rostedt <rostedt@goodmis.org>2009-06-17 17:01:09 -0400
commit4b221f0313f0f7f1f7aa0a1fd16ad400840def26 (patch)
treea294e6719eefb3c68562627f59a7c0a67ae9b760 /kernel/trace
parent8d707e8eb4de4b930573155ab4df4b3270ee25dd (diff)
ring-buffer: have benchmark test print to trace buffer
Currently the output of the ring buffer benchmark/test prints to the console. This test runs for ten seconds every ten seconds and ouputs the result after every iteration. This needlessly fills up the logs. This patch makes the ring buffer benchmark/test print to the ftrace buffer using trace_printk. To view the test results, you must examine the debug/tracing/trace file. Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Diffstat (limited to 'kernel/trace')
-rw-r--r--kernel/trace/ring_buffer_benchmark.c37
1 files changed, 19 insertions, 18 deletions
diff --git a/kernel/trace/ring_buffer_benchmark.c b/kernel/trace/ring_buffer_benchmark.c
index cf6b0f50134e..573d3cc762c3 100644
--- a/kernel/trace/ring_buffer_benchmark.c
+++ b/kernel/trace/ring_buffer_benchmark.c
@@ -203,7 +203,7 @@ static void ring_buffer_producer(void)
203 * Hammer the buffer for 10 secs (this may 203 * Hammer the buffer for 10 secs (this may
204 * make the system stall) 204 * make the system stall)
205 */ 205 */
206 pr_info("Starting ring buffer hammer\n"); 206 trace_printk("Starting ring buffer hammer\n");
207 do_gettimeofday(&start_tv); 207 do_gettimeofday(&start_tv);
208 do { 208 do {
209 struct ring_buffer_event *event; 209 struct ring_buffer_event *event;
@@ -239,7 +239,7 @@ static void ring_buffer_producer(void)
239#endif 239#endif
240 240
241 } while (end_tv.tv_sec < (start_tv.tv_sec + RUN_TIME) && !kill_test); 241 } while (end_tv.tv_sec < (start_tv.tv_sec + RUN_TIME) && !kill_test);
242 pr_info("End ring buffer hammer\n"); 242 trace_printk("End ring buffer hammer\n");
243 243
244 if (consumer) { 244 if (consumer) {
245 /* Init both completions here to avoid races */ 245 /* Init both completions here to avoid races */
@@ -262,49 +262,50 @@ static void ring_buffer_producer(void)
262 overruns = ring_buffer_overruns(buffer); 262 overruns = ring_buffer_overruns(buffer);
263 263
264 if (kill_test) 264 if (kill_test)
265 pr_info("ERROR!\n"); 265 trace_printk("ERROR!\n");
266 pr_info("Time: %lld (usecs)\n", time); 266 trace_printk("Time: %lld (usecs)\n", time);
267 pr_info("Overruns: %lld\n", overruns); 267 trace_printk("Overruns: %lld\n", overruns);
268 if (disable_reader) 268 if (disable_reader)
269 pr_info("Read: (reader disabled)\n"); 269 trace_printk("Read: (reader disabled)\n");
270 else 270 else
271 pr_info("Read: %ld (by %s)\n", read, 271 trace_printk("Read: %ld (by %s)\n", read,
272 read_events ? "events" : "pages"); 272 read_events ? "events" : "pages");
273 pr_info("Entries: %lld\n", entries); 273 trace_printk("Entries: %lld\n", entries);
274 pr_info("Total: %lld\n", entries + overruns + read); 274 trace_printk("Total: %lld\n", entries + overruns + read);
275 pr_info("Missed: %ld\n", missed); 275 trace_printk("Missed: %ld\n", missed);
276 pr_info("Hit: %ld\n", hit); 276 trace_printk("Hit: %ld\n", hit);
277 277
278 /* Convert time from usecs to millisecs */ 278 /* Convert time from usecs to millisecs */
279 do_div(time, USEC_PER_MSEC); 279 do_div(time, USEC_PER_MSEC);
280 if (time) 280 if (time)
281 hit /= (long)time; 281 hit /= (long)time;
282 else 282 else
283 pr_info("TIME IS ZERO??\n"); 283 trace_printk("TIME IS ZERO??\n");
284 284
285 pr_info("Entries per millisec: %ld\n", hit); 285 trace_printk("Entries per millisec: %ld\n", hit);
286 286
287 if (hit) { 287 if (hit) {
288 /* Calculate the average time in nanosecs */ 288 /* Calculate the average time in nanosecs */
289 avg = NSEC_PER_MSEC / hit; 289 avg = NSEC_PER_MSEC / hit;
290 pr_info("%ld ns per entry\n", avg); 290 trace_printk("%ld ns per entry\n", avg);
291 } 291 }
292 292
293 if (missed) { 293 if (missed) {
294 if (time) 294 if (time)
295 missed /= (long)time; 295 missed /= (long)time;
296 296
297 pr_info("Total iterations per millisec: %ld\n", hit + missed); 297 trace_printk("Total iterations per millisec: %ld\n",
298 hit + missed);
298 299
299 /* it is possible that hit + missed will overflow and be zero */ 300 /* it is possible that hit + missed will overflow and be zero */
300 if (!(hit + missed)) { 301 if (!(hit + missed)) {
301 pr_info("hit + missed overflowed and totalled zero!\n"); 302 trace_printk("hit + missed overflowed and totalled zero!\n");
302 hit--; /* make it non zero */ 303 hit--; /* make it non zero */
303 } 304 }
304 305
305 /* Caculate the average time in nanosecs */ 306 /* Caculate the average time in nanosecs */
306 avg = NSEC_PER_MSEC / (hit + missed); 307 avg = NSEC_PER_MSEC / (hit + missed);
307 pr_info("%ld ns per entry\n", avg); 308 trace_printk("%ld ns per entry\n", avg);
308 } 309 }
309} 310}
310 311
@@ -355,7 +356,7 @@ static int ring_buffer_producer_thread(void *arg)
355 356
356 ring_buffer_producer(); 357 ring_buffer_producer();
357 358
358 pr_info("Sleeping for 10 secs\n"); 359 trace_printk("Sleeping for 10 secs\n");
359 set_current_state(TASK_INTERRUPTIBLE); 360 set_current_state(TASK_INTERRUPTIBLE);
360 schedule_timeout(HZ * SLEEP_TIME); 361 schedule_timeout(HZ * SLEEP_TIME);
361 __set_current_state(TASK_RUNNING); 362 __set_current_state(TASK_RUNNING);