| 1 | #!/usr/bin/env python2 |
| 2 | # softirqtimes.py |
| 3 | # |
| 4 | # Babeltrace time of softirqs example script |
| 5 | # |
| 6 | # Copyright 2012 EfficiOS Inc. |
| 7 | # |
| 8 | # Author: Danny Serres <danny.serres@efficios.com> |
| 9 | # |
| 10 | # Permission is hereby granted, free of charge, to any person obtaining a copy |
| 11 | # of this software and associated documentation files (the "Software"), to deal |
| 12 | # in the Software without restriction, including without limitation the rights |
| 13 | # to use, copy, modify, merge, publish, distribute, sublicense, and/or sell |
| 14 | # copies of the Software, and to permit persons to whom the Software is |
| 15 | # furnished to do so, subject to the following conditions: |
| 16 | # |
| 17 | # The above copyright notice and this permission notice shall be included in |
| 18 | # all copies or substantial portions of the Software. |
| 19 | |
| 20 | # The script checks the number of events in the trace |
| 21 | # and outputs a table and a .svg histogram for the specified |
| 22 | # range (microseconds) or the total trace if no range specified. |
| 23 | # The graph is generated using the cairoplot module. |
| 24 | |
| 25 | # The script checks the trace for the amount of time |
| 26 | # spent from each softirq_raise to softirq_exit. |
| 27 | # It prints out the min, max (with timestamp), |
| 28 | # average times, the standard deviation and the total count. |
| 29 | # Using the cairoplot module, a .svg graph is also outputted |
| 30 | # showing the taken time in function of the time since the |
| 31 | # beginning of the trace. |
| 32 | |
| 33 | import sys, math |
| 34 | from output_format_modules import cairoplot |
| 35 | from babeltrace import * |
| 36 | |
| 37 | if len(sys.argv) < 2: |
| 38 | raise TypeError("Usage: python softirqtimes.py path/to/trace") |
| 39 | |
| 40 | ctx = Context() |
| 41 | ret = ctx.add_trace(sys.argv[1], "ctf") |
| 42 | if ret is None: |
| 43 | raise IOError("Error adding trace") |
| 44 | |
| 45 | time_taken = [] |
| 46 | graph_data = [] |
| 47 | max_time = (0.0, 0.0) # (val, ts) |
| 48 | |
| 49 | # tmp template: {(cpu_id, vec):TS raise} |
| 50 | tmp = {} |
| 51 | largest_val = 0 |
| 52 | |
| 53 | # Setting iterator |
| 54 | bp = IterPos(SEEK_BEGIN) |
| 55 | ctf_it = ctf.Iterator(ctx, bp) |
| 56 | |
| 57 | # Reading events |
| 58 | event = ctf_it.read_event() |
| 59 | start_time = event.get_timestamp() |
| 60 | while(event is not None): |
| 61 | |
| 62 | event_name = event.get_name() |
| 63 | error = True |
| 64 | appendNext = False |
| 65 | |
| 66 | if event_name == 'softirq_raise' or event_name == 'softirq_exit': |
| 67 | # Recover cpu_id and vec values to make a key to tmp |
| 68 | error = False |
| 69 | scope = event.get_top_level_scope(ctf.scope.STREAM_PACKET_CONTEXT) |
| 70 | field = event.get_field(scope, "cpu_id") |
| 71 | cpu_id = field.get_uint64() |
| 72 | if ctf.field_error(): |
| 73 | print("ERROR: Missing cpu_id info for {}".format( |
| 74 | event.get_name())) |
| 75 | error = True |
| 76 | |
| 77 | scope = event.get_top_level_scope(ctf.scope.EVENT_FIELDS) |
| 78 | field = event.get_field(scope, "_vec") |
| 79 | vec = field.get_uint64() |
| 80 | if ctf.field_error(): |
| 81 | print("ERROR: Missing vec info for {}".format( |
| 82 | event.get_name())) |
| 83 | error = True |
| 84 | key = (cpu_id, vec) |
| 85 | |
| 86 | if event_name == 'softirq_raise' and not error: |
| 87 | # Add timestamp to tmp |
| 88 | if key in tmp: |
| 89 | # If key already exists |
| 90 | i = 0 |
| 91 | while True: |
| 92 | # Add index |
| 93 | key = (cpu_id, vec, i) |
| 94 | if key in tmp: |
| 95 | i += 1 |
| 96 | continue |
| 97 | if i > largest_val: |
| 98 | largest_val = i |
| 99 | break |
| 100 | |
| 101 | tmp[key] = event.get_timestamp() |
| 102 | |
| 103 | if event_name == 'softirq_exit' and not error: |
| 104 | # Saving data for output |
| 105 | # Key check |
| 106 | if not (key in tmp): |
| 107 | i = 0 |
| 108 | while i <= largest_val: |
| 109 | key = (key[0], key[1], i) |
| 110 | if key in tmp: |
| 111 | break |
| 112 | i += 1 |
| 113 | |
| 114 | raise_timestamp = tmp[key] |
| 115 | time_data = event.get_timestamp() - tmp.pop(key) |
| 116 | if time_data > max_time[0]: |
| 117 | # max_time = (val, ts) |
| 118 | max_time = (time_data, raise_timestamp) |
| 119 | time_taken.append(time_data) |
| 120 | graph_data.append((raise_timestamp - start_time, time_data)) |
| 121 | |
| 122 | # Next Event |
| 123 | ret = ctf_it.next() |
| 124 | if ret < 0: |
| 125 | break |
| 126 | event = ctf_it.read_event() |
| 127 | |
| 128 | |
| 129 | del ctf_it |
| 130 | |
| 131 | # Standard dev. calc. |
| 132 | try: |
| 133 | mean = sum(time_taken)/float(len(time_taken)) |
| 134 | except ZeroDivisionError: |
| 135 | raise TypeError("empty data") |
| 136 | deviations_squared = [] |
| 137 | for x in time_taken: |
| 138 | deviations_squared.append(math.pow((x - mean), 2)) |
| 139 | try: |
| 140 | stddev = math.sqrt(sum(deviations_squared) / (len(deviations_squared) - 1)) |
| 141 | except ZeroDivisionError: |
| 142 | stddev = '-' |
| 143 | |
| 144 | # Terminal output |
| 145 | print("AVG TIME: {} ns".format(mean)) |
| 146 | print("MIN TIME: {} ns".format(min(time_taken))) |
| 147 | print("MAX TIME: {} ns, TS: {}".format(max_time[0], max_time[1])) |
| 148 | print("STD DEV: {}".format(stddev)) |
| 149 | print("TOTAL COUNT: {}".format(len(time_taken))) |
| 150 | |
| 151 | # Graph output |
| 152 | cairoplot.scatter_plot ( 'softirqtimes.svg', data = graph_data, |
| 153 | width = 5000, height = 4000, border = 20, axis = True, |
| 154 | grid = True, series_colors = ["red"] ) |