From 4c137f4ad073e5c0a442c9a7d10b7cfad50c0f95 Mon Sep 17 00:00:00 2001 From: "stefan.schirmeister" Date: Thu, 1 Jun 2023 10:08:27 +0200 Subject: [PATCH 1/6] add logging --- ebus_toolbox/__main__.py | 30 ++++++++++++++++++++++++---- ebus_toolbox/consumption.py | 38 ++++++++++++++++++------------------ ebus_toolbox/costs.py | 3 ++- ebus_toolbox/optimization.py | 25 ++++++++---------------- ebus_toolbox/report.py | 13 ++++++------ ebus_toolbox/simulate.py | 21 ++++++++++---------- ebus_toolbox/trip.py | 7 ++++--- ebus_toolbox/util.py | 28 +++++++++++++++----------- 8 files changed, 93 insertions(+), 72 deletions(-) diff --git a/ebus_toolbox/__main__.py b/ebus_toolbox/__main__.py index ad2fefef..18681253 100644 --- a/ebus_toolbox/__main__.py +++ b/ebus_toolbox/__main__.py @@ -1,15 +1,16 @@ from datetime import datetime +import logging from pathlib import Path import shutil from ebus_toolbox import simulate, util + if __name__ == '__main__': args = util.get_args() - args.output_directory = Path(args.output_directory) / ( - datetime.now().strftime("%Y-%m-%d-%H-%M-%S") + "_eBus_results") - + time_str = datetime.now().strftime("%Y-%m-%d-%H-%M-%S") + args.output_directory = Path(args.output_directory) / (time_str + "_eBus_results") # create subfolder for specific sim results with timestamp. # if folder doesnt exists, create folder. # needs to happen after set_options_from_config since @@ -30,4 +31,25 @@ util.save_version(args.output_directory_input / "program_version.txt") - simulate.simulate(args) + # set up logging + # always to console + log_handlers = [logging.StreamHandler()] + if args.logfile is not None: + # optionally to file in output dir + if args.logfile: + log_name = f"{time_str}_{[args.log_file]}.log" + else: + log_name = f"{time_str}.log" + log_handlers.append(logging.FileHandler(args.output_directory / log_name)) + logging.basicConfig( + level=vars(logging)[args.loglevel], + # format="%(asctime)s [%(levelname)s] %(message)s", + handlers=log_handlers + ) + logging.captureWarnings(True) + + try: + simulate.simulate(args) + except Exception as e: + logging.error(e) + raise diff --git a/ebus_toolbox/consumption.py b/ebus_toolbox/consumption.py index 7857abf0..a4a4ec65 100644 --- a/ebus_toolbox/consumption.py +++ b/ebus_toolbox/consumption.py @@ -74,31 +74,31 @@ def calculate_consumption(self, time, distance, vehicle_type, charging_type, tem if temp is None: try: temp = self.temperatures_by_hour[time.hour] - except AttributeError: - print("Neither of these conditions is met:\n" - "1. Temperature data is available for every trip through the trips file " - "or a temperature over day file.\n" - f"2. A constant mileage for the vehicle " - f"{vehicle_info['mileage']} is provided.") - raise AttributeError - except IndexError: - print(f"No temperature data for the hour {time.hour} is provided") - raise IndexError + except AttributeError as e: + raise AttributeError( + "Neither of these conditions is met:\n" + "1. Temperature data is available for every trip through the trips file " + "or a temperature over day file.\n" + f"2. A constant mileage for the vehicle " + f"{vehicle_info['mileage']} is provided." + ) from e + except IndexError as e: + raise IndexError (f"No temperature data for the hour {time.hour} is provided") from e # if no specific LoL is given, lookup temperature if level_of_loading is None: try: level_of_loading = self.lol_by_hour[time.hour] - except AttributeError: - print("Neither of these conditions is met:\n" - "1. Level of loading data is available for every trip through the trips file " - "or a level of loading over day file.\n" - f"2. A constant mileage for the vehicle " - f"{vehicle_info['mileage']} is provided.") - raise AttributeError + except AttributeError as e: + raise AttributeError( + "Neither of these conditions is met:\n" + "1. Level of loading data is available for every trip through the trips file " + "or a level of loading over day file.\n" + f"2. A constant mileage for the vehicle " + f"{vehicle_info['mileage']} is provided." + ) from e except IndexError: - print(f"No level of loading data for the hour {time.hour} is provided") - raise IndexError + raise IndexError(f"No level of loading for the hour {time.hour} is provided") from e # load consumption csv consumption_path = vehicle_info["mileage"] diff --git a/ebus_toolbox/costs.py b/ebus_toolbox/costs.py index 6d78ebec..bb800065 100644 --- a/ebus_toolbox/costs.py +++ b/ebus_toolbox/costs.py @@ -1,3 +1,4 @@ +import logging import warnings from spice_ev.costs import calculate_costs as calc_costs_spice_ev @@ -187,7 +188,7 @@ def calculate_costs(c_params, scenario, schedule, args): for key, v in costs.items(): costs[key] = round(v, 2) - print("\n" + logging.info("\n" "Total costs: \n" f"Investment cost: {costs['c_invest']} €. \n" f"Annual investment costs: {costs['c_invest_annual']} €/a. \n" diff --git a/ebus_toolbox/optimization.py b/ebus_toolbox/optimization.py index ce4c2073..1856ac9a 100644 --- a/ebus_toolbox/optimization.py +++ b/ebus_toolbox/optimization.py @@ -1,17 +1,8 @@ """ Collection of procedures optimizing arbitrary parameters of a bus schedule or infrastructure. """ - from copy import deepcopy import datetime - import logging -import sys -logger = logging.getLogger(__name__) -if "pytest" not in sys.modules: - logger.setLevel(logging.DEBUG) - sh = logging.StreamHandler(sys.stdout) - sh.setLevel(logging.DEBUG) - logger.addHandler(sh) def service_optimization(schedule, scenario, args): @@ -34,7 +25,7 @@ def service_optimization(schedule, scenario, args): # single out negative rotations. Try to run these with common non-negative rotations negative_rotations = schedule.get_negative_rotations(scenario) - logger.info(f"Initially, rotations {sorted(negative_rotations)} have neg. SoC.") + logging.info(f"Initially, rotations {sorted(negative_rotations)} have neg. SoC.") if not negative_rotations: return { @@ -48,7 +39,7 @@ def service_optimization(schedule, scenario, args): rotation = schedule.rotations.pop(rot_key) if rotation.charging_type != "oppb": # only oppb rotations are optimized -> skip others - logger.warn(f"Rotation {rot_key} should be optimized, " + logging.warn(f"Rotation {rot_key} should be optimized, " f"but is of type {rotation.charging_type}.") continue # oppb: build non-interfering sets of negative rotations @@ -67,7 +58,7 @@ def service_optimization(schedule, scenario, args): dependent_station.update({r2: t2 for r2, t2 in common_stations[r].items() if t2 <= t}) elif r.charging_type != "obbp": - logger.warn(f"Rotation {rot_key} depends on negative non-oppb rotation") + logging.warn(f"Rotation {rot_key} depends on negative non-oppb rotation") negative_sets[rot_key] = s @@ -80,7 +71,7 @@ def service_optimization(schedule, scenario, args): ignored = [] for i, (rot, s) in enumerate(negative_sets.items()): schedule.rotations = {r: original[0].rotations[r] for r in s} - logger.debug(f"{i+1} / {len(negative_sets)} negative schedules: {rot}") + logging.debug(f"{i+1} / {len(negative_sets)} negative schedules: {rot}") scenario = schedule.run(args) if scenario.negative_soc_tracker: # still fail: try just the negative rotation @@ -88,10 +79,10 @@ def service_optimization(schedule, scenario, args): scenario = schedule.run(args) if scenario.negative_soc_tracker: # no hope, this just won't work - logger.info(f"Rotation {rot} will stay negative") + logging.info(f"Rotation {rot} will stay negative") else: # works alone with other non-negative rotations - logger.info(f"Rotation {rot} works alone") + logging.info(f"Rotation {rot} works alone") ignored.append(rot) negative_sets = {k: v for k, v in negative_sets.items() if k not in ignored} @@ -100,7 +91,7 @@ def service_optimization(schedule, scenario, args): # try to combine them possible = [(a, b) for a in negative_sets for b in negative_sets if a != b] while possible: - logger.debug(f"{len(possible)} combinations remain") + logging.debug(f"{len(possible)} combinations remain") r1, r2 = possible.pop() combined = negative_sets[r1].union(negative_sets[r2]) schedule.rotations = {r: original[0].rotations[r] for r in combined} @@ -115,7 +106,7 @@ def service_optimization(schedule, scenario, args): if optimal is None or len(scenario[0].rotations) > len(optimal[0].rotations): optimal = (deepcopy(schedule), deepcopy(scenario)) - logger.info(negative_sets) + logging.info("Service optimization finished") return { "original": original, diff --git a/ebus_toolbox/report.py b/ebus_toolbox/report.py index 4bac3ed2..ddca98da 100644 --- a/ebus_toolbox/report.py +++ b/ebus_toolbox/report.py @@ -2,8 +2,9 @@ """ import csv import datetime -import warnings +import logging import matplotlib.pyplot as plt +import warnings from spice_ev.report import aggregate_global_results, plot, generate_reports @@ -187,10 +188,10 @@ def generate(schedule, scenario, args): rotation_socs[id][start_idx:end_idx] = rotation_soc_ts if incomplete_rotations: - warnings.warn("SpiceEV stopped before simulation of the these rotations were completed:\n" - f"{', '.join(incomplete_rotations)}\n" - "Omit parameter to simulate entire schedule.", - stacklevel=100) + logging.warn( + "SpiceEV stopped before simulation of the these rotations were completed:\n" + f"{', '.join(incomplete_rotations)}\n" + "Omit parameter to simulate entire schedule.") with open(args.results_directory / "rotation_socs.csv", "w", newline='') as f: csv_writer = csv.writer(f) @@ -218,4 +219,4 @@ def generate(schedule, scenario, args): else: csv_writer.writerow([key, round(value, 2), "€"]) - print("Plots and output files saved in", args.results_directory) + logging.info("Plots and output files saved in", args.results_directory) diff --git a/ebus_toolbox/simulate.py b/ebus_toolbox/simulate.py index ebb8967a..0f424cb4 100644 --- a/ebus_toolbox/simulate.py +++ b/ebus_toolbox/simulate.py @@ -1,5 +1,4 @@ -import warnings -from warnings import warn +import logging from ebus_toolbox.consumption import Consumption from ebus_toolbox.schedule import Schedule @@ -72,7 +71,7 @@ def simulate(args): result = optimization.service_optimization(schedule, scenario, args) schedule, scenario = result['optimized'] if scenario is None: - print('*'*49 + '\nNo optimization possible (all rotations negative), reverting') + logging.warn('*'*49 + '\nNo optimization possible (all rotations negative), reverting') schedule, scenario = result['original'] elif mode in ['neg_depb_to_oppb', 'neg_oppb_to_depb']: # simple optimization: change charging type, simulate again @@ -84,17 +83,17 @@ def simulate(args): neg_rot = [r for r in neg_rot if schedule.rotations[r].charging_type == change_from if change_to in vehicle_types[schedule.rotations[r].vehicle_type]] if neg_rot: - print(f'Changing charging type from {change_from} to {change_to} for rotations ' + logging.info(f'Changing charging type from {change_from} to {change_to} for rotations ' + ', '.join(neg_rot)) schedule.set_charging_type(change_to, neg_rot) # simulate again scenario = schedule.run(args) neg_rot = schedule.get_negative_rotations(scenario) if neg_rot: - print(f'Rotations {", ".join(neg_rot)} remain negative.') + logging.info(f'Rotations {", ".join(neg_rot)} remain negative.') elif mode == "station_optimization": if not args.optimizer_config: - warnings.warn("Station optimization needs an optimization config file. " + logging.warn("Station optimization needs an optimization config file. " "Since no path was given, station optimization is skipped") continue conf = read_optimizer_config(args.optimizer_config) @@ -103,18 +102,18 @@ def simulate(args): schedule, scenario = run_optimization(conf, sched=schedule, scen=scenario, args=args) except Exception as err: - warnings.warn('During Station optimization an error occurred {0}. ' + logging.warn('During Station optimization an error occurred {0}. ' 'Optimization was skipped'.format(err)) elif mode == 'remove_negative': neg_rot = schedule.get_negative_rotations(scenario) if neg_rot: schedule.rotations = { k: v for k, v in schedule.rotations.items() if k not in neg_rot} - print('Rotations ' + ', '.join(neg_rot) + ' removed') + logging.info('Rotations ' + ', '.join(sorted(neg_rot)) + ' removed') # re-run schedule scenario = schedule.run(args) else: - print('No negative rotations to remove') + logging.info('No negative rotations to remove') elif mode == 'report': # create report based on all previous modes if args.cost_calculation: @@ -126,9 +125,9 @@ def simulate(args): elif mode == 'sim': if i > 0: # ignore anyway, but at least give feedback that this has no effect - warn('Intermediate sim ignored') + logging.info('Intermediate sim ignored') else: - warn(f'Unknown mode {mode} ignored') + logging.error(f'Unknown mode {mode} ignored') def create_results_directory(args, i): diff --git a/ebus_toolbox/trip.py b/ebus_toolbox/trip.py index da9fe205..258276e8 100644 --- a/ebus_toolbox/trip.py +++ b/ebus_toolbox/trip.py @@ -67,8 +67,9 @@ def calculate_consumption(self): height_diff=self.height_diff, level_of_loading=self.level_of_loading, mean_speed=self.mean_speed) - except AttributeError: - print("""To calculate consumption, a consumption object needs to be constructed - and linked to Trip class.""") + except AttributeError as e: + raise Exception( + 'To calculate consumption, a consumption object needs to be constructed \ + and linked to Trip class.').with_traceback(e.__traceback__) return self.consumption diff --git a/ebus_toolbox/util.py b/ebus_toolbox/util.py index 4442dcba..270b1d25 100644 --- a/ebus_toolbox/util.py +++ b/ebus_toolbox/util.py @@ -1,5 +1,6 @@ import argparse import json +import logging import warnings import subprocess @@ -125,19 +126,19 @@ def get_csv_delim(path, other_delims=set()): # delete the counter if it is different to the first row if counters[delim] != amount: del counters[delim] - # if only one delimiter is remaining - if len(counters) == 1: - # take the last item and return the key - return counters.popitem()[0] - # if not even a single delimiter is remaining - elif not counters: - warnings.warn("Warning: Delimiter could not be found.\n" - "Returning standard Delimiter ','", stacklevel=100) - return "," + # if only one delimiter is remaining + if len(counters) == 1: + # take the last item and return the key + return counters.popitem()[0] + # if not even a single delimiter is remaining + elif not counters: + logging.warn("Warning: Delimiter could not be found.\n" + "Returning standard Delimiter ','") + return "," # multiple delimiters are possible. Every row was checked but more than 1 delimiter # has the same amount of occurrences (>0) in every row. - warnings.warn("Warning: Delimiter could not be found.\n" - "Returning standard delimiter ','", stacklevel=100) + logging.warn("Warning: Delimiter could not be found.\n" + "Returning standard delimiter ','") return "," @@ -308,6 +309,11 @@ def get_args(): help='Show estimated time to finish simulation after each step, ' 'instead of progress bar. Not recommended for fast computations.') + # #### LOGGING PARAMETERS #### # + parser.add_argument('--loglevel', default='INFO', + choices=logging._nameToLevel.keys(), help='Log level.') + parser.add_argument('--logfile', default='', help='Log file suffix. null: no log file.') + # #### SPICE EV PARAMETERS ONLY DEFAULT VALUES NOT IN eBus-Toolbox CONFIG ##### parser.add_argument('--seed', default=1, type=int, help='set random seed') parser.add_argument('--include-price-csv', From de4e498fccab70fc9ecc7d95461d48783cd6d4d1 Mon Sep 17 00:00:00 2001 From: "stefan.schirmeister" Date: Thu, 1 Jun 2023 10:32:31 +0200 Subject: [PATCH 2/6] small changes to logging --- data/examples/ebus_toolbox.cfg | 9 +++++++++ ebus_toolbox/__main__.py | 8 +++++--- ebus_toolbox/report.py | 2 +- 3 files changed, 15 insertions(+), 4 deletions(-) diff --git a/data/examples/ebus_toolbox.cfg b/data/examples/ebus_toolbox.cfg index 81cc1549..3990bc52 100644 --- a/data/examples/ebus_toolbox.cfg +++ b/data/examples/ebus_toolbox.cfg @@ -80,6 +80,15 @@ default_buffer_time_opps = 0 # Options: HV, HV/MV, MV, MV/LV, LV (default: MV) default_voltage_level = "MV" +##### LOGGING ##### +# minimum log level. Allowed/useful: DEBUG, INFO, WARN, ERROR +# INFO includes INFO, WARN and ERROR but excludes DEBUG +loglevel = INFO +# log file name. Placed in output directory +# set to null to disable logfile creation +# leave empty to have default [timestamp].log +logfile = + ##### SIMULATION PARAMETERS ##### # Maximum number of days to simulate, if not set simulate entire schedule #days = 10 diff --git a/ebus_toolbox/__main__.py b/ebus_toolbox/__main__.py index 18681253..5f7bcc86 100644 --- a/ebus_toolbox/__main__.py +++ b/ebus_toolbox/__main__.py @@ -37,13 +37,15 @@ if args.logfile is not None: # optionally to file in output dir if args.logfile: - log_name = f"{time_str}_{[args.log_file]}.log" + log_name = args.logfile else: log_name = f"{time_str}.log" - log_handlers.append(logging.FileHandler(args.output_directory / log_name)) + log_path = args.output_directory / log_name + print(f"Writing log to {log_path}") + log_handlers.append(logging.FileHandler(log_path)) logging.basicConfig( level=vars(logging)[args.loglevel], - # format="%(asctime)s [%(levelname)s] %(message)s", + format="%(asctime)s [%(levelname)s] %(message)s", handlers=log_handlers ) logging.captureWarnings(True) diff --git a/ebus_toolbox/report.py b/ebus_toolbox/report.py index ddca98da..43131f80 100644 --- a/ebus_toolbox/report.py +++ b/ebus_toolbox/report.py @@ -219,4 +219,4 @@ def generate(schedule, scenario, args): else: csv_writer.writerow([key, round(value, 2), "€"]) - logging.info("Plots and output files saved in", args.results_directory) + logging.info(f"Plots and output files saved in {args.results_directory}") From 8c38ae9c8d043ff9a89f8019e6d7ed878c0b00cf Mon Sep 17 00:00:00 2001 From: "stefan.schirmeister" Date: Thu, 1 Jun 2023 12:26:51 +0200 Subject: [PATCH 3/6] fixes, refactoring, continue after mode fail If there is an exception while running a mode, print to log, generate plot (if there is anything to plot) and continue with next mode. --- ebus_toolbox/consumption.py | 4 +- ebus_toolbox/costs.py | 12 ++-- ebus_toolbox/optimization.py | 2 +- ebus_toolbox/report.py | 29 +++++--- ebus_toolbox/schedule.py | 11 +-- ebus_toolbox/simulate.py | 136 ++++++++++++++++++++--------------- ebus_toolbox/trip.py | 1 + ebus_toolbox/util.py | 1 - 8 files changed, 113 insertions(+), 83 deletions(-) diff --git a/ebus_toolbox/consumption.py b/ebus_toolbox/consumption.py index a4a4ec65..53337311 100644 --- a/ebus_toolbox/consumption.py +++ b/ebus_toolbox/consumption.py @@ -83,7 +83,7 @@ def calculate_consumption(self, time, distance, vehicle_type, charging_type, tem f"{vehicle_info['mileage']} is provided." ) from e except IndexError as e: - raise IndexError (f"No temperature data for the hour {time.hour} is provided") from e + raise IndexError(f"No temperature data for the hour {time.hour} is provided") from e # if no specific LoL is given, lookup temperature if level_of_loading is None: @@ -97,7 +97,7 @@ def calculate_consumption(self, time, distance, vehicle_type, charging_type, tem f"2. A constant mileage for the vehicle " f"{vehicle_info['mileage']} is provided." ) from e - except IndexError: + except IndexError as e: raise IndexError(f"No level of loading for the hour {time.hour} is provided") from e # load consumption csv diff --git a/ebus_toolbox/costs.py b/ebus_toolbox/costs.py index ae783a2a..69670fdf 100644 --- a/ebus_toolbox/costs.py +++ b/ebus_toolbox/costs.py @@ -190,11 +190,11 @@ def calculate_costs(c_params, scenario, schedule, args): for key, v in costs.items(): costs[key] = round(v, 2) - logging.info("\n" - "Total costs: \n" - f"Investment cost: {costs['c_invest']} €. \n" - f"Annual investment costs: {costs['c_invest_annual']} €/a. \n" - f"Annual maintenance costs: {costs['c_maint_annual']} €/a. \n" - f"Annual costs for electricity: {costs['c_el_annual']} €/a.\n") + logging.info( + "\nTotal costs:\n" + f"Investment cost: {costs['c_invest']} €. \n" + f"Annual investment costs: {costs['c_invest_annual']} €/a. \n" + f"Annual maintenance costs: {costs['c_maint_annual']} €/a. \n" + f"Annual costs for electricity: {costs['c_el_annual']} €/a.\n") setattr(scenario, "costs", costs) diff --git a/ebus_toolbox/optimization.py b/ebus_toolbox/optimization.py index 1856ac9a..e6243d6e 100644 --- a/ebus_toolbox/optimization.py +++ b/ebus_toolbox/optimization.py @@ -40,7 +40,7 @@ def service_optimization(schedule, scenario, args): if rotation.charging_type != "oppb": # only oppb rotations are optimized -> skip others logging.warn(f"Rotation {rot_key} should be optimized, " - f"but is of type {rotation.charging_type}.") + f"but is of type {rotation.charging_type}.") continue # oppb: build non-interfering sets of negative rotations # (these include the dependent non-negative rotations) diff --git a/ebus_toolbox/report.py b/ebus_toolbox/report.py index 43131f80..d01c404f 100644 --- a/ebus_toolbox/report.py +++ b/ebus_toolbox/report.py @@ -93,6 +93,25 @@ def generate_gc_overview(schedule, scenario, args): *use_factors]) +def generate_plots(scenario, args): + """Save plots as png and pdf. + + :param scenario: Scenario to plot. + :type scenario: spice_ev.Scenario + :param args: Configuration. Uses results_directory and show_plots. + :type args: argparse.Namespace + """ + aggregate_global_results(scenario) + with plt.ion(): # make plotting temporarily interactive, so plt.show does not block + plt.clf() + plot(scenario) + plt.gcf().set_size_inches(10, 10) + plt.savefig(args.results_directory / "run_overview.png") + plt.savefig(args.results_directory / "run_overview.pdf") + if args.show_plots: + plt.show() + + def generate(schedule, scenario, args): """Generates all output files/ plots and saves them in the output directory. @@ -123,15 +142,7 @@ def generate(schedule, scenario, args): generate_gc_overview(schedule, scenario, args) # save plots as png and pdf - aggregate_global_results(scenario) - with plt.ion(): # make plotting temporarily interactive, so plt.show does not block - plt.clf() - plot(scenario) - plt.gcf().set_size_inches(10, 10) - plt.savefig(args.results_directory / "run_overview.png") - plt.savefig(args.results_directory / "run_overview.pdf") - if args.show_plots: - plt.show() + generate_plots(scenario, args) # calculate SOCs for each rotation rotation_infos = [] diff --git a/ebus_toolbox/schedule.py b/ebus_toolbox/schedule.py index 514542ac..1caefe52 100644 --- a/ebus_toolbox/schedule.py +++ b/ebus_toolbox/schedule.py @@ -1,8 +1,9 @@ import csv -import random import datetime -import warnings +import logging from pathlib import Path +import random +import warnings from ebus_toolbox import util from ebus_toolbox.rotation import Rotation @@ -120,7 +121,7 @@ def from_csv(cls, path_to_csv, vehicle_types, stations, **kwargs): with open(kwargs["output_directory"] / "inconsistent_rotations.csv", "w") as f: for rot_id, e in inconsistent_rotations.items(): f.write(f"Rotation {rot_id}: {e}\n") - print(f"Rotation {rot_id}: {e}") + logging.error(f"Rotation {rot_id}: {e}") if kwargs.get("skip_inconsistent_rotations"): # remove this rotation from schedule del schedule.rotations[rot_id] @@ -185,7 +186,7 @@ def run(self, args): scenario = self.generate_scenario(args) - print("Running Spice EV...") + logging.info("Running Spice EV...") with warnings.catch_warnings(): warnings.simplefilter('ignore', UserWarning) scenario.run('distributed', vars(args).copy()) @@ -639,7 +640,7 @@ def generate_scenario(self, args): events['energy_price_from_csv'] = options price_csv_path = args.output_directory / filename if not price_csv_path.exists(): - print("Warning: price csv file '{}' does not exist yet".format(price_csv_path)) + logging.warn(f"Price csv file '{price_csv_path}' does not exist yet") # reformat vehicle types for spiceEV vehicle_types_spiceev = { diff --git a/ebus_toolbox/simulate.py b/ebus_toolbox/simulate.py index 0f424cb4..a2b158a1 100644 --- a/ebus_toolbox/simulate.py +++ b/ebus_toolbox/simulate.py @@ -1,4 +1,5 @@ import logging +import traceback from ebus_toolbox.consumption import Consumption from ebus_toolbox.schedule import Schedule @@ -66,68 +67,85 @@ def simulate(args): # scenario must be set from initial run / prior modes assert scenario is not None, f"Scenario became None after mode {args.mode[i-1]} (index {i})" - if mode == 'service_optimization': - # find largest set of rotations that produce no negative SoC - result = optimization.service_optimization(schedule, scenario, args) - schedule, scenario = result['optimized'] - if scenario is None: - logging.warn('*'*49 + '\nNo optimization possible (all rotations negative), reverting') - schedule, scenario = result['original'] - elif mode in ['neg_depb_to_oppb', 'neg_oppb_to_depb']: - # simple optimization: change charging type, simulate again - change_from = mode[4:8] - change_to = mode[-4:] - # get negative rotations - neg_rot = schedule.get_negative_rotations(scenario) - # check which rotations are relevant and if vehicle with other charging type exists - neg_rot = [r for r in neg_rot if schedule.rotations[r].charging_type == change_from - if change_to in vehicle_types[schedule.rotations[r].vehicle_type]] - if neg_rot: - logging.info(f'Changing charging type from {change_from} to {change_to} for rotations ' - + ', '.join(neg_rot)) - schedule.set_charging_type(change_to, neg_rot) - # simulate again - scenario = schedule.run(args) + try: + if mode == 'service_optimization': + # find largest set of rotations that produce no negative SoC + result = optimization.service_optimization(schedule, scenario, args) + schedule, scenario = result['optimized'] + if scenario is None: + logging.warn('No optimization possible (all rotations negative), reverting') + schedule, scenario = result['original'] + elif mode in ['neg_depb_to_oppb', 'neg_oppb_to_depb']: + # simple optimization: change charging type, simulate again + change_from = mode[4:8] + change_to = mode[-4:] + # get negative rotations neg_rot = schedule.get_negative_rotations(scenario) + # check which rotations are relevant and if vehicle with other charging type exists + neg_rot = [r for r in neg_rot if schedule.rotations[r].charging_type == change_from + if change_to in vehicle_types[schedule.rotations[r].vehicle_type]] if neg_rot: - logging.info(f'Rotations {", ".join(neg_rot)} remain negative.') - elif mode == "station_optimization": - if not args.optimizer_config: - logging.warn("Station optimization needs an optimization config file. " - "Since no path was given, station optimization is skipped") - continue - conf = read_optimizer_config(args.optimizer_config) - try: - create_results_directory(args, i+1) - schedule, scenario = run_optimization(conf, sched=schedule, scen=scenario, - args=args) - except Exception as err: - logging.warn('During Station optimization an error occurred {0}. ' - 'Optimization was skipped'.format(err)) - elif mode == 'remove_negative': - neg_rot = schedule.get_negative_rotations(scenario) - if neg_rot: - schedule.rotations = { - k: v for k, v in schedule.rotations.items() if k not in neg_rot} - logging.info('Rotations ' + ', '.join(sorted(neg_rot)) + ' removed') - # re-run schedule - scenario = schedule.run(args) + logging.info( + f'Changing charging type from {change_from} to {change_to} for rotations ' + + ', '.join(sorted(neg_rot))) + schedule.set_charging_type(change_to, neg_rot) + # simulate again + scenario = schedule.run(args) + neg_rot = schedule.get_negative_rotations(scenario) + if neg_rot: + logging.info(f'Rotations {", ".join(neg_rot)} remain negative.') + elif mode == "station_optimization": + if not args.optimizer_config: + logging.warn("Station optimization needs an optimization config file. " + "Since no path was given, station optimization is skipped") + continue + conf = read_optimizer_config(args.optimizer_config) + try: + create_results_directory(args, i+1) + schedule, scenario = run_optimization(conf, sched=schedule, scen=scenario, + args=args) + except Exception as err: + logging.warn('During Station optimization an error occurred {0}. ' + 'Optimization was skipped'.format(err)) + elif mode == 'remove_negative': + neg_rot = schedule.get_negative_rotations(scenario) + if neg_rot: + schedule.rotations = { + k: v for k, v in schedule.rotations.items() if k not in neg_rot} + logging.info('Rotations ' + ', '.join(sorted(neg_rot)) + ' removed') + # re-run schedule + scenario = schedule.run(args) + else: + logging.info('No negative rotations to remove') + elif mode == 'report': + # create report based on all previous modes + if args.cost_calculation: + # cost calculation part of report + calculate_costs(cost_parameters_file, scenario, schedule, args) + # name: always start with sim, append all prior optimization modes + create_results_directory(args, i) + report.generate(schedule, scenario, args) + elif mode == 'sim': + if i > 0: + # ignore anyway, but at least give feedback that this has no effect + logging.info('Intermediate sim ignored') else: - logging.info('No negative rotations to remove') - elif mode == 'report': - # create report based on all previous modes - if args.cost_calculation: - # cost calculation part of report - calculate_costs(cost_parameters_file, scenario, schedule, args) - # name: always start with sim, append all prior optimization modes - create_results_directory(args, i) - report.generate(schedule, scenario, args) - elif mode == 'sim': - if i > 0: - # ignore anyway, but at least give feedback that this has no effect - logging.info('Intermediate sim ignored') - else: - logging.error(f'Unknown mode {mode} ignored') + logging.error(f'Unknown mode {mode} ignored') + except Exception as e: + msg = f"{e.__class__.__name__} during {mode}: {e}" + logging.error('*'*len(msg)) + logging.error(e) + logging.error('*'*len(msg)) + # logging.error(str(e.__traceback__)) + logging.error(traceback.format_exc()) + # logging.error(traceback.print_exception(type(e), e, e.__traceback__)) + if scenario is not None and scenario.step_i > 0: + # generate plot of failed scenario + args.mode = args.mode[:i] + ["ABORTED"] + create_results_directory(args, i+1) + report.generate_plots(scenario, args) + logging.info(f"Created plot of failed scenario in {args.results_directory}") + # continue with other modes after error def create_results_directory(args, i): diff --git a/ebus_toolbox/trip.py b/ebus_toolbox/trip.py index 258276e8..0d7d4713 100644 --- a/ebus_toolbox/trip.py +++ b/ebus_toolbox/trip.py @@ -55,6 +55,7 @@ def calculate_consumption(self): :return: Consumption of trip [kWh] :rtype: float + :raises with_traceback: if consumption cannot be constructed """ try: diff --git a/ebus_toolbox/util.py b/ebus_toolbox/util.py index 270b1d25..1ae3040f 100644 --- a/ebus_toolbox/util.py +++ b/ebus_toolbox/util.py @@ -1,7 +1,6 @@ import argparse import json import logging -import warnings import subprocess from spice_ev.util import set_options_from_config From d0541baba30309a738eb12f0be3e9e8630953a09 Mon Sep 17 00:00:00 2001 From: "stefan.schirmeister" Date: Thu, 1 Jun 2023 12:43:10 +0200 Subject: [PATCH 4/6] tidy up --- ebus_toolbox/__main__.py | 1 - ebus_toolbox/simulate.py | 2 -- 2 files changed, 3 deletions(-) diff --git a/ebus_toolbox/__main__.py b/ebus_toolbox/__main__.py index 5f7bcc86..511503f7 100644 --- a/ebus_toolbox/__main__.py +++ b/ebus_toolbox/__main__.py @@ -5,7 +5,6 @@ from ebus_toolbox import simulate, util - if __name__ == '__main__': args = util.get_args() diff --git a/ebus_toolbox/simulate.py b/ebus_toolbox/simulate.py index a2b158a1..e5c1e76f 100644 --- a/ebus_toolbox/simulate.py +++ b/ebus_toolbox/simulate.py @@ -136,9 +136,7 @@ def simulate(args): logging.error('*'*len(msg)) logging.error(e) logging.error('*'*len(msg)) - # logging.error(str(e.__traceback__)) logging.error(traceback.format_exc()) - # logging.error(traceback.print_exception(type(e), e, e.__traceback__)) if scenario is not None and scenario.step_i > 0: # generate plot of failed scenario args.mode = args.mode[:i] + ["ABORTED"] From 9293070df5e0748b375279befc35494ac2dd396f Mon Sep 17 00:00:00 2001 From: "stefan.schirmeister" Date: Fri, 2 Jun 2023 09:13:19 +0200 Subject: [PATCH 5/6] minor changes - logging.warning instead of logging.warn (deprecated) - correct spelling of SpiceEV - remove DEBUG logging of matplotlib - move logging setup to util --- ebus_toolbox/__main__.py | 20 +------------------- ebus_toolbox/optimization.py | 6 +++--- ebus_toolbox/report.py | 6 +++++- ebus_toolbox/schedule.py | 16 ++++++++-------- ebus_toolbox/simulate.py | 10 +++++----- ebus_toolbox/util.py | 31 ++++++++++++++++++++++++++----- 6 files changed, 48 insertions(+), 41 deletions(-) diff --git a/ebus_toolbox/__main__.py b/ebus_toolbox/__main__.py index 511503f7..486afa42 100644 --- a/ebus_toolbox/__main__.py +++ b/ebus_toolbox/__main__.py @@ -29,25 +29,7 @@ shutil.copy(c_file, args.output_directory_input / c_file.name) util.save_version(args.output_directory_input / "program_version.txt") - - # set up logging - # always to console - log_handlers = [logging.StreamHandler()] - if args.logfile is not None: - # optionally to file in output dir - if args.logfile: - log_name = args.logfile - else: - log_name = f"{time_str}.log" - log_path = args.output_directory / log_name - print(f"Writing log to {log_path}") - log_handlers.append(logging.FileHandler(log_path)) - logging.basicConfig( - level=vars(logging)[args.loglevel], - format="%(asctime)s [%(levelname)s] %(message)s", - handlers=log_handlers - ) - logging.captureWarnings(True) + util.setup_logging(args, time_str) try: simulate.simulate(args) diff --git a/ebus_toolbox/optimization.py b/ebus_toolbox/optimization.py index e6243d6e..a0906a32 100644 --- a/ebus_toolbox/optimization.py +++ b/ebus_toolbox/optimization.py @@ -39,8 +39,8 @@ def service_optimization(schedule, scenario, args): rotation = schedule.rotations.pop(rot_key) if rotation.charging_type != "oppb": # only oppb rotations are optimized -> skip others - logging.warn(f"Rotation {rot_key} should be optimized, " - f"but is of type {rotation.charging_type}.") + logging.warning(f"Rotation {rot_key} should be optimized, " + f"but is of type {rotation.charging_type}.") continue # oppb: build non-interfering sets of negative rotations # (these include the dependent non-negative rotations) @@ -58,7 +58,7 @@ def service_optimization(schedule, scenario, args): dependent_station.update({r2: t2 for r2, t2 in common_stations[r].items() if t2 <= t}) elif r.charging_type != "obbp": - logging.warn(f"Rotation {rot_key} depends on negative non-oppb rotation") + logging.warning(f"Rotation {rot_key} depends on negative non-oppb rotation") negative_sets[rot_key] = s diff --git a/ebus_toolbox/report.py b/ebus_toolbox/report.py index d01c404f..0ae9e790 100644 --- a/ebus_toolbox/report.py +++ b/ebus_toolbox/report.py @@ -102,6 +102,8 @@ def generate_plots(scenario, args): :type args: argparse.Namespace """ aggregate_global_results(scenario) + # disable DEBUG logging from matplotlib + logging.disable(logging.INFO) with plt.ion(): # make plotting temporarily interactive, so plt.show does not block plt.clf() plot(scenario) @@ -110,6 +112,8 @@ def generate_plots(scenario, args): plt.savefig(args.results_directory / "run_overview.pdf") if args.show_plots: plt.show() + # revert logging override + logging.disable(logging.NOTSET) def generate(schedule, scenario, args): @@ -199,7 +203,7 @@ def generate(schedule, scenario, args): rotation_socs[id][start_idx:end_idx] = rotation_soc_ts if incomplete_rotations: - logging.warn( + logging.warning( "SpiceEV stopped before simulation of the these rotations were completed:\n" f"{', '.join(incomplete_rotations)}\n" "Omit parameter to simulate entire schedule.") diff --git a/ebus_toolbox/schedule.py b/ebus_toolbox/schedule.py index 1caefe52..5f4d24e7 100644 --- a/ebus_toolbox/schedule.py +++ b/ebus_toolbox/schedule.py @@ -186,12 +186,12 @@ def run(self, args): scenario = self.generate_scenario(args) - logging.info("Running Spice EV...") + logging.info("Running SpiceEV...") with warnings.catch_warnings(): warnings.simplefilter('ignore', UserWarning) scenario.run('distributed', vars(args).copy()) assert scenario.step_i == scenario.n_intervals, \ - 'spiceEV simulation aborted, see above for details' + 'SpiceEV simulation aborted, see above for details' return scenario def set_charging_type(self, ct, rotation_ids=None): @@ -345,7 +345,7 @@ def get_common_stations(self, only_opps=True): def get_negative_rotations(self, scenario): """ - Get rotations with negative soc from spice_ev outputs + Get rotations with negative soc from SpiceEV outputs :param scenario: Simulation scenario containing simulation results including the SoC of all vehicles over time @@ -382,13 +382,13 @@ def get_negative_rotations(self, scenario): return list(negative_rotations) def generate_scenario(self, args): - """ Generate scenario.json for spiceEV + """ Generate scenario.json for SpiceEV :param args: Command line arguments and/or arguments from config file. :type args: argparse.Namespace - :return: A spiceEV Scenario instance that can be run and also collects all + :return: A SpiceEV Scenario instance that can be run and also collects all simulation outputs. - :rtype: spice_ev.Scenario + :rtype: SpiceEV.Scenario """ random.seed(args.seed) @@ -640,9 +640,9 @@ def generate_scenario(self, args): events['energy_price_from_csv'] = options price_csv_path = args.output_directory / filename if not price_csv_path.exists(): - logging.warn(f"Price csv file '{price_csv_path}' does not exist yet") + logging.warning(f"Price csv file '{price_csv_path}' does not exist yet") - # reformat vehicle types for spiceEV + # reformat vehicle types for SpiceEV vehicle_types_spiceev = { f'{vehicle_type}_{charging_type}': body for vehicle_type, subtypes in self.vehicle_types.items() diff --git a/ebus_toolbox/simulate.py b/ebus_toolbox/simulate.py index e5c1e76f..d960fa16 100644 --- a/ebus_toolbox/simulate.py +++ b/ebus_toolbox/simulate.py @@ -73,7 +73,7 @@ def simulate(args): result = optimization.service_optimization(schedule, scenario, args) schedule, scenario = result['optimized'] if scenario is None: - logging.warn('No optimization possible (all rotations negative), reverting') + logging.warning('No optimization possible (all rotations negative), reverting') schedule, scenario = result['original'] elif mode in ['neg_depb_to_oppb', 'neg_oppb_to_depb']: # simple optimization: change charging type, simulate again @@ -96,8 +96,8 @@ def simulate(args): logging.info(f'Rotations {", ".join(neg_rot)} remain negative.') elif mode == "station_optimization": if not args.optimizer_config: - logging.warn("Station optimization needs an optimization config file. " - "Since no path was given, station optimization is skipped") + logging.warning("Station optimization needs an optimization config file. " + "Since no path was given, station optimization is skipped") continue conf = read_optimizer_config(args.optimizer_config) try: @@ -105,8 +105,8 @@ def simulate(args): schedule, scenario = run_optimization(conf, sched=schedule, scen=scenario, args=args) except Exception as err: - logging.warn('During Station optimization an error occurred {0}. ' - 'Optimization was skipped'.format(err)) + logging.warning('During Station optimization an error occurred {0}. ' + 'Optimization was skipped'.format(err)) elif mode == 'remove_negative': neg_rot = schedule.get_negative_rotations(scenario) if neg_rot: diff --git a/ebus_toolbox/util.py b/ebus_toolbox/util.py index 1ae3040f..2e3b6896 100644 --- a/ebus_toolbox/util.py +++ b/ebus_toolbox/util.py @@ -131,13 +131,13 @@ def get_csv_delim(path, other_delims=set()): return counters.popitem()[0] # if not even a single delimiter is remaining elif not counters: - logging.warn("Warning: Delimiter could not be found.\n" - "Returning standard Delimiter ','") + logging.warning("Warning: Delimiter could not be found.\n" + "Returning standard Delimiter ','") return "," # multiple delimiters are possible. Every row was checked but more than 1 delimiter # has the same amount of occurrences (>0) in every row. - logging.warn("Warning: Delimiter could not be found.\n" - "Returning standard delimiter ','") + logging.warning("Warning: Delimiter could not be found.\n" + "Returning standard delimiter ','") return "," @@ -218,6 +218,27 @@ def nd_interp(input_values, lookup_table): return points[0][-1] +def setup_logging(args, time_str): + # set up logging + # always to console + log_handlers = [logging.StreamHandler()] + if args.logfile is not None: + # optionally to file in output dir + if args.logfile: + log_name = args.logfile + else: + log_name = f"{time_str}.log" + log_path = args.output_directory / log_name + print(f"Writing log to {log_path}") + log_handlers.append(logging.FileHandler(log_path)) + logging.basicConfig( + level=vars(logging)[args.loglevel], + format="%(asctime)s [%(levelname)s] %(message)s", + handlers=log_handlers + ) + logging.captureWarnings(True) + + def get_args(): parser = argparse.ArgumentParser( description='eBus-Toolbox - simulation program for electric bus fleets.') @@ -313,7 +334,7 @@ def get_args(): choices=logging._nameToLevel.keys(), help='Log level.') parser.add_argument('--logfile', default='', help='Log file suffix. null: no log file.') - # #### SPICE EV PARAMETERS ONLY DEFAULT VALUES NOT IN eBus-Toolbox CONFIG ##### + # #### SpiceEV PARAMETERS ONLY DEFAULT VALUES NOT IN eBus-Toolbox CONFIG ##### parser.add_argument('--seed', default=1, type=int, help='set random seed') parser.add_argument('--include-price-csv', help='include CSV for energy price. \ From 1ed378e9218e960f06bafe009d13ade252cc466b Mon Sep 17 00:00:00 2001 From: "stefan.schirmeister" Date: Wed, 2 Aug 2023 13:54:10 +0200 Subject: [PATCH 6/6] set log file encoding to UTF-8 --- ebus_toolbox/util.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ebus_toolbox/util.py b/ebus_toolbox/util.py index 3f40d4ed..323d376e 100644 --- a/ebus_toolbox/util.py +++ b/ebus_toolbox/util.py @@ -230,7 +230,7 @@ def setup_logging(args, time_str): log_name = f"{time_str}.log" log_path = args.output_directory / log_name print(f"Writing log to {log_path}") - log_handlers.append(logging.FileHandler(log_path)) + log_handlers.append(logging.FileHandler(log_path, encoding='utf-8')) logging.basicConfig( level=vars(logging)[args.loglevel], format="%(asctime)s [%(levelname)s] %(message)s",