More informative log message when granule covers

.github/workflows/ci.yaml

@@ -21,7 +21,7 @@ jobs:
           python-version: ${{ matrix.python-version }}
       - name: Install dependencies
         run: |
-          pip install -U pytest pytest-cov trollsift six netifaces watchdog posttroll pyyaml pyinotify
+          pip install -U pytest pytest-cov trollsift six netifaces watchdog posttroll pyyaml pyinotify pyresample pytroll-schedule
       - name: Install pytroll-collectors
         run: |
           pip install --no-deps -e .
@@ -32,4 +32,4 @@ jobs:
         uses: codecov/codecov-action@v1
         with:
           file: ./coverage.xml
-          env_vars: PYTHON_VERSION
+          env_vars: PYTHON_VERSION

pytroll_collectors/region_collector.py

@@ -92,7 +92,7 @@ def collect(self, granule_metadata):
 
         granule_metadata['end_time'] = end_time
 
-        LOG.debug("Adding area ID to metadata: %s", str(self.region.area_id))
+        LOG.debug(f"Adding area ID for {platform!s} to metadata: {self.region.area_id!s}")
         granule_metadata['collection_area_id'] = self.region.area_id
 
         self.last_file_added = False
@@ -102,15 +102,14 @@ def collect(self, granule_metadata):
                 self.granule_times.add(ptime)
                 self.granules.append(granule_metadata)
                 self.last_file_added = True
-                LOG.info("Added %s (%s) granule to area %s",
+                LOG.info("Added %s (%s) granule to area %s because we expect it",
                          platform,
                          str(start_time),
                          self.region.area_id)
                 # If last granule return swath and cleanup
                 # if self.granule_times == self.planned_granule_times:
                 if self.is_swath_complete():
-                    LOG.info("Collection finished for area: %s",
-                             str(self.region.area_id))
+                    LOG.info(f"Collection finished for {platform!s} area: {self.region.area_id!s}")
                     return self.finish()
                 else:
                     try:
@@ -127,8 +126,7 @@ def collect(self, granule_metadata):
 
                     if new_timeout < self.timeout:
                         self.timeout = new_timeout
-                        LOG.info("Adjusted timeout: %s",
-                                 self.timeout.isoformat())
+                        LOG.info(f"Adjusted timeout for {platform!s}: {self.timeout:%Y-%m-%d %H:%M:%S}")
 
                     return
 
@@ -151,7 +149,10 @@ def collect(self, granule_metadata):
 
         # If file is within region, make pass prediction to know what to wait
         # for
-        if granule_pass.area_coverage(self.region) > 0:
+        cov = granule_pass.area_coverage(self.region)
+        if cov > 0:
+            LOG.debug(f"Granule {granule_metadata['uri']:s} is overlapping "
+                      f"region {self.region.name:s} by fraction {cov:.5f}")
             self.granule_times.add(start_time)
             self.granules.append(granule_metadata)
             self.last_file_added = True
@@ -160,7 +161,7 @@ def collect(self, granule_metadata):
 
             if not self.planned_granule_times:
                 self.planned_granule_times.add(start_time)
-                LOG.info("Added %s (%s) granule to area %s",
+                LOG.info("Added %s (%s) granule to area %s because it overlaps",
                          platform,
                          str(start_time),
                          self.region.area_id)
@@ -186,8 +187,8 @@ def collect(self, granule_metadata):
                         break
                     self.planned_granule_times.add(gr_time)
 
-                LOG.info("Planned granules for %s: %s", self.region.name,
-                         str(sorted(self.planned_granule_times)))
+                LOG.info(f"Planned granules for {platform!s} over "
+                         f"{self.region.name:s}: {sorted(self.planned_granule_times)!s}")
                 self.timeout = (max(self.planned_granule_times) +
                                 self.granule_duration +
                                 self.timeliness)

pytroll_collectors/tests/test_region_collector.py

@@ -0,0 +1,86 @@
+"""Test region collector functionality."""
+
+import logging
+import pytest
+import datetime
+import unittest.mock
+import io
+
+yaml_europe = """
+euro_ma:
+  description: euro_ma
+  projection:
+    proj: stere
+    lat_0: 45
+    lon_0: 15
+    k: 1
+    x_0: 0
+    y_0: 0
+    ellps: WGS84
+    no_defs: null
+  shape:
+    height: 1069
+    width: 1538
+  area_extent:
+    lower_left_xy:
+    - -3845890.2472199923
+    - -2150868.4484187816
+    upper_right_xy:
+    - 3845890.2472199923
+    - 3198354.325865823
+    units: m
+"""
+
+tles = b"""
+METOP-C
+1 43689U 18087A   21101.60865186  .00000002  00000-0  20894-4 0  9998
+2 43689  98.6928 163.0161 0002296 181.8672 178.2497 14.21491657125954
+"""
+
+
+@pytest.fixture
+def europe():
+    """Return european AreaDefinition."""
+    from pyresample.area_config import load_area_from_string
+    return load_area_from_string(yaml_europe)
+
+
+@pytest.fixture
+def europe_collector(europe):
+    """Construct RegionCollector for Central Europe."""
+    from pytroll_collectors.region_collector import RegionCollector
+    return RegionCollector(europe)
+
+
+def test_init(europe):
+    """Test that initialisation appears to work."""
+    from pytroll_collectors.region_collector import RegionCollector
+    RegionCollector(europe)
+
+
+def test_collect(europe_collector, caplog):
+    """Test that granules can be collected."""
+    granule_metadata = {
+            "platform_name": "Metop-C",
+            "sensor": "avhrr"}
+
+    def fakeopen(url):
+        return io.BytesIO(tles)
+    with unittest.mock.patch("pyorbital.tlefile.urlopen", new=fakeopen):
+        # tu.return_value = io.BytesIO(tles)
+        with caplog.at_level(logging.DEBUG):
+            for s_min in (0, 3, 6, 9, 12, 15, 18):
+                europe_collector.collect(
+                        {**granule_metadata,
+                         **{"start_time": datetime.datetime(2021, 4, 11, 10, s_min, 0),
+                            "end_time": datetime.datetime(2021, 4, 11, 10, s_min+3, 0),
+                            "uri": f"file://{s_min:d}"}})
+    assert "Granule file://0 is overlapping region euro_ma by fraction 0.03685" in caplog.text
+    assert "Added Metop-C (2021-04-11 10:00:00) granule to area euro_ma because it overlaps" in caplog.text
+    assert "Collection finished for Metop-C area: euro_ma" in caplog.text
+    for n in (3, 6, 9, 12, 15):
+        assert f"Added Metop-C (2021-04-11 10:{n:>02d}:00) granule to area euro_ma because we expect it" in caplog.text
+    assert "Granule file://18 is not overlapping euro_ma"
+
+
+# fixme: add (failing) test when area coverage too large