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