diff options
author | Steven Rostedt <srostedt@redhat.com> | 2009-06-17 17:01:09 -0400 |
---|---|---|
committer | Steven Rostedt <rostedt@goodmis.org> | 2009-06-17 17:01:09 -0400 |
commit | 4b221f0313f0f7f1f7aa0a1fd16ad400840def26 (patch) | |
tree | a294e6719eefb3c68562627f59a7c0a67ae9b760 /kernel/trace | |
parent | 8d707e8eb4de4b930573155ab4df4b3270ee25dd (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.c | 37 |
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); |