GH-1404: Handle monitor delay errors

If there are more "stimulus transitions" than "photodiode events",
truncate the "stimulus transitions" to the number of
"photodiode events". This is similar to what is done with
ophys timestamps data in this module. Update test coverage
to handle this case.

Update logging to show the min and max delay, to help
with debugging in the case of unusual/default values.

allensdk/internal/brain_observatory/time_sync.py

@@ -58,11 +58,23 @@ def monitor_delay(sync_dset, stim_times, photodiode_key,
     """Calculate monitor delay."""
     try:
         transitions = stim_times[::transition_frame_interval]
-        photodiode_events = get_real_photodiode_events(sync_dset, photodiode_key)
-        transition_events = photodiode_events[0:len(transitions)]
+        photodiode_events = get_real_photodiode_events(sync_dset,
+                                                       photodiode_key)
+        if len(transitions) > len(photodiode_events):
+            logging.warning(
+                "More stimulus transitions counted than "
+                f"photodiode events (transitions={len(transitions)}, "
+                f"events={len(photodiode_events)}). "
+                "Truncating stimulus transitions to length of "
+                "photodiode events.")
+            transitions = transitions[:len(photodiode_events)]
 
-        delay = np.mean(transition_events-transitions)
-        logging.info("Calculated monitor delay: %s", delay)
+        transition_events = photodiode_events[0:len(transitions)]
+        delays = transition_events - transitions
+        delay = np.mean(delays)
+        logging.info(f"Calculated monitor delay: {delay}. \n "
+                     f"Max monitor delay: {np.max(delays)}. \n "
+                     f"Min monitor delay: {np.min(delays)}.")
 
         if delay < 0 or delay > max_monitor_delay:
             delay = assumed_delay

allensdk/test/internal/brain_observatory/test_time_sync.py

@@ -413,6 +413,22 @@ def test_module(input_json):
                            equal_nan=True)
 
 
+@pytest.mark.parametrize(
+    "photodiode_events,stim_events,expected_delay",
+    [
+        (np.array([2, 3, 4, 5]), np.array([1, 2, 3, 4]), ts.ASSUMED_DELAY),
+        (np.array([2.02, 3.02, 4.02, 5.02]), np.array([2., 3., 4., 5.]), 0.02),
+        (np.array([2, 3, 4]), np.array([1, 2, 3, 4]), ts.ASSUMED_DELAY),
+    ]
+)
+def test_monitor_delay_mocked(photodiode_events, stim_events, expected_delay,
+                              monkeypatch):
+    monkeypatch.setattr(ts, "get_real_photodiode_events", lambda x, y: x)
+    assert (ts.monitor_delay(photodiode_events, stim_events, "dummy_key",
+                             transition_frame_interval=1)
+            == pytest.approx(expected_delay, 0.000001))
+
+
 @pytest.mark.skipif(data_skip, reason="No sync or data")
 def test_monitor_delay(scientifica_input):
     sync_file = scientifica_input.pop("sync_file")