Feature logging

setup.py

@@ -14,7 +14,9 @@
   url = 'https://spotpy.readthedocs.io/en/latest/',
   license = 'MIT',
   install_requires=[
-          'scipy', 'pandas'],
+    'click', 
+    'scipy', 
+    'pandas'],
   packages=find_packages(exclude=["tests*", "docs*"]),
   use_2to3 = True,
   keywords = 'Monte Carlo, MCMC, MLE, SCE-UA, Simulated Annealing, DE-MCz, DREAM, ROPE, Artifical Bee Colony, DDS, PA-DDS, NSGAii, Uncertainty, Calibration, Model, Signatures',

spotpy/__init__.py

@@ -5,18 +5,18 @@
 
 :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/) 
                - Scipy >1.5 (https://pypi.org/project/scipy/)
                - 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/)
@@ -32,13 +32,14 @@
 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
 from . import examples            # Contains tutorials how to use SPOTPY
 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.14'
+__version__ = '1.5.14'

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
@@ -30,7 +31,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:
@@ -40,13 +41,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 maximized')
+            self.logger.info('The objective function will be maximized')
         if optimization_direction == 'grid':
             self.compare = self.grid
 
@@ -59,7 +63,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
 
@@ -117,42 +121,44 @@ 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('')
+        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)
 
         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('******************************')
+        self.logger.info('')
 
 
     def __repr__(self):
@@ -167,24 +173,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
@@ -208,7 +214,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.float32,
-                 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.instantiate_logger(self.__class__.__name__, quiet, logfile, logdir)
 
         # Initialize the user defined setup class
         self.setup = spot_setup
@@ -220,7 +230,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']
@@ -241,13 +251,12 @@ 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) #Both numpy.random and random or used in spotpy
         random.seed(random_state)    #Both numpy.random and random or used in spotpy
-
 
         # 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
@@ -256,11 +265,11 @@ def __init__(self, spot_setup, dbname=None, dbformat=None, dbinit=True,
         self._return_all_likes = False #allows multi-objective calibration if set to True, is set by the algorithm
 
         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
@@ -295,7 +304,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__,
@@ -332,7 +341,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,
@@ -394,10 +403,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)
@@ -409,6 +418,7 @@ 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 self._return_all_likes:
@@ -420,19 +430,19 @@ def postprocessing(self, rep, params, simulation, chains=1, save_run=True, negat
             except TypeError: # Happens if iter(like) fails, i.e. if like is just one value      
                 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

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.debug('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.debug('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.debug('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.debug('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()