linux/kernel/trace/ring_buffer_benchmark.c
<<
>>
Prefs
   1/*
   2 * ring buffer tester and benchmark
   3 *
   4 * Copyright (C) 2009 Steven Rostedt <srostedt@redhat.com>
   5 */
   6#include <linux/ring_buffer.h>
   7#include <linux/completion.h>
   8#include <linux/kthread.h>
   9#include <linux/module.h>
  10#include <linux/time.h>
  11#include <asm/local.h>
  12
  13struct rb_page {
  14        u64             ts;
  15        local_t         commit;
  16        char            data[4080];
  17};
  18
  19/* run time and sleep time in seconds */
  20#define RUN_TIME        10
  21#define SLEEP_TIME      10
  22
  23/* number of events for writer to wake up the reader */
  24static int wakeup_interval = 100;
  25
  26static int reader_finish;
  27static struct completion read_start;
  28static struct completion read_done;
  29
  30static struct ring_buffer *buffer;
  31static struct task_struct *producer;
  32static struct task_struct *consumer;
  33static unsigned long read;
  34
  35static int disable_reader;
  36module_param(disable_reader, uint, 0644);
  37MODULE_PARM_DESC(disable_reader, "only run producer");
  38
  39static int write_iteration = 50;
  40module_param(write_iteration, uint, 0644);
  41MODULE_PARM_DESC(write_iteration, "# of writes between timestamp readings");
  42
  43static int producer_nice = 19;
  44static int consumer_nice = 19;
  45
  46static int producer_fifo = -1;
  47static int consumer_fifo = -1;
  48
  49module_param(producer_nice, uint, 0644);
  50MODULE_PARM_DESC(producer_nice, "nice prio for producer");
  51
  52module_param(consumer_nice, uint, 0644);
  53MODULE_PARM_DESC(consumer_nice, "nice prio for consumer");
  54
  55module_param(producer_fifo, uint, 0644);
  56MODULE_PARM_DESC(producer_fifo, "fifo prio for producer");
  57
  58module_param(consumer_fifo, uint, 0644);
  59MODULE_PARM_DESC(consumer_fifo, "fifo prio for consumer");
  60
  61static int read_events;
  62
  63static int kill_test;
  64
  65#define KILL_TEST()                             \
  66        do {                                    \
  67                if (!kill_test) {               \
  68                        kill_test = 1;          \
  69                        WARN_ON(1);             \
  70                }                               \
  71        } while (0)
  72
  73enum event_status {
  74        EVENT_FOUND,
  75        EVENT_DROPPED,
  76};
  77
  78static enum event_status read_event(int cpu)
  79{
  80        struct ring_buffer_event *event;
  81        int *entry;
  82        u64 ts;
  83
  84        event = ring_buffer_consume(buffer, cpu, &ts, NULL);
  85        if (!event)
  86                return EVENT_DROPPED;
  87
  88        entry = ring_buffer_event_data(event);
  89        if (*entry != cpu) {
  90                KILL_TEST();
  91                return EVENT_DROPPED;
  92        }
  93
  94        read++;
  95        return EVENT_FOUND;
  96}
  97
  98static enum event_status read_page(int cpu)
  99{
 100        struct ring_buffer_event *event;
 101        struct rb_page *rpage;
 102        unsigned long commit;
 103        void *bpage;
 104        int *entry;
 105        int ret;
 106        int inc;
 107        int i;
 108
 109        bpage = ring_buffer_alloc_read_page(buffer, cpu);
 110        if (!bpage)
 111                return EVENT_DROPPED;
 112
 113        ret = ring_buffer_read_page(buffer, &bpage, PAGE_SIZE, cpu, 1);
 114        if (ret >= 0) {
 115                rpage = bpage;
 116                /* The commit may have missed event flags set, clear them */
 117                commit = local_read(&rpage->commit) & 0xfffff;
 118                for (i = 0; i < commit && !kill_test; i += inc) {
 119
 120                        if (i >= (PAGE_SIZE - offsetof(struct rb_page, data))) {
 121                                KILL_TEST();
 122                                break;
 123                        }
 124
 125                        inc = -1;
 126                        event = (void *)&rpage->data[i];
 127                        switch (event->type_len) {
 128                        case RINGBUF_TYPE_PADDING:
 129                                /* failed writes may be discarded events */
 130                                if (!event->time_delta)
 131                                        KILL_TEST();
 132                                inc = event->array[0] + 4;
 133                                break;
 134                        case RINGBUF_TYPE_TIME_EXTEND:
 135                                inc = 8;
 136                                break;
 137                        case 0:
 138                                entry = ring_buffer_event_data(event);
 139                                if (*entry != cpu) {
 140                                        KILL_TEST();
 141                                        break;
 142                                }
 143                                read++;
 144                                if (!event->array[0]) {
 145                                        KILL_TEST();
 146                                        break;
 147                                }
 148                                inc = event->array[0] + 4;
 149                                break;
 150                        default:
 151                                entry = ring_buffer_event_data(event);
 152                                if (*entry != cpu) {
 153                                        KILL_TEST();
 154                                        break;
 155                                }
 156                                read++;
 157                                inc = ((event->type_len + 1) * 4);
 158                        }
 159                        if (kill_test)
 160                                break;
 161
 162                        if (inc <= 0) {
 163                                KILL_TEST();
 164                                break;
 165                        }
 166                }
 167        }
 168        ring_buffer_free_read_page(buffer, bpage);
 169
 170        if (ret < 0)
 171                return EVENT_DROPPED;
 172        return EVENT_FOUND;
 173}
 174
 175static void ring_buffer_consumer(void)
 176{
 177        /* toggle between reading pages and events */
 178        read_events ^= 1;
 179
 180        read = 0;
 181        while (!reader_finish && !kill_test) {
 182                int found;
 183
 184                do {
 185                        int cpu;
 186
 187                        found = 0;
 188                        for_each_online_cpu(cpu) {
 189                                enum event_status stat;
 190
 191                                if (read_events)
 192                                        stat = read_event(cpu);
 193                                else
 194                                        stat = read_page(cpu);
 195
 196                                if (kill_test)
 197                                        break;
 198                                if (stat == EVENT_FOUND)
 199                                        found = 1;
 200                        }
 201                } while (found && !kill_test);
 202
 203                set_current_state(TASK_INTERRUPTIBLE);
 204                if (reader_finish)
 205                        break;
 206
 207                schedule();
 208                __set_current_state(TASK_RUNNING);
 209        }
 210        reader_finish = 0;
 211        complete(&read_done);
 212}
 213
 214static void ring_buffer_producer(void)
 215{
 216        struct timeval start_tv;
 217        struct timeval end_tv;
 218        unsigned long long time;
 219        unsigned long long entries;
 220        unsigned long long overruns;
 221        unsigned long missed = 0;
 222        unsigned long hit = 0;
 223        unsigned long avg;
 224        int cnt = 0;
 225
 226        /*
 227         * Hammer the buffer for 10 secs (this may
 228         * make the system stall)
 229         */
 230        trace_printk("Starting ring buffer hammer\n");
 231        do_gettimeofday(&start_tv);
 232        do {
 233                struct ring_buffer_event *event;
 234                int *entry;
 235                int i;
 236
 237                for (i = 0; i < write_iteration; i++) {
 238                        event = ring_buffer_lock_reserve(buffer, 10);
 239                        if (!event) {
 240                                missed++;
 241                        } else {
 242                                hit++;
 243                                entry = ring_buffer_event_data(event);
 244                                *entry = smp_processor_id();
 245                                ring_buffer_unlock_commit(buffer, event);
 246                        }
 247                }
 248                do_gettimeofday(&end_tv);
 249
 250                cnt++;
 251                if (consumer && !(cnt % wakeup_interval))
 252                        wake_up_process(consumer);
 253
 254#ifndef CONFIG_PREEMPT
 255                /*
 256                 * If we are a non preempt kernel, the 10 second run will
 257                 * stop everything while it runs. Instead, we will call
 258                 * cond_resched and also add any time that was lost by a
 259                 * rescedule.
 260                 *
 261                 * Do a cond resched at the same frequency we would wake up
 262                 * the reader.
 263                 */
 264                if (cnt % wakeup_interval)
 265                        cond_resched();
 266#endif
 267
 268        } while (end_tv.tv_sec < (start_tv.tv_sec + RUN_TIME) && !kill_test);
 269        trace_printk("End ring buffer hammer\n");
 270
 271        if (consumer) {
 272                /* Init both completions here to avoid races */
 273                init_completion(&read_start);
 274                init_completion(&read_done);
 275                /* the completions must be visible before the finish var */
 276                smp_wmb();
 277                reader_finish = 1;
 278                /* finish var visible before waking up the consumer */
 279                smp_wmb();
 280                wake_up_process(consumer);
 281                wait_for_completion(&read_done);
 282        }
 283
 284        time = end_tv.tv_sec - start_tv.tv_sec;
 285        time *= USEC_PER_SEC;
 286        time += (long long)((long)end_tv.tv_usec - (long)start_tv.tv_usec);
 287
 288        entries = ring_buffer_entries(buffer);
 289        overruns = ring_buffer_overruns(buffer);
 290
 291        if (kill_test)
 292                trace_printk("ERROR!\n");
 293
 294        if (!disable_reader) {
 295                if (consumer_fifo < 0)
 296                        trace_printk("Running Consumer at nice: %d\n",
 297                                     consumer_nice);
 298                else
 299                        trace_printk("Running Consumer at SCHED_FIFO %d\n",
 300                                     consumer_fifo);
 301        }
 302        if (producer_fifo < 0)
 303                trace_printk("Running Producer at nice: %d\n",
 304                             producer_nice);
 305        else
 306                trace_printk("Running Producer at SCHED_FIFO %d\n",
 307                             producer_fifo);
 308
 309        /* Let the user know that the test is running at low priority */
 310        if (producer_fifo < 0 && consumer_fifo < 0 &&
 311            producer_nice == 19 && consumer_nice == 19)
 312                trace_printk("WARNING!!! This test is running at lowest priority.\n");
 313
 314        trace_printk("Time:     %lld (usecs)\n", time);
 315        trace_printk("Overruns: %lld\n", overruns);
 316        if (disable_reader)
 317                trace_printk("Read:     (reader disabled)\n");
 318        else
 319                trace_printk("Read:     %ld  (by %s)\n", read,
 320                        read_events ? "events" : "pages");
 321        trace_printk("Entries:  %lld\n", entries);
 322        trace_printk("Total:    %lld\n", entries + overruns + read);
 323        trace_printk("Missed:   %ld\n", missed);
 324        trace_printk("Hit:      %ld\n", hit);
 325
 326        /* Convert time from usecs to millisecs */
 327        do_div(time, USEC_PER_MSEC);
 328        if (time)
 329                hit /= (long)time;
 330        else
 331                trace_printk("TIME IS ZERO??\n");
 332
 333        trace_printk("Entries per millisec: %ld\n", hit);
 334
 335        if (hit) {
 336                /* Calculate the average time in nanosecs */
 337                avg = NSEC_PER_MSEC / hit;
 338                trace_printk("%ld ns per entry\n", avg);
 339        }
 340
 341        if (missed) {
 342                if (time)
 343                        missed /= (long)time;
 344
 345                trace_printk("Total iterations per millisec: %ld\n",
 346                             hit + missed);
 347
 348                /* it is possible that hit + missed will overflow and be zero */
 349                if (!(hit + missed)) {
 /a>        if (missed) {
 349                ifP time tt mill tiref= 251      3     3   if (hit + /* it is possible thatll)   theref="kernel/trace/ring_buffer_benchmark.c#L349" id="L349" class="line" n3me="L252"> 252      3     3            253
 254#ifnde3 /* Calculate the averagetime in nanosecs */
 255      3     3   avg = NSEC_PER_MSEC / read_events ? "events" 254#ifnde3 a href="+code=start_tv" class="sref">start_tv.start_tv.start_tv.333                *3hit +  203                set_current_state(3tv_secthion" chpan _d="Lcurrent_state" >thion" chpan _d="L/a>  f="+code=hit" class="sref">hit +  3               */3 207                wakeup_interval)3 203                set_current_state( ?ref">cond_resched();3 266#endif3 208                __set_current_state( 2673kill_test);3prodthion"ries + prodthion"a hreic v.c#L244" id="L244arart_tv. 342                if ( 2703hit + consumer) {3tv_secthion" chpan _d="Lcurrent_state" >thion" chpan _d="L/a>  f_sec" class="sref">tv_sec + hit +  211 ="+code=init_completion" class="sref">init_completion(&read_start);3read_done);3prories + pro name="L207"> 207                smp_wmb();3 203                set_current_state(reader_finish = 1;3thion" chpan _d="L/a>  f_||buffer_benchmarkmark.c#L291" id="L291" class="line" name="L291"> 291        if ( 203p_wmb" cl3ss="sref">smp_wmb();3consumer);3 207                read_done);3 208                __set_current_state( 282        }3 2833 208                __set_current_state(tv_sec;3USEC_PER_SEC;3 291        if (tv_usec);3__set_current_state( 2873buffer);3 224        int buffer);3 2903kill_test)3 +  342                if (&quo3;ERROR!\n");3hit +  2933 273                init_completion(&disable_reader) {33onsumer_fifo < 0)3tv_secthion" chpan _d="Lcurrent_state" >thion" chpan _d="L/a>  f_sec" class="sref">tv_sec + hit +  245                even4               ring_buffer_overruns(consumer_nice);3 293                else3 271        if ( 279                consumer_fifo);4 280                wake_up_process( 301        }4 281                init_completion(&4roducer_fifo < 0)4,4producer_nice);4 +  279                 254#ifnde3 a href="+coSleepass=uffe56sa>) {
 349   4" class="4ref">producer_fifo);4 203                set_current_state( 3084start_tv.sturrent_state(4 208                __set_current_state( == 19)4 291        if ( 3134__set_current_state(time);4overruns);4 224        int disable_reader)4);4 318        else4read,4 271        if (&4uot;pages");4 245     eNSEC_PER_MSEC" class="sref">NSEC_PER_MSEC / entries);4read);4 251      3     3  a one mecode=tracinemisswite m.c#4#ifnde3 /* Calculate th4=missed" 4lass="sref">missed);4 289     alloa> - (long)     alloaa hre1000000/a>.RB_FL_OVERWRITtart_tv.__set_current_state(hit);4tv_sec( 3254tv_secNSEC_PER_MSEC / USEC_PER_MSEC);4 294        if (!time)4 >thion" cion" class="line" na>thion" cion"                prodthion"ries + prodthion"a hra>("Total iterations pe4+code=tim4" class="sref">time;4read_eventsrbLref">pro) {
 349   4" name="L430"> 330        else4 245     eNSEC_2ne" name="L289"> PTR_ref5"> 245    PTR_ref280                wake_up_process( 245    IS_ref280                ( 3324NSEC_PER_MSEC / hit);4 3344hit) {4 +  >thion" ru class="line" na>thion" ru                 + ("Total iterations pe4+ class="4me in nanosecs */4read_eventsrbL="line" ) {
 349   4" class="4t" class="sref">hit;4 245     eNSEC_2ne" name="L289"> PTR_ref5"> 245    PTR_ref280             ="line" ries +  349   4"code=tim4" class="sref">avg);4 339        }4 245    IS_ref280             ="line" ries + ( 3404NSEC_PER_MSEC / missed) {4time)4 251      3  a>#ifnde3 /* Calculate th4+code=tim4" class="sref">time;4 251      3ce/ring_b* Run clam asref"-ce_p backgrous="sasks by default:a>#ifnde3 /* Calculate th4+class="l4ne" name="L344"> 3444 251      3ce/ring_b*/a>#ifnde3 /* Calculate th4 millisec4 %ld\n",4 294        if (!missed);4 295        if (! 3474ucfer_benchmark.c#L.="li_paramde=init_complet.="li_param"kernu_benchmark.c#Lparamde=init_completparam"kern=294        if (!4tv_.="li_pe_printde=init_complet.="li_pe_printSEC_2ne" name="L289"> 295" id="L295" class="line" name="L295"> 295<4        if (!missed)) {4NSEC_PER_MSEC /                 .intk" clasart_tv. 349   4;nt">/* i4 is possible thatll) 4 ther4f="kernel/trace/ring_buce/ring_buffer_benchmark.c#L330" id="L330" class="lin4e="L252">4252      3     3    4     45="kernel/trace/ring_buffer_benchmark.c#L343"="L2d="Lducer_nice" class="s="L2d="Lducer280                .ass="line" name="L297"> 297                                      2534&q4ot;ev45="kernel/trace/ring_buffer_benchmark.c#L310" id="L310" class="line" name="L310"gt;= 0 294        if (!4ucfer_benchmark.c#L.="li_paramde=init_complet.="li_param"kernu_benchmark.c#Lparamde=init_completparam"kern=294        if (!tv_.="li_pe_printde=init_complet.="li_pe_printSEC_2ne" name="L289"> 295" id="L295" class="line" name="L295"> 295<4        if (!4NSEC_PER_MSEC / 4             ="line" ries + .intk" clasart_tv. 349   4comment">4                *4 + .L304" class="line" name="L304"> 304                              4               */4 224        int wakeup_interval)4cond_resched();4 266#endif4 2674thion" c="L/a>  a>                wake_up_process(kill_test);4 2704  a>             ="+code=ring_buffer_overruns" class="sref">ring_buffer_overruns(consumer) {4 245     eNSEC_PER_MSEC" class="sref">NSEC_PER_MSEC / 4read_start);4read_done);4        if (!smp_wmb();4thion" c="L/a>  a>             ="line" ries +  349   4lass="sre4">reader_finish = 1;4thion" c="Lcurrent_state" >thion" c="L/a>  a>                wake_up_process(smp_wmb();4  a>             ="+code=ring_buffer_overruns" class="sref">ring_buffer_overruns(consumer);4read_done);4 282        }4ring_buffer_overruns( 2834ring_buffer_overruns(tv_sec;4USEC_PER_SEC;4 245    MODULE_AUTHOf      ="+code=init_">a href="+coSthref Rostedt) {
 349   4v_usec" c4ass="sref">tv_usec);4 245    MODULE_DESCRIPTION      ="+code=init_">a href="+co" name="L349"> 349 349   4vass="sre4ne" name="L287"> 2874a href="+coGPL) {
 349   4v waking 4lass="sref">buffer);4
The original LXR software by clasnel/tracehttp://sourceforge.net/projects/lxde>LXR a>  unintSEC_, clis experi    al version by nel/tracemai to:lxd@>buux.no">lxd@>buux.noSEC_.
lxd.>buux.no kindly hosted by nel/tracehttp://www.redpill->bupro.no">Redpill Lbupro ASSEC_, proviace_of Lbuux up_prltass=ss="opode=traceservicecesince 1995.