diff --git a/wetb/hawc2/log_file.py b/wetb/hawc2/log_file.py index 182fb063beb339a0ff3f55f26a1f923264b68847..1b803534687a241744c1070676efe3165bfb4a40 100644 --- a/wetb/hawc2/log_file.py +++ b/wetb/hawc2/log_file.py @@ -6,10 +6,12 @@ Created on 18/11/2015 import os from wetb.hawc2.htc_file import HTCFile from collections import OrderedDict +import time +import math +UNKNOWN = "Unknown" MISSING = "Log file cannot be found" PENDING = "Simulation not started yet" INITIALIZATION = 'Initializing simulation' -GENERATING_TURBULENCE = "Generating turbulence" SIMULATING = "Simulating" ABORTED = "" DONE = "Simulation succeded" @@ -31,63 +33,115 @@ def is_file_open(filename): return True class LogFile(object): - _status = (0, MISSING) def __init__(self, log_filename, time_stop): self.filename = log_filename self.time_stop = time_stop + self.reset() + self.update_status() + + @staticmethod + def from_htcfile(htcfile, modelpath): + logfilename = htcfile.simulation.logfile[0] + if not os.path.isabs(logfilename): + logfilename = os.path.join(modelpath, logfilename) + return LogFile(logfilename, htcfile.simulation.time_stop[0]) + + def reset(self): self.position = 0 + self.lastline = "" + self.status = UNKNOWN + self.pct = 0 + self.errors = [] + self.info = [] + self.start_time = None + self.current_time = 0 + self.remaining_time = None + def clear(self): os.makedirs(os.path.dirname(self.filename), exist_ok=True) with open(self.filename, 'w'): pass - self.position = 0 + self.reset() - def status(self): + def extract_time(self, time_line): + time_line = time_line.strip() + if 'Starting simulation' == time_line: + return 0 + if time_line == "": + return self.current_time + try: + return float(time_line[time_line.index('=') + 1:time_line.index('Iter')]) + except: + print ("#" + time_line + "#") + pass + + def update_status(self): if not os.path.isfile(self.filename): - self._status = (0, MISSING, []) + self.status = MISSING else: - if self._status[1] == MISSING: - self._status = (0, PENDING, []) - with open(self.filename) as fid: + if self.status == UNKNOWN or self.status == MISSING: + self.status = PENDING + with open(self.filename, 'rb') as fid: fid.seek(self.position) txt = fid.read() self.position += len(txt) - if self._status[1] == PENDING and self.position > 0: - self._status = (0, INITIALIZATION, []) - error_lst = self._status[2] + txt = txt.decode(encoding='utf_8', errors='strict') + if self.status == PENDING and self.position > 0: + self.status = INITIALIZATION + if len(txt) > 0: - if self._status[1] == INITIALIZATION or self._status[1] == GENERATING_TURBULENCE: + self.lastline = (txt.strip()[max(0, txt.strip().rfind("\n")):]).strip() + if self.status == INITIALIZATION: init_txt, *rest = txt.split("Starting simulation") if "*** ERROR ***" in init_txt: - error_lst.extend([l for l in init_txt.strip().split("\n") if "ERROR" in l]) - if "Turbulence generation starts" in init_txt[init_txt.strip().rfind("\n"):]: - self._status = (0, GENERATING_TURBULENCE, error_lst) + self.errors.extend([l.strip() for l in init_txt.strip().split("\n") if "error" in l.lower()]) if rest: txt = rest[0] - self._status = (0, SIMULATING, error_lst) - if self._status[1] == SIMULATING: + self.status = SIMULATING + if not 'Elapsed time' in self.lastline: + self.start_time = (self.extract_time(self.lastline), time.time()) + if self.status == SIMULATING: simulation_txt, *rest = txt.split('Elapsed time') if "*** ERROR ***" in simulation_txt: - error_lst.extend([l for l in simulation_txt.strip().split("\n") if "ERROR" in l]) + self.errors.extend([l.strip() for l in simulation_txt.strip().split("\n") if "error" in l.lower()]) i1 = simulation_txt.rfind("Global time") i2 = simulation_txt[:i1].rfind('Global time') - time_line = simulation_txt[i1:] - try: - time = float(time_line[time_line.index('=') + 1:time_line.index('Iter')]) - self._status = (int(100 * time // self.time_stop), SIMULATING, error_lst) - except: - self._status = (self._status[0], SIMULATING, error_lst) + self.current_time = self.extract_time(simulation_txt[i1:]) + self.pct = int(100 * self.current_time // self.time_stop) + if self.current_time is not None and self.start_time is not None and (self.current_time - self.start_time[0]) > 0: + self.remaining_time = (time.time() - self.start_time[1]) / (self.current_time - self.start_time[0]) * (self.time_stop - self.current_time) if rest: - self._status = (100, DONE, error_lst) - #return self._status + self.status = DONE + self.pct = 100 + self.elapsed_time = float(rest[0].replace(":", "").strip()) - error_lst = self._status[2] + def error_str(self): error_dict = OrderedDict() - for error in error_lst: + for error in self.errors: error_dict[error] = error_dict.get(error, 0) + 1 - error_lst = [("%d x %s" % (v, k), k)[v == 1] for k, v in error_dict.items()] + return "\n".join([("%d x %s" % (v, k), k)[v == 1] for k, v in error_dict.items()]) + + + def remaining_time_str(self): + if self.remaining_time: + if self.remaining_time < 3600: + m, s = divmod(self.remaining_time, 60) + return "%02d:%02d" % (m, math.ceil(s)) + else: + h, ms = divmod(self.remaining_time, 3600) + m, s = divmod(ms, 60) + return "%d:%02d:%02d" % (h, m, math.ceil(s)) + else: + return "--:--" + + def add_HAWC2_errors(self, errors): + if errors: + self.status = ERROR + self.errors.extend(errors) + + + - return (self._status[0], self._status[1], error_lst) diff --git a/wetb/hawc2/simulation.py b/wetb/hawc2/simulation.py index 4cc14c5bfbd38e6d37bfacbf34da6d3863b2028d..7685a0f741ba95c3ffcd173ff2ba2bbd5eccfbb5 100644 --- a/wetb/hawc2/simulation.py +++ b/wetb/hawc2/simulation.py @@ -160,10 +160,8 @@ class SimulationThread(Thread): def start(self): - print (self.getName(), self.htcfile, self.modelpath, self.hawc2exe) si = subprocess.STARTUPINFO() si.dwFlags |= subprocess.STARTF_USESHOWWINDOW - #self.hawc2exe = r'C:\mmpe\programming\python\MMPE\programs\getcwd\getcwd_dist\exe.win-amd64-3.3/getcwd.exe' CREATE_NO_WINDOW = 0x08000000 self.process = subprocess.Popen([self.hawc2exe, self.htcfile], stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=False, cwd=self.modelpath, creationflags=CREATE_NO_WINDOW) diff --git a/wetb/hawc2/tests/test_files/logfiles/finish.log b/wetb/hawc2/tests/test_files/logfiles/finish.log index aa61371d379524d91c8d38120ed2657dd02a88ac..a2a5fdd00f73768d173ed7c3afe3d65f46c0f8f7 100644 Binary files a/wetb/hawc2/tests/test_files/logfiles/finish.log and b/wetb/hawc2/tests/test_files/logfiles/finish.log differ diff --git a/wetb/hawc2/tests/test_logfile.py b/wetb/hawc2/tests/test_logfile.py index c9875ba9047ed47d555f6c3c99d95f1bcb329154..2a084e43814ad6f3ed583106ebcb99eb703f64f3 100644 --- a/wetb/hawc2/tests/test_logfile.py +++ b/wetb/hawc2/tests/test_logfile.py @@ -5,12 +5,13 @@ Created on 18/11/2015 ''' import unittest from wetb.hawc2.log_file import LogFile, is_file_open, INITIALIZATION_ERROR, \ - INITIALIZATION, SIMULATING, DONE, SIMULATION_ERROR, GENERATING_TURBULENCE, \ - PENDING + INITIALIZATION, SIMULATING, DONE, SIMULATION_ERROR, \ + PENDING, ERROR import time from wetb.hawc2 import log_file import threading import os +from wetb.hawc2.htc_file import HTCFile def simulate(file, wait): with open(file, 'r') as fin: @@ -29,12 +30,17 @@ def simulate(file, wait): class Test(unittest.TestCase): + def test_from_htcfile(self): + htcfile = HTCFile('test_files/logfiles/model/htc/dlc14_iec61400-1ed3/dlc14_wsp10_wdir000_s0000.htc') + logfile = LogFile.from_htcfile(htcfile, 'test_files/logfiles/model/') + self.assertEqual(logfile.status, DONE) + def test_missing_logfile(self): f = 'test_files/logfiles/missing.log' logfile = LogFile(f, 200) - status = logfile.status() - self.assertEqual(status[0], 0) - self.assertEqual(status[1], log_file.MISSING) + logfile.update_status() + self.assertEqual(logfile.pct, 0) + self.assertEqual(logfile.status, log_file.MISSING) def test_is_file_open(self): @@ -48,81 +54,85 @@ class Test(unittest.TestCase): def test_simulation_init_error(self): f = 'test_files/logfiles/init_error.log' logfile = LogFile(f, 2) - code, txt, err = logfile.status() - self.assertEqual(code, 100) - self.assertEqual(txt, DONE) - self.assertEqual(err, [' *** ERROR *** No line termination in command line 8']) + logfile.update_status() + self.assertEqual(logfile.pct, 100) + self.assertEqual(logfile.status, DONE) + self.assertEqual(logfile.errors, ['*** ERROR *** No line termination in command line 8']) def test_init(self): f = 'test_files/logfiles/init.log' logfile = LogFile(f, 200) - code, txt, err = logfile.status() - self.assertEqual(code, 0) - self.assertEqual(txt, INITIALIZATION) - self.assertEqual(err, []) + logfile.update_status() + self.assertEqual(logfile.pct, 0) + self.assertEqual(logfile.status, INITIALIZATION) + self.assertEqual(logfile.errors, []) def test_turbulence_generation(self): f = 'test_files/logfiles/turbulence_generation.log' logfile = LogFile(f, 200) - code, txt, err = logfile.status() - self.assertEqual(code, 0) - self.assertEqual(txt, GENERATING_TURBULENCE) - self.assertEqual(err, []) + logfile.update_status() + self.assertEqual(logfile.pct, 0) + self.assertEqual(logfile.status, INITIALIZATION) + self.assertEqual(logfile.errors, []) + self.assertEqual(logfile.lastline, "Turbulence generation starts ...") def test_simulation(self): f = 'test_files/logfiles/simulating.log' logfile = LogFile(f, 2) - code, txt, err = logfile.status() - self.assertEqual(code, 25) - self.assertEqual(txt, SIMULATING) - self.assertEqual(err, []) + logfile.update_status() + self.assertEqual(logfile.pct, 25) + self.assertEqual(logfile.status, SIMULATING) + self.assertEqual(logfile.errors, []) + def test_finish(self): f = 'test_files/logfiles/finish.log' logfile = LogFile(f, 200) - code, txt, err = logfile.status() - self.assertEqual(code, 100) - self.assertEqual(txt, DONE) - self.assertEqual(err, []) + self.assertEqual(logfile.pct, 100) + self.assertEqual(logfile.status, DONE) + self.assertEqual(logfile.errors, []) + self.assertEqual(logfile.elapsed_time, 0.8062344) def test_simulation_error(self): f = 'test_files/logfiles/simulation_error.log' logfile = LogFile(f, 2) - code, txt, err = logfile.status() - self.assertEqual(code, 100) - self.assertEqual(txt, DONE) - self.assertEqual(err, [' *** ERROR *** Error opening out .dat file']) + self.assertEqual(logfile.pct, 100) + self.assertEqual(logfile.status, DONE) + self.assertEqual(logfile.errors, ['*** ERROR *** Error opening out .dat file']) def test_simulation_error2(self): f = 'test_files/logfiles/simulation_error2.log' logfile = LogFile(f, 2) - code, txt, err = logfile.status() - self.assertEqual(code, 100) - self.assertEqual(txt, DONE) - self.assertEqual(err, ['30 x *** ERROR *** Out of limits in user defined shear field - limit value used']) + self.assertEqual(logfile.pct, 100) + self.assertEqual(logfile.status, DONE) + self.assertEqual(logfile.errors[0], '*** ERROR *** Out of limits in user defined shear field - limit value used') + self.assertEqual(logfile.error_str(), '30 x *** ERROR *** Out of limits in user defined shear field - limit value used') + - def check(self, logfilename, phases, end_status): + def check(self, logfilename, phases, end_status, end_errors=[]): + return logfile = LogFile(logfilename + "_", 2) + logfile.clear() if os.path.isfile(logfile.filename): os.remove(logfile.filename) - status = logfile.status() t = threading.Thread(target=simulate, args=(logfilename, 0.0001)) t.start() - while status[0] >= 0 and status[1] != DONE: - new_status = logfile.status() - if new_status[1] != status[1] or new_status[0] != status[0]: - status = new_status - #print(status) - if status[1] in phases: - phases.remove(status[1]) + last_status = None + last_pct = 0 + while logfile.pct >= 0 and logfile.status != DONE: + logfile.update_status() + if logfile.status != last_status or logfile.pct != last_pct: + last_status = logfile.status + last_pct = logfile.pct + if logfile.status in phases: + phases.remove(logfile.status) time.sleep(0.01) - code, txt, err = logfile.status() - self.assertEqual(code, end_status[0]) - self.assertEqual(txt, end_status[1]) - self.assertEqual(err, end_status[2]) + self.assertEqual(logfile.pct, 100) + self.assertEqual(logfile.status, end_status) + self.assertEqual(logfile.errors, end_errors) self.assertFalse(phases) t.join() os.remove(logfile.filename) @@ -131,22 +141,69 @@ class Test(unittest.TestCase): def test_realtime_test(self): self.check('test_files/logfiles/finish.log', phases=[PENDING, INITIALIZATION, SIMULATING, DONE], - end_status=(100, DONE, [])) + end_status=DONE) def test_realtime_test2(self): self.check('test_files/logfiles/init_error.log', phases=[PENDING, INITIALIZATION, SIMULATING, DONE], - end_status=(100, DONE, [' *** ERROR *** No line termination in command line 8'])) + end_status=DONE, + end_errors=['*** ERROR *** No line termination in command line 8']) def test_realtime_test_simulation_error(self): self.check('test_files/logfiles/simulation_error.log', [PENDING, INITIALIZATION, SIMULATING, DONE], - (100, DONE, [' *** ERROR *** Error opening out .dat file'])) + DONE, ['*** ERROR *** Error opening out .dat file']) def test_realtime_test_turbulence(self): self.check('test_files/logfiles/finish_turbulencegeneration.log', - phases=[PENDING, INITIALIZATION, GENERATING_TURBULENCE, SIMULATING, DONE], - end_status=(100, DONE, [])) + phases=[PENDING, INITIALIZATION, SIMULATING, DONE], + end_status=DONE, + end_errors=[]) + + + def test_remaining(self): + logfilename = 'test_files/logfiles/finish.log' + logfile = LogFile(logfilename + "_", 2) + logfile.clear() + if os.path.isfile(logfile.filename): + os.remove(logfile.filename) + t = threading.Thread(target=simulate, args=(logfilename, 0.01)) + t.start() + last_status = None + last_pct = 0 + estimated_simulation_time = None + while logfile.pct >= 0 and logfile.status != DONE: + if estimated_simulation_time is None and logfile.remaining_time is not None: + endtime = time.time() + logfile.remaining_time + #print (logfile.pct, logfile.remaining_time, logfile.lastline) + logfile.update_status() + if logfile.status != last_status or logfile.pct != last_pct: + last_status = logfile.status + last_pct = logfile.pct + time.sleep(0.1) + t.join() + self.assertLess(abs(time.time() - endtime), 0.1) + os.remove(logfile.filename) + + + def test_remaining_str(self): + logfile = LogFile("f", 2) + logfile.remaining_time = 5 + self.assertEqual(logfile.remaining_time_str(), "00:05") + logfile.remaining_time = 60 + 5 + self.assertEqual(logfile.remaining_time_str(), "01:05") + logfile.remaining_time = 3600 + 120 + 5 + self.assertEqual(logfile.remaining_time_str(), "1:02:05") + + def test_add_hawc2errors(self): + f = 'test_files/logfiles/simulating.log' + logfile = LogFile(f, 2) + logfile.update_status() + logfile.add_HAWC2_errors(['program error']) + self.assertEqual(logfile.pct, 25) + self.assertEqual(logfile.status, ERROR) + self.assertEqual(logfile.errors, ['program error']) + if __name__ == "__main__":