Merge pull request #1503 from pints-team/1467-csv-time-field

Removed units from time headers in controllers.

CHANGELOG.md

@@ -8,6 +8,7 @@ All notable changes to this project will be documented in this file.
 - [#1499](https://github.com/pints-team/pints/pull/1499) Added a log-uniform prior class.
 - [#1505](https://github.com/pints-team/pints/pull/1505) Added notes to `ErrorMeasure` and `LogPDF` to say parameters must be real and continuous.
 ### Changed
+- [#1503](https://github.com/pints-team/pints/pull/1503) Stopped showing time units in controller logs, because the units change depending on the output type (see #1467).
 ### Deprecated
 ### Removed
 ### Fixed

pints/_abc/__init__.py

@@ -235,7 +235,9 @@ def run(self):
             logger.add_counter('Eval.', max_value=max_eval_guess)
             logger.add_float('Acceptance rate')
             self._sampler._log_init(logger)
-            logger.add_time('Time m:s')
+            # Note: removed units from time field, see
+            # https://github.com/pints-team/pints/issues/1467
+            logger.add_time('Time')
 
         # Start sampling
         timer = pints.Timer()

pints/_mcmc/__init__.py

@@ -665,7 +665,9 @@ def run(self):
             logger.add_counter('Eval.', max_value=max_eval_guess)
             for sampler in self._samplers:
                 sampler._log_init(logger)
-            logger.add_time('Time m:s')
+            # Note: deleted time units from header, see
+            # https://github.com/pints-team/pints/issues/1467
+            logger.add_time('Time')
 
         # Pre-allocate arrays for chain storage
         # Note: we store the inverse transformed (to model space) parameters

pints/_nested/__init__.py

@@ -409,7 +409,9 @@ def _initialise_logger(self):
             # Add fields to log
             self._logger.add_counter('Iter.', max_value=self._iterations)
             self._logger.add_counter('Eval.', max_value=self._iterations * 10)
-            self._logger.add_time('Time m:s')
+            # Note: removed units from time field, see
+            # https://github.com/pints-team/pints/issues/1467
+            self._logger.add_time('Time')
             self._logger.add_float('Delta_log(z)')
             self._logger.add_float('Acceptance rate')
 

pints/_optimisers/__init__.py

@@ -635,7 +635,9 @@ def run(self):
             logger.add_float('Best')
             logger.add_float('Current')
             self._optimiser._log_init(logger)
-            logger.add_time('Time m:s')
+            # Note: No units shown in time field, for the reason why see
+            # https://github.com/pints-team/pints/issues/1467
+            logger.add_time('Time')
 
         # Start searching
         timer = pints.Timer()

pints/tests/test_abc_controller.py

@@ -18,7 +18,7 @@
 LOG_SCREEN_1 = [
     'Using Rejection ABC',
     'Running in sequential mode.',
-    'Iter. Eval. Acceptance rate Time m:s',
+    'Iter. Eval. Acceptance rate Time    ',
     '1     127    0.00787401575    0:00.0',
     '2     167    0.0119760479     0:00.0',
     '3     209    0.014354067      0:00.0',
@@ -28,7 +28,7 @@
 LOG_SCREEN_2 = [
     'Using Rejection ABC',
     'Running in parallel with 2 worker processess.',
-    'Iter. Eval. Acceptance rate Time m:s',
+    'Iter. Eval. Acceptance rate Time    ',
     '1     20     0.05             0:00.0',
     '2     22     0.0909090909     0:00.0',
     '3     144    0.0208333333     0:00.0',
@@ -38,15 +38,15 @@
 ]
 
 LOG_FILE = [
-    'Iter. Eval. Acceptance rate Time m:s',
+    'Iter. Eval. Acceptance rate Time    ',
     '1     127    0.00787401575    0:00.0',
     '2     167    0.0119760479     0:00.0',
     '3     209    0.014354067      0:00.0',
     '6     369    0.0162601626     0:00.0',
 ]
 
 LOG_FILE_CSV = [
-    '"Iter.","Eval.","Acceptance rate","Time m:s"',
+    '"Iter.","Eval.","Acceptance rate","Time"',
     '1,127,7.87401574803149595e-03,0:00.0',
     '2,167,0.0119760479,0:00.0',
     '3,209,0.014354067,0:00.0',

pints/tests/test_mcmc_adaptive.py

@@ -145,7 +145,7 @@ def test_logging(self):
         self.assertIn('Accept.', text)
         self.assertIn('Eval.', text)
         self.assertIn('Iter.', text)
-        self.assertIn('Time m:s', text)
+        self.assertIn('Time', text)
 
     def test_replace(self):
         # Tests the replace() method

pints/tests/test_mcmc_controller.py

@@ -14,6 +14,7 @@
 import unittest.mock
 import numpy as np
 import numpy.testing as npt
+import warnings
 
 from shared import StreamCapture, TemporaryDirectory
 
@@ -24,7 +25,7 @@
     'Using Haario-Bardenet adaptive covariance MCMC',
     'Generating 3 chains.',
     'Running in sequential mode.',
-    'Iter. Eval. Accept.   Accept.   Accept.   Time m:s',
+    'Iter. Eval. Accept.   Accept.   Accept.   Time    ',
     '0     3      0         0         0          0:00.0',
     '1     6      0         0         0.5        0:00.0',
     '2     9      0         0         0.333      0:00.0',
@@ -35,7 +36,7 @@
 ]
 
 LOG_FILE = [
-    'Iter. Eval. Accept.   Accept.   Accept.   Time m:s',
+    'Iter. Eval. Accept.   Accept.   Accept.   Time    ',
     '0     3      0         0         0          0:00.0',
     '1     6      0         0         0.5        0:00.0',
     '2     9      0         0         0.333      0:00.0',
@@ -791,8 +792,11 @@ def test_log_pdf_storage_in_memory_single_complex(self):
 
     def test_deprecated_alias(self):
 
-        mcmc = pints.MCMCSampling(
-            self.log_posterior, 1, [self.real_parameters])
+        with warnings.catch_warnings(record=True) as w:
+            mcmc = pints.MCMCSampling(
+                self.log_posterior, 1, [self.real_parameters])
+        self.assertEqual(len(w), 1)
+        self.assertIn('deprecated', str(w[-1].message))
         self.assertIsInstance(mcmc, pints.MCMCController)
 
     def test_exception_on_multi_use(self):

pints/tests/test_nested_controller.py

@@ -160,7 +160,7 @@ def test_logging(self):
         self.assertEqual(lines[1], 'Number of active points: 400')
         self.assertEqual(lines[2], 'Total number of iterations: 20')
         self.assertEqual(lines[3], 'Total number of posterior samples: 2')
-        self.assertEqual(lines[4], ('Iter. Eval. Time m:s Delta_log(z) ' +
+        self.assertEqual(lines[4], ('Iter. Eval. Time     Delta_log(z) ' +
                                     'Acceptance rate'))
         pattern = re.compile('[0-9]+[ ]+[0-9]+[ ]+[0-9]{1}:[0-9]{2}.[0-9]{1}')
         for line in lines[5:]:
@@ -182,7 +182,7 @@ def test_logging(self):
                     lines = f.read().splitlines()
             self.assertEqual(c.text(), '')
         self.assertEqual(len(lines), 23)
-        self.assertEqual(lines[0], ('Iter. Eval. Time m:s Delta_log(z) ' +
+        self.assertEqual(lines[0], ('Iter. Eval. Time     Delta_log(z) ' +
                                     'Acceptance rate'))
         pattern = re.compile('[0-9]+[ ]+[0-9]+[ ]+[0-9]{1}:[0-9]{2}.[0-9]{1}')
         for line in lines[5:]:

pints/tests/test_opt_adam.py

@@ -19,15 +19,15 @@
 method = pints.Adam
 
 
-log_1 = '''
-Minimising error measure
-Using Adam
-Running in sequential mode.
-Iter. Eval. Best      Current   b1        b2        Time m:s
-0     1      0.02      0.02      0.9       0.999      0:00.0
-1     2      5e-17     5e-17     0.81      0.998001   0:00.0
-2     3      5e-17     0.00898   0.729     0.997003   0:00.0
-'''.strip()
+log_1 = '\n'.join((
+    'Minimising error measure',
+    'Using Adam',
+    'Running in sequential mode.',
+    'Iter. Eval. Best      Current   b1        b2        Time    ',
+    '0     1      0.02      0.02      0.9       0.999      0:00.0',
+    '1     2      5e-17     5e-17     0.81      0.998001   0:00.0',
+    '2     3      5e-17     0.00898   0.729     0.997003   0:00.0',
+))
 
 
 class TestAdam(unittest.TestCase):

pints/tests/test_opt_controller.py

@@ -251,7 +251,7 @@ def test_logging(self):
         self.assertEqual(lines[2], 'Running in sequential mode.')
         self.assertEqual(lines[3], 'Population size: 6')
         self.assertEqual(lines[4],
-                         'Iter. Eval. Best      Current   Time m:s')
+                         'Iter. Eval. Best      Current   Time    ')
         self.assertEqual(lines[5][:-3],
                          '0     3     -4.140462 -4.140462   0:0')
         self.assertEqual(lines[6][:-3],
@@ -290,7 +290,7 @@ def test_logging(self):
         self.assertEqual(lines[2], 'Running in sequential mode.')
         self.assertEqual(lines[3], 'Population size: 4')
         self.assertEqual(lines[4],
-                         'Iter. Eval. Best      Current   Time m:s')
+                         'Iter. Eval. Best      Current   Time    ')
         self.assertEqual(lines[5][:-3],
                          '0     4      6.471867  6.471867   0:0')
         self.assertEqual(lines[6][:-3],

pints/tests/test_opt_irpropmin.py

@@ -19,25 +19,25 @@
 method = pints.IRPropMin
 
 
-log_1 = '''
-Minimising error measure
-Using iRprop-
-Running in sequential mode.
-Iter. Eval. Best      Current   Min. step Max. step Bound corr. Time m:s
-0     1      0.02      0.02      0.12      0.12                   0:00.0
-1     2      0.0008    0.0008    0.06      0.06                   0:00.0
-'''.strip()
-
-log_2 = '''
-Minimising error measure
-Using iRprop-
-Running in sequential mode.
-Iter. Eval. Best      Current   Min. step Max. step Bound corr. Time m:s
-0     1      0.02      0.02      0.11      0.11                   0:00.0
-1     2      0.0002    0.0002    0.055     0.055                  0:00.0
-2     3      0.0002    0.0002    0.055     0.055                  0:00.0
-3     4      0.0002    0.00405   0.03      0.03                   0:00.0
-'''.strip()
+log_1 = '\n'.join((
+    'Minimising error measure',
+    'Using iRprop-',
+    'Running in sequential mode.',
+    'Iter. Eval. Best      Current   Min. step Max. step Bound corr. Time    ',
+    '0     1      0.02      0.02      0.12      0.12                   0:00.0',
+    '1     2      0.0008    0.0008    0.06      0.06                   0:00.0',
+))
+
+log_2 = '\n'.join((
+    'Minimising error measure',
+    'Using iRprop-',
+    'Running in sequential mode.',
+    'Iter. Eval. Best      Current   Min. step Max. step Bound corr. Time    ',
+    '0     1      0.02      0.02      0.11      0.11                   0:00.0',
+    '1     2      0.0002    0.0002    0.055     0.055                  0:00.0',
+    '2     3      0.0002    0.0002    0.055     0.055                  0:00.0',
+    '3     4      0.0002    0.00405   0.03      0.03                   0:00.0',
+))
 
 
 class TestIRPropMin(unittest.TestCase):

pints/tests/test_opt_nelder_mead.py

@@ -170,7 +170,7 @@ def test_rosenbrock(self):
             'Minimising error measure',
             'Using Nelder-Mead',
             'Running in sequential mode.',
-            'Iter. Eval. Best      Current   Time m:s',
+            'Iter. Eval. Best      Current   Time',
             '0     3      865.9531  865.9531   0:00.0',
             '1     4      832.5452  832.5452   0:00.0',
             '2     5      832.5452  832.5452   0:00.0',

pints/tests/test_opt_pso.py

@@ -130,7 +130,7 @@ def test_logging(self):
         self.assertEqual(
             lines[2], 'Running in parallel with 4 worker processes.')
         self.assertEqual(lines[3], 'Population size: 6')
-        self.assertEqual(lines[4], 'Iter. Eval. Best      Current   Time m:s')
+        self.assertEqual(lines[4], 'Iter. Eval. Best      Current   Time    ')
 
         pint = '[0-9]+[ ]+'
         pflt = '[0-9.-]+[ ]+'
@@ -158,7 +158,7 @@ def test_logging(self):
         self.assertEqual(
             lines[0],
             'Iter. Eval. Best      Current   f0        f1        f2        '
-            'f3        f4        f5        Time m:s'
+            'f3        f4        f5        Time    '
         )
 
         pattern = re.compile(pint * 2 + pflt * 8 + ptim)