• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1import sys
2import os
3from datetime import datetime
4
5# Usage:
6# python3 parse_timing.py logcat.txt "08-23 23:10:32.555" 10 200
7#
8# Description: extract events and timing in the log that start from timestamp "08-23 23:10:32.555"
9# till 10 seconds
10#
11# Usage:
12# python3 parse_timing.py logcat1.txt logcat2.txt 10 ts1 ts1 200
13#
14# Description: report the timing that the differences are bigger than 200
15#
16# Example:
17# python3 log_processing/parse_timing.py 8976224/logcat.txt 8879724/logcat.txt
18# "08-23 23:10:32.555" "07-29 06:39:06.254" 200
19def main():
20   if len(sys.argv) == 5:
21      process_one_log()
22   elif len(sys.argv) == 6:
23      compair_two_log()
24   else:
25      print("wrong number of arguments")
26
27def compair_two_log():
28   filepath1 = sys.argv[1]
29   print(filepath1)
30   if not os.path.isfile(filepath1):
31       print("File path {} does not exist. Exiting...".format(filepath1))
32       sys.exit()
33
34   filepath2 = sys.argv[2]
35   print(filepath2)
36   if not os.path.isfile(filepath2):
37       print("File path {} does not exist. Exiting...".format(filepath2))
38       sys.exit()
39
40   ts1 = datetime.strptime(sys.argv[3], '%m-%d %H:%M:%S.%f')
41   ts2 = datetime.strptime(sys.argv[4], '%m-%d %H:%M:%S.%f')
42   duration = float(sys.argv[5])*1000
43
44   # 1: took to complete 1000ms
45   # 2: took 33ms
46   # 3: took 33 ms or took 0.3 seconds
47   file1_events = [{}, {}, {}]
48   file2_events = [{}, {}, {}]
49
50   extract_events(filepath1, file1_events, ts1, duration)
51   extract_events(filepath2, file2_events, ts2, duration)
52
53
54   sum_events_timing(file1_events)
55   sum_events_timing(file2_events)
56
57   sum_all_events_timing_diff(file1_events, file2_events)
58
59   sys.exit()
60
61
62def process_one_log():
63   filepath = sys.argv[1]
64   print(filepath)
65   if not os.path.isfile(filepath):
66       print("File path {} does not exist. Exiting...".format(filepath))
67       sys.exit()
68
69   # 1: took to complete 1000ms
70   # 2: took 33ms
71   # 3: took 33 ms or took 0.3 seconds
72   events = [{}, {}, {}]
73   ts = datetime.strptime(sys.argv[2], '%m-%d %H:%M:%S.%f')
74   duration = float(sys.argv[3])*1000
75   extract_events(filepath, events, ts, duration)
76
77   timing = float(sys.argv[3])
78   print_sorted_all_events(events, timing)
79
80   sys.exit()
81
82def print_sorted_all_events(file_events, timing):
83   for i in range(len(file_events)):
84      print_sorted_events(file_events[i], timing)
85
86def print_sorted_events(events, timing):
87   for word in sorted(events, key=events.get, reverse=True):
88      if (events[word]) > timing:
89         print("event:{} \ttiming:{} ".format(word, events[word]))
90
91def sum_events_timing(events):
92   total_sum = 0;
93   for i in range(len(events)):
94      sum = 0
95      print("start summary for type {}".format(i))
96      for event in events[i]:
97         sum += events[i][event]
98         #print("event {} timing {} ".format(event, events[i][event]))
99      print("sum events type {} {} : timing {}".format(i, len(events), sum))
100      total_sum += sum
101   print("sum all type events timing {}\n".format(total_sum))
102
103def sum_events_timing_diff(type, file1_events, file2_events):
104   sum_diff = 0
105   max_diff = 0
106   regression_events = {}
107   print("start summary for type {}".format(type))
108   for event in file1_events:
109      val = file2_events.get(event)
110      if val != None:
111         diff = file1_events[event] - val
112         if diff > 100 and val > 100:
113            # print("regression event {} \t{}: {} \t{}: {} \tdiff: {}"
114            #      .format(event, "case1", file1_events[event], "case2", val, diff))
115            regression_events[event] = diff
116            sum_diff += diff
117            max_diff = max(max_diff, diff)
118   print("\nsummary for timing type {} sum_diff {} max_diff {}".format(type, sum_diff, max_diff))
119   print_events(regression_events, file1_events, file2_events)
120
121def sum_all_events_timing_diff(file1_events, file2_events):
122   for i in range(len(file1_events)):
123      sum_events_timing_diff(i, file1_events[i], file2_events[i])
124
125def print_events(events, file1_events, file2_events):
126   for word in sorted(events, key=events.get, reverse=True):
127      if (events[word]) > 10:
128          print("{} \tdiff {} \t{} \t{}".format(word, events[word],file1_events[word], file2_events[word]))
129
130def find_took(words):
131   for i in range(len(words)):
132      if words[i] == 'took' or words[i] == "took:":
133         return i
134
135def extract_time(line, events):
136   if not "took" in line:
137      return
138
139   # 1: took to complete 1000ms
140   # 2: took 33ms
141   # 3: took 33 ms or took 0.3 seconds
142   words = line.strip().split(' ')
143   i = find_took(words)
144   index = 0;
145   str1 = " "
146   key = str1.join(words[8:i])
147
148   if words[i+1] == 'to' and words[i+2] == 'complete:':
149      index = 0;
150      val = float(words[i+3][:-2]);
151   elif words[i+1][-2:] == 'ms':
152      index = 1
153      val = float(words[i+1][:-2]);
154   elif len(words) > i+2:
155      index = 2
156      if words[i+2] == 'seconds':
157         val = float(words[i+1])*1000;
158      elif words[i+2] == 'ms':
159         val = float(words[i+1])
160      else:
161         return True
162
163   # print("index: {}  key: {} val: {}".format(index, key, val));
164
165   if events[index].get(key) == None:
166      events[index][key] = val
167      return True
168   else:
169      # print("duplicate key: " + key + " line: " + line)
170      return True
171
172def check_time_range(line, ts, duration):
173   index = line.find(" ", 6)
174   if index <= 0:
175      return False
176
177   try:
178      current_time = datetime.strptime(line[:index], '%m-%d %H:%M:%S.%f')
179   except ValueError:
180      return False
181
182   deltatime = current_time - ts
183   if deltatime.total_seconds()*1000 < 0 or deltatime.total_seconds() > duration:
184      return False
185   return True
186
187def extract_events(filepath, events, ts, duration):
188   with open(filepath, errors='ignore') as fp:
189      for line in fp:
190         if check_time_range(line, ts, duration) == False:
191            continue
192         if extract_time(line, events) == False:
193            return
194
195
196if __name__ == '__main__':
197    main()
198