more test for the mongo observer

sacred/observers/base.py

@@ -14,7 +14,7 @@ class RunObserver(object):
     def started_event(self, ex_info, host_info, start_time, config):
         pass
 
-    def heartbeat_event(self, info, captured_out):
+    def heartbeat_event(self, info, captured_out, beat_time):
         pass
 
     def completed_event(self, stop_time, result):
@@ -37,7 +37,7 @@ class DebugObserver(RunObserver):
     def started_event(self, ex_info, host_info, start_time, config):
         print('experiment_started_event')
 
-    def heartbeat_event(self, info, captured_out):
+    def heartbeat_event(self, info, captured_out, beat_time):
         print('experiment_info_updated')
 
     def completed_event(self, stop_time, result):

sacred/observers/mongo.py

@@ -1,7 +1,6 @@
 #!/usr/bin/env python
 # coding=utf-8
 from __future__ import division, print_function, unicode_literals
-from datetime import datetime
 import os.path
 import pickle
 import sys
@@ -124,11 +123,14 @@ def started_event(self, ex_info, host_info, start_time, config):
         self.experiment_entry = dict(ex_info)
         self.host_entry = dict(host_info)
         self.run_entry = {
-            'start_time': datetime.fromtimestamp(start_time),
+            'start_time': start_time,
             'config': config,
             'status': 'RUNNING',
             'resources': [],
-            'artifacts': []
+            'artifacts': [],
+            'captured_out': '',
+            'info': {},
+            'heartbeat': None
         }
 
         self.save()
@@ -137,28 +139,25 @@ def started_event(self, ex_info, host_info, start_time, config):
                 with open(source_name, 'rb') as f:
                     self.fs.put(f, filename=source_name)
 
-    def heartbeat_event(self, info, captured_out):
+    def heartbeat_event(self, info, captured_out, beat_time):
         self.run_entry['info'] = info
         self.run_entry['captured_out'] = captured_out
-        self.run_entry['heartbeat'] = datetime.now()
+        self.run_entry['heartbeat'] = beat_time
         self.save()
 
     def completed_event(self, stop_time, result):
-        self.run_entry['stop_time'] = \
-            datetime.fromtimestamp(stop_time)
+        self.run_entry['stop_time'] = stop_time
         self.run_entry['result'] = result
         self.run_entry['status'] = 'COMPLETED'
         self.final_save(attempts=10)
 
     def interrupted_event(self, interrupt_time):
-        self.run_entry['stop_time'] = \
-            datetime.fromtimestamp(interrupt_time)
+        self.run_entry['stop_time'] = interrupt_time
         self.run_entry['status'] = 'INTERRUPTED'
         self.final_save(attempts=3)
 
     def failed_event(self, fail_time, fail_trace):
-        self.run_entry['stop_time'] = \
-            datetime.fromtimestamp(fail_time)
+        self.run_entry['stop_time'] = fail_time
         self.run_entry['status'] = 'FAILED'
         self.run_entry['fail_trace'] = fail_trace
         self.final_save(attempts=1)

sacred/run.py

@@ -2,11 +2,10 @@
 # coding=utf-8
 
 from __future__ import division, print_function, unicode_literals
-from datetime import timedelta
+import datetime
 import os.path
 import sys
 import threading
-import time
 import traceback
 from sacred.randomness import set_global_seed
 from sacred.utils import tee_output
@@ -81,7 +80,7 @@ def _stop_heartbeat(self):
         self._emit_heatbeat()  # one final beat to flush pending changes
 
     def _emit_started(self):
-        self.start_time = time.time()
+        self.start_time = datetime.datetime.now()
         for observer in self._observers:
             try:
                 observer.started_event(
@@ -95,19 +94,20 @@ def _emit_started(self):
     def _emit_heatbeat(self):
         if self.start_time is None or self.stop_time is not None:
             return
-
+        beat_time = datetime.datetime.now()
         for observer in self._observers:
             try:
                 observer.heartbeat_event(
                     info=self.info,
-                    captured_out=self.captured_out.getvalue())
+                    captured_out=self.captured_out.getvalue(),
+                    beat_time=beat_time)
             except AttributeError:
                 pass
 
     def _stop_time(self):
-        self.stop_time = time.time()
-        elapsed_seconds = round(self.stop_time - self.start_time)
-        self.elapsed_time = timedelta(seconds=elapsed_seconds)
+        self.stop_time = datetime.datetime.now()
+        self.elapsed_time = datetime.timedelta(
+            seconds=round((self.stop_time - self.start_time).total_seconds()))
         return self.stop_time
 
     def _emit_completed(self, result):

tests/test_examples.py

@@ -4,7 +4,7 @@
 
 
 # example_test will be parametrized by the test generation hook in conftest.py
-def tast_example(capsys, example_test):
+def test_example(capsys, example_test):
     ex, call, out = example_test
     ex.run_commandline(call)
     captured_out, captured_err = capsys.readouterr()

tests/test_mongo_observer.py

@@ -3,11 +3,14 @@
 from __future__ import division, print_function, unicode_literals
 import mock
 from sacred.observers.mongo import MongoObserver
+import datetime
 import time
 import mongomock
 import pytest
 from copy import copy
 
+T1 = datetime.datetime(1999, 5, 4, 3, 2, 1, 0)
+T2 = datetime.datetime(1999, 5, 5, 5, 5, 5, 5)
 
 @pytest.fixture
 def mongo_obs():
@@ -22,7 +25,7 @@ def mongo_obs():
 def test_mongo_observer_started_event_creates_host_if_new(mongo_obs):
     host = {'hostname': 'test_host', 'cpu_count': 1, 'python_version': '3.4'}
     other = {'hostname': 'test_host', 'cpu_count': 1, 'python_version': '2.7'}
-    h_id = mongo_obs.hosts.insert(copy(other))
+    mongo_obs.hosts.insert(copy(other))
 
     mongo_obs.started_event(
         {'name': 'test_exp', 'sources': [], 'doc': ''},
@@ -99,4 +102,91 @@ def test_mongo_observer_started_event_creates_experiment_if_new(mongo_obs):
     assert db_run['experiment'].collection == 'experiments'
 
     del db_exp['_id']
-    assert db_exp == exp
+    assert db_exp == exp
+
+
+def test_mongo_observer_started_event_creates_run(mongo_obs):
+    exp = {'name': 'test_exp', 'sources': [], 'doc': ''}
+    host = {'hostname': 'test_host', 'cpu_count': 1, 'python_version': '3.4'}
+    config = {'config': 'True', 'foo': 'bar', 'answer': 42}
+    mongo_obs.started_event(exp, host, T1, config)
+
+    assert mongo_obs.runs.count() == 1
+    db_run = mongo_obs.runs.find_one()
+    del db_run['_id']
+    del db_run['host']
+    del db_run['experiment']
+    assert db_run == {
+        'start_time': T1,
+        'heartbeat': None,
+        'info': {},
+        'captured_out': '',
+        'artifacts': [],
+        'config': config,
+        'status': 'RUNNING',
+        'resources': []
+    }
+
+
+def test_mongo_observer_heartbeat_event_updates_run(mongo_obs):
+    exp = {'name': 'test_exp', 'sources': [], 'doc': ''}
+    host = {'hostname': 'test_host', 'cpu_count': 1, 'python_version': '3.4'}
+
+    config = {'config': 'True', 'foo': 'bar', 'answer': 42}
+    mongo_obs.started_event(exp, host, T1, config)
+
+    info = {'my_info': [1, 2, 3], 'nr': 7}
+    outp = 'some output'
+    mongo_obs.heartbeat_event(info=info, captured_out=outp, beat_time=T2)
+
+    assert mongo_obs.runs.count() == 1
+    db_run = mongo_obs.runs.find_one()
+    assert db_run['heartbeat'] == T2
+    assert db_run['info'] == info
+    assert db_run['captured_out'] == outp
+
+
+def test_mongo_observer_completed_event_updates_run(mongo_obs):
+    exp = {'name': 'test_exp', 'sources': [], 'doc': ''}
+    host = {'hostname': 'test_host', 'cpu_count': 1, 'python_version': '3.4'}
+    config = {'config': 'True', 'foo': 'bar', 'answer': 42}
+    mongo_obs.started_event(exp, host, T1, config)
+
+    mongo_obs.completed_event(stop_time=T2, result=42)
+
+    assert mongo_obs.runs.count() == 1
+    db_run = mongo_obs.runs.find_one()
+    assert db_run['stop_time'] == T2
+    assert db_run['result'] == 42
+    assert db_run['status'] == 'COMPLETED'
+
+
+def test_mongo_observer_interrupted_event_updates_run(mongo_obs):
+    exp = {'name': 'test_exp', 'sources': [], 'doc': ''}
+    host = {'hostname': 'test_host', 'cpu_count': 1, 'python_version': '3.4'}
+    config = {'config': 'True', 'foo': 'bar', 'answer': 42}
+    mongo_obs.started_event(exp, host, T1, config)
+
+    mongo_obs.interrupted_event(interrupt_time=T2)
+
+    assert mongo_obs.runs.count() == 1
+    db_run = mongo_obs.runs.find_one()
+    assert db_run['stop_time'] == T2
+    assert db_run['status'] == 'INTERRUPTED'
+
+
+def test_mongo_observer_failed_event_updates_run(mongo_obs):
+    exp = {'name': 'test_exp', 'sources': [], 'doc': ''}
+    host = {'hostname': 'test_host', 'cpu_count': 1, 'python_version': '3.4'}
+    config = {'config': 'True', 'foo': 'bar', 'answer': 42}
+    mongo_obs.started_event(exp, host, T1, config)
+
+    fail_trace = "lots of errors and\nso\non..."
+    mongo_obs.failed_event(fail_time=T2,
+                           fail_trace=fail_trace)
+
+    assert mongo_obs.runs.count() == 1
+    db_run = mongo_obs.runs.find_one()
+    assert db_run['stop_time'] == T2
+    assert db_run['status'] == 'FAILED'
+    assert db_run['fail_trace'] == fail_trace