0511 v1.3.0 init

msgpi/analysis.py

@@ -1,15 +1,16 @@
 import os
-import sys
 import traceback
-import datetime as dt
 import subprocess as sbp
+
+import msgpi.logger as mlog
+import msgpi.timer as mtime
 import msgpi.presg as psg
-import msgpi.sg as sgm
 import msgpi.io.iosc as miosc
 import msgpi.io.iovabs as miovabs
+import msgpi.utils as utils
 
 
-def solve(sg_xml, analysis, ppcmd, solver, timeout=30, scrnout=True):
+def solve(sg_xml, analysis, ppcmd, solver, timeout=30, scrnout=True, logger=None):
     """Solve
 
     Parameters
@@ -32,28 +33,57 @@ def solve(sg_xml, analysis, ppcmd, solver, timeout=30, scrnout=True):
         Switch of printing solver messages.
     """
 
+    if logger is None:
+        logger = mlog.initLogger(__name__)
+
+    # t = mtime.Timer(logger=logger.info)
+
     # Preprocess
-    sg_in, smdim = psg.preSG(sg_xml, analysis, ppcmd, solver, timeout=timeout, scrnout=scrnout)
+    logger.info('preprocessing...')
+    # t.start()
+    sg_in, smdim = psg.preSG(
+        sg_xml, analysis, ppcmd, solver,
+        timeout=timeout, scrnout=scrnout, logger=logger
+    )
+    # t.stop()
 
     # Solve
-    run(sg_in, analysis, solver, smdim, scrnout)
+    logger.info('running analysis...')
+    # t.start()
+    run(sg_in, analysis, solver, smdim, scrnout, logger=logger)
+    # t.stop()
 
     # Parse results
-    print('    - reading results...')
+    # print('    - reading results...')
+    logger.info('reading results...')
+    # t.start()
     if analysis == 'h':
         if solver == 'vabs':
             sm = miovabs.readVABSOutHomo(sg_in + '.K')
+            # t.stop()
         elif solver == 'swiftcomp':
             sm = miosc.readSCOutHomo(sg_in + '.k', smdim)
+            # t.stop()
         return sm
     elif analysis == 'd':
+        # t.stop()
         pass
     elif 'f' in analysis:
         results = miosc.readSCOutFailure(sg_in, analysis)
+        # t.stop()
         return results
+
+    # t.stop()
+
+
+
+
 
 
-def run(input_name, analysis, solver, smdim, scrnout=True):
+
+
+
+def run(input_name, analysis, solver, smdim, scrnout=True, logger=None):
     """Run codes.
 
     Parameters
@@ -75,6 +105,9 @@ def run(input_name, analysis, solver, smdim, scrnout=True):
     scrnout : bool, default True
         Switch of printing solver messages.
     """
+    if logger is None:
+        logger = utils.initLogger(__name__)
+
     try:
         analysis_long = {
             'h': 'homogenization',
@@ -90,6 +123,8 @@ def run(input_name, analysis, solver, smdim, scrnout=True):
         }
         msg = '    - running {cn} for {an}...\n'
 
+        cmd = []
+
         if solver == 'vabs':
             # solver = solver + 'iii'
             cmd = ['VABSIII', input_name]
@@ -103,13 +138,14 @@ def run(input_name, analysis, solver, smdim, scrnout=True):
             cmd.append(analysis.upper())
 
         # cmd = ' '.join(cmd)
+        logger.debug(' '.join(cmd))
 
         # try:
         if scrnout:
-            sys.stdout.write(msg.format(
-                cn=solver, an=analysis_long[analysis]
-            ))
-            sys.stdout.flush()
+            # sys.stdout.write(msg.format(
+            #     cn=solver, an=analysis_long[analysis]
+            # ))
+            # sys.stdout.flush()
             sbp.call(cmd)
         else:
             FNULL = open(os.devnull, 'w')

msgpi/dakota_interface.py

@@ -2,14 +2,16 @@
 import csv
 import datetime as dt
 import json
-import logging
 import os
 import platform
 import subprocess as sbp
 import sys
 import traceback as tb
 import numpy as np
 import xml.etree.ElementTree as et
+
+import msgpi.logger as mlog
+import msgpi.timer as mtime
 import msgpi.presg as psg
 import msgpi.analysis as sga
 import msgpi.io.iosc as miosc
@@ -25,16 +27,22 @@
 fsi = ' > [{0:%H}:{0:%M}:{0:%S}] EVAL {1:d}: {2:s}'
 
 
-def process(fn_json_args):
+def process(fn_json_args, logger=None, timer=None):
+    if logger is None:
+        logger = mlog.initLogger(__name__)
+    if timer is None:
+        timer = mtime.Timer(logger=logger.info)
+
+    timer.start()
     # Load JSON arguments
     with open(fn_json_args, 'r') as fo:
         interface_args = json.load(fo)
 
-    logging.basicConfig(
-        filename='app.log', filemode='w',
-        format='%(asctime)s - %(message)s', datefmt='%d-%b-%y %H:%M:%S',
-        level=20
-    )
+    # logging.basicConfig(
+    #     filename='app.log', filemode='w',
+    #     format='%(asctime)s - %(message)s', datefmt='%d-%b-%y %H:%M:%S',
+    #     level=20
+    # )
 
     # Load data processing module
     if 'data_process_functions_file' in interface_args.keys():
@@ -65,12 +73,13 @@ def process(fn_json_args):
     #     ts=dt.datetime.now(),
     #     msg=' '.join(('eval', str(evid), 'start'))
     # ))
-    logging.info(' '.join(('eval', str(evid), 'start')))
+    logger.info(' '.join(('eval', str(evid), 'start')))
 
 
     try:
         # preVABS/VABS
-        print('  - running cross-sectional analysis...')
+        # print('  - running cross-sectional analysis...')
+        logger.info('running cross-sectional analysis...')
         fn_main = interface_args['fn_main']
         analysis = interface_args['analysis']
 
@@ -86,11 +95,19 @@ def process(fn_json_args):
         scrnout = False
         if 'scrnout' in interface_args.keys():
             scrnout = interface_args['scrnout']
+
+        timer.stop()
+
+
+        timer.start()
         ms = sga.solve(
             fn_main, analysis, ppcmd, solver,
             timeout=timeout, scrnout=scrnout
         )
+        timer.stop()
+
 
+        timer.start()
         # Location of the origin relative to a ref point
         # e.g., leading edge of the airfoil
         # origin_ref_2 = interface_args['origin_ref_2']
@@ -174,12 +191,14 @@ def process(fn_json_args):
         results.write()
 
         # print('  - done.')
-        logging.info('done')
+        logger.info('done')
+        timer.stop()
 
         return
 
     except:
-        print(fse.format(dt.datetime.now(), evid, 'FAIL'))
+        # print(fse.format(dt.datetime.now(), evid, 'FAIL'))
+        logger.critical(' '.join(('eval', str(evid), 'failed')))
         if 'fail_replace' in interface_args.keys():
             for k, v in interface_args['fail_replace'].items():
                 # if v == 'inf' or v == '-inf':
@@ -191,6 +210,9 @@ def process(fn_json_args):
                 results.write(stream=fout)
             e = tb.format_exc()
             print(e)
+
+        timer.stop()
+
         return
 
 

msgpi/io/iovabs.py

@@ -1,6 +1,7 @@
 import os
 import sys
 import traceback
+import logging
 import numpy as np
 import msgpi.io.utils as utl
 import msgpi.sg as sgm
@@ -14,7 +15,7 @@
 #
 # ====================================================================
 
-def readVABSIn(fn_vabs_in):
+def readVABSIn(fn_vabs_in, logger=None):
     """ Read data from the VABS input file.
 
     Parameters
@@ -28,6 +29,11 @@ def readVABSIn(fn_vabs_in):
         Structure gene object
     """
 
+    if logger is None:
+        logger = logging.getLogger(__name__)
+
+    logger.info('reading VABS input: {0}...'.format(fn_vabs_in))
+
     try:
         fn_base, fn_extn = os.path.splitext(fn_vabs_in)
         name = os.path.basename(fn_base)

msgpi/logger.py

@@ -0,0 +1,33 @@
+import logging
+
+
+def initLogger(name, cout_level='INFO', fout_level='INFO', filename='log.txt'):
+    logger = logging.getLogger(name)
+    logger.setLevel('DEBUG')
+
+    ch = logging.StreamHandler()
+    ch.setLevel(cout_level)
+
+    fh = logging.FileHandler(filename)
+    fh.setLevel(fout_level)
+
+    # c_format = logging.Formatter(
+    #     '%(asctime)s - %(levelname)s - %(module)s.%(funcName)s - %(message)s'
+    # )
+    cf = logging.Formatter(
+        fmt='{levelname:8s} | {asctime} | {module}.{funcName} | {message}',
+        datefmt='%Y-%m-%d %H:%M:%S', style='{'
+    )
+    ch.setFormatter(cf)
+
+    ff = logging.Formatter(
+        fmt='{levelname:8s} | {asctime} | {module}.{funcName} | {message}',
+        datefmt='%Y-%m-%d %H:%M:%S', style='{'
+    )
+    fh.setFormatter(ff)
+
+    logger.addHandler(ch)
+    logger.addHandler(fh)
+
+    return logger
+

msgpi/presg.py

@@ -278,7 +278,10 @@ def preSG1D(xr_sg, smdim):
     return sg
 
 
-def preSG(sg_xml, analysis, ppcmd='prevabs', solver='swiftcomp', write_input=True, timeout=30, scrnout=True):
+def preSG(
+    sg_xml, analysis, ppcmd='prevabs', solver='swiftcomp',
+    write_input=True, timeout=30, scrnout=True, logger=None
+    ):
     """ Preprocessor of a structure gene.
 
     Parameters
@@ -314,6 +317,9 @@ def preSG(sg_xml, analysis, ppcmd='prevabs', solver='swiftcomp', write_input=Tru
         print('    - preprocessing structure gene...')
     # fn_head, fn_tail = os.path.split(xml_sg)
 
+    if logger is None:
+        logger = utl.initLogger(__name__)
+
     try:
         fn_base, fn_extn = os.path.splitext(sg_xml)
         fn_sg_in = fn_base + '.sg'
@@ -331,6 +337,7 @@ def preSG(sg_xml, analysis, ppcmd='prevabs', solver='swiftcomp', write_input=Tru
             cmd.append('-' + analysis)
 
             # cmd = ' '.join(cmd)
+            logger.debug(' '.join(cmd))
             utl.run(cmd, timeout, scrnout)
             # if scrnout:
             #     print('cmd:', cmd)

msgpi/timer.py

@@ -0,0 +1,35 @@
+import time
+
+class Timer:
+    timers = dict()
+
+    def __init__(self, name=None, text='Elapsed time {:0.4f} seconds', logger=print):
+        self._start_time = None
+        self.name = name
+        self.text = text
+        self.logger = logger
+
+        if name:
+            self.timers.setdefault(name, 0)
+
+    def start(self):
+        if self._start_time is not None:
+            raise Exception(f"Timer is running.")
+
+        self._start_time = time.perf_counter()
+
+    def stop(self):
+        if self._start_time is None:
+            raise Exception(f"Timer is not running.")
+
+        elapsed_time = time.perf_counter() - self._start_time
+        self._start_time = None
+
+        if self.logger:
+            self.logger(self.text.format(elapsed_time))
+        if self.name:
+            self.timers[self.name] += elapsed_time
+
+        return elapsed_time
+
+