diff --git a/energy_model/analyze.py b/energy_model/analyze.py index c613aba..239dc36 100644 --- a/energy_model/analyze.py +++ b/energy_model/analyze.py @@ -25,33 +25,67 @@ class EnergyAnalyzer(): self.logger = EmptyLogger( "EnergyAnalyzer", isDebugging=self.DEBUG, printout=True) + ''' + Variable clean up functions + ''' def clean_up_cpu(self): + self.clean_up_cpu_data() + self.clean_up_cpu_result() + + def clean_up_cpu_data(self): self.data_cpu = [] # (sorted) cpu results of logs self.data_cpu_d = [] # deltas between pair of results + + def clean_up_cpu_result(self): self.instant_freqs = [] # freq of each core at time unit self.instant_utils = [] # util perc of each core at time unit self.instant_power = [] # power spent at time unit self.total_idle = [] # [cpu0, cpu1, ..., cpuN, cpuOverall] self.total_used = [] # [cpu0, cpu1, ..., cpuN, cpuOverall] - self.total_energy = 0 # unit as defined in unit - self.avg_power = 0 # average power across time - self.avg_utils = [] # [cpu0, cpu1, ..., cpuN, cpuOverall] - self.total_time = 0 + self.cpu_energy_total = 0 # unit as defined in unit + self.cpu_power_avg = 0 # average power across time + self.cpu_utils_avg = [] # [cpu0, cpu1, ..., cpuN, cpuOverall] + self.cpu_time_total = 0 def clean_up_net(self): + self.clean_up_net_data() + self.clean_up_wifi_result() + self.clean_up_lte_result() + + def clean_up_net_data(self): self.data_tcpdump = [] + # [[time, net_state, data_len], ...] + # net_state: 'i': 'idle', 'a': 'active', 't': 'tail' self.net_start_time = -1 self.net_end_time = -1 + # WiFi self.wifi_rssi = [] + # LTE self.lte_rsrp = [] + def clean_up_wifi_result(self): + self.wifi_energy = 0 + self.wifi_time = 0 + self.wifi_power = 0 + self.wifi_active_time = 0 + self.wifi_tail_time = 0 + self.wifi_tail_energy = 0 + self.wifi_active_energy = 0 + + def clean_up_lte_result(self): + pass + + ''' + CPU + ''' def read_cpu_log(self, filepath, - startT=None, endT=None): - self.logger.debug("re-initialize variables") - self.clean_up_cpu() + startT=float('-inf'), endT=float('inf')): + self.logger.debug("clean up cpu data") + self.clean_up_cpu_data() self.logger.debug("read_cpu_log started") contents = [] skipFirstTime = True + timeGap = 0.1 with open(filepath, 'rU') as f: contents = f.readlines() for line in contents: @@ -60,14 +94,18 @@ class EnergyAnalyzer(): print "something is wrong at splitting the line for cpu_log" sys.exit(-1) timestamp = int(tmp[0]) / 1000.0 # ms -> s - if (startT is not None and timestamp < startT) \ - or (endT is not None and timestamp > endT): + # self.logger.debug( + # "time: {0}, startT: {1}, endT: {2}".format( + # timestamp, startT, endT)) + if timestamp < (startT - timeGap) or timestamp > (endT + timeGap): continue + # self.logger.debug("passed") cpu_total_idle = int(tmp[1]) cpu_total_used = int(tmp[2]) cpu_per_core = [] if not skipFirstTime: delta_t = timestamp - self.data_cpu[-1][0] + timeGap = delta_t delta_total_idle = cpu_total_idle - self.data_cpu[-1][1] delta_total_used = cpu_total_used - self.data_cpu[-1][2] delta_per_core = [] @@ -92,6 +130,8 @@ class EnergyAnalyzer(): def parse_cpu_energy(self, power_base=0): + self.logger.debug("clean up cpu result") + self.clean_up_cpu_result() if len(self.data_cpu_d) < 1: self.logger.error("parse_cpu_energy finds delta empty") self.logger.error(self.data_cpu) @@ -102,7 +142,7 @@ class EnergyAnalyzer(): # allocate memory self.total_idle = [0 for i in xrange(num_of_cores + 1)] self.total_used = [0 for i in xrange(num_of_cores + 1)] - self.avg_utils = [0 for i in xrange(num_of_cores + 1)] + self.cpu_utils_avg = [0 for i in xrange(num_of_cores + 1)] for result in self.data_cpu_d: # allocate memory freqs = [0 for i in xrange(num_of_cores)] @@ -136,29 +176,22 @@ class EnergyAnalyzer(): self.instant_power.append(instant_power) energy = instant_power * result[0] else: - self.instant_power.append(instant_power / result[0]) + self.instant_power.append( + instant_power / result[0] - power_base) instant_power -= power_base * result[0] energy = instant_power - self.total_time += result[0] - self.total_energy += energy - self.avg_power = self.total_energy / self.total_time + self.cpu_time_total += result[0] + self.cpu_energy_total += energy + self.cpu_power_avg = self.cpu_energy_total / self.cpu_time_total for i in xrange(num_of_cores + 1): - self.avg_utils[i] = 1.0 * \ + self.cpu_utils_avg[i] = 1.0 * \ self.total_used[i] / (self.total_used[i] + self.total_idle[i]) - - self.logger.info( - "total energy: {0:.4f}mJ".format(self.total_energy)) - self.logger.info( - "total time: {0:.4f}s".format(self.total_time)) - self.logger.info( - "average power: {0:.4f}mW".format(self.avg_power)) - self.logger.info( - "average util: {0}".format( - ",".join( - ["{0:.2f}%".format(x * 100) for x in self.avg_utils]))) # self.logger.debug(self.instant_power) self.logger.debug("parse_cpu_energy ended") + ''' + Network + ''' def read_sslogger_file(self, fp_sslogger): if not os.path.isfile(fp_sslogger): self.logger.error( @@ -178,7 +211,7 @@ class EnergyAnalyzer(): # [timestamp (us), wifi rssi] # or # [timestamp (us), gsm rssi, lte ss, lte rsrp, lte rsrq] - tmp = list(myMatch.groups()) + tmp = myMatch.groups() break if tmp is None: self.logger.debug("nothing found in {0}".format(line.rstrip())) @@ -210,7 +243,7 @@ class EnergyAnalyzer(): content = f.readlines() firstLine = True # check the network status: idle, active, or tail - net_state = 'i' # idle + net_state = 'a' # active for line in content: tmp = None for pattern in myPatterns: @@ -262,21 +295,25 @@ class EnergyAnalyzer(): def read_wifi_log(self, fp_tcpdump, tcpdump_filter="", fp_sslogger=None): + self.logger.debug("clean up network data") + self.clean_up_net_data() self.logger.debug("read_wifi_log started") - self.logger.debug("re-initialize variables") - self.clean_up_net() # parse tcpdump file self.logger.debug("parse tcpdump") - if not os.path.isfile(fp_tcpdump): - self.logger.error( - "tcpdump file {0} does not exist".format(fp_tcpdump)) - sys.exit(-1) if ".tcpdump" not in fp_tcpdump: - # generate the parsed tcpdump file - subprocess.call( - "tcpdump -tt -n -r {0} {1} > {0}.tcpdump".format( - fp_tcpdump, tcpdump_filter), - shell=True) + if not os.path.isfile("{0}.tcpdump".format(fp_tcpdump)): + # check if raw file exists + if not os.path.isfile(fp_tcpdump): + self.logger.error( + "tcpdump file {0} does not exist".format(fp_tcpdump)) + sys.exit(-1) + # generate the parsed tcpdump file + subprocess.call( + "tcpdump -tt -n -r {0} {1} > {0}.tcpdump".format( + fp_tcpdump, tcpdump_filter), + shell=True) + # remove the big file as it is too big + subprocess.call("rm {0}".format(fp_tcpdump), shell=True) fp_tcpdump += '.tcpdump' # read the file self.read_tcpdump_file(fp_tcpdump, isWiFi=True) @@ -293,11 +330,91 @@ class EnergyAnalyzer(): self.read_sslogger_file(fp_sslogger) self.logger.debug("read_wifi_log ended") - def parse_wifi_energy(self, power_base=0): + def parse_wifi_energy(self, power_base=0, isTX=True): + self.logger.debug("clean up wifi result") + self.clean_up_wifi_result() + if len(self.data_tcpdump) < 2: + self.logger.error("parse_wifi_energy finds data_tcpdump empty") + self.logger.error(self.data_tcpdump) + self.logger.error("did you call read_wifi_log?") + return self.logger.debug("parse_wifi_energy started") - + # by default assume the rssi is the max + curRSSI = sorted( + self.myModel.net_wifi['active'].keys(), reverse=True)[0] + # derive energy for wifi network + for i in xrange(len(self.data_tcpdump) - 1): + diffT = self.data_tcpdump[i + 1][0] - self.data_tcpdump[i][0] + # self.logger.debug("diffT: {0:.8f}".format(diffT)) + # self.logger.debug("{0}".format(self.data_tcpdump[i])) + if self.data_tcpdump[i][1] == 'a': + curPower = self.myModel.get_wifi_active_energy( + diffT, curRSSI) + # check if returned is power (watt) or energy (joule) + if self.myModel.using_power: + # subtract base (background) if desired + curPower -= power_base + energy = curPower * diffT + else: + curPower -= power_base * diffT + energy = curPower + self.wifi_active_energy += energy + self.wifi_active_time += diffT + elif self.data_tcpdump[i][1] == 't': + curPower = self.myModel.get_wifi_tail_energy(diffT) + # check if returned is power (watt) or energy (joule) + if self.myModel.using_power: + # subtract base (background) if desired + curPower -= power_base + energy = curPower * diffT + else: + curPower -= power_base * diffT + energy = curPower + self.wifi_tail_energy += energy + self.wifi_tail_time += diffT + else: + self.logger.debug("{0}".format(self.data_tcpdump[i])) + self.logger.error( + "net_state is not recognized: {0}".format( + self.data_tcpdump[i][1])) + self.wifi_energy = self.wifi_active_energy + self.wifi_tail_energy + self.wifi_time = self.wifi_active_time + self.wifi_tail_time + try: + self.wifi_power = self.wifi_energy / self.wifi_time + except: + self.wifi_power = -1 self.logger.debug("parse_wifi_energy ended") + def generate_result_summary(self, cpu=True, wifi=True): + ''' + Print summary of the results + ''' + + self.logger.info("total energy: {0:.4f}mJ".format( + self.cpu_energy_total + self.wifi_energy)) + + if cpu: + self.logger.info( + "total cpu energy: {0:.4f}mJ".format(self.cpu_energy_total)) + self.logger.info( + "total cpu time: {0:.4f}s".format(self.cpu_time_total)) + self.logger.info( + "average cpu power: {0:.4f}mW".format(self.cpu_power_avg)) + self.logger.info( + "average cpu util: {0}".format( + ",".join( + ["{0:.2f}%".format(x * 100) + for x in self.cpu_utils_avg]))) + if wifi: + self.logger.info( + "total wifi energy: {0:.4f}mJ".format(self.wifi_energy)) + self.logger.info( + "total wifi time: {0:.4f}s".format(self.wifi_time)) + self.logger.info( + "total wifi power: {0:.4f}mW".format(self.wifi_power)) + self.logger.info( + "active wifi {0:.4f}mW vs. idle {1:.4f}mW".format( + self.wifi_active_energy, self.wifi_tail_energy)) if __name__ == "__main__": # cpuFile = sys.argv[1] @@ -308,14 +425,12 @@ if __name__ == "__main__": print ".....!" sys.exit(-1) myObj = EnergyAnalyzer("shamu", isDebugging=True, unit="mW") - myObj.read_cpu_log(cpuFile) - myObj.parse_cpu_energy() myObj.read_wifi_log( tcpdumpFile, fp_sslogger=ssFile, tcpdump_filter="host 128.111.68.220") myObj.parse_wifi_energy() - # for i in xrange(1, len(myObj.freqs)): - # print myObj.freqs[i] - myObj.freqs[i-1] - # myObj.get_wifi_tail_energy(1) - # myObj.get_wifi_active_energy(1, -60, isTX=False) - # myObj.get_cpu_energy(1, [1036800, 422400], [0, 1]) \ No newline at end of file + myObj.read_cpu_log( + cpuFile, + startT=myObj.net_start_time, endT=myObj.net_end_time) + myObj.parse_cpu_energy() + myObj.generate_result_summary() diff --git a/energy_model/modules/model.py b/energy_model/modules/model.py index 3628dda..783fbb6 100644 --- a/energy_model/modules/model.py +++ b/energy_model/modules/model.py @@ -152,6 +152,8 @@ class Model(): @param time: s @return defined energy with unit conversion ''' + # self.logger.debug("current: {0}, time_diff: {1:.8f}".format( + # current, time)) if 'W' in self.unit: tmp = current * self.voltage elif 'J' in self.unit: @@ -160,6 +162,7 @@ class Model(): self.logger.error( "Unit {0} not supported!".format(self.unit)) sys.exit(-1) + # self.logger.debug("tmp: {0}".format(tmp, current * self.voltage)) if 'm' == self.unit[0]: return tmp else: @@ -197,12 +200,12 @@ class Model(): active_current = db[i][freq[i]][0] idle_current = db[i][freq[i]][1] current += util[i] * active_current + (1 - util[i]) * idle_current - # derive energy - energy = self.get_final_energy(current, time_diff) + # derive power or energy + result = self.get_final_energy(current, time_diff) self.logger.debug( "duration: {0:.4f}s, cpu_energy: {1:.4f}{2}".format( - time_diff, energy, self.unit)) - return energy + time_diff, result, self.unit)) + return result def get_lte_prom_energy(self, time_diff, rssi, isTX=True): self.logger.error('TODO: not implemented yet') @@ -233,25 +236,25 @@ class Model(): if rssi >= table_rssi[i]: endp = self.net_wifi['active'][table_rssi[i-1]][currentIdx] startp = self.net_wifi['active'][table_rssi[i]][currentIdx] - rssi_diff = table_rssi[i-1] - table_rssi[i] + rssi_diff = table_rssi[i - 1] - table_rssi[i] current = (endp + 1.0 * (endp - startp) * (rssi - table_rssi[i-1]) / rssi_diff) break if current is None: self.logger.error("Current {0} is nothing!".format(current)) sys.exit(-1) - # derive energy - energy = self.get_final_energy(current, time_diff) - self.logger.debug( - "wifi_active_energy: {0:.4f}{1}".format(energy, self.unit)) - return energy + # derive power or energy + result = self.get_final_energy(current, time_diff) + # self.logger.debug( + # "cpu_energy: {0:.4f}{1}".format(result, self.unit)) + return result def get_wifi_tail_energy(self, time_diff): current = self.net_wifi['tail']['0'][1] - energy = self.get_final_energy(current, time_diff) - self.logger.debug( - "wifi_active_energy: {0:.4f}{1}".format(energy, self.unit)) - return energy + result = self.get_final_energy(current, time_diff) + # self.logger.debug( + # "cpu_energy: {0:.4f}{1}".format(result, self.unit)) + return result if __name__ == "__main__": print "Usage: from model import *"