From a4673f400ef1eff136fb8534c7ee5f716f2b09db Mon Sep 17 00:00:00 2001 From: Chris Weber Date: Wed, 1 Apr 2020 19:06:30 +0200 Subject: [PATCH 01/13] WIP: Adds logging --- spotpy/__init__.py | 17 +++--- spotpy/algorithms/_algorithm.py | 97 +++++++++++++++++-------------- spotpy/algorithms/abc.py | 26 ++++----- spotpy/algorithms/dds.py | 6 +- spotpy/algorithms/demcz.py | 72 +++++++++++------------ spotpy/algorithms/dream.py | 92 ++++++++++++++--------------- spotpy/algorithms/fast.py | 14 ++--- spotpy/algorithms/fscabc.py | 20 +++---- spotpy/algorithms/lhs.py | 4 +- spotpy/algorithms/list_sampler.py | 2 +- spotpy/algorithms/mc.py | 2 +- spotpy/algorithms/mcmc.py | 39 ++++++------- spotpy/algorithms/mle.py | 8 +-- spotpy/algorithms/padds.py | 4 +- spotpy/algorithms/rope.py | 16 ++--- spotpy/algorithms/sa.py | 4 +- spotpy/algorithms/sceua.py | 52 ++++++++--------- spotpy/analyser.py | 97 ++++++++++++++++--------------- spotpy/database/base.py | 23 ++++---- spotpy/database/csv.py | 4 +- spotpy/database/hdf5.py | 2 +- spotpy/objectivefunctions.py | 79 ++++++++++++------------- spotpy/spotpylogging.py | 34 +++++++++++ 23 files changed, 380 insertions(+), 334 deletions(-) create mode 100644 spotpy/spotpylogging.py diff --git a/spotpy/__init__.py b/spotpy/__init__.py index eed88abe..084fd2db 100644 --- a/spotpy/__init__.py +++ b/spotpy/__init__.py @@ -5,17 +5,17 @@ :author: Tobias Houska -:paper: Houska, T., Kraft, P., Chamorro-Chavez, A. and Breuer, L.: -SPOTting Model Parameters Using a Ready-Made Python Package, +:paper: Houska, T., Kraft, P., Chamorro-Chavez, A. and Breuer, L.: +SPOTting Model Parameters Using a Ready-Made Python Package, PLoS ONE, 10(12), e0145180, doi:10.1371/journal.pone.0145180, 2015. -This package enables the comprehensive use of different Bayesian and Heuristic calibration -techniques in one Framework. It comes along with an algorithms folder for the +This package enables the comprehensive use of different Bayesian and Heuristic calibration +techniques in one Framework. It comes along with an algorithms folder for the sampling and an analyser class for the plotting of results by the sampling. -:dependencies: - Numpy >1.8 (http://www.numpy.org/) +:dependencies: - Numpy >1.8 (http://www.numpy.org/) - Pandas >0.13 (optional) (http://pandas.pydata.org/) - - Matplotlib >1.4 (optional) (http://matplotlib.org/) + - Matplotlib >1.4 (optional) (http://matplotlib.org/) - CMF (optional) (http://fb09-pasig.umwelt.uni-giessen.de:8000/) - mpi4py (optional) (http://mpi4py.scipy.org/) - pathos (optional) (https://pypi.python.org/pypi/pathos/) @@ -30,8 +30,9 @@ Please cite our paper, if you are using SPOTPY. ''' from . import database # Writes the results of the sampler in a user defined output file -from . import algorithms # Contains all the different algorithms implemented in SPOTPY +from . import algorithms # Contains all the different algorithms implemented in SPOTPY from . import parameter # Contains different distributions to describe the prior information for every model parameter +from . import spotpylogging from . import analyser # Contains some examples to analyse the results of the different algorithms from . import objectivefunctions # Quantifies goodness of fit between simulation and evaluation data with objective functions from . import likelihoods # Quantifies goodness of fit between simulation and evaluation data with likelihood functions @@ -39,4 +40,4 @@ from . import describe # Contains some helper functions to describe samplers and set-ups from .hydrology import signatures # Quantifies goodness of fit between simulation and evaluation data with hydrological signatures -__version__ = '1.5.8' \ No newline at end of file +__version__ = '1.5.8' diff --git a/spotpy/algorithms/_algorithm.py b/spotpy/algorithms/_algorithm.py index 2fe61884..e1166ac4 100644 --- a/spotpy/algorithms/_algorithm.py +++ b/spotpy/algorithms/_algorithm.py @@ -11,6 +11,7 @@ from __future__ import unicode_literals from spotpy import database from spotpy import parameter +from spotpy import spotpylogging import numpy as np import time import threading @@ -29,7 +30,7 @@ class _RunStatistic(object): """ - this class checks for each run if the objectivefunction got better and holds the + this class checks for each run if the objectivefunction got better and holds the best parameter set. Every _algorithm has an object of this class as status. Usage: @@ -39,13 +40,16 @@ class _RunStatistic(object): def __init__(self, repetitions, algorithm_name, optimization_direction, parnames): self.optimization_direction = optimization_direction #grid, mazimize, minimize - print('Initializing the ',algorithm_name,' with ',repetitions,' repetitions') + + self.logger = spotpylogging.get_logger("RunStatistic(%s)" % algorithm_name ) + + self.logger.info('Initializing the %s with %s repetitions', algorithm_name, repetitions) if optimization_direction == 'minimize': self.compare = self.minimizer - print('The objective function will be minimized') + self.logger.info('The objective function will be minimized') if optimization_direction == 'maximize': self.compare = self.maximizer - print('The objective function will be minimized') + self.logger.info('The objective function will be minimized') if optimization_direction == 'grid': self.compare = self.grid @@ -58,7 +62,7 @@ def __init__(self, repetitions, algorithm_name, optimization_direction, parnames self.objectivefunction_max = -1e308 self.starttime = time.time() self.last_print = time.time() - + self.repetitions = repetitions self.stop = False @@ -116,42 +120,42 @@ def print_status(self): text = '%i of %i, min objf=%g, max objf=%g, time remaining: %s' % ( self.rep, self.repetitions, self.objectivefunction_min, self.objectivefunction_max, timestr) - print(text) + self.logger.info(text) self.last_print = time.time() def print_status_final(self): - print('\n*** Final SPOTPY summary ***') - print('Total Duration: ' + str(round((time.time() - self.starttime), 2)) + ' seconds') - print('Total Repetitions:', self.rep) + self.logger.info('\n*** Final SPOTPY summary ***') + self.logger.info('Total Duration: %s seconds' % str(round((time.time() - self.starttime), 2))) + self.logger.info('Total Repetitions: %s', self.rep) if self.optimization_direction == 'minimize': - print('Minimal objective value: %g' % (self.objectivefunction_min)) - print('Corresponding parameter setting:') + self.logger.info('Minimal objective value: %g' % (self.objectivefunction_min)) + self.logger.info('Corresponding parameter setting:') for i in range(self.parameters): text = '%s: %g' % (self.parnames[i], self.params_min[i]) - print(text) + self.logger.info(text) if self.optimization_direction == 'maximize': - print('Maximal objective value: %g' % (self.objectivefunction_max)) - print('Corresponding parameter setting:') + self.logger.info('Maximal objective value: %g' % (self.objectivefunction_max)) + self.logger.info('Corresponding parameter setting:') for i in range(self.parameters): text = '%s: %g' % (self.parnames[i], self.params_max[i]) - print(text) + self.logger.info(text) if self.optimization_direction == 'grid': - print('Minimal objective value: %g' % (self.objectivefunction_min)) - print('Corresponding parameter setting:') + self.logger.info('Minimal objective value: %g' % (self.objectivefunction_min)) + self.logger.info('Corresponding parameter setting:') for i in range(self.parameters): text = '%s: %g' % (self.parnames[i], self.params_min[i]) - print(text) + self.logger.info(text) - print('Maximal objective value: %g' % (self.objectivefunction_max)) - print('Corresponding parameter setting:') + self.logger.info('Maximal objective value: %g' % (self.objectivefunction_max)) + self.logger.info('Corresponding parameter setting:') for i in range(self.parameters): text = '%s: %g' % (self.parnames[i], self.params_max[i]) - print(text) + self.logger.info(text) - print('******************************\n') + self.logger.info('******************************\n') def __repr__(self): @@ -166,24 +170,24 @@ class _algorithm(object): Input ---------- spot_setup: class - model: function - Should be callable with a parameter combination of the parameter-function + model: function + Should be callable with a parameter combination of the parameter-function and return an list of simulation results (as long as evaluation list) parameter: function - When called, it should return a random parameter combination. Which can + When called, it should return a random parameter combination. Which can be e.g. uniform or Gaussian - objectivefunction: function - Should return the objectivefunction for a given list of a model simulation and + objectivefunction: function + Should return the objectivefunction for a given list of a model simulation and observation. evaluation: function Should return the true values as return by the model. dbname: str - Name of the database where parameter, objectivefunction value and simulation + Name of the database where parameter, objectivefunction value and simulation results will be saved. dbformat: str ram: fast suited for short sampling time. no file will be created and results are saved in an array. - csv: A csv file will be created, which you can import afterwards. + csv: A csv file will be created, which you can import afterwards. parallel: str seq: Sequentiel sampling (default): Normal iterations on one core of your cpu. mpc: Multi processing: Iterations on all available cores on your (single) pc @@ -209,6 +213,9 @@ def __init__(self, spot_setup, dbname=None, dbformat=None, dbinit=True, backup_every_rep=100, save_threshold=-np.inf, db_precision=np.float16, sim_timeout=None, random_state=None, optimization_direction='grid', algorithm_name=''): + # Instatiate logging + self.logger = spotpylogging.get_logger(self.__class__.__name__) + # Initialize the user defined setup class self.setup = spot_setup param_info = parameter.get_parameters_array(self.setup, unaccepted_parameter_types=self._unaccepted_parameter_types) @@ -219,7 +226,7 @@ def __init__(self, spot_setup, dbname=None, dbformat=None, dbinit=True, for i, val in enumerate(self.all_params): if self.all_params[i] not in self.constant_positions: self.non_constant_positions.append(i) - else: + else: self.non_constant_positions = np.arange(0,len(self.all_params)) self.parameter = self.get_parameters self.parnames = param_info['name'] @@ -240,22 +247,22 @@ def __init__(self, spot_setup, dbname=None, dbformat=None, dbinit=True, # 'dbappend' used to append to the existing data base, after restart self.dbinit = dbinit self.dbappend = dbappend - + # Set the random state if random_state is None: #ToDo: Have to discuss if these 3 lines are neccessary. random_state = np.random.randint(low=0, high=2**30) - np.random.seed(random_state) + np.random.seed(random_state) # If value is not None a timeout will set so that the simulation will break after sim_timeout seconds without return a value self.sim_timeout = sim_timeout self.save_threshold = save_threshold if breakpoint == 'read' or breakpoint == 'readandwrite': - print('Reading backupfile') + self.logger.info('Reading backupfile') try: open(self.dbname+'.break') except FileNotFoundError: - print('Backupfile not found') + self.logger.info('Backupfile not found') self.dbappend = True # Now a repeater (ForEach-object) is loaded @@ -290,7 +297,7 @@ def __init__(self, spot_setup, dbname=None, dbformat=None, dbinit=True, # method "save" needs to know whether objective function result is list or float, default is float self.like_struct_typ = type(1.1) - + def __str__(self): return '{type}({mtype}())->{dbname}'.format( type=type(self).__name__, @@ -327,7 +334,7 @@ def final_call(self): def _init_database(self, like, randompar, simulations): if self.dbinit: - print('Initialize database...') + self.logger.info('Initialize database...') self.datawriter = database.get_datawriter(self.dbformat, self.dbname, self.parnames, like, randompar, simulations, @@ -387,10 +394,10 @@ def update_params(self, params): #Add potential Constant parameters self.all_params[self.non_constant_positions] = params return self.all_params - - + + def postprocessing(self, rep, params, simulation, chains=1, save_run=True, negativlike=False, block_print=False): # TODO: rep not necessaray - + params = self.update_params(params) if negativlike is True: like = -self.getfitness(simulation=simulation, params=params) @@ -402,27 +409,27 @@ def postprocessing(self, rep, params, simulation, chains=1, save_run=True, negat # before they actually save the run in a database (e.g. sce-ua) self.status(like,params,block_print=block_print) - + if save_run is True and simulation is not None: self.save(like, params, simulations=simulation, chains=chains) if type(like)==type([]): return like[0] - else: + else: return like - + def getfitness(self, simulation, params): """ Calls the user defined spot_setup objectivefunction """ try: - #print('Using parameters in fitness function') + #self.logger.info('Using parameters in fitness function') return self.setup.objectivefunction(evaluation=self.evaluation, simulation=simulation, params = (params,self.parnames)) except TypeError: # Happens if the user does not allow to pass parameter in the spot_setup.objectivefunction - #print('Not using parameters in fitness function') + #self.logger.info('Not using parameters in fitness function') return self.setup.objectivefunction(evaluation=self.evaluation, simulation=simulation) - + def simulate(self, id_params_tuple): """This is a simple wrapper of the model, returning the result together with the run id and the parameters. This is needed, because some parallel things diff --git a/spotpy/algorithms/abc.py b/spotpy/algorithms/abc.py index be0d4fba..0c12876c 100644 --- a/spotpy/algorithms/abc.py +++ b/spotpy/algorithms/abc.py @@ -79,7 +79,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, ownlimit=False, li sets the limit """ self.set_repetiton(repetitions) - print('Starting the ABC algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Starting the ABC algotrithm with '+str(repetitions)+ ' repetitions...') # Initialize ABC parameters: randompar = self.parameter()['random'] self.nopt = randompar.size @@ -104,7 +104,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, ownlimit=False, li work.append([like, randompar, like, randompar, c, p]) icall +=1 if self.status.stop: - print('Stopping sampling') + self.logger.info('Stopping sampling') break while icall < repetitions and gnrng > peps: @@ -133,10 +133,10 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, ownlimit=False, li work[rep][0] = clike work[rep][4] = 0 else: - work[rep][4] = work[rep][4] + 1 + work[rep][4] = work[rep][4] + 1 icall += 1 if self.status.stop: - print('Stopping samplig') + self.logger.info('Stopping samplig') break # Probability distribution for roulette wheel selection bn = [] for i, val in enumerate(work): @@ -179,10 +179,10 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, ownlimit=False, li work[rep][0] = clike work[rep][4] = 0 else: - work[rep][4] = work[rep][4] + 1 + work[rep][4] = work[rep][4] + 1 icall += 1 if self.status.stop: - print('Stopping samplig') + self.logger.info('Stopping samplig') break # Scout bee phase for i, val in enumerate(work): @@ -195,17 +195,17 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, ownlimit=False, li work[i][0] = clike icall += 1 if self.status.stop: - print('Stopping samplig') + self.logger.info('Stopping samplig') break gnrng = -self.status.objectivefunction_max if icall >= repetitions: - print('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') - print('ON THE MAXIMUM NUMBER OF TRIALS ') - print(repetitions) - print('HAS BEEN EXCEEDED.') + self.logger.info('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') + self.logger.info('ON THE MAXIMUM NUMBER OF TRIALS ') + self.logger.info(repetitions) + self.logger.info('HAS BEEN EXCEEDED.') if gnrng < peps: - print( + self.logger.info( 'THE POPULATION HAS CONVERGED TO A PRESPECIFIED SMALL PARAMETER SPACE AT RUN') - print(icall) + self.logger.info(icall) self.final_call() diff --git a/spotpy/algorithms/dds.py b/spotpy/algorithms/dds.py index 11c488cc..d9cccba0 100644 --- a/spotpy/algorithms/dds.py +++ b/spotpy/algorithms/dds.py @@ -273,7 +273,7 @@ def sample(self, repetitions, trials=1, x_initial=np.array([])): self.set_repetiton(repetitions) self.min_bound, self.max_bound = self.parameter( )['minbound'], self.parameter()['maxbound'] - print('Starting the DDS algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Starting the DDS algotrithm with '+str(repetitions)+ ' repetitions...') number_of_parameters = self.status.parameters # number_of_parameters is the amount of parameters @@ -311,7 +311,7 @@ def sample(self, repetitions, trials=1, x_initial=np.array([])): self.params_max = list(x_curr) self.params_max = self.fix_status_params_format(self.params_max) - print('Best solution found has obj function value of ' + str(objectivefunction_max) + ' at ' + self.logger.info('Best solution found has obj function value of ' + str(objectivefunction_max) + ' at ' + str(repitionno_best) + '\n\n') debug_results.append({"sbest": self.params_max, "trial_initial": trial_best_value,"objfunc_val": objectivefunction_max}) self.final_call() @@ -334,7 +334,7 @@ def calc_initial_para_configuration(self, initial_iterations, trial, repetitions # by trying which randomized generated input matches best # initial_iterations is the number of function evaluations to initialize the DDS algorithm solution if initial_iterations > 1: - print('Finding best starting point for trial ' + str(trial + 1) + ' using ' + str( + self.logger.info('Finding best starting point for trial ' + str(trial + 1) + ' using ' + str( initial_iterations) + ' random samples.') repetions_left = repetitions - initial_iterations # use this to reduce number of fevals in DDS loop if repetions_left <= 0: diff --git a/spotpy/algorithms/demcz.py b/spotpy/algorithms/demcz.py index d325613a..6096d3dc 100644 --- a/spotpy/algorithms/demcz.py +++ b/spotpy/algorithms/demcz.py @@ -77,19 +77,19 @@ def __init__(self, *args, **kwargs): observation. evaluation: function Should return the true values as return by the model. - + dbname: str * Name of the database where parameter, objectivefunction value and simulation results will be saved. - + dbformat: str * ram: fast suited for short sampling time. no file will be created and results are saved in an array. * csv: A csv file will be created, which you can import afterwards. - + parallel: str * seq: Sequentiel sampling (default): Normal iterations on one core of your cpu. * mpc: Multi processing: Iterations on all available cores on your cpu (recommended for windows os). * mpi: Message Passing Interface: Parallel computing on cluster pcs (recommended for unix os). - + save_sim: boolean * True: Simulation results will be saved * False: Simulationt results will not be saved @@ -106,10 +106,10 @@ def check_par_validity(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - print('ERROR Bounds have not the same lenghts as Parameterarray') + self.logger.info('ERROR Bounds have not the same lenghts as Parameterarray') return par - - def sample(self, repetitions, nChains=3, burnIn=100, thin=1, + + def sample(self, repetitions, nChains=3, burnIn=100, thin=1, convergenceCriteria=.8, variables_of_interest=None, DEpairs=2, adaptationRate='auto', eps=5e-2, mConvergence=True, mAccept=True): @@ -119,7 +119,7 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, Parameters ---------- repetitions : int - number of draws from the sample distribution to be returned + number of draws from the sample distribution to be returned nChains : int number of different chains to employ burnInSize : int @@ -133,9 +133,9 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, ------- None : None """ - + self.set_repetiton(repetitions) - print('Starting the DEMCz algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Starting the DEMCz algotrithm with '+str(repetitions)+ ' repetitions...') self.min_bound, self.max_bound = self.parameter( )['minbound'], self.parameter()['maxbound'] @@ -179,7 +179,7 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, likelist = self.postprocessing(i, vector, simulations, chains=rep) simulationlist.append(simulations) self._logPs.append(likelist) - old_like[rep] = likelist + old_like[rep] = likelist burnInpar[i][rep] = vector if self.status.stop: break @@ -188,16 +188,16 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, gamma = None self.accepts_ratio = 0.000001 - + # initilize the convergence diagnostic object grConvergence = _GRConvergence() covConvergence = _CovarianceConvergence() - + # get the starting log objectivefunction and position for each of the # chains currentVectors = burnInpar[-1] currentLogPs = self._logPs[-1] - + # 2)now loop through and sample cur_iter = 0 accepts_ratio_weighting = 1 - np.exp(-1.0 / 30) @@ -206,19 +206,19 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, # 1) we have not drawn enough samples to satisfy the minimum number of iterations # 2) or any of the dimensions have not converged # 3) and we have not done more than the maximum number of iterations - + while cur_iter < maxChainDraws: - print(cur_iter, burnIn) + self.logger.info("%s, %s", cur_iter, burnIn) if cur_iter == burnIn: - print('starting') + self.logger.info('starting') history.start_sampling() - + # every5th iteration allow a big jump if np.random.randint(5) == 0.0: gamma = np.array([1.0]) else: gamma = np.array([2.38 / np.sqrt(2 * DEpairs * dimensions)]) - + if cur_iter >= burnIn: proposalVectors = _dream_proposals( currentVectors, history, dimensions, nChains, DEpairs, gamma, .05, eps) @@ -232,14 +232,14 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, proposalVectors.append(self.parameter()['random']) proposalVectors[i] = self.check_par_validity( proposalVectors[i]) - + # if self.bounds_ok(minbound,maxbound,proposalVectors,nChains): proposalLogPs = [] old_simulationlist = simulationlist old_likelist = self._logPs[-1] new_simulationlist = [] new_likelist = [] - + param_generator = ( (rep, list(proposalVectors[rep])) for rep in range(int(nChains))) for rep, vector, simulations in self.repeat(param_generator): @@ -251,13 +251,13 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, if self.status.stop: cur_iter = maxChainDraws break - + if not self.status.stop: # apply the metrop decision to decide whether to accept or reject # each chain proposal decisions, acceptance = self._metropolis_hastings( currentLogPs, proposalLogPs, nChains) - self._update_accepts_ratio(accepts_ratio_weighting, acceptance) + self._update_accepts_ratio(accepts_ratio_weighting, acceptance) # choose from list of possible choices if 1d_decision is True at # specific index, else use default choice # np.choose(1d_decision[:,None], (list of possible choices, default @@ -276,33 +276,33 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, save_likes.append(old_like[curchain]) save_pars.append(currentVectors[curchain]) save_sims.append(old_simulationlist[curchain]) - + currentVectors = np.choose( decisions[:, np.newaxis], (currentVectors, proposalVectors)) currentLogPs = np.choose(decisions, (currentLogPs, proposalLogPs)) - + simulationlist = [[new_simulationlist, old_simulationlist][ int(x)][ix] for ix, x in enumerate(decisions)] - + likelist = list( np.choose(decisions[:, np.newaxis], (new_likelist, old_likelist))) - + # we only want to recalculate convergence criteria when we are past # the burn in period - + if cur_iter % thin == 0: - + historyStartMovementRate = adaptationRate # try to adapt more when the acceptance rate is low and less # when it is high if adaptationRate == 'auto': historyStartMovementRate = min( (.234 / self.accepts_ratio) * .5, .95) - + history.record( currentVectors, currentLogPs, historyStartMovementRate, grConvergence=grConvergence.R) - + if history.nsamples > 0 and cur_iter > lastRecalculation * 1.1 and history.nsequence_histories > dimensions: lastRecalculation = cur_iter grConvergence.update(history) @@ -310,10 +310,10 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, covConvergence.update(history, 'interest') if all(grConvergence.R < convergenceCriteria): cur_iter = maxChainDraws - print( + self.logger.info( 'All chains fullfil the convergence criteria. Sampling stopped.') cur_iter+=1 - + # 3) finalize # only make the second half of draws available because that's the only # part used by the convergence diagnostic @@ -323,10 +323,10 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, self.burnIn = burnIn self.R = grConvergence.R text = 'Gelman Rubin R=' + str(self.R) - print(text) + self.logger.info(text) self.status.rep = self.status.repetitions self.final_call() - + def _update_accepts_ratio(self, weighting, acceptances): self.accepts_ratio = weighting * \ @@ -503,7 +503,7 @@ def rv(relevantHistory): projection = np.dot(np.linalg.inv(basis1), basis2) except np.linalg.linalg.LinAlgError: projection = (np.array(basis1) * np.nan) - print('Exception happend!') + self.logger.info('Exception happend!') # find the releative size in each of the basis1 directions return np.log(np.sum(projection**2, axis=0)**.5) diff --git a/spotpy/algorithms/dream.py b/spotpy/algorithms/dream.py index 055dcc65..554c09ae 100644 --- a/spotpy/algorithms/dream.py +++ b/spotpy/algorithms/dream.py @@ -17,7 +17,7 @@ class dream(_algorithm): """ - Implements the DiffeRential Evolution Adaptive Metropolis (DREAM) algorithhm + Implements the DiffeRential Evolution Adaptive Metropolis (DREAM) algorithhm based on: Vrugt, J. A. (2016) Markov chain Monte Carlo simulation using the DREAM software package. """ @@ -67,11 +67,11 @@ def check_par_validity_bound(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - print('ERROR: Bounds have not the same lenghts as Parameterarray') + self.logger.info('ERROR: Bounds have not the same lenghts as Parameterarray') return par def get_regular_startingpoint(self,nChains): - randompar=self.parameter()['random'] + randompar=self.parameter()['random'] for i in range(1000): randompar=np.column_stack((randompar,self.parameter()['random'])) startpoints = [] @@ -81,7 +81,7 @@ def get_regular_startingpoint(self,nChains): for k in range(len(randompar)): random.shuffle(startpoints[:, k]) return startpoints - + def check_par_validity_reflect(self, par): if len(par) == len(self.min_bound) and len(par) == len(self.max_bound): for i in range(len(par)): @@ -97,7 +97,7 @@ def check_par_validity_reflect(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - print('ERROR: Bounds have not the same lenghts as Parameterarray') + self.logger.info('ERROR: Bounds have not the same lenghts as Parameterarray') return par def _get_gamma(self,N): @@ -110,39 +110,39 @@ def _get_gamma(self,N): return gamma def get_other_random_chains(self,cur_chain): - valid=False - while valid == False: + valid=False + while valid == False: random_chain1 = np.random.randint(0,self.nChains) random_chain2 = np.random.randint(0,self.nChains) if random_chain1!=cur_chain and random_chain2!=cur_chain and random_chain1!=random_chain2: valid=True return random_chain1, random_chain2 - + def get_new_proposal_vector(self,cur_chain,newN,nrN): gamma = self._get_gamma(nrN) random_chain1,random_chain2 = self.get_other_random_chains(cur_chain) - new_parameterset=[] + new_parameterset=[] #position = self.chain_samples-1#self.nChains*self.chain_samples+self.chain_samples+cur_chain-1 cur_par_set = list(self.bestpar[cur_chain][self.nChainruns[cur_chain]-1]) random_par_set1 = list(self.bestpar[random_chain1][self.nChainruns[random_chain1]-1]) random_par_set2 = list(self.bestpar[random_chain2][self.nChainruns[random_chain2]-1]) - + for i in range(self.N):#Go through parameters - + if newN[i] == True: new_parameterset.append(cur_par_set[i] + gamma*np.array(random_par_set1[i]-random_par_set2[i]) + np.random.normal(0,self.eps)) else: new_parameterset.append(cur_par_set[i]) - - new_parameter=self.check_par_validity_reflect(new_parameterset) - #new_parameter=self.check_par_validity_bound(new_parameterset) + + new_parameter=self.check_par_validity_reflect(new_parameterset) + #new_parameter=self.check_par_validity_bound(new_parameterset) return new_parameter - + # new_par = np.random.normal(loc=old_par, scale=self.stepsizes) # new_par = self.check_par_validity_reflect(new_par) # return new_par - def update_mcmc_status(self,par,like,sim,cur_chain): + def update_mcmc_status(self,par,like,sim,cur_chain): self.bestpar[cur_chain][self.nChainruns[cur_chain]]=list(par) self.bestlike[cur_chain]=like self.bestsim[cur_chain]=list(sim) @@ -199,8 +199,8 @@ def get_r_hat(self, parameter_array): W_uni[whichW_UNIIsNull] = np.random.uniform(0.1,1,1) R_stat = np.sqrt((n + 1) / n * (np.divide(sigma2, W_uni)) - (d - 1) / (n * d)) - - + + # W_mult = 0 # for ii in range(n): # W_mult = W_mult + np.cov(np.nan_to_num(np.transpose(parameter_array[ii, :, :])), ddof=1) @@ -220,9 +220,9 @@ def get_r_hat(self, parameter_array): def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, runs_after_convergence=100,acceptance_test_option=6): self.set_repetiton(repetitions) - print('Starting the DREAM algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Starting the DREAM algotrithm with '+str(repetitions)+ ' repetitions...') if nChains <3: - print('Please use at least n=3 chains!') + self.logger.info('Please use at least n=3 chains!') return None # Prepare storing MCMC chain as array of arrays. # define stepsize of MCMC. @@ -244,15 +244,15 @@ def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, self.nChainruns=[0]*self.nChains self.min_bound, self.max_bound = self.parameter( )['minbound'], self.parameter()['maxbound'] - + #firstcall = True - - print('Initialize ', self.nChains, ' chain(s)...') + + self.logger.info('Initialize %s chain(s)...', self.nChains) self.iter=0 #for i in range(10): startpoints = self.get_regular_startingpoint(nChains) - #param_generator = ((curChain,list(self.parameter()['random'])) for curChain in range(int(self.nChains))) #TODO: Start with regular interval raster - param_generator = ((curChain,list(startpoints[curChain])) for curChain in range(int(self.nChains))) #TODO: Start with regular interval raster + #param_generator = ((curChain,list(self.parameter()['random'])) for curChain in range(int(self.nChains))) #TODO: Start with regular interval raster + param_generator = ((curChain,list(startpoints[curChain])) for curChain in range(int(self.nChains))) #TODO: Start with regular interval raster for curChain,par,sim in self.repeat(param_generator): like = self.postprocessing(self.iter, par, sim, chains=curChain) self.update_mcmc_status(par,like,sim,curChain) @@ -260,7 +260,7 @@ def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, self.nChainruns[curChain] +=1 - print('Beginn of Random Walk') + self.logger.info('Beginn of Random Walk') convergence = False #Walf through chains self.r_hats=[] @@ -272,10 +272,10 @@ def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, nrN=1 newN = [True]*self.N while self.iter < self.repetitions: - param_generator = ((curChain,self.get_new_proposal_vector(curChain,newN,nrN)) for curChain in range(int(self.nChains))) + param_generator = ((curChain,self.get_new_proposal_vector(curChain,newN,nrN)) for curChain in range(int(self.nChains))) for cChain,par,sim in self.repeat(param_generator): pCr = np.random.randint(0,nCr) - ids=[] + ids=[] for i in range(self.N): ids.append(np.random.uniform(low=0,high=1)) newN = [] @@ -317,21 +317,21 @@ def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, logMetropHastRatio = np.exp(-0.5 * (-like + self.bestlike[cChain])) # signs are different because we write -SSR u = np.random.uniform(low=0.0, high=1) - + if logMetropHastRatio>u: - self.update_mcmc_status(par,like,sim,cChain) + self.update_mcmc_status(par,like,sim,cChain) self.accepted[cChain] += 1 # monitor acceptance - + else: - self.update_mcmc_status(self.bestpar[cChain][self.nChainruns[cChain]-1],self.bestlike[cChain],self.bestsim[cChain],cChain) - + self.update_mcmc_status(self.bestpar[cChain][self.nChainruns[cChain]-1],self.bestlike[cChain],self.bestsim[cChain],cChain) + if self.status.stop: self.iter = self.repetitions - print('Stopping samplig') + self.logger.info('Stopping samplig') break self.iter+=1 self.nChainruns[cChain] +=1 - + r_hat = self.get_r_hat(self.bestpar) self.r_hats.append(r_hat) @@ -339,21 +339,21 @@ def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, acttime = time.time() if acttime - intervaltime >= 2 and self.iter >=2 and self.nChainruns[-1] >=3: text = "Acceptance rates [%] =" +str(np.around((self.accepted)/float(((self.iter-self.burnIn)/self.nChains)),decimals=4)*100).strip('array([])') - print(text) + self.logger.info(text) text = "Convergence rates =" +str(np.around((r_hat),decimals=4)).strip('array([])') - print(text) + self.logger.info(text) intervaltime = time.time() if (np.array(r_hat) < convergence_limit).all() and not convergence and self.nChainruns[-1] >=5: #Stop sampling - print('#############') - print('Convergence has been achieved after '+str(self.iter)+' of '+str(self.repetitions)+' runs! Finally, '+str(runs_after_convergence)+' runs will be additionally sampled to form the posterior distribution') - print('#############') + self.logger.info('#############') + self.logger.info('Convergence has been achieved after '+str(self.iter)+' of '+str(self.repetitions)+' runs! Finally, '+str(runs_after_convergence)+' runs will be additionally sampled to form the posterior distribution') + self.logger.info('#############') self.repetitions = self.iter + runs_after_convergence self.set_repetiton(self.repetitions) #self.iter =self.repetitions - runs_after_convergence convergence=True - + self.final_call() @@ -361,12 +361,12 @@ def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, # self.datawriter.finalize() #except AttributeError: # Happens if no database was assigned # pass - #print('End of sampling') + #self.logger.info('End of sampling') #text = '%i of %i (best like=%g)' % ( # self.status.rep, repetitions, self.status.objectivefunction) - #print(text) - #print('Best parameter set') - #print(self.status.params) + #self.logger.info(text) + #self.logger.info('Best parameter set') + #self.logger.info(self.status.params) #text = 'Duration:' + str(round((acttime - starttime), 2)) + ' s' - #print(text) + #self.logger.info(text) return self.r_hats diff --git a/spotpy/algorithms/fast.py b/spotpy/algorithms/fast.py index 9556e2ec..b1c25a9e 100644 --- a/spotpy/algorithms/fast.py +++ b/spotpy/algorithms/fast.py @@ -134,19 +134,19 @@ def matrix(self, bounds, N, M=4): def analyze(self, problem, Y, D, parnames, M=4, print_to_console=False): if len(Y.shape) > 1: Y = Y.flatten() - print(Y.size) + self.logger.info(Y.size) if Y.size % (D) == 0: N = int(Y.size / D) elif Y.size > D: N = int(Y.size / D) rest = Y.size - N*D - print(""" + self.logger.info(""" We can not use """ + str(rest) + """ samples which was generated of totaly """ + str(Y.size) + """ """) else: - print(""" + self.logger.info(""" Error: Number of samples in model output file must be a multiple of D, where D is the number of parameters in your parameter file. """) @@ -164,14 +164,14 @@ def analyze(self, problem, Y, D, parnames, M=4, print_to_console=False): # Calculate and Output the First and Total Order Values if print_to_console: - print("Parameter First Total") + self.logger.info("Parameter First Total") Si = dict((k, [None] * D) for k in ['S1', 'ST']) for i in range(D): l = np.arange(i * N, (i + 1) * N) Si['S1'][i] = self.compute_first_order(Y[l], N, M, omega[0]) Si['ST'][i] = self.compute_total_order(Y[l], N, omega[0]) if print_to_console: - print("%s %f %f" % + self.logger.info("%s %f %f" % (parnames[i], Si['S1'][i], Si['ST'][i])) return Si @@ -199,8 +199,8 @@ def sample(self, repetitions, M=4): Maximum number of runs. """ self.set_repetiton(repetitions) - print('Starting the FAST algotrithm with '+str(repetitions)+ ' repetitions...') - print('Creating FAST Matrix') + self.logger.info('Starting the FAST algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Creating FAST Matrix') # Get the names of the parameters to analyse names = self.parameter()['name'] # Get the minimum and maximum value for each parameter from the diff --git a/spotpy/algorithms/fscabc.py b/spotpy/algorithms/fscabc.py index 1538f760..cbfabfbc 100644 --- a/spotpy/algorithms/fscabc.py +++ b/spotpy/algorithms/fscabc.py @@ -87,7 +87,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, kpow=4, limit=None sets the limit for scout bee phase """ self.set_repetiton(repetitions) - print('Starting the FSCABC algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Starting the FSCABC algotrithm with '+str(repetitions)+ ' repetitions...') # Initialize FSCABC parameters: parset = self.parameter() randompar = parset['random'] @@ -130,7 +130,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, kpow=4, limit=None icall +=1 if self.status.stop: #icall = repetitions - print('Stopping samplig') + self.logger.info('Stopping samplig') break #Bee Phases @@ -167,7 +167,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, kpow=4, limit=None work[rep][4] = work[rep][4] + 1 icall += 1 if self.status.stop: - print('Stopping samplig') + self.logger.info('Stopping samplig') break # Fitness scaling @@ -213,7 +213,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, kpow=4, limit=None work[rep][4] = work[rep][4] + 1 icall += 1 if self.status.stop: - print('Stopping samplig') + self.logger.info('Stopping samplig') break # Scout bee phase for i, val in enumerate(work): @@ -228,7 +228,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, kpow=4, limit=None work[i][0] = clike icall += 1 if self.status.stop: - print('Stopping samplig') + self.logger.info('Stopping samplig') break gnrng = -self.status.objectivefunction_max @@ -238,12 +238,12 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, kpow=4, limit=None self.write_breakdata(self.dbname, savework) lastbackup = icall if icall >= repetitions: - print('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') - print('ON THE MAXIMUM NUMBER OF TRIALS ') - print(repetitions) - print('HAS BEEN EXCEEDED.') + self.logger.info('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') + self.logger.info('ON THE MAXIMUM NUMBER OF TRIALS ') + self.logger.info(repetitions) + self.logger.info('HAS BEEN EXCEEDED.') if gnrng < peps: - print( + self.logger.info( 'THE POPULATION HAS CONVERGED TO A PRESPECIFIED SMALL PARAMETER SPACE') self.final_call() diff --git a/spotpy/algorithms/lhs.py b/spotpy/algorithms/lhs.py index d9ac0535..b677d4d0 100644 --- a/spotpy/algorithms/lhs.py +++ b/spotpy/algorithms/lhs.py @@ -62,8 +62,8 @@ def sample(self, repetitions): maximum number of function evaluations allowed during optimization """ self.set_repetiton(repetitions) - print('Starting the LHS algotrithm with '+str(repetitions)+ ' repetitions...') - print('Creating LatinHyperCube Matrix') + self.logger.info('Starting the LHS algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Creating LatinHyperCube Matrix') # Get the names of the parameters to analyse names = self.parameter()['name'] # Define the jump size between the parameter diff --git a/spotpy/algorithms/list_sampler.py b/spotpy/algorithms/list_sampler.py index 3138ea43..57338c3a 100644 --- a/spotpy/algorithms/list_sampler.py +++ b/spotpy/algorithms/list_sampler.py @@ -64,7 +64,7 @@ def sample(self, repetitions=None): self.set_repetiton(repetitions) # Initialization - print('Starting the List sampler with '+str(repetitions)+ ' repetitions...') + self.logger.info('Starting the List sampler with '+str(repetitions)+ ' repetitions...') param_generator = ((rep, list(parameters[rep])) for rep in range(int(repetitions))) for rep, randompar, simulations in self.repeat(param_generator): diff --git a/spotpy/algorithms/mc.py b/spotpy/algorithms/mc.py index a22e853b..6145ce73 100644 --- a/spotpy/algorithms/mc.py +++ b/spotpy/algorithms/mc.py @@ -62,7 +62,7 @@ def sample(self, repetitions): Maximum number of runs. """ self.set_repetiton(repetitions) - print('Starting the MC algorithm with {} repetitions...'.format(repetitions)) + self.logger.info('Starting the MC algorithm with {} repetitions...'.format(repetitions)) # A generator that produces parametersets if called param_generator = ((rep, self.parameter()['random']) for rep in range(int(repetitions))) diff --git a/spotpy/algorithms/mcmc.py b/spotpy/algorithms/mcmc.py index 7682f68f..cbd9b7d7 100644 --- a/spotpy/algorithms/mcmc.py +++ b/spotpy/algorithms/mcmc.py @@ -13,11 +13,11 @@ import numpy as np import time - + class mcmc(_algorithm): """ This class holds the MarkovChainMonteCarlo (MCMC) algorithm, based on: - Metropolis, N., Rosenbluth, A. W., Rosenbluth, M. N., Teller, A. H. and Teller, E. (1953) + Metropolis, N., Rosenbluth, A. W., Rosenbluth, M. N., Teller, A. H. and Teller, E. (1953) Equation of state calculations by fast computing machines, J. Chem. Phys. """ @@ -65,7 +65,7 @@ def check_par_validity(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - print('ERROR: Bounds have not the same lenghts as Parameterarray') + self.logger.info('ERROR: Bounds have not the same lenghts as Parameterarray') return par def check_par_validity_reflect(self, par): @@ -83,29 +83,29 @@ def check_par_validity_reflect(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - print('ERROR: Bounds have not the same lenghts as Parameterarray') + self.logger.info('ERROR: Bounds have not the same lenghts as Parameterarray') return par - + def get_new_proposal_vector(self,old_par): new_par = np.random.normal(loc=old_par, scale=self.stepsizes) #new_par = self.check_par_validity(new_par) new_par = self.check_par_validity_reflect(new_par) return new_par - def update_mcmc_status(self,par,like,sim,cur_chain): + def update_mcmc_status(self,par,like,sim,cur_chain): self.bestpar[cur_chain]=par self.bestlike[cur_chain]=like self.bestsim[cur_chain]=sim - + def sample(self, repetitions,nChains=1): self.set_repetiton(repetitions) - print('Starting the MCMC algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Starting the MCMC algotrithm with '+str(repetitions)+ ' repetitions...') # Prepare storing MCMC chain as array of arrays. self.nChains = int(nChains) #Ensure initialisation of chains and database self.burnIn = self.nChains - # define stepsize of MCMC. + # define stepsize of MCMC. self.stepsizes = self.parameter()['step'] # array of stepsizes # Metropolis-Hastings iterations. @@ -116,29 +116,29 @@ def sample(self, repetitions,nChains=1): self.nChainruns=[[0]]*self.nChains self.min_bound, self.max_bound = self.parameter( )['minbound'], self.parameter()['maxbound'] - print('Initialize ', self.nChains, ' chain(s)...') + self.logger.info('Initialize %s chain(s)...', self.nChains) self.iter=0 - param_generator = ((curChain,self.parameter()['random']) for curChain in range(int(self.nChains))) + param_generator = ((curChain,self.parameter()['random']) for curChain in range(int(self.nChains))) for curChain,randompar,simulations in self.repeat(param_generator): - # A function that calculates the fitness of the run and the manages the database + # A function that calculates the fitness of the run and the manages the database like = self.postprocessing(self.iter, randompar, simulations, chains=curChain) self.update_mcmc_status(randompar, like, simulations, curChain) self.iter+=1 intervaltime = time.time() - print('Beginn of Random Walk') + self.logger.info('Beginn of Random Walk') # Walk through chains while self.iter <= repetitions - self.burnIn: - param_generator = ((curChain,self.get_new_proposal_vector(self.bestpar[curChain])) for curChain in range(int(self.nChains))) + param_generator = ((curChain,self.get_new_proposal_vector(self.bestpar[curChain])) for curChain in range(int(self.nChains))) for cChain,randompar,simulations in self.repeat(param_generator): - # A function that calculates the fitness of the run and the manages the database + # A function that calculates the fitness of the run and the manages the database like = self.postprocessing(self.iter, randompar, simulations, chains=cChain) logMetropHastRatio = np.abs(self.bestlike[cChain])/np.abs(like) u = np.random.uniform(low=0.3, high=1) if logMetropHastRatio>1.0 or logMetropHastRatio>u: - self.update_mcmc_status(randompar,like,simulations,cChain) + self.update_mcmc_status(randompar,like,simulations,cChain) self.accepted[cChain] += 1 # monitor acceptance - self.iter+=1 + self.iter+=1 # Progress bar acttime = time.time() #Refresh MCMC progressbar every two second @@ -146,7 +146,6 @@ def sample(self, repetitions,nChains=1): text = '%i of %i (best like=%g)' % ( self.iter + self.burnIn, repetitions, self.status.objectivefunction_max) text = "Acceptance rates [%] =" +str(np.around((self.accepted)/float(((self.iter-self.burnIn)/self.nChains)),decimals=4)*100).strip('array([])') - print(text) + self.logger.info(text) intervaltime = time.time() - self.final_call() - + self.final_call() diff --git a/spotpy/algorithms/mle.py b/spotpy/algorithms/mle.py index 2a6fec48..52779ac8 100644 --- a/spotpy/algorithms/mle.py +++ b/spotpy/algorithms/mle.py @@ -60,12 +60,12 @@ def check_par_validity(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - print('ERROR Bounds have not the same lenghts as Parameterarray') + self.logger.info('ERROR Bounds have not the same lenghts as Parameterarray') return par def sample(self, repetitions): self.set_repetiton(repetitions) - print('Starting the MLE algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Starting the MLE algotrithm with '+str(repetitions)+ ' repetitions...') # Define stepsize of MLE stepsizes = self.parameter()['step'] # array of stepsizes accepted = 0.0 @@ -76,7 +76,7 @@ def sample(self, repetitions): likes = [] pars = [] sims = [] - print('burnIn...') + self.logger.info('burnIn...') for i in range(burnIn): randompar = self.parameter()['random'] pars.append(randompar) @@ -88,7 +88,7 @@ def sample(self, repetitions): old_like = max(likes) old_par = pars[likes.index(old_like)] - print('Beginn Random Walk') + self.logger.info('Beginn Random Walk') for rep in range(repetitions - burnIn): # Suggest new candidate from Gaussian proposal distribution. # Use stepsize provided for every dimension. diff --git a/spotpy/algorithms/padds.py b/spotpy/algorithms/padds.py index a53c364a..7191e3a5 100644 --- a/spotpy/algorithms/padds.py +++ b/spotpy/algorithms/padds.py @@ -181,7 +181,7 @@ def sample(self, repetitions, trials=1, initial_objs=np.array([]), initial_param # every iteration a map of all relevant values is stored, only for debug purpose. # Spotpy will not need this values. debug_results = [] - print('Starting the PADDS algotrithm with ' + str(repetitions) + ' repetitions...') + self.logger.info('Starting the PADDS algotrithm with ' + str(repetitions) + ' repetitions...') self.set_repetiton(repetitions) self.number_of_parameters = len(self.best_value.parameters) # number_of_parameters is the amount of parameters @@ -219,7 +219,7 @@ def sample(self, repetitions, trials=1, initial_objs=np.array([]), initial_param # update the new status structure self.status.params_max, self.status.params_min = self.parameter_current, self.parameter_current - print('Best solution found has obj function value of ' + str(self.best_value.best_obj_val) + ' at ' + self.logger.info('Best solution found has obj function value of ' + str(self.best_value.best_obj_val) + ' at ' + str(repitionno_best) + '\n\n') debug_results.append({"sbest": self.best_value.parameters , "objfunc_val": self.best_value.best_obj_val}) diff --git a/spotpy/algorithms/rope.py b/spotpy/algorithms/rope.py index caf1ae2a..90e28ec0 100644 --- a/spotpy/algorithms/rope.py +++ b/spotpy/algorithms/rope.py @@ -94,7 +94,7 @@ def sample(self, repetitions=None, repetitions_first_run=None, # Takes ways´to long for npar >8 # wenn mehr parameter produziert werden sollen als reingehen, rechnet er sich tot (ngen>n) #Subsets < 5 führt manchmal zu Absturz - print('Starting the ROPE algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Starting the ROPE algotrithm with '+str(repetitions)+ ' repetitions...') self.set_repetiton(repetitions) if repetitions_first_run is None: @@ -109,7 +109,7 @@ def sample(self, repetitions=None, repetitions_first_run=None, / (subsets-1)) # Needed to avoid an error in integer division somewhere in depth function if repetitions_following_runs % 2 != 0: - print('Warning: Burn-in samples and total number of repetions are not compatible.\n' + self.logger.info('Warning: Burn-in samples and total number of repetions are not compatible.\n' 'SPOTPY will automatically adjust the number of total repetitions.') repetitions_following_runs+=1 @@ -156,7 +156,7 @@ def sample(self, repetitions=None, repetitions_first_run=None, if acttime - intervaltime >= 2: text = '1 Subset: Run %i of %i (best like=%g)' % ( rep, first_run, self.status.objectivefunction_max) - print(text) + self.logger.info(text) intervaltime = time.time() for subset in range(subsets - 1): @@ -186,7 +186,7 @@ def sample(self, repetitions=None, repetitions_first_run=None, likes.append(like) pars.append(ropepar) if self.status.stop: - print('Stopping samplig') + self.logger.info('Stopping samplig') break # Progress bar @@ -199,7 +199,7 @@ def sample(self, repetitions=None, repetitions_first_run=None, rep, repetitions_following_runs, self.status.objectivefunction_max) - print(text) + self.logger.info(text) intervaltime = time.time() if self.status.stop: break @@ -212,10 +212,10 @@ def programm_depth(self, pars, runs): N, NP = X.shape text = str(N) + ' input vectors with ' + str(NP) + ' parameters' - print(text) + self.logger.info(text) Ngen = int(runs) # int(N*(1/self.percentage)) - print(('Generating ' + str(Ngen) + ' parameters:')) + self.logger.info(('Generating ' + str(Ngen) + ' parameters:')) NPOSI = Ngen # Number of points to generate @@ -247,7 +247,7 @@ def programm_depth(self, pars, runs): if LNDEP[L] >= 1: CL = np.vstack((CL, TL[L, :])) IPOS = IPOS + 1 - print((IPOS, ITRY)) + self.logger.info((IPOS, ITRY)) CL = np.delete(CL, 0, 0) CL = CL[:NPOSI] diff --git a/spotpy/algorithms/sa.py b/spotpy/algorithms/sa.py index 15bc3f31..b26c9de2 100644 --- a/spotpy/algorithms/sa.py +++ b/spotpy/algorithms/sa.py @@ -65,7 +65,7 @@ def check_par_validity(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - print('ERROR: Bounds have not the same lenghts as Parameterarray') + self.logger.info('ERROR: Bounds have not the same lenghts as Parameterarray') return par def sample(self, repetitions, Tini=80, Ntemp=50, alpha=0.99): @@ -78,7 +78,7 @@ def sample(self, repetitions, Tini=80, Ntemp=50, alpha=0.99): Maximum number of runs. """ self.set_repetiton(repetitions) - print('Starting the SA algotrithm with '+str(repetitions)+ ' repetitions...') + self.logger.info('Starting the SA algotrithm with '+str(repetitions)+ ' repetitions...') self.min_bound, self.max_bound = self.parameter( )['minbound'], self.parameter()['maxbound'] stepsizes = self.parameter()['step'] diff --git a/spotpy/algorithms/sceua.py b/spotpy/algorithms/sceua.py index bdcc5f9a..c126e96a 100644 --- a/spotpy/algorithms/sceua.py +++ b/spotpy/algorithms/sceua.py @@ -177,7 +177,7 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 icall = 0 xf = np.zeros(npt) - print ('Starting burn-in sampling...') + self.logger.info('Starting burn-in sampling...') # Burn in param_generator = ((rep, x[rep]) for rep in range(int(npt))) @@ -187,7 +187,7 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 xf[rep] = like icall+=1 if self.status.stop: - print('Stopping samplig. Maximum number of repetitions reached already during burn-in') + self.logger.info('Stopping samplig. Maximum number of repetitions reached already during burn-in') proceed = False break # Sort the population in order of increasing function values; @@ -210,18 +210,18 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 # Check for convergency; if self.status.rep >= repetitions: - print('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') - print('ON THE MAXIMUM NUMBER OF TRIALS ') - print(repetitions) - print('HAS BEEN EXCEEDED. SEARCH WAS STOPPED AT TRIAL NUMBER:') - print(self.status.rep) - print('OF THE INITIAL LOOP!') + self.logger.info('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') + self.logger.info('ON THE MAXIMUM NUMBER OF TRIALS ') + self.logger.info(repetitions) + self.logger.info('HAS BEEN EXCEEDED. SEARCH WAS STOPPED AT TRIAL NUMBER:') + self.logger.info(self.status.rep) + self.logger.info('OF THE INITIAL LOOP!') if gnrng < peps: - print( + self.logger.info( 'THE POPULATION HAS CONVERGED TO A PRESPECIFIED SMALL PARAMETER SPACE') - print ('Burn-in sampling completed...') + self.logger.info('Burn-in sampling completed...') # Begin evolution loops: nloop = 0 @@ -229,11 +229,11 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 criter_change_pcent = 1e+5 self.repeat.setphase('ComplexEvo') - print ('Starting Complex Evolution...') + self.logger.info('Starting Complex Evolution...') proceed = True while icall < repetitions and gnrng > peps and criter_change_pcent > pcento and proceed == True: nloop += 1 - print ('ComplexEvo loop #%d in progress...' % nloop) + self.logger.info('ComplexEvo loop #%d in progress...' % nloop) # Loop on complexes (sub-populations); cx = np.zeros((self.npg, self.nopt)) cf = np.zeros((self.npg)) @@ -258,7 +258,7 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 proceed=False like = self.postprocessing(i, pars[i], sims[i], chains=i+1, save_run=False) self.discarded_runs+=1 - print('Skipping saving') + self.logger.info('Skipping saving') if self.breakpoint == 'write' or self.breakpoint == 'readandwrite'\ and self.status.rep >= self.backup_every_rep: @@ -288,18 +288,18 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 # Check for convergency; if self.status.rep >= repetitions: - print('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') - print('ON THE MAXIMUM NUMBER OF TRIALS ') - print(repetitions) - print('HAS BEEN EXCEEDED.') + self.logger.info('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') + self.logger.info('ON THE MAXIMUM NUMBER OF TRIALS ') + self.logger.info(repetitions) + self.logger.info('HAS BEEN EXCEEDED.') elif gnrng < peps: - print( + self.logger.info( 'THE POPULATION HAS CONVERGED TO A PRESPECIFIED SMALL PARAMETER SPACE') elif nloop >= kstop: # necessary so that the area of high posterior density is visited as much as possible - print ('Objective function convergence criteria is now being updated and assessed...') + self.logger.info('Objective function convergence criteria is now being updated and assessed...') absolute_change = np.abs( criter[nloop - 1] - criter[nloop - kstop])*100 denominator = np.mean(np.abs(criter[(nloop - kstop):nloop])) @@ -307,21 +307,21 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 criter_change_pcent = 0.0 else: criter_change_pcent = absolute_change / denominator - print ('Updated convergence criteria: %f' % criter_change_pcent) + self.logger.info('Updated convergence criteria: %f' % criter_change_pcent) if criter_change_pcent <= pcento: - print('THE BEST POINT HAS IMPROVED IN LAST %d LOOPS BY LESS THAN THE USER-SPECIFIED THRESHOLD %f' % ( + self.logger.info('THE BEST POINT HAS IMPROVED IN LAST %d LOOPS BY LESS THAN THE USER-SPECIFIED THRESHOLD %f' % ( kstop, pcento)) - print( + self.logger.info( 'CONVERGENCY HAS ACHIEVED BASED ON OBJECTIVE FUNCTION CRITERIA!!!') elif self.status.stop: proceed = False break # End of the Outer Loops - print('SEARCH WAS STOPPED AT TRIAL NUMBER: %d' % self.status.rep) - print('NUMBER OF DISCARDED TRIALS: %d' % self.discarded_runs) - print('NORMALIZED GEOMETRIC RANGE = %f' % gnrng) - print('THE BEST POINT HAS IMPROVED IN LAST %d LOOPS BY %f PERCENT' % ( + self.logger.info('SEARCH WAS STOPPED AT TRIAL NUMBER: %d' % self.status.rep) + self.logger.info('NUMBER OF DISCARDED TRIALS: %d' % self.discarded_runs) + self.logger.info('NORMALIZED GEOMETRIC RANGE = %f' % gnrng) + self.logger.info('THE BEST POINT HAS IMPROVED IN LAST %d LOOPS BY %f PERCENT' % ( kstop, criter_change_pcent)) # reshape BESTX diff --git a/spotpy/analyser.py b/spotpy/analyser.py index e026de95..422248d4 100644 --- a/spotpy/analyser.py +++ b/spotpy/analyser.py @@ -10,6 +10,7 @@ Note: This part of SPOTPY is in alpha status and not yet ready for production use. ''' +from spotpylogging import get_logger import numpy as np import spotpy @@ -17,6 +18,8 @@ 'weight' : 'normal', 'size' : 18} +logger = get_logger('analyser') + def load_csv_results(filename, usecols=None): """ Get an array of your results in the given file. @@ -34,13 +37,13 @@ def load_csv_results(filename, usecols=None): def load_hdf5_results(filename): """ - Get an array of your results in the given file. - - :filename: Expects an available filename, without the .h5 ending, + Get an array of your results in the given file. + + :filename: Expects an available filename, without the .h5 ending, in your working directory :type: str - :return: Result array, simulation is an ndarray, + :return: Result array, simulation is an ndarray, which is different to structured arrays return by the csv/sql/ram databases :rtype: array """ @@ -64,14 +67,14 @@ def load_csv_parameter_results(filename, usecols=None): line = ofile.readline() header=line.split(',') ofile.close() - + words=[] index =[] - for i,word in enumerate(header): + for i,word in enumerate(header): if word.startswith('par'): words.append(word) index.append(i) - return np.genfromtxt(filename+'.csv', delimiter=',', names=words, + return np.genfromtxt(filename+'.csv', delimiter=',', names=words, usecols=index, invalid_raise=False, skip_header=1) def get_header(results): @@ -161,7 +164,7 @@ def get_maxlikeindex(results,verbose=True): text2=str(' has the highest objectivefunction with: ') textv=text+str(index[0][0])+text2+value if verbose: - print(textv) + logger.info(textv) return index, maximum def get_minlikeindex(results): @@ -185,7 +188,7 @@ def get_minlikeindex(results): index=np.where(likes==minimum) text2=str(' has the lowest objectivefunction with: ') textv=text+str(index[0][0])+text2+value - print(textv) + logger.info(textv) return index, minimum @@ -222,7 +225,7 @@ def calc_like(results,evaluation,objectivefunction): :evaluation: Expects values, which correspond to your simulations :type: list - + :objectivefunction: Takes evaluation and simulation data and returns a objectivefunction, e.g. spotpy.objectvefunction.rmse :type: function @@ -250,11 +253,11 @@ def compare_different_objectivefunctions(like1,like2): """ from scipy import stats out = stats.ttest_ind(like1, like2, equal_var=False) - print(out) + logger.info(out) if out[1]>0.05: - print('like1 is NOT signifikant different to like2: p>0.05') + logger.info('like1 is NOT signifikant different to like2: p>0.05') else: - print('like1 is signifikant different to like2: p<0.05' ) + logger.info('like1 is signifikant different to like2: p<0.05' ) return out def get_posterior(results,percentage=10, maximize=True): @@ -266,7 +269,7 @@ def get_posterior(results,percentage=10, maximize=True): :percentag: Optional, ratio of values that will be deleted. :type: float - + :maximize: If True (default), higher "like1" column values are assumed to be better. If False, lower "like1" column values are assumed to be better. @@ -305,7 +308,7 @@ def plot_parameter_uncertainty(posterior_results,evaluation, fig_name='Posterior plt.legend(loc='upper right') fig.savefig(fig_name,dpi=300) text='A plot of the parameter uncertainty has been saved as '+fig_name - print(text) + logger.info(text) @@ -341,7 +344,7 @@ def get_best_parameterset(results,maximize=True): text='' for i in range(len(parameter_names)): text+=parameter_names[i]+'='+str(best_parameter_set[i])+', ' - print('Best parameter set:\n'+text[:-2]) + logger.info('Best parameter set:\n'+text[:-2]) return get_parameters(results[index]) def get_min_max(spotpy_setup): @@ -391,14 +394,14 @@ def get_sensitivity_of_fast(results,like_index=1,M=4, print_to_console=True): """ import math likes=results['like'+str(like_index)] - print('Number of model runs:', likes.size) + logger.info('Number of model runs: %s', likes.size) parnames = get_parameternames(results) parnumber=len(parnames) - print('Number of parameters:', parnumber) - + logger.info('Number of parameters: %s', parnumber) + rest = likes.size % (parnumber) if rest != 0: - print("""" + logger.info("""" Number of samples in model output file must be a multiple of D, where D is the number of parameters in your parameter file. We handle this by ignoring the last """, rest, """runs.""") @@ -410,26 +413,26 @@ def get_sensitivity_of_fast(results,like_index=1,M=4, print_to_console=True): omega[0] = math.floor((N - 1) / (2 * M)) m = math.floor(omega[0] / (2 * M)) - print('m =', m) + logger.info('m = %s', m) if m >= (parnumber - 1): omega[1:] = np.floor(np.linspace(1, m, parnumber - 1)) else: omega[1:] = np.arange(parnumber - 1) % m + 1 - print('Omega =', omega) + logger.info('Omega = %s', omega) # Calculate and Output the First and Total Order Values if print_to_console: - print("Parameter First Total") + logger.info("Parameter First Total") Si = dict((k, [None] * parnumber) for k in ['S1', 'ST']) - print(Si) + logger.info(Si) for i in range(parnumber): l = np.arange(i * N, (i + 1) * N) - print(l) + logger.info(l) Si['S1'][i] = _compute_first_order(likes[l], N, M, omega[0]) Si['ST'][i] = _compute_total_order(likes[l], N, omega[0]) - print(Si) + logger.info(Si) if print_to_console: - print("%s %f %f" % + logger.info("%s %f %f" % (parnames[i], Si['S1'][i], Si['ST'][i])) return Si @@ -464,12 +467,12 @@ def plot_fast_sensitivity(results,like_index=1,number_of_sensitiv_pars=10,fig_na no_values = [] index=[] no_index=[] - + try: - threshold = np.sort(list(Si.values())[1])[-number_of_sensitiv_pars] + threshold = np.sort(list(Si.values())[1])[-number_of_sensitiv_pars] except IndexError: threshold = 0 - + first_sens_call=True first_insens_call=True try: @@ -487,7 +490,7 @@ def plot_fast_sensitivity(results,like_index=1,number_of_sensitiv_pars=10,fig_na else: ax.bar(j, list(Si.values())[1][j], color='blue') first_sens_call=False - + else: #names.append('') @@ -506,17 +509,17 @@ def plot_fast_sensitivity(results,like_index=1,number_of_sensitiv_pars=10,fig_na ax.legend() ax.set_xticks(np.arange(0,len(parnames))) xtickNames = ax.set_xticklabels(parnames, color='grey') - + plt.setp(xtickNames, rotation=90) for name_id in names: ax.get_xticklabels()[name_id].set_color("black") - + #ax.set_xticklabels(['0']+parnames) ax.plot(np.arange(-1,len(parnames)+1,1),[threshold]*(len(parnames)+2),'r--') ax.set_xlim(-0.5,len(parnames)-0.5) plt.tight_layout() fig.savefig(fig_name,dpi=300) - + def plot_heatmap_griewank(results,algorithms, fig_name='heatmap_griewank.png'): """Example Plot as seen in the SPOTPY Documentation""" @@ -583,9 +586,9 @@ def plot_objectivefunction(results,evaluation,limit=None,sort=True, fig_name = ' # sum mean to the confidence interval ci = [mean + critval * stddev / np.sqrt(len(data)) for critval in t_bounds] value="Mean: %f" % mean - print(value) + logger.info(value) value="Confidence Interval 95%%: %f, %f" % (ci[0], ci[1]) - print(value) + logger.info(value) threshold=ci[1] happend=None bestlike=[data[0]] @@ -606,7 +609,7 @@ def plot_objectivefunction(results,evaluation,limit=None,sort=True, fig_name = ' plt.plot(bestlike) plt.savefig(fig_name) -def plot_parametertrace_algorithms(result_lists, algorithmnames, spot_setup, +def plot_parametertrace_algorithms(result_lists, algorithmnames, spot_setup, fig_name='parametertrace_algorithms.png'): """Example Plot as seen in the SPOTPY Documentation""" import matplotlib.pyplot as plt @@ -635,7 +638,7 @@ def plot_parametertrace_algorithms(result_lists, algorithmnames, spot_setup, ax.plot([1]*rep,'r--') ax.set_xlim(0,rep) ax.set_ylim(parameter['minbound'][j],parameter['maxbound'][j]) - + #plt.tight_layout() fig.savefig(fig_name, bbox_inches='tight') @@ -673,7 +676,7 @@ def plot_parametertrace(results,parameternames=None,fig_name='Parameter_trace.pn i+=1 fig.savefig(fig_name) text='The figure as been saved as "'+fig_name - print(text) + logger.info(text) def plot_posterior_parametertrace(results,parameternames=None,threshold=0.1, fig_name='Posterior_parametertrace.png'): """ @@ -710,7 +713,7 @@ def plot_posterior_parametertrace(results,parameternames=None,threshold=0.1, fig i+=1 fig.savefig(fig_name) text='The figure as been saved as '+fig_name - print(text) + logger.info(text) def plot_posterior(results,evaluation,dates=None,ylabel='Posterior model simulation',xlabel='Time',bestperc=0.1, fig_name='bestmodelrun.png'): """ @@ -762,7 +765,7 @@ def plot_posterior(results,evaluation,dates=None,ylabel='Posterior model simulat plt.title('Maximum objectivefunction of Simulations with '+bestparameterstring[0:-2]) fig.savefig(fig_name) text='The figure as been saved as '+fig_name - print(text) + logger.info(text) def plot_bestmodelrun(results,evaluation,fig_name ='Best_model_run.png'): @@ -795,8 +798,8 @@ def plot_bestmodelrun(results,evaluation,fig_name ='Best_model_run.png'): plt.legend(loc='upper right') fig.savefig(fig_name,dpi=300) text='A plot of the best model run has been saved as '+fig_name - print(text) - + logger.info(text) + def plot_bestmodelruns(results,evaluation,algorithms=None,dates=None,ylabel='Best model simulation',xlabel='Date',objectivefunctionmax=True,calculatelike=True,fig_name='bestmodelrun.png'): @@ -848,7 +851,7 @@ def plot_bestmodelruns(results,evaluation,algorithms=None,dates=None,ylabel='Bes index=likes.index(maximum) bestmodelrun=list(sim[index]) bestparameterset=list(par[index]) - print(bestparameterset) + logger.info(bestparameterset) else: if objectivefunctionmax==True: @@ -872,7 +875,7 @@ def plot_bestmodelruns(results,evaluation,algorithms=None,dates=None,ylabel='Bes fig.savefig(fig_name) text='The figure as been saved as '+fig_name - print(text) + logger.info(text) def plot_objectivefunctiontraces(results,evaluation,algorithms,fig_name='Like_trace.png'): import matplotlib.pyplot as plt @@ -914,7 +917,7 @@ def plot_regression(results,evaluation,fig_name='regressionanalysis.png'): plt.title('Regression between simulations and evaluation data') fig.savefig(fig_name) text='The figure as been saved as '+fig_name - print(text) + logger.info(text) def plot_parameterInteraction(results, fig_name ='ParameterInteraction.png'): @@ -957,7 +960,7 @@ def plot_allmodelruns(modelruns,observations,dates=None, fig_name='bestmodel.png ax.set_title = 'Maximum objectivefunction of Simulations' fig.savefig(fig_name) text='The figure as been saved as '+fig_name - print(text) + logger.info(text) def plot_autocorellation(parameterdistribution,parametername,fig_name='Autocorrelation.png'): diff --git a/spotpy/database/base.py b/spotpy/database/base.py index 6ade100c..058ef1b9 100644 --- a/spotpy/database/base.py +++ b/spotpy/database/base.py @@ -13,6 +13,7 @@ from __future__ import division from __future__ import print_function from __future__ import unicode_literals +from spotpy import spotpylogging import numpy as np import time from itertools import product @@ -31,6 +32,9 @@ class database(object): def __init__(self, dbname, parnames, like, randompar, simulations=None, chains=1, save_sim=True, db_precision=np.float32, **kwargs): # Just needed for the first line in the database + + self.logger = spotpylogging.get_logger(self.__class__.__name__) + self.chains = chains self.dbname = dbname self.like = like @@ -76,15 +80,15 @@ def _empty_list(self, obj): return [] def _scalar_to_list(self, obj): - # print('scalar') + # self.logger.info('scalar') return [obj] def _iterable_to_list(self, obj): - # print('iterable') + # self.logger.info('iterable') return list(obj) def _array_to_list(self, obj): - # print('array') + # self.logger.info('array') values = [] for val in obj: values.append(val) @@ -92,13 +96,13 @@ def _array_to_list(self, obj): # return obj.flatten().tolist() def _nestediterable_to_list(self, obj): - # print('nested') + # self.logger.info('nested') values = [] for nestedlist in obj: - # print(len(nestedlist)) + # self.logger.info(len(nestedlist)) for val in nestedlist: values.append(val) - # print(len(values)) + # self.logger.info(len(values)) return values # return np.array(obj).flatten().tolist() @@ -107,8 +111,8 @@ def _make_header(self, simulations, parnames): self.header.extend(['like' + '_'.join(map(str, x)) for x in product(*self._tuple_2_xrange(self.singular_data_lens[0]))]) self.header.extend(['par{0}'.format(x) for x in parnames]) - # print(self.singular_data_lens[2]) - # print(type(self.singular_data_lens[2])) + # self.logger.info(self.singular_data_lens[2]) + # self.logger.info(type(self.singular_data_lens[2])) if self.save_sim: for i in range(len(simulations)): if isinstance(simulations[0], list) or type(simulations[0]) == type(np.array([])): @@ -168,6 +172,3 @@ def finalize(self): def getdata(self): pass - - - diff --git a/spotpy/database/csv.py b/spotpy/database/csv.py index 9fc7c596..97579f33 100644 --- a/spotpy/database/csv.py +++ b/spotpy/database/csv.py @@ -21,7 +21,7 @@ def __init__(self, *args, **kwargs): super(csv, self).__init__(*args, **kwargs) # store init item only if dbinit if kwargs.get('dbappend', False) is False: - print("* Database file '{}.csv' created.".format(self.dbname)) + self.logger.info("* Database file '{}.csv' created.".format(self.dbname)) # Create a open file, which needs to be closed after the sampling mode = 'w' if sys.version_info.major < 3: @@ -30,7 +30,7 @@ def __init__(self, *args, **kwargs): # write header line self.db.write(unicode(','.join(self.header) + '\n')) else: - print("* Appending to database file '{}.csv'.".format(self.dbname)) + self.logger.info("* Appending to database file '{}.csv'.".format(self.dbname)) # Continues writing file mode = 'a' if sys.version_info.major < 3: diff --git a/spotpy/database/hdf5.py b/spotpy/database/hdf5.py index ea5de0a8..62c63779 100644 --- a/spotpy/database/hdf5.py +++ b/spotpy/database/hdf5.py @@ -19,7 +19,7 @@ try: import tables except ImportError: - print('ImportError: Pytables is not correctly installed. Please also make sure you', + self.logger.info('ImportError: Pytables is not correctly installed. Please also make sure you', 'installed the hdf5 extension (https://www.hdfgroup.org/downloads/hdf5/)') raise import sys diff --git a/spotpy/objectivefunctions.py b/spotpy/objectivefunctions.py index d5c7e626..f6b91bb6 100644 --- a/spotpy/objectivefunctions.py +++ b/spotpy/objectivefunctions.py @@ -9,14 +9,15 @@ This tool holds functions for statistic analysis. It takes Python-lists and returns the objective function value of interest. ''' - +from spotpy import spotpylogging import numpy as np -import logging -logging.basicConfig(format='%(levelname)s: %(module)s.%(funcName)s(): %(message)s') +#logger.basicConfig(format='%(levelname)s: %(module)s.%(funcName)s(): %(message)s') + +logger = spotpylogging.get_logger('objective_function') def bias(evaluation, simulation): """ - Bias as shown in Gupta in Sorooshian (1998), Toward improved calibration of hydrologic models: + Bias as shown in Gupta in Sorooshian (1998), Toward improved calibration of hydrologic models: Multiple and noncommensurable measures of information, Water Resources Research .. math:: @@ -38,7 +39,7 @@ def bias(evaluation, simulation): return float(bias) else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -65,7 +66,7 @@ def pbias(evaluation, simulation): return 100 * (float(np.nansum(sim - obs)) / float(np.nansum(obs))) else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -75,7 +76,7 @@ def nashsutcliffe(evaluation, simulation): .. math:: - NSE = 1-\\frac{\\sum_{i=1}^{N}(e_{i}-s_{i})^2}{\\sum_{i=1}^{N}(e_{i}-\\bar{e})^2} + NSE = 1-\\frac{\\sum_{i=1}^{N}(e_{i}-s_{i})^2}{\\sum_{i=1}^{N}(e_{i}-\\bar{e})^2} :evaluation: Observed data to compared with simulation data. :type: list @@ -98,7 +99,7 @@ def nashsutcliffe(evaluation, simulation): return 1 - (numerator / denominator) else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -118,7 +119,7 @@ def lognashsutcliffe(evaluation, simulation, epsilon=0): :epsilon: Value which is added to simulation and evaluation data to errors when simulation or evaluation data has zero values :type: float or list - + :return: log Nash-Sutcliffe model efficiency :rtype: float @@ -127,7 +128,7 @@ def lognashsutcliffe(evaluation, simulation, epsilon=0): s, e = np.array(simulation)+epsilon, np.array(evaluation)+epsilon return float(1 - sum((np.log(s) - np.log(e))**2) / sum((np.log(e) - np.mean(np.log(e)))**2)) else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -152,7 +153,7 @@ def log_p(evaluation, simulation): normpdf = -y**2 / 2 - np.log(np.sqrt(2 * np.pi)) return np.mean(normpdf) else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -177,7 +178,7 @@ def correlationcoefficient(evaluation, simulation): correlation_coefficient = np.corrcoef(evaluation, simulation)[0, 1] return correlation_coefficient else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -201,7 +202,7 @@ def rsquared(evaluation, simulation): if len(evaluation) == len(simulation): return correlationcoefficient(evaluation, simulation)**2 else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -228,7 +229,7 @@ def mse(evaluation, simulation): mse = np.nanmean((obs - sim)**2) return mse else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -252,7 +253,7 @@ def rmse(evaluation, simulation): if len(evaluation) == len(simulation) > 0: return np.sqrt(mse(evaluation, simulation)) else: - logging.warning("evaluation and simulation lists do not have the same length.") + logger.warning("evaluation and simulation lists do not have the same length.") return np.nan @@ -278,7 +279,7 @@ def mae(evaluation, simulation): mae = np.mean(np.abs(sim - obs)) return mae else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -286,7 +287,7 @@ def rrmse(evaluation, simulation): """ Relative Root Mean Squared Error - .. math:: + .. math:: RRMSE=\\frac{\\sqrt{\\frac{1}{N}\\sum_{i=1}^{N}(e_{i}-s_{i})^2}}{\\bar{e}} @@ -304,7 +305,7 @@ def rrmse(evaluation, simulation): rrmse = rmse(evaluation, simulation) / np.mean(evaluation) return rrmse else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -312,9 +313,9 @@ def agreementindex(evaluation, simulation): """ Agreement Index (d) developed by Willmott (1981) - .. math:: + .. math:: - d = 1 - \\frac{\\sum_{i=1}^{N}(e_{i} - s_{i})^2}{\\sum_{i=1}^{N}(\\left | s_{i} - \\bar{e} \\right | + \\left | e_{i} - \\bar{e} \\right |)^2} + d = 1 - \\frac{\\sum_{i=1}^{N}(e_{i} - s_{i})^2}{\\sum_{i=1}^{N}(\\left | s_{i} - \\bar{e} \\right | + \\left | e_{i} - \\bar{e} \\right |)^2} :evaluation: Observed data to compared with simulation data. @@ -332,7 +333,7 @@ def agreementindex(evaluation, simulation): (np.abs(simulation - np.mean(evaluation)) + np.abs(evaluation - np.mean(evaluation)))**2)) return Agreement_index else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -359,7 +360,7 @@ def covariance(evaluation, simulation): covariance = np.mean((obs - obs_mean)*(sim - sim_mean)) return covariance else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -396,7 +397,7 @@ def decomposed_mse(evaluation, simulation): return decomposed_mse else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -404,13 +405,13 @@ def kge(evaluation, simulation, return_all=False): """ Kling-Gupta Efficiency - Corresponding paper: + Corresponding paper: Gupta, Kling, Yilmaz, Martinez, 2009, Decomposition of the mean squared error and NSE performance criteria: Implications for improving hydrological modelling output: kge: Kling-Gupta Efficiency optional_output: - cc: correlation + cc: correlation alpha: ratio of the standard deviation beta: ratio of the mean """ @@ -424,7 +425,7 @@ def kge(evaluation, simulation, return_all=False): else: return kge else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan def _spearmann_corr(x, y): @@ -457,28 +458,28 @@ def kge_non_parametric(evaluation, simulation, return_all=False): output: kge: Kling-Gupta Efficiency - + author: Nadine Maier and Tobias Houska optional_output: - cc: correlation + cc: correlation alpha: ratio of the standard deviation beta: ratio of the mean """ if len(evaluation) == len(simulation): - ## self-made formula + ## self-made formula cc = _spearmann_corr(evaluation, simulation) ### scipy-Version #cc = stm.spearmanr(evaluation, simulation, axis=0)[0] - ### pandas version + ### pandas version #a = pd.DataFrame({'eva': evaluation, 'sim': simulation}) #cc = a.ix[:,1].corr(a.ix[:,0], method = 'spearman') fdc_sim = np.sort(simulation / (np.nanmean(simulation)*len(simulation))) fdc_obs = np.sort(evaluation / (np.nanmean(evaluation)*len(evaluation))) alpha = 1 - 0.5 * np.nanmean(np.abs(fdc_sim - fdc_obs)) - + beta = np.mean(simulation) / np.mean(evaluation) kge = 1 - np.sqrt((cc - 1)**2 + (alpha - 1)**2 + (beta - 1)**2) if return_all: @@ -486,24 +487,24 @@ def kge_non_parametric(evaluation, simulation, return_all=False): else: return kge else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan def rsr(evaluation, simulation): """ - RMSE-observations standard deviation ratio + RMSE-observations standard deviation ratio - Corresponding paper: + Corresponding paper: Moriasi, Arnold, Van Liew, Bingner, Harmel, Veith, 2007, Model Evaluation Guidelines for Systematic Quantification of Accuracy in Watershed Simulations output: - rsr: RMSE-observations standard deviation ratio + rsr: RMSE-observations standard deviation ratio """ if len(evaluation) == len(simulation): rsr = rmse(evaluation, simulation) / np.std(evaluation) return rsr else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan @@ -514,8 +515,8 @@ def volume_error(evaluation, simulation): and observed runoff (i.e. long-term water balance). used in this paper: Reynolds, J.E., S. Halldin, C.Y. Xu, J. Seibert, and A. Kauffeldt. 2017. - “Sub-Daily Runoff Predictions Using Parameters Calibrated on the Basis of Data with a - Daily Temporal Resolution.” Journal of Hydrology 550 (July):399–411. + “Sub-Daily Runoff Predictions Using Parameters Calibrated on the Basis of Data with a + Daily Temporal Resolution.” Journal of Hydrology 550 (July):399–411. https://doi.org/10.1016/j.jhydrol.2017.05.012. .. math:: @@ -534,7 +535,7 @@ def volume_error(evaluation, simulation): ve = np.sum(simulation - evaluation) / np.sum(evaluation) return float(ve) else: - logging.warning("evaluation and simulation lists does not have the same length.") + logger.warning("evaluation and simulation lists does not have the same length.") return np.nan diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py new file mode 100644 index 00000000..fc1178bc --- /dev/null +++ b/spotpy/spotpylogging.py @@ -0,0 +1,34 @@ +# -*- coding: utf-8 -*- + +import logging + +# TODO possible next steps +# TODO 1. (tobias) remove logging calls with \n und passe die logging aufrufe an (grade alle info) +# TODO 2. (pr) make cli flags to control verbosity (ich weiß grade nicht wie das gehen soll) +# TODO 3. (pr) be able to create a file config + +path_to_logfile = 'spotpy.log' + +# Standard defintion of main logger +spotpy_logger = logging.getLogger("spotpy") + +# Add logging to stdout +handler_stdout = logging.StreamHandler() +formatter = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s %(message)s') +handler_stdout.setFormatter(formatter) +spotpy_logger.addHandler(handler_stdout) + +# Add logging to file +handler_file = logging.FileHandler(path_to_logfile) # TODO this should be bound to cli arguments +handler_file.setFormatter(formatter) +spotpy_logger.addHandler(handler_file) + +spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments +spotpy_logger.info('Write logging output to file \'%s\'', path_to_logfile) + + +def get_logger(name): + """ Returns a new child logger for the main spotpy application logging + + Use this logger to return new childs of the main logger""" + return spotpy_logger.getChild(name) # Set the logger name, with the implementation class From d4d2e138663dc7588bac21e54b149ec6f037cfb2 Mon Sep 17 00:00:00 2001 From: Chris Weber Date: Thu, 2 Apr 2020 12:16:41 +0200 Subject: [PATCH 02/13] Removes todos --- spotpy/spotpylogging.py | 9 ++++----- 1 file changed, 4 insertions(+), 5 deletions(-) diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py index fc1178bc..23429eef 100644 --- a/spotpy/spotpylogging.py +++ b/spotpy/spotpylogging.py @@ -1,12 +1,11 @@ # -*- coding: utf-8 -*- +""" +Defines a standard logger for the main application, which every child can derive from. +Also it's possible to use the logger for the main application. +""" import logging -# TODO possible next steps -# TODO 1. (tobias) remove logging calls with \n und passe die logging aufrufe an (grade alle info) -# TODO 2. (pr) make cli flags to control verbosity (ich weiß grade nicht wie das gehen soll) -# TODO 3. (pr) be able to create a file config - path_to_logfile = 'spotpy.log' # Standard defintion of main logger From 3090ca86988d777b7e1fc70887f75925d66cc39b Mon Sep 17 00:00:00 2001 From: Chris Weber Date: Thu, 2 Apr 2020 14:25:18 +0200 Subject: [PATCH 03/13] Fix pep8 and unused comment --- spotpy/objectivefunctions.py | 3 +-- spotpy/spotpylogging.py | 15 +++++++++------ 2 files changed, 10 insertions(+), 8 deletions(-) diff --git a/spotpy/objectivefunctions.py b/spotpy/objectivefunctions.py index f6b91bb6..8714b08e 100644 --- a/spotpy/objectivefunctions.py +++ b/spotpy/objectivefunctions.py @@ -11,9 +11,8 @@ ''' from spotpy import spotpylogging import numpy as np -#logger.basicConfig(format='%(levelname)s: %(module)s.%(funcName)s(): %(message)s') -logger = spotpylogging.get_logger('objective_function') +logger = spotpylogging.get_logger('objective_functions') def bias(evaluation, simulation): """ diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py index 23429eef..93f1c0d4 100644 --- a/spotpy/spotpylogging.py +++ b/spotpy/spotpylogging.py @@ -1,7 +1,8 @@ # -*- coding: utf-8 -*- """ -Defines a standard logger for the main application, which every child can derive from. -Also it's possible to use the logger for the main application. +Defines a standard logger for the main application, which every child can + derive from. Also it's possible to use the logger for the main + application. """ import logging @@ -13,16 +14,17 @@ # Add logging to stdout handler_stdout = logging.StreamHandler() -formatter = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s %(message)s') +formatter = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s ' + + '%(message)s') handler_stdout.setFormatter(formatter) spotpy_logger.addHandler(handler_stdout) # Add logging to file -handler_file = logging.FileHandler(path_to_logfile) # TODO this should be bound to cli arguments +handler_file = logging.FileHandler(path_to_logfile) # TODO this should be bound to cli arguments handler_file.setFormatter(formatter) spotpy_logger.addHandler(handler_file) -spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments +spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments spotpy_logger.info('Write logging output to file \'%s\'', path_to_logfile) @@ -30,4 +32,5 @@ def get_logger(name): """ Returns a new child logger for the main spotpy application logging Use this logger to return new childs of the main logger""" - return spotpy_logger.getChild(name) # Set the logger name, with the implementation class + # Set the logger name, with the implementation class + return spotpy_logger.getChild(name) From fe380f7b322f8c34843719d882b58cae5d6ffabf Mon Sep 17 00:00:00 2001 From: thouska Date: Thu, 16 Apr 2020 14:03:44 +0200 Subject: [PATCH 04/13] Fix doubled logging message https://stackoverflow.com/questions/6729268/log-messages-appearing-twice-with-python-logging --- spotpy/analyser.py | 2 +- spotpy/spotpylogging.py | 35 +++++++++++++++++++---------------- 2 files changed, 20 insertions(+), 17 deletions(-) diff --git a/spotpy/analyser.py b/spotpy/analyser.py index 422248d4..257fc887 100644 --- a/spotpy/analyser.py +++ b/spotpy/analyser.py @@ -10,7 +10,7 @@ Note: This part of SPOTPY is in alpha status and not yet ready for production use. ''' -from spotpylogging import get_logger +from .spotpylogging import get_logger import numpy as np import spotpy diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py index 93f1c0d4..c5554f99 100644 --- a/spotpy/spotpylogging.py +++ b/spotpy/spotpylogging.py @@ -11,22 +11,25 @@ # Standard defintion of main logger spotpy_logger = logging.getLogger("spotpy") - -# Add logging to stdout -handler_stdout = logging.StreamHandler() -formatter = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s ' + - '%(message)s') -handler_stdout.setFormatter(formatter) -spotpy_logger.addHandler(handler_stdout) - -# Add logging to file -handler_file = logging.FileHandler(path_to_logfile) # TODO this should be bound to cli arguments -handler_file.setFormatter(formatter) -spotpy_logger.addHandler(handler_file) - -spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments -spotpy_logger.info('Write logging output to file \'%s\'', path_to_logfile) - +if not spotpy_logger.handlers: + # create the handlers and call logger.addHandler(logging_handler) + # Add logging to stdout + handler_stdout = logging.StreamHandler() +# formatter = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s ' + +# '%(message)s') + formatter = logging.Formatter('%(message)s') + + handler_stdout.setFormatter(formatter) + spotpy_logger.addHandler(handler_stdout) + + # Add logging to file + handler_file = logging.FileHandler(path_to_logfile) # TODO this should be bound to cli arguments + handler_file.setFormatter(formatter) + spotpy_logger.addHandler(handler_file) + + spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments + spotpy_logger.info('Write logging output to file \'%s\'', path_to_logfile) + def get_logger(name): """ Returns a new child logger for the main spotpy application logging From 85e0b7abda5cafbe3b9ea84cfbc2ea6e0fef5cb1 Mon Sep 17 00:00:00 2001 From: thouska Date: Thu, 16 Apr 2020 14:11:09 +0200 Subject: [PATCH 05/13] Use different formats for logging in file and console --- spotpy/spotpylogging.py | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py index c5554f99..e39e80f6 100644 --- a/spotpy/spotpylogging.py +++ b/spotpy/spotpylogging.py @@ -15,16 +15,16 @@ # create the handlers and call logger.addHandler(logging_handler) # Add logging to stdout handler_stdout = logging.StreamHandler() -# formatter = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s ' + -# '%(message)s') - formatter = logging.Formatter('%(message)s') + formatter_file = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s ' + + '%(message)s') + formatter_stdout = logging.Formatter('%(message)s') - handler_stdout.setFormatter(formatter) + handler_stdout.setFormatter(formatter_stdout) spotpy_logger.addHandler(handler_stdout) # Add logging to file handler_file = logging.FileHandler(path_to_logfile) # TODO this should be bound to cli arguments - handler_file.setFormatter(formatter) + handler_file.setFormatter(formatter_file) spotpy_logger.addHandler(handler_file) spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments From f7fa4fdef4f66b6c2cbda21ed747179536ea465d Mon Sep 17 00:00:00 2001 From: thouska Date: Thu, 16 Apr 2020 15:25:18 +0200 Subject: [PATCH 06/13] Nuanced using of debug/info/error in algorithms --- spotpy/algorithms/abc.py | 8 +++--- spotpy/algorithms/dds.py | 4 +-- spotpy/algorithms/demcz.py | 14 +++++----- spotpy/algorithms/dream.py | 12 ++++----- spotpy/algorithms/fast.py | 4 +-- spotpy/algorithms/fscabc.py | 8 +++--- spotpy/algorithms/lhs.py | 2 +- spotpy/algorithms/mcmc.py | 10 +++---- spotpy/algorithms/mle.py | 6 ++--- spotpy/algorithms/padds.py | 2 +- spotpy/algorithms/rope.py | 10 +++---- spotpy/algorithms/sa.py | 2 +- spotpy/algorithms/sceua.py | 54 +++++++++++++++++++------------------ spotpy/spotpylogging.py | 6 ++--- 14 files changed, 72 insertions(+), 70 deletions(-) diff --git a/spotpy/algorithms/abc.py b/spotpy/algorithms/abc.py index 0c12876c..015514b0 100644 --- a/spotpy/algorithms/abc.py +++ b/spotpy/algorithms/abc.py @@ -104,7 +104,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, ownlimit=False, li work.append([like, randompar, like, randompar, c, p]) icall +=1 if self.status.stop: - self.logger.info('Stopping sampling') + self.logger.debug('Stopping sampling') break while icall < repetitions and gnrng > peps: @@ -136,7 +136,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, ownlimit=False, li work[rep][4] = work[rep][4] + 1 icall += 1 if self.status.stop: - self.logger.info('Stopping samplig') + self.logger.debug('Stopping samplig') break # Probability distribution for roulette wheel selection bn = [] for i, val in enumerate(work): @@ -182,7 +182,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, ownlimit=False, li work[rep][4] = work[rep][4] + 1 icall += 1 if self.status.stop: - self.logger.info('Stopping samplig') + self.logger.debug('Stopping samplig') break # Scout bee phase for i, val in enumerate(work): @@ -195,7 +195,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, ownlimit=False, li work[i][0] = clike icall += 1 if self.status.stop: - self.logger.info('Stopping samplig') + self.logger.debug('Stopping samplig') break gnrng = -self.status.objectivefunction_max if icall >= repetitions: diff --git a/spotpy/algorithms/dds.py b/spotpy/algorithms/dds.py index d9cccba0..f403c7f4 100644 --- a/spotpy/algorithms/dds.py +++ b/spotpy/algorithms/dds.py @@ -311,7 +311,7 @@ def sample(self, repetitions, trials=1, x_initial=np.array([])): self.params_max = list(x_curr) self.params_max = self.fix_status_params_format(self.params_max) - self.logger.info('Best solution found has obj function value of ' + str(objectivefunction_max) + ' at ' + self.logger.debug('Best solution found has obj function value of ' + str(objectivefunction_max) + ' at ' + str(repitionno_best) + '\n\n') debug_results.append({"sbest": self.params_max, "trial_initial": trial_best_value,"objfunc_val": objectivefunction_max}) self.final_call() @@ -334,7 +334,7 @@ def calc_initial_para_configuration(self, initial_iterations, trial, repetitions # by trying which randomized generated input matches best # initial_iterations is the number of function evaluations to initialize the DDS algorithm solution if initial_iterations > 1: - self.logger.info('Finding best starting point for trial ' + str(trial + 1) + ' using ' + str( + self.logger.debug('Finding best starting point for trial ' + str(trial + 1) + ' using ' + str( initial_iterations) + ' random samples.') repetions_left = repetitions - initial_iterations # use this to reduce number of fevals in DDS loop if repetions_left <= 0: diff --git a/spotpy/algorithms/demcz.py b/spotpy/algorithms/demcz.py index 6096d3dc..ea87d428 100644 --- a/spotpy/algorithms/demcz.py +++ b/spotpy/algorithms/demcz.py @@ -106,7 +106,7 @@ def check_par_validity(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - self.logger.info('ERROR Bounds have not the same lenghts as Parameterarray') + self.logger.error('ERROR Bounds have not the same lenghts as Parameterarray') return par def sample(self, repetitions, nChains=3, burnIn=100, thin=1, @@ -208,9 +208,9 @@ def sample(self, repetitions, nChains=3, burnIn=100, thin=1, # 3) and we have not done more than the maximum number of iterations while cur_iter < maxChainDraws: - self.logger.info("%s, %s", cur_iter, burnIn) + self.logger.debug("%s, %s", cur_iter, burnIn) if cur_iter == burnIn: - self.logger.info('starting') + self.logger.debug('starting') history.start_sampling() # every5th iteration allow a big jump @@ -473,8 +473,8 @@ def _random_no_replace(sampleSize, populationSize, numSamples): return samples -class _CovarianceConvergence: - +class _CovarianceConvergence(): + relativeVariances = {} def update(self, history, group): @@ -503,7 +503,7 @@ def rv(relevantHistory): projection = np.dot(np.linalg.inv(basis1), basis2) except np.linalg.linalg.LinAlgError: projection = (np.array(basis1) * np.nan) - self.logger.info('Exception happend!') + #self.logger.debug('Exception happend!') # find the releative size in each of the basis1 directions return np.log(np.sum(projection**2, axis=0)**.5) @@ -555,7 +555,7 @@ def _dream_proposals(currentVectors, history, dimensions, nChains, DEpairs, gamm return proposalVectors -class _GRConvergence: +class _GRConvergence(): """ Gelman Rubin convergence diagnostic calculator class. It currently only calculates the naive version found in the first paper. It does not check to see whether the variances have been diff --git a/spotpy/algorithms/dream.py b/spotpy/algorithms/dream.py index 554c09ae..7bc09800 100644 --- a/spotpy/algorithms/dream.py +++ b/spotpy/algorithms/dream.py @@ -67,7 +67,7 @@ def check_par_validity_bound(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - self.logger.info('ERROR: Bounds have not the same lenghts as Parameterarray') + self.logger.error('ERROR: Bounds have not the same lenghts as Parameterarray') return par def get_regular_startingpoint(self,nChains): @@ -97,7 +97,7 @@ def check_par_validity_reflect(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - self.logger.info('ERROR: Bounds have not the same lenghts as Parameterarray') + self.logger.error('ERROR: Bounds have not the same lenghts as Parameterarray') return par def _get_gamma(self,N): @@ -222,7 +222,7 @@ def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, self.set_repetiton(repetitions) self.logger.info('Starting the DREAM algotrithm with '+str(repetitions)+ ' repetitions...') if nChains <3: - self.logger.info('Please use at least n=3 chains!') + self.logger.error('Please use at least n=3 chains!') return None # Prepare storing MCMC chain as array of arrays. # define stepsize of MCMC. @@ -247,7 +247,7 @@ def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, #firstcall = True - self.logger.info('Initialize %s chain(s)...', self.nChains) + self.logger.debug('Initialize %s chain(s)...', self.nChains) self.iter=0 #for i in range(10): startpoints = self.get_regular_startingpoint(nChains) @@ -260,7 +260,7 @@ def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, self.nChainruns[curChain] +=1 - self.logger.info('Beginn of Random Walk') + self.logger.debug('Beginn of Random Walk') convergence = False #Walf through chains self.r_hats=[] @@ -327,7 +327,7 @@ def sample(self, repetitions,nChains=5, nCr=3, eps=10e-6, convergence_limit=1.2, if self.status.stop: self.iter = self.repetitions - self.logger.info('Stopping samplig') + self.logger.debug('Stopping samplig') break self.iter+=1 self.nChainruns[cChain] +=1 diff --git a/spotpy/algorithms/fast.py b/spotpy/algorithms/fast.py index b1c25a9e..d3746310 100644 --- a/spotpy/algorithms/fast.py +++ b/spotpy/algorithms/fast.py @@ -146,7 +146,7 @@ def analyze(self, problem, Y, D, parnames, M=4, print_to_console=False): of totaly """ + str(Y.size) + """ """) else: - self.logger.info(""" + self.logger.error(""" Error: Number of samples in model output file must be a multiple of D, where D is the number of parameters in your parameter file. """) @@ -200,7 +200,7 @@ def sample(self, repetitions, M=4): """ self.set_repetiton(repetitions) self.logger.info('Starting the FAST algotrithm with '+str(repetitions)+ ' repetitions...') - self.logger.info('Creating FAST Matrix') + self.logger.debug('Creating FAST Matrix') # Get the names of the parameters to analyse names = self.parameter()['name'] # Get the minimum and maximum value for each parameter from the diff --git a/spotpy/algorithms/fscabc.py b/spotpy/algorithms/fscabc.py index cbfabfbc..bca024df 100644 --- a/spotpy/algorithms/fscabc.py +++ b/spotpy/algorithms/fscabc.py @@ -130,7 +130,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, kpow=4, limit=None icall +=1 if self.status.stop: #icall = repetitions - self.logger.info('Stopping samplig') + self.logger.debug('Stopping samplig') break #Bee Phases @@ -167,7 +167,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, kpow=4, limit=None work[rep][4] = work[rep][4] + 1 icall += 1 if self.status.stop: - self.logger.info('Stopping samplig') + self.logger.debug('Stopping samplig') break # Fitness scaling @@ -213,7 +213,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, kpow=4, limit=None work[rep][4] = work[rep][4] + 1 icall += 1 if self.status.stop: - self.logger.info('Stopping samplig') + self.logger.debug('Stopping samplig') break # Scout bee phase for i, val in enumerate(work): @@ -228,7 +228,7 @@ def sample(self, repetitions, eb=48, a=(1 / 10), peps=0.0001, kpow=4, limit=None work[i][0] = clike icall += 1 if self.status.stop: - self.logger.info('Stopping samplig') + self.logger.debug('Stopping samplig') break gnrng = -self.status.objectivefunction_max diff --git a/spotpy/algorithms/lhs.py b/spotpy/algorithms/lhs.py index b677d4d0..ec52a175 100644 --- a/spotpy/algorithms/lhs.py +++ b/spotpy/algorithms/lhs.py @@ -63,7 +63,7 @@ def sample(self, repetitions): """ self.set_repetiton(repetitions) self.logger.info('Starting the LHS algotrithm with '+str(repetitions)+ ' repetitions...') - self.logger.info('Creating LatinHyperCube Matrix') + self.logger.debug('Creating LatinHyperCube Matrix') # Get the names of the parameters to analyse names = self.parameter()['name'] # Define the jump size between the parameter diff --git a/spotpy/algorithms/mcmc.py b/spotpy/algorithms/mcmc.py index cbd9b7d7..ab305fa6 100644 --- a/spotpy/algorithms/mcmc.py +++ b/spotpy/algorithms/mcmc.py @@ -65,7 +65,7 @@ def check_par_validity(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - self.logger.info('ERROR: Bounds have not the same lenghts as Parameterarray') + self.logger.error('ERROR: Bounds have not the same lenghts as Parameterarray') return par def check_par_validity_reflect(self, par): @@ -83,7 +83,7 @@ def check_par_validity_reflect(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - self.logger.info('ERROR: Bounds have not the same lenghts as Parameterarray') + self.logger.error('ERROR: Bounds have not the same lenghts as Parameterarray') return par def get_new_proposal_vector(self,old_par): @@ -116,7 +116,7 @@ def sample(self, repetitions,nChains=1): self.nChainruns=[[0]]*self.nChains self.min_bound, self.max_bound = self.parameter( )['minbound'], self.parameter()['maxbound'] - self.logger.info('Initialize %s chain(s)...', self.nChains) + self.logger.debug('Initialize %s chain(s)...', self.nChains) self.iter=0 param_generator = ((curChain,self.parameter()['random']) for curChain in range(int(self.nChains))) for curChain,randompar,simulations in self.repeat(param_generator): @@ -126,7 +126,7 @@ def sample(self, repetitions,nChains=1): self.iter+=1 intervaltime = time.time() - self.logger.info('Beginn of Random Walk') + self.logger.debug('Beginn of Random Walk') # Walk through chains while self.iter <= repetitions - self.burnIn: param_generator = ((curChain,self.get_new_proposal_vector(self.bestpar[curChain])) for curChain in range(int(self.nChains))) @@ -146,6 +146,6 @@ def sample(self, repetitions,nChains=1): text = '%i of %i (best like=%g)' % ( self.iter + self.burnIn, repetitions, self.status.objectivefunction_max) text = "Acceptance rates [%] =" +str(np.around((self.accepted)/float(((self.iter-self.burnIn)/self.nChains)),decimals=4)*100).strip('array([])') - self.logger.info(text) + self.logger.debug(text) intervaltime = time.time() self.final_call() diff --git a/spotpy/algorithms/mle.py b/spotpy/algorithms/mle.py index 52779ac8..2e8ccc3b 100644 --- a/spotpy/algorithms/mle.py +++ b/spotpy/algorithms/mle.py @@ -60,7 +60,7 @@ def check_par_validity(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - self.logger.info('ERROR Bounds have not the same lenghts as Parameterarray') + self.logger.error('ERROR Bounds have not the same lenghts as Parameterarray') return par def sample(self, repetitions): @@ -76,7 +76,7 @@ def sample(self, repetitions): likes = [] pars = [] sims = [] - self.logger.info('burnIn...') + self.logger.debug('burnIn...') for i in range(burnIn): randompar = self.parameter()['random'] pars.append(randompar) @@ -88,7 +88,7 @@ def sample(self, repetitions): old_like = max(likes) old_par = pars[likes.index(old_like)] - self.logger.info('Beginn Random Walk') + self.logger.debug('Beginn Random Walk') for rep in range(repetitions - burnIn): # Suggest new candidate from Gaussian proposal distribution. # Use stepsize provided for every dimension. diff --git a/spotpy/algorithms/padds.py b/spotpy/algorithms/padds.py index 7191e3a5..c2b1dd73 100644 --- a/spotpy/algorithms/padds.py +++ b/spotpy/algorithms/padds.py @@ -219,7 +219,7 @@ def sample(self, repetitions, trials=1, initial_objs=np.array([]), initial_param # update the new status structure self.status.params_max, self.status.params_min = self.parameter_current, self.parameter_current - self.logger.info('Best solution found has obj function value of ' + str(self.best_value.best_obj_val) + ' at ' + self.logger.debug('Best solution found has obj function value of ' + str(self.best_value.best_obj_val) + ' at ' + str(repitionno_best) + '\n\n') debug_results.append({"sbest": self.best_value.parameters , "objfunc_val": self.best_value.best_obj_val}) diff --git a/spotpy/algorithms/rope.py b/spotpy/algorithms/rope.py index 90e28ec0..7f6756b3 100644 --- a/spotpy/algorithms/rope.py +++ b/spotpy/algorithms/rope.py @@ -156,7 +156,7 @@ def sample(self, repetitions=None, repetitions_first_run=None, if acttime - intervaltime >= 2: text = '1 Subset: Run %i of %i (best like=%g)' % ( rep, first_run, self.status.objectivefunction_max) - self.logger.info(text) + self.logger.debug(text) intervaltime = time.time() for subset in range(subsets - 1): @@ -186,7 +186,7 @@ def sample(self, repetitions=None, repetitions_first_run=None, likes.append(like) pars.append(ropepar) if self.status.stop: - self.logger.info('Stopping samplig') + self.logger.debug('Stopping samplig') break # Progress bar @@ -199,7 +199,7 @@ def sample(self, repetitions=None, repetitions_first_run=None, rep, repetitions_following_runs, self.status.objectivefunction_max) - self.logger.info(text) + self.logger.debug(text) intervaltime = time.time() if self.status.stop: break @@ -212,10 +212,10 @@ def programm_depth(self, pars, runs): N, NP = X.shape text = str(N) + ' input vectors with ' + str(NP) + ' parameters' - self.logger.info(text) + self.logger.debug(text) Ngen = int(runs) # int(N*(1/self.percentage)) - self.logger.info(('Generating ' + str(Ngen) + ' parameters:')) + self.logger.debug(('Generating ' + str(Ngen) + ' parameters:')) NPOSI = Ngen # Number of points to generate diff --git a/spotpy/algorithms/sa.py b/spotpy/algorithms/sa.py index b26c9de2..a277dd92 100644 --- a/spotpy/algorithms/sa.py +++ b/spotpy/algorithms/sa.py @@ -65,7 +65,7 @@ def check_par_validity(self, par): if par[i] > self.max_bound[i]: par[i] = self.max_bound[i] else: - self.logger.info('ERROR: Bounds have not the same lenghts as Parameterarray') + self.logger.error('ERROR: Bounds have not the same lenghts as Parameterarray') return par def sample(self, repetitions, Tini=80, Ntemp=50, alpha=0.99): diff --git a/spotpy/algorithms/sceua.py b/spotpy/algorithms/sceua.py index c126e96a..721cfacd 100644 --- a/spotpy/algorithms/sceua.py +++ b/spotpy/algorithms/sceua.py @@ -148,6 +148,8 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 Value of the normalized geometric range of the parameters in the population below which convergence is deemed achieved. """ self.set_repetiton(repetitions) + self.logger.info('Starting the SCEUA algotrithm with '+str(repetitions)+ ' repetitions...') + # Initialize SCE parameters: self.ngs = ngs randompar = self.parameter()['random'] @@ -177,7 +179,7 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 icall = 0 xf = np.zeros(npt) - self.logger.info('Starting burn-in sampling...') + self.logger.debug('Starting burn-in sampling...') # Burn in param_generator = ((rep, x[rep]) for rep in range(int(npt))) @@ -187,7 +189,7 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 xf[rep] = like icall+=1 if self.status.stop: - self.logger.info('Stopping samplig. Maximum number of repetitions reached already during burn-in') + self.logger.debug('Stopping samplig. Maximum number of repetitions reached already during burn-in') proceed = False break # Sort the population in order of increasing function values; @@ -210,18 +212,18 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 # Check for convergency; if self.status.rep >= repetitions: - self.logger.info('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') - self.logger.info('ON THE MAXIMUM NUMBER OF TRIALS ') - self.logger.info(repetitions) - self.logger.info('HAS BEEN EXCEEDED. SEARCH WAS STOPPED AT TRIAL NUMBER:') - self.logger.info(self.status.rep) - self.logger.info('OF THE INITIAL LOOP!') + self.logger.debug('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') + self.logger.debug('ON THE MAXIMUM NUMBER OF TRIALS ') + self.logger.debug(repetitions) + self.logger.debug('HAS BEEN EXCEEDED. SEARCH WAS STOPPED AT TRIAL NUMBER:') + self.logger.debug(self.status.rep) + self.logger.debug('OF THE INITIAL LOOP!') if gnrng < peps: - self.logger.info( + self.logger.debug( 'THE POPULATION HAS CONVERGED TO A PRESPECIFIED SMALL PARAMETER SPACE') - self.logger.info('Burn-in sampling completed...') + self.logger.debug('Burn-in sampling completed...') # Begin evolution loops: nloop = 0 @@ -229,11 +231,11 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 criter_change_pcent = 1e+5 self.repeat.setphase('ComplexEvo') - self.logger.info('Starting Complex Evolution...') + self.logger.debug('Starting Complex Evolution...') proceed = True while icall < repetitions and gnrng > peps and criter_change_pcent > pcento and proceed == True: nloop += 1 - self.logger.info('ComplexEvo loop #%d in progress...' % nloop) + self.logger.debug('ComplexEvo loop #%d in progress...' % nloop) # Loop on complexes (sub-populations); cx = np.zeros((self.npg, self.nopt)) cf = np.zeros((self.npg)) @@ -258,7 +260,7 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 proceed=False like = self.postprocessing(i, pars[i], sims[i], chains=i+1, save_run=False) self.discarded_runs+=1 - self.logger.info('Skipping saving') + self.logger.debug('Skipping saving') if self.breakpoint == 'write' or self.breakpoint == 'readandwrite'\ and self.status.rep >= self.backup_every_rep: @@ -288,18 +290,18 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 # Check for convergency; if self.status.rep >= repetitions: - self.logger.info('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') - self.logger.info('ON THE MAXIMUM NUMBER OF TRIALS ') - self.logger.info(repetitions) - self.logger.info('HAS BEEN EXCEEDED.') + self.logger.debug('*** OPTIMIZATION SEARCH TERMINATED BECAUSE THE LIMIT') + self.logger.debug('ON THE MAXIMUM NUMBER OF TRIALS ') + self.logger.debug(repetitions) + self.logger.debug('HAS BEEN EXCEEDED.') elif gnrng < peps: - self.logger.info( + self.logger.debug( 'THE POPULATION HAS CONVERGED TO A PRESPECIFIED SMALL PARAMETER SPACE') elif nloop >= kstop: # necessary so that the area of high posterior density is visited as much as possible - self.logger.info('Objective function convergence criteria is now being updated and assessed...') + self.logger.debug('Objective function convergence criteria is now being updated and assessed...') absolute_change = np.abs( criter[nloop - 1] - criter[nloop - kstop])*100 denominator = np.mean(np.abs(criter[(nloop - kstop):nloop])) @@ -307,21 +309,21 @@ def sample(self, repetitions, ngs=20, kstop=100, pcento=0.0000001, peps=0.000000 criter_change_pcent = 0.0 else: criter_change_pcent = absolute_change / denominator - self.logger.info('Updated convergence criteria: %f' % criter_change_pcent) + self.logger.debug('Updated convergence criteria: %f' % criter_change_pcent) if criter_change_pcent <= pcento: - self.logger.info('THE BEST POINT HAS IMPROVED IN LAST %d LOOPS BY LESS THAN THE USER-SPECIFIED THRESHOLD %f' % ( + self.logger.debug('THE BEST POINT HAS IMPROVED IN LAST %d LOOPS BY LESS THAN THE USER-SPECIFIED THRESHOLD %f' % ( kstop, pcento)) - self.logger.info( + self.logger.debug( 'CONVERGENCY HAS ACHIEVED BASED ON OBJECTIVE FUNCTION CRITERIA!!!') elif self.status.stop: proceed = False break # End of the Outer Loops - self.logger.info('SEARCH WAS STOPPED AT TRIAL NUMBER: %d' % self.status.rep) - self.logger.info('NUMBER OF DISCARDED TRIALS: %d' % self.discarded_runs) - self.logger.info('NORMALIZED GEOMETRIC RANGE = %f' % gnrng) - self.logger.info('THE BEST POINT HAS IMPROVED IN LAST %d LOOPS BY %f PERCENT' % ( + self.logger.debug('SEARCH WAS STOPPED AT TRIAL NUMBER: %d' % self.status.rep) + self.logger.debug('NUMBER OF DISCARDED TRIALS: %d' % self.discarded_runs) + self.logger.debug('NORMALIZED GEOMETRIC RANGE = %f' % gnrng) + self.logger.debug('THE BEST POINT HAS IMPROVED IN LAST %d LOOPS BY %f PERCENT' % ( kstop, criter_change_pcent)) # reshape BESTX diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py index e39e80f6..b345f0a1 100644 --- a/spotpy/spotpylogging.py +++ b/spotpy/spotpylogging.py @@ -26,8 +26,8 @@ handler_file = logging.FileHandler(path_to_logfile) # TODO this should be bound to cli arguments handler_file.setFormatter(formatter_file) spotpy_logger.addHandler(handler_file) - - spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments + + spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments spotpy_logger.info('Write logging output to file \'%s\'', path_to_logfile) @@ -36,4 +36,4 @@ def get_logger(name): Use this logger to return new childs of the main logger""" # Set the logger name, with the implementation class - return spotpy_logger.getChild(name) + return spotpy_logger.getChild(name) \ No newline at end of file From 5ea1a924bbf32368fb591f6387abf21aca3fac77 Mon Sep 17 00:00:00 2001 From: Chris Date: Wed, 26 May 2021 18:27:38 +0200 Subject: [PATCH 07/13] Adds cli param (WIP) and logfile timestamp --- spotpy/cli.py | 3 ++- spotpy/spotpylogging.py | 3 ++- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/spotpy/cli.py b/spotpy/cli.py index 04ad2807..ad8ef84a 100644 --- a/spotpy/cli.py +++ b/spotpy/cli.py @@ -62,6 +62,8 @@ def cli(): @click.option('--runs', '-n', type=click.INT, default=1, help='Number of runs') @click.option('--config', '-c', is_flag=True, help='Print only the configuration, can be used to create a config file with your_model.py > spotpy.conf') +@click.option('--quiet', '-q', is_flag=True, + help='Suppress any logging messages to stdout during computation.') def run(ctx, **kwargs): """ Runs a sampler for automatic calibration @@ -94,4 +96,3 @@ def main(setup): cli.help = '\b\n' + describe.setup(setup).replace('\n\n', '\n\b\n') config = get_config_from_file() cli(obj=setup, auto_envvar_prefix='SPOTPY', default_map=config) - diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py index b345f0a1..bc9d9f77 100644 --- a/spotpy/spotpylogging.py +++ b/spotpy/spotpylogging.py @@ -6,8 +6,9 @@ """ import logging +from datetime import datetime -path_to_logfile = 'spotpy.log' +path_to_logfile = '{}-spotpy.log'.format(datetime.isoformat(datetime.now())) # Standard defintion of main logger spotpy_logger = logging.getLogger("spotpy") From ebc1448b71536fb990ed18864c475c2c484813a1 Mon Sep 17 00:00:00 2001 From: Chris Date: Thu, 27 May 2021 10:02:02 +0200 Subject: [PATCH 08/13] Logifle option --- spotpy/cli.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/spotpy/cli.py b/spotpy/cli.py index ad8ef84a..53312f54 100644 --- a/spotpy/cli.py +++ b/spotpy/cli.py @@ -63,7 +63,9 @@ def cli(): @click.option('--config', '-c', is_flag=True, help='Print only the configuration, can be used to create a config file with your_model.py > spotpy.conf') @click.option('--quiet', '-q', is_flag=True, - help='Suppress any logging messages to stdout during computation.') + help='Suppress any logging messages to stdout during computation') +@click.option('--logfile', type=click.Path(), + help='Logging messages will be written to this file. If already exists, contents are appended') def run(ctx, **kwargs): """ Runs a sampler for automatic calibration From d175060603879e1e058e6c9c173c35d1061dca5a Mon Sep 17 00:00:00 2001 From: Chris Date: Fri, 28 May 2021 11:12:21 +0200 Subject: [PATCH 09/13] Adds logdir option and click parameter delegation for _algorithm * Also new logging instantiation --- spotpy/algorithms/_algorithm.py | 5 ++- spotpy/cli.py | 7 +++- spotpy/spotpylogging.py | 71 +++++++++++++++++++++++---------- 3 files changed, 58 insertions(+), 25 deletions(-) diff --git a/spotpy/algorithms/_algorithm.py b/spotpy/algorithms/_algorithm.py index 5e5ad0c3..8da92e90 100644 --- a/spotpy/algorithms/_algorithm.py +++ b/spotpy/algorithms/_algorithm.py @@ -212,10 +212,11 @@ class _algorithm(object): def __init__(self, spot_setup, dbname=None, dbformat=None, dbinit=True, dbappend=False, parallel='seq', save_sim=True, breakpoint=None, backup_every_rep=100, save_threshold=-np.inf, db_precision=np.float16, - sim_timeout=None, random_state=None, optimization_direction='grid', algorithm_name=''): + sim_timeout=None, random_state=None, optimization_direction='grid', algorithm_name='', + quiet=False, logfile=None, logdir=None): # Instatiate logging - self.logger = spotpylogging.get_logger(self.__class__.__name__) + self.logger = spotpylogging.instantiate_logger(self.__class__.__name__, quiet, logfile, logdir) # Initialize the user defined setup class self.setup = spot_setup diff --git a/spotpy/cli.py b/spotpy/cli.py index 53312f54..3320a520 100644 --- a/spotpy/cli.py +++ b/spotpy/cli.py @@ -64,8 +64,11 @@ def cli(): help='Print only the configuration, can be used to create a config file with your_model.py > spotpy.conf') @click.option('--quiet', '-q', is_flag=True, help='Suppress any logging messages to stdout during computation') -@click.option('--logfile', type=click.Path(), - help='Logging messages will be written to this file. If already exists, contents are appended') +@click.option('--logfile', type=click.Path(dir_okay=False), + help='Logging messages will be written to this file. If already exists, ' + 'contents are appended. A default filename is created with a current timestamp') +@click.option('--logdir', type=click.Path(file_okay=False), + help='Logging files will be written to this directory. Default is "."') def run(ctx, **kwargs): """ Runs a sampler for automatic calibration diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py index bc9d9f77..31ffeff7 100644 --- a/spotpy/spotpylogging.py +++ b/spotpy/spotpylogging.py @@ -7,34 +7,63 @@ import logging from datetime import datetime +from os import path -path_to_logfile = '{}-spotpy.log'.format(datetime.isoformat(datetime.now())) +path_to_logfile = None # Standard defintion of main logger spotpy_logger = logging.getLogger("spotpy") -if not spotpy_logger.handlers: - # create the handlers and call logger.addHandler(logging_handler) - # Add logging to stdout - handler_stdout = logging.StreamHandler() - formatter_file = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s ' + - '%(message)s') - formatter_stdout = logging.Formatter('%(message)s') - - handler_stdout.setFormatter(formatter_stdout) - spotpy_logger.addHandler(handler_stdout) - - # Add logging to file - handler_file = logging.FileHandler(path_to_logfile) # TODO this should be bound to cli arguments - handler_file.setFormatter(formatter_file) - spotpy_logger.addHandler(handler_file) - spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments - spotpy_logger.info('Write logging output to file \'%s\'', path_to_logfile) - +handler_stdout = None +handler_file = None + +formatter_file = logging.Formatter('%(asctime)s %(name)-12s %(levelname)-8s %(message)s') +formatter_stdout = logging.Formatter('%(message)s') + +def instantiate_logger(name, quiet=None, logfile=None, logdir=None): + + + path_to_logdir = '.' + path_to_logfile = '{}-spotpy.log'.format(datetime.isoformat(datetime.now())) + + print(quiet, logfile, logdir) + + if not spotpy_logger.handlers: + # create the handlers and call logger.addHandler(logging_handler) + # Add logging to stdout + handler_stdout = logging.StreamHandler() + + handler_stdout.setFormatter(formatter_stdout) + spotpy_logger.addHandler(handler_stdout) + + if quiet: + handler_stdout.setLevel(logging.ERROR) + + # Add logging to file + if logdir is not None: + path_to_logdir = logdir + if logfile is not None: + path_to_logfile = logfile + path_to_logfile = path_to_logdir + path.sep + path_to_logfile + + handler_file = logging.FileHandler(path_to_logfile) # TODO this should be bound to cli arguments + handler_file.setFormatter(formatter_file) + spotpy_logger.addHandler(handler_file) + + spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments + spotpy_logger.info('Write logging output to file \'%s\'', path_to_logfile) + + return get_logger(name) + #else: + #if quiet and not (logfile is None): + # raise RuntimeError("Logger is already instantiated!") + + # Set the logger name, with the implementation class def get_logger(name): """ Returns a new child logger for the main spotpy application logging Use this logger to return new childs of the main logger""" - # Set the logger name, with the implementation class - return spotpy_logger.getChild(name) \ No newline at end of file + + + return spotpy_logger.getChild(name) \ No newline at end of file From cfb3ac8a8bc45a8c757a60aa67d2e8e24c0f6a49 Mon Sep 17 00:00:00 2001 From: Chris Date: Tue, 1 Jun 2021 11:14:22 +0200 Subject: [PATCH 10/13] Fix tests and instantiation --- spotpy/spotpylogging.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py index 31ffeff7..2def50be 100644 --- a/spotpy/spotpylogging.py +++ b/spotpy/spotpylogging.py @@ -53,7 +53,7 @@ def instantiate_logger(name, quiet=None, logfile=None, logdir=None): spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments spotpy_logger.info('Write logging output to file \'%s\'', path_to_logfile) - return get_logger(name) + return get_logger(name) #else: #if quiet and not (logfile is None): # raise RuntimeError("Logger is already instantiated!") From 13bf1601510942423baac5d48e905f5eea5f2be6 Mon Sep 17 00:00:00 2001 From: Chris Date: Sun, 6 Jun 2021 12:50:01 +0200 Subject: [PATCH 11/13] Various * Remove comments * Replaces last print and log messages with backspace char --- spotpy/algorithms/_algorithm.py | 6 ++++-- spotpy/database/__init__.py | 5 ++++- spotpy/spotpylogging.py | 25 ++++++++++--------------- 3 files changed, 18 insertions(+), 18 deletions(-) diff --git a/spotpy/algorithms/_algorithm.py b/spotpy/algorithms/_algorithm.py index 8da92e90..65691e55 100644 --- a/spotpy/algorithms/_algorithm.py +++ b/spotpy/algorithms/_algorithm.py @@ -125,7 +125,8 @@ def print_status(self): self.last_print = time.time() def print_status_final(self): - self.logger.info('\n*** Final SPOTPY summary ***') + self.logger.info('') + self.logger.info('*** Final SPOTPY summary ***') self.logger.info('Total Duration: %s seconds' % str(round((time.time() - self.starttime), 2))) self.logger.info('Total Repetitions: %s', self.rep) @@ -156,7 +157,8 @@ def print_status_final(self): text = '%s: %g' % (self.parnames[i], self.params_max[i]) self.logger.info(text) - self.logger.info('******************************\n') + self.logger.info('******************************') + self.logger.info('') def __repr__(self): diff --git a/spotpy/database/__init__.py b/spotpy/database/__init__.py index 8c539ba2..e5d51042 100644 --- a/spotpy/database/__init__.py +++ b/spotpy/database/__init__.py @@ -1,5 +1,8 @@ from importlib import import_module +from spotpy.spotpylogging import get_logger + +logger = get_logger('database.__init__') def __dir__(): """ @@ -18,7 +21,7 @@ def __dir__(): def __getattr__(name): names = __dir__() - print(names) + logger.info(names) if name in names: try: db_module = import_module('.' + name, __name__) diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py index 2def50be..04f3b0d4 100644 --- a/spotpy/spotpylogging.py +++ b/spotpy/spotpylogging.py @@ -9,11 +9,10 @@ from datetime import datetime from os import path -path_to_logfile = None - # Standard defintion of main logger spotpy_logger = logging.getLogger("spotpy") +path_to_logfile = None handler_stdout = None handler_file = None @@ -21,13 +20,14 @@ formatter_stdout = logging.Formatter('%(message)s') def instantiate_logger(name, quiet=None, logfile=None, logdir=None): - + """ + Instantiate the logger, + if already instantiated returns a new child of the main logger + """ path_to_logdir = '.' path_to_logfile = '{}-spotpy.log'.format(datetime.isoformat(datetime.now())) - print(quiet, logfile, logdir) - if not spotpy_logger.handlers: # create the handlers and call logger.addHandler(logging_handler) # Add logging to stdout @@ -46,24 +46,19 @@ def instantiate_logger(name, quiet=None, logfile=None, logdir=None): path_to_logfile = logfile path_to_logfile = path_to_logdir + path.sep + path_to_logfile - handler_file = logging.FileHandler(path_to_logfile) # TODO this should be bound to cli arguments + handler_file = logging.FileHandler(path_to_logfile) handler_file.setFormatter(formatter_file) spotpy_logger.addHandler(handler_file) - spotpy_logger.setLevel(logging.INFO) # TODO this should be bound to cli arguments + spotpy_logger.setLevel(logging.INFO) spotpy_logger.info('Write logging output to file \'%s\'', path_to_logfile) return get_logger(name) - #else: - #if quiet and not (logfile is None): - # raise RuntimeError("Logger is already instantiated!") - - # Set the logger name, with the implementation class + def get_logger(name): - """ Returns a new child logger for the main spotpy application logging + """ Returns a new child logger for the main spotpy application logging. Use this logger to return new childs of the main logger""" - - return spotpy_logger.getChild(name) \ No newline at end of file + return spotpy_logger.getChild(name) From 533409f2bfe6b9b5ffd7b67ccf3295308ca95cab Mon Sep 17 00:00:00 2001 From: Chris Date: Sun, 6 Jun 2021 13:30:09 +0200 Subject: [PATCH 12/13] Adds missing dependecy click to setup py --- setup.py | 1 + 1 file changed, 1 insertion(+) diff --git a/setup.py b/setup.py index 5dcda235..db5655e8 100644 --- a/setup.py +++ b/setup.py @@ -14,6 +14,7 @@ url = 'https://spotpy.readthedocs.io/en/latest/', license = 'MIT', install_requires=[ + 'click', 'scipy'], packages=find_packages(exclude=["tests*", "docs*"]), use_2to3 = True, From cb8d951788357fca651e9ee70bf771cd67ac5e7f Mon Sep 17 00:00:00 2001 From: Chris Date: Mon, 12 Jul 2021 13:24:48 +0200 Subject: [PATCH 13/13] Use os agnostic path objects --- spotpy/spotpylogging.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/spotpy/spotpylogging.py b/spotpy/spotpylogging.py index 04f3b0d4..e4f8daa1 100644 --- a/spotpy/spotpylogging.py +++ b/spotpy/spotpylogging.py @@ -7,7 +7,7 @@ import logging from datetime import datetime -from os import path +from pathlib import PurePath # Standard defintion of main logger spotpy_logger = logging.getLogger("spotpy") @@ -25,8 +25,8 @@ def instantiate_logger(name, quiet=None, logfile=None, logdir=None): if already instantiated returns a new child of the main logger """ - path_to_logdir = '.' - path_to_logfile = '{}-spotpy.log'.format(datetime.isoformat(datetime.now())) + path_to_logdir = PurePath() # current directory is assumed + path_to_logfile = PurePath('{}-spotpy.log'.format(datetime.isoformat(datetime.now()))) if not spotpy_logger.handlers: # create the handlers and call logger.addHandler(logging_handler) @@ -44,7 +44,7 @@ def instantiate_logger(name, quiet=None, logfile=None, logdir=None): path_to_logdir = logdir if logfile is not None: path_to_logfile = logfile - path_to_logfile = path_to_logdir + path.sep + path_to_logfile + path_to_logfile = PurePath(path_to_logdir, path_to_logfile) handler_file = logging.FileHandler(path_to_logfile) handler_file.setFormatter(formatter_file)