parse_log.py
1 #!/usr/bin/env python3 2 3 import csv 4 import re 5 import sys 6 7 # import os 8 # parent_dir = os.path.dirname(os.path.dirname(os.path.abspath(__file__))) 9 # sys.path.append(parent_dir) 10 # # from components.paddock.telemetry.models import Coach 11 # from components.paddock.telemetry.pitcrew.message import Message 12 13 14 # One commonly used average reading speed for English is around 150 words per minute 15 # when spoken. This translates to 2.5 words per second. So you can estimate the time 16 # it takes to read a phrase out loud by counting the words and dividing by 2.5. 17 # or check https://github.com/alanhamlett/readtime 18 def read_time(msg=""): 19 words = len(msg.split(" ")) 20 # r_time = words / 1.5 21 r_time = words / 2.2 22 delta_add = 2.0 23 delta_add = 0.2 24 # self.log_debug(f"read_time: '{msg}' ({words}) {r_time:.1f} seconds + {delta_add:.1f} seconds") 25 # return words * 0.8 # avg ms per word 26 # return words / 2.5 # avg ms per word 27 return r_time + delta_add 28 29 30 def sorted_lines(lines): 31 lines_dicts = [] 32 for line in lines: 33 line_dict = {"line": line, "sort_key": 0.0} 34 # use pattern matching to extract stat_total_duration 35 # m = re.match(r'.*stat_total_duration=(\d+\.\d+)ms.*', line) 36 m = re.match(r".*status_code=(\d+) .*", line) 37 if m: 38 duration = float(m.group(1)) 39 # print(f'Duration: {duration}') 40 line_dict["sort_key"] = duration 41 42 lines_dicts.append(line_dict) 43 44 # now sort lines by sort_key 45 sorted_lines = sorted(lines_dicts, key=lambda line: line["sort_key"]) 46 47 for line in sorted_lines: 48 print("%s: %s" % (line["sort_key"], line["line"].strip())) 49 # print(line['line'].strip()) 50 51 52 def find_event(data, msg, is_none="play"): 53 for i in range(len(data) - 1, -1, -1): 54 if data[i]["msg"] == msg: 55 if data[i].get(is_none) is None: 56 return data[i] 57 else: 58 sys.stderr.write(f"Warning: {msg} already has {is_none} set to {data[i][is_none]}\n") 59 return {} 60 return {} 61 62 63 def extract_cc_data(lines): 64 data = [] 65 for line in lines: 66 # 19:27:57.502 : MQTT: queue mqtt_response_brake hard gear 3_0 - drt: 4141.392 67 m = re.match(r".*queue mqtt_response_([\w _]+) - drt: (\d+\.\d+).*", line) 68 if m: 69 event = {} 70 msg = m.group(1) 71 drt = m.group(2) 72 txt, distance = msg.split("_") 73 event["msg"] = msg 74 event["read_time"] = round(read_time(txt), 2) 75 event["queue"] = drt 76 event["distance"] = distance 77 data.append(event) 78 continue 79 # 19:29:17.923 : MQTT: play mqtt_response_brake hard gear 4_2842 - max: 2857 drt: 2842.955 80 m = re.match(r".*play mqtt_response_([\w _]+) - max: (\d+) drt: (\d+\.\d+).*", line) 81 if m: 82 msg = m.group(1) 83 max_distance = m.group(2) 84 drt = m.group(3) 85 event = find_event(data, msg, is_none="max_distance") 86 event["max_distance"] = max_distance 87 if event.get("distance") is not None: 88 event["max_delta"] = int(max_distance) - int(event["distance"]) 89 continue 90 # 19:29:19.442 : MQTT - AudioPlayer - COMPOUND_mqtt_response_brake hard gear 4_2842 finished drt: 2945.812 time: 1.5190201 # noqa: E501 91 m = re.match(r".*COMPOUND_mqtt_response_([\w _]+) finished drt: (\d+\.\d+) time: (\d+\.\d+).*", line) 92 if m: 93 msg = m.group(1) 94 drt = m.group(2) 95 play_time = m.group(3) 96 event = find_event(data, msg, is_none="play_time") 97 event["play_time"] = play_time 98 if event.get("read_time") is not None: 99 event["read_delta"] = round(float(play_time) - event["read_time"], 2) 100 event["finished"] = drt 101 continue 102 # 11:57:02.350 : MQTT - AudioPlayer - COMPOUND_mqtt_response_brake hard gear 2_4636 drt: 4639.859 speed: 24.06989 # noqa: E501 103 m = re.match(r".*COMPOUND_mqtt_response_([\w _]+) drt: (\d+\.\d+) speed: (\d+\.\d+).*", line) 104 if m: 105 msg = m.group(1) 106 drt = m.group(2) 107 speed = m.group(3) 108 event = find_event(data, msg, is_none="play") 109 if event.get("distance") is not None: 110 event["play_delta"] = round(float(drt) - float(event["distance"]), 2) 111 event["speed"] = speed 112 event["delta_speed_ratio"] = round(float(event["play_delta"]) / float(speed), 2) 113 event["play"] = drt 114 continue 115 # 19:29:48.669 : Clip COMPOUND_mqtt_response_brake 9_3809 has expired after being queued for 10032 milliseconds 116 m = re.match( 117 r".*Clip COMPOUND_mqtt_response_([\w _]+) has expired after being queued for (\d+) milliseconds.*", line 118 ) 119 if m: 120 msg = m.group(1) 121 queue_time = m.group(2) 122 event = find_event(data, msg) 123 event = find_event(data, msg, is_none="play") 124 event["not_played_reason"] = "expired" 125 event["expired"] = queue_time 126 continue 127 # 19:30:34.125 : Clip COMPOUND_mqtt_response_brake 5_1536will not be played because higher priority message is waiting to be played: penalties/cut_track_race_1 # noqa: E501 128 m = re.match( 129 r".*Clip COMPOUND_mqtt_response_([\w _]+)will not be played because higher priority message is waiting to be played: ([\w _]+).*", # noqa: E501 130 line, 131 ) 132 if m: 133 msg = m.group(1) 134 higher_priority_msg = m.group(2) 135 event = find_event(data, msg) 136 event = find_event(data, msg, is_none="play") 137 event["not_played_reason"] = "higher_priority_msg" 138 event["higher_priority_msg"] = higher_priority_msg 139 continue 140 141 # for event in data: 142 # print(event) 143 144 # convert data to a csv using csv module 145 # print csv lines to stdout 146 147 # print header 148 fieldnames = [ 149 "msg", 150 "queue", 151 "distance", 152 "play", 153 "play_delta", 154 "finished", 155 "max_delta", 156 "max_distance", 157 "speed", 158 "delta_speed_ratio", 159 "play_time", 160 "read_time", 161 "read_delta", 162 "not_played_reason", 163 "expired", 164 "higher_priority_msg", 165 ] 166 writer = csv.DictWriter(sys.stdout, fieldnames=fieldnames) 167 writer.writeheader() 168 for event in data: 169 writer.writerow(event) 170 171 172 lines = sys.stdin.readlines() 173 # sorted_lines(lines) 174 extract_cc_data(lines)