JP-3729: log version and crds context at end of step/pipeline runs

CHANGES.rst

@@ -191,6 +191,8 @@ stpipe
   added a `query_step_status()` function to use as an alternative to checking
   `self.skip`. [#8600]
 
+- Log jwst version and crds context at the end of step/pipeline runs. [#8760]
+
 tso_photometry
 --------------
 

jwst/stpipe/core.py

@@ -76,19 +76,23 @@ def load_as_level3_asn(self, obj):
         return asn
 
     def finalize_result(self, result, reference_files_used):
+        crds_context = crds_client.get_context_used('jwst')
+
+        if self.parent is None:
+            log.info(f"Results used CRDS context: {crds_context}")
+            log.info(f"Results used jwst version: {__version__}")
+
         if isinstance(result, JwstDataModel):
             result.meta.calibration_software_revision = __version_commit__ or 'RELEASE'
             result.meta.calibration_software_version = __version__
 
+
             if len(reference_files_used) > 0:
                 for ref_name, filename in reference_files_used:
                     if hasattr(result.meta.ref_file, ref_name):
                         getattr(result.meta.ref_file, ref_name).name = filename
                 result.meta.ref_file.crds.sw_version = crds_client.get_svn_version()
-                result.meta.ref_file.crds.context_used = crds_client.get_context_used(result.crds_observatory)
-                if self.parent is None:
-                    log.info(f"Results used CRDS context: {result.meta.ref_file.crds.context_used}")
-
+                result.meta.ref_file.crds.context_used = crds_context
 
     def remove_suffix(self, name):
         return remove_suffix(name)
@@ -98,6 +102,4 @@ def remove_suffix(self, name):
 # be a subclass of JwstStep so that it will pass checks
 # when constructing a pipeline using JwstStep class methods.
 class JwstPipeline(Pipeline, JwstStep):
-    def finalize_result(self, result, reference_files_used):
-        if isinstance(result, JwstDataModel):
-            log.info(f"Results used CRDS context: {crds_client.get_context_used(result.crds_observatory)}")
+    pass

jwst/stpipe/tests/test_step.py

@@ -1,3 +1,4 @@
+import logging
 import os
 from os.path import (
     abspath,
@@ -15,8 +16,10 @@
 
 from stdatamodels.jwst import datamodels
 
+from jwst import __version__ as jwst_version
 from jwst.white_light import WhiteLightStep
 from jwst.stpipe import Step
+from jwst.tests.helpers import LogWatcher
 
 from jwst.stpipe.tests.steps import (
     EmptyPipeline, MakeListPipeline, MakeListStep,
@@ -39,6 +42,10 @@
 
 CRDS_ERROR_STRING = 'PARS-WITHDEFAULTSSTEP: No parameters found'
 
+# used in logging tests below to provide a deterministic crds
+# context to look for in the log messages
+FAKE_CRDS_CONTEXT = "0000.pmap"
+
 
 @pytest.fixture(scope='module')
 def data_path():
@@ -607,3 +614,22 @@ def test_call_with_config(caplog, tmp_cwd):
     ProperPipeline.call(model, config_file=cfg)
 
     assert "newpar1" in caplog.text
+
+
+@pytest.mark.parametrize(
+    "message", [
+        f"Results used CRDS context: {FAKE_CRDS_CONTEXT}",
+        f"Results used jwst version: {jwst_version}",
+    ])
+def test_finalize_logging(monkeypatch, message):
+    """
+    Check that the jwst version and crds context are logged
+    when a step/pipeline is run.
+    """
+    pipeline = EmptyPipeline()
+    model = datamodels.ImageModel()
+    monkeypatch.setattr(crds_client, 'get_context_used', lambda observatory: FAKE_CRDS_CONTEXT)
+    watcher = LogWatcher(message)
+    monkeypatch.setattr(logging.getLogger("jwst.stpipe.core"), "info", watcher)
+    pipeline.run(model)
+    assert watcher.seen