Added execution time information in logs

This commit is contained in:
Ganesh Gore 2019-08-21 11:08:47 -06:00
parent a335a57c6c
commit e51ff44710
1 changed files with 31 additions and 12 deletions

View File

@ -2,6 +2,7 @@ import os
import sys import sys
import shutil import shutil
import time import time
from datetime import timedelta
import shlex import shlex
import argparse import argparse
from configparser import ConfigParser, ExtendedInterpolation from configparser import ConfigParser, ExtendedInterpolation
@ -13,6 +14,10 @@ import csv
from string import Template from string import Template
import run_fpga_flow import run_fpga_flow
import pprint import pprint
import importlib
if importlib.util.find_spec("humanize"):
import humanize
# = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = # = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = =
# Configure logging system # Configure logging system
@ -35,6 +40,8 @@ parser.add_argument('--test_run', action="store_true",
help="Dummy run shows final generated VPR commands") help="Dummy run shows final generated VPR commands")
parser.add_argument('--debug', action="store_true", parser.add_argument('--debug', action="store_true",
help="Run script in debug mode") help="Run script in debug mode")
parser.add_argument('--skip_tread_logs', action="store_true",
help="Skips logs from running thread")
args = parser.parse_args() args = parser.parse_args()
# = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = # = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = =
@ -220,9 +227,13 @@ def create_run_command(curr_job_dir, archfile, benchmark_obj, task_conf):
command += ["--vpr_fpga_spice"] command += ["--vpr_fpga_spice"]
if task_conf.getboolean("GENERAL", "verilog_output", fallback=False): if task_conf.getboolean("GENERAL", "verilog_output", fallback=False):
command += ["--vpr_fpga_verilog"] command += ["--vpr_fpga_verilog"]
command += ["--vpr_fpga_verilog_dir", "."]
command += ["--vpr_fpga_x2p_rename_illegal_port"]
# Add other paramters to pass # Add other paramters to pass
for key, values in task_conf["SCRIPT_PARAM"].items(): for key, values in task_conf["SCRIPT_PARAM"].items():
command += ["--"+key, values] if values else ["--"+key]
if args.debug: if args.debug:
command += ["--debug"] command += ["--debug"]
return command return command
@ -234,23 +245,31 @@ def run_single_script(s, eachJob):
logger.debug("Running OpenFPGA flow with " + logger.debug("Running OpenFPGA flow with " +
" ".join(eachJob["commands"])) " ".join(eachJob["commands"]))
name = threading.currentThread().getName() name = threading.currentThread().getName()
eachJob["starttime"] = time.time()
try: try:
logfile = "%s_out.log" % name logfile = "%s_out.log" % name
with open(logfile, 'w+') as output: with open(logfile, 'w+') as output:
process = subprocess.run(["python3.5", process = subprocess.Popen(["python3.5",
gc["script_default"]] + gc["script_default"]] +
eachJob["commands"], eachJob["commands"],
check=True, stdout=subprocess.PIPE,
stdout=subprocess.PIPE, stderr=subprocess.STDOUT,
stderr=subprocess.PIPE, universal_newlines=True)
universal_newlines=True) for line in process.stdout:
output.write(process.stdout) if not args.skip_tread_logs:
logging.info(line[:-1])
sys.stdout.buffer.flush()
output.write(line)
process.wait()
eachJob["status"] = True eachJob["status"] = True
except: except:
logger.error("Failed to execute openfpga flow - " + logger.exception("Failed to execute openfpga flow - " +
eachJob["name"]) eachJob["name"])
# logger.exception("Failed to launch openfpga flow") eachJob["endtime"] = time.time()
logger.info("%s Finished " % name) timediff = timedelta(seconds=(eachJob["endtime"]-eachJob["starttime"]))
timestr = humanize.naturaldelta(timediff) if "humanize" in sys.modules \
else str(timediff)
logger.info("%s Finished, Time Taken %s " % (name, timestr))
def run_actions(job_run_list): def run_actions(job_run_list):