Merge pull request #299 from ummavi/master

Added metric logging for FileStorage Observer

sacred/observers/file_storage.py

@@ -6,7 +6,6 @@
 import os.path
 import tempfile
 
-from datetime import datetime
 from shutil import copyfile
 
 from sacred.commandline_options import CommandLineOption
@@ -20,14 +19,6 @@
 DEFAULT_FILE_STORAGE_PRIORITY = 20
 
 
-def json_serial(obj):
-    """JSON serializer for objects not serializable by default json code."""
-    if isinstance(obj, datetime):
-        serial = obj.isoformat()
-        return serial
-    raise TypeError("Type not serializable")
-
-
 class FileStorageObserver(RunObserver):
     VERSION = 'FileStorageObserver-0.7.0'
 
@@ -218,6 +209,34 @@ def artifact_event(self, name, filename):
         self.run_entry['artifacts'].append(name)
         self.save_json(self.run_entry, 'run.json')
 
+    def log_metrics(self, metrics_by_name, info):
+        """Store new measurements into metrics.json.
+        """
+        try:
+            metrics_path = os.path.join(self.dir, "metrics.json")
+            saved_metrics = json.load(open(metrics_path, 'r'))
+        except IOError as e:
+            # We haven't recorded anything yet. Start Collecting.
+            saved_metrics = {}
+
+        for metric_name, metric_ptr in metrics_by_name.items():
+
+            if metric_name not in saved_metrics:
+                saved_metrics[metric_name] = {"values": [],
+                                              "steps": [],
+                                              "timestamps": []}
+
+            saved_metrics[metric_name]["values"] += metric_ptr["values"]
+            saved_metrics[metric_name]["steps"] += metric_ptr["steps"]
+
+            # Manually convert them to avoid passing a datetime dtype handler
+            # when we're trying to convert into json.
+            timestamps_norm = [ts.isoformat()
+                               for ts in metric_ptr["timestamps"]]
+            saved_metrics[metric_name]["timestamps"] += timestamps_norm
+
+        self.save_json(saved_metrics, 'metrics.json')
+
     def __eq__(self, other):
         if isinstance(other, FileStorageObserver):
             return self.basedir == other.basedir

tests/test_observers/test_file_storage_observer.py

@@ -11,6 +11,8 @@
 
 from sacred.observers.file_storage import FileStorageObserver
 from sacred.serializer import restore
+from sacred.metrics_logger import ScalarMetricLogEntry, linearize_metrics
+
 
 T1 = datetime.datetime(1999, 5, 4, 3, 2, 1, 0)
 T2 = datetime.datetime(1999, 5, 5, 5, 5, 5, 5)
@@ -231,3 +233,101 @@ def test_fs_observer_equality(dir_obs):
 
     assert not obs == 'foo'
     assert obs != 'foo'
+
+@pytest.fixture
+def logged_metrics():
+    return [
+        ScalarMetricLogEntry("training.loss", 10, datetime.datetime.utcnow(), 1),
+        ScalarMetricLogEntry("training.loss", 20, datetime.datetime.utcnow(), 2),
+        ScalarMetricLogEntry("training.loss", 30, datetime.datetime.utcnow(), 3),
+
+        ScalarMetricLogEntry("training.accuracy", 10, datetime.datetime.utcnow(), 100),
+        ScalarMetricLogEntry("training.accuracy", 20, datetime.datetime.utcnow(), 200),
+        ScalarMetricLogEntry("training.accuracy", 30, datetime.datetime.utcnow(), 300),
+
+        ScalarMetricLogEntry("training.loss", 40, datetime.datetime.utcnow(), 10),
+        ScalarMetricLogEntry("training.loss", 50, datetime.datetime.utcnow(), 20),
+        ScalarMetricLogEntry("training.loss", 60, datetime.datetime.utcnow(), 30)
+    ]
+
+
+def test_log_metrics(dir_obs, sample_run, logged_metrics):
+    """Test storing of scalar measurements.
+
+    Test whether measurements logged using _run.metrics.log_scalar_metric
+    are being stored in the metrics.json file.
+
+    Metrics are stored as a json with each metric indexed by a name 
+    (e.g.: 'training.loss'). Each metric for the given name is then
+    stored as three lists: iteration step(steps), the values logged(values)
+    and the timestamp at which the measurement was taken(timestamps)
+    """
+
+    # Start the experiment 
+    basedir, obs = dir_obs
+    sample_run['_id'] = None
+    _id = obs.started_event(**sample_run)    
+    run_dir = basedir.join(str(_id))
+
+    # Initialize the info dictionary and standard output with arbitrary values
+    info = {'my_info': [1, 2, 3], 'nr': 7}
+    outp = 'some output'
+
+    obs.log_metrics(linearize_metrics(logged_metrics[:6]), info)
+    obs.heartbeat_event(info=info, captured_out=outp, beat_time=T1,
+                              result=0)
+
+
+    assert run_dir.join('metrics.json').exists()
+    metrics = json.loads(run_dir.join('metrics.json').read())
+
+
+    # Confirm that we have only two metric names registered.
+    # and they have all the information we need.
+    assert len(metrics) == 2
+    assert "training.loss" in metrics
+    assert "training.accuracy" in metrics
+    for v in ["steps","values","timestamps"]:
+        assert v in metrics["training.loss"] 
+        assert v in metrics["training.accuracy"]
+
+
+    # Verify they have all the information 
+    # we logged in the right order.
+    loss = metrics["training.loss"]
+    assert loss["steps"] == [10, 20, 30]
+    assert loss["values"] == [1, 2, 3]
+    for i in range(len(loss["timestamps"]) - 1):
+        assert loss["timestamps"][i] <= loss["timestamps"][i + 1]
+
+    accuracy = metrics["training.accuracy"]
+    assert accuracy["steps"] == [10, 20, 30]
+    assert accuracy["values"] == [100, 200, 300]
+
+
+    # Now, process the remaining events
+    # The metrics shouldn't be overwritten, but appended instead.
+    obs.log_metrics(linearize_metrics(logged_metrics[6:]), info)
+    obs.heartbeat_event(info=info, captured_out=outp, beat_time=T2,
+                              result=0)
+
+    # Reload the new metrics
+    metrics = json.loads(run_dir.join('metrics.json').read())
+
+    # The newly added metrics belong to the same run and have the same names,
+    # so the total number of metrics should not change.
+    assert len(metrics) == 2
+
+    assert "training.loss" in metrics
+    loss = metrics["training.loss"]
+    assert loss["steps"] == [10, 20, 30, 40, 50, 60]
+    assert loss["values"] == [1, 2, 3, 10, 20, 30]
+    for i in range(len(loss["timestamps"]) - 1):
+        assert loss["timestamps"][i] <= loss["timestamps"][i + 1]
+
+
+    # Read the training.accuracy metric and verify it's unchanged
+    assert "training.accuracy" in metrics
+    accuracy = metrics["training.accuracy"]
+    assert accuracy["steps"] == [10, 20, 30]
+    assert accuracy["values"] == [100, 200, 300]