Refactor some pdep logging statements for improved performance

Instead of pre-formatting strings provided to the logging module,
use sprintf style formatting and provide arguments directly.

This way, the logging module can decide whether or not to
format the strings, which can take a significant amount of time.

Also, this converts a few statements from warning to debug
in order to clean up the log file for pdep jobs.

rmgpy/pdep/network.py

@@ -401,8 +401,8 @@ def set_conditions(self, T, P, ymB=None):
             # Update parameters that depend on temperature and pressure if necessary
             if temperature_changed or pressure_changed:
                 self.calculate_collision_model()
-        logging.debug('Finished setting conditions for network {0}.'.format(self.label))
-        logging.debug('The network now has values of {0}'.format(repr(self)))
+        logging.debug('Finished setting conditions for network %.', self.label)
+        logging.debug('The network now has values of %r', self)
 
     def _get_energy_grains(self, Emin, Emax, grain_size=0.0, grain_count=0):
         """
@@ -781,17 +781,18 @@ def calculate_microcanonical_rates(self):
             # If the k(E) values are invalid (in that they give the wrong 
             # kf(T) or kr(T) when integrated), then raise an exception
             if error or warning:
-                logging.warning('For path reaction {0!s}:'.format(rxn))
-                logging.warning('    Expected kf({0:g} K) = {1:g}'.format(temperature, kf_expected))
-                logging.warning('      Actual kf({0:g} K) = {1:g}'.format(temperature, kf_actual))
-                logging.warning('    Expected Keq({0:g} K) = {1:g}'.format(temperature, Keq_expected))
-                logging.warning('      Actual Keq({0:g} K) = {1:g}'.format(temperature, Keq_actual))
+                level = logging.WARNING if error else logging.DEBUG
+                logging.log(level, 'For path reaction %s:', rxn)
+                logging.log(level, '    Expected kf(%g K) = %g', temperature, kf_expected)
+                logging.log(level, '      Actual kf(%g K) = %g', temperature, kf_actual)
+                logging.log(level, '    Expected Keq(%g K) = %g', temperature, Keq_expected)
+                logging.log(level, '      Actual Keq(%g K) = %g', temperature, Keq_actual)
                 if error:
                     raise InvalidMicrocanonicalRateError(
                         'Invalid k(E) values computed for path reaction "{0}".'.format(rxn), k_ratio, Keq_ratio)
                 else:
                     logging.warning('Significant corrections to k(E) to be consistent with high-pressure limit for '
-                                    'path reaction "{0}".'.format(rxn))
+                                    'path reaction "%s".', rxn)
 
         # import pylab
         # for prod in range(n_isom):

rmgpy/pdep/reaction.pyx

@@ -105,7 +105,7 @@ def calculate_microcanonical_rate_coefficient(reaction,
 
         # We've been provided with molecular degree of freedom data for the
         # transition state, so let's use the more accurate RRKM theory
-        logging.debug('Calculating microcanonical rate coefficient using RRKM theory for {0}...'.format(reaction))
+        logging.debug('Calculating microcanonical rate coefficient using RRKM theory for %s...', reaction)
         if reactant_states_known and (reaction.is_isomerization() or reaction.is_dissociation()):
             kf = apply_rrkm_theory(reaction.transition_state, e_list, j_list, reac_dens_states)
             kf *= c0_inv ** (len(reaction.reactants) - 1)
@@ -121,7 +121,7 @@ def calculate_microcanonical_rate_coefficient(reaction,
     elif reaction.kinetics is not None:
         # We've been provided with high-pressure-limit rate coefficient data,
         # so let's use the less accurate inverse Laplace transform method
-        logging.debug('Calculating microcanonical rate coefficient using ILT method for {0}...'.format(reaction))
+        logging.debug('Calculating microcanonical rate coefficient using ILT method for %s...', reaction)
         if reactant_states_known:
             kinetics = reaction.kinetics if reaction.network_kinetics is None else reaction.network_kinetics
             kf = apply_inverse_laplace_transform_method(reaction.transition_state, kinetics, e_list, j_list, reac_dens_states, T)
@@ -169,8 +169,8 @@ def calculate_microcanonical_rate_coefficient(reaction,
                 if reac_dens_states[r, s] != 0:
                     kf[r, s] = kr[r, s] * prod_dens_states[r, s] / reac_dens_states[r, s]
         kf *= c0_inv ** (len(reaction.reactants) - len(reaction.products))
-    logging.debug('Finished finding microcanonical rate coefficients for path reaction {}'.format(reaction))
-    logging.debug('The forward and reverse rates are found to be  {0} and {1} respectively.'.format(kf, kr))
+    logging.debug('Finished finding microcanonical rate coefficients for path reaction %s', reaction)
+    logging.debug('The forward and reverse rates are found to be %g and %g respectively.', kf, kr)
 
     return kf, kr
 
@@ -231,8 +231,8 @@ def apply_rrkm_theory(transition_state,
         for r in range(n_grains):
             if sum_states[r, s] > 0 and dens_states[r, s] > 0:
                 k[r, s] = sum_states[r, s] / dens_states[r, s] * d_e
-    logging.debug('Finished applying RRKM for path transition state {}'.format(transition_state))
-    logging.debug('The rate constant is found to be {}'.format(k))
+    logging.debug('Finished applying RRKM for path transition state %s', transition_state)
+    logging.debug('The rate constant is found to be %s', k)
     return k
 
 @cython.boundscheck(False)
@@ -330,8 +330,8 @@ def apply_inverse_laplace_transform_method(transition_state,
 
     else:
         raise PressureDependenceError('Unable to use inverse Laplace transform method for non-Arrhenius kinetics or for n < 0.')
-    logging.debug('Finished applying inverse lapace transform for path transition state {}'.format(transition_state))
-    logging.debug('The rate constant is found to be {}'.format(k))
+    logging.debug('Finished applying inverse lapace transform for path transition state %s', transition_state)
+    logging.debug('The rate constant is found to be %s', k)
 
     return k
 
@@ -396,7 +396,7 @@ def fit_interpolation_model(reaction, Tlist, Plist, K, model, Tmin, Tmax, Pmin,
                 log_rms += (log_k_model - log_k_data) * (log_k_model - log_k_data)
         log_rms = sqrt(log_rms / len(Tlist) / len(Plist))
         if log_rms > 0.5:
-            logging.warning('RMS error for k(T,P) fit = {0:g} for reaction {1}.'.format(log_rms, reaction))
-    logging.debug('Finished fitting model for path reaction {}'.format(reaction))
-    logging.debug('The kinetics fit is {0!r}'.format(kinetics))
+            logging.warning('RMS error for k(T,P) fit = %g for reaction %s.', log_rms, reaction)
+    logging.debug('Finished fitting model for path reaction %s', reaction)
+    logging.debug('The kinetics fit is %r', kinetics)
     return kinetics