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