Reduce std output messages (#259)

* output -> debug,info,error

* QA

cads_adaptors/adaptors/cds.py

@@ -243,7 +243,7 @@ def normalise_request(self, request: Request) -> Request:
         #  it is the only one. Adaptors should be updated to use self.mapped_requests instead.
         self.mapped_request = self.mapped_requests[0]
 
-        self.context.add_stdout(
+        self.context.info(
             f"Request mapped to (collection_id={self.collection_id}):\n{self.mapped_requests}"
         )
 
@@ -298,7 +298,7 @@ def pp_mapping(self, in_pp_config: list[dict[str, Any]]) -> list[dict[str, Any]]
     def post_process(self, result: Any) -> dict[str, Any]:
         """Perform post-process steps on the retrieved data."""
         for i, pp_step in enumerate(self.pp_mapping(self.post_process_steps)):
-            self.context.add_stdout(
+            self.context.info(
                 f"Performing post-process step {i+1} of {len(self.post_process_steps)}: {pp_step}"
             )
             # TODO: pp_mapping should have ensured "method" is always present
@@ -333,7 +333,7 @@ def post_process(self, result: Any) -> dict[str, Any]:
                 post_open_datasets_kwargs = post_processing_kwargs.get(
                     "post_open_datasets_kwargs", {}
                 )
-                self.context.add_stdout(
+                self.context.debug(
                     f"Opening result: {result} as xarray dictionary with kwargs:\n"
                     f"open_dataset_kwargs: {open_datasets_kwargs}\n"
                     f"post_open_datasets_kwargs: {post_open_datasets_kwargs}"
@@ -380,7 +380,7 @@ def make_download_object(
             kwargs.setdefault(
                 "receipt", self.make_receipt(filenames=filenames, **receipt_kwargs)
             )
-        self.context.add_stdout(
+        self.context.debug(
             f"Creating download object as {download_format} with paths:\n{paths}\n and kwargs:\n{kwargs}"
         )
         # self.context.add_user_visible_log(
@@ -398,7 +398,7 @@ def make_download_object(
                     "\n -".join(filenames)
                 )
             )
-            self.context.add_stderr(
+            self.context.error(
                 f"Error whilst preparing download object: {err}\n"
                 f"Paths: {paths}\n"
                 f"Download format: {download_format}\n"

cads_adaptors/adaptors/mars.py

@@ -86,10 +86,10 @@ def execute_mars(
     }
     env["username"] = str(env["namespace"]) + ":" + str(env["user_id"]).split("-")[-1]
 
-    context.add_stdout(f"Request sent to proxy MARS client: {requests}")
+    context.info(f"Request sent to proxy MARS client: {requests}")
     reply = cluster.execute(requests, env, target)
     reply_message = str(reply.message)
-    context.add_stdout(message=reply_message)
+    context.debug(message=reply_message)
 
     if reply.error:
         error_lines = "\n".join(

cads_adaptors/adaptors/multi.py

@@ -65,16 +65,17 @@ def split_adaptors(
             this_request = self.split_request(
                 request, this_values, **this_adaptor.config
             )
-            self.context.add_stdout(
+            self.context.debug(
                 f"MultiAdaptor, {adaptor_tag}, this_request: {this_request}"
             )
 
             if len(this_request) > 0:
                 try:
                     this_request = this_adaptor.normalise_request(this_request)
                 except Exception:
-                    self.context.add_stdout(
-                        f"MultiAdaptor, {adaptor_tag}, this_request: {this_request}"
+                    self.context.warning(
+                        f"MultiAdaptor failed to normalise request.\n"
+                        f"adaptor_tag: {adaptor_tag}\nthis_request: {this_request}"
                     )
                 sub_adaptors[adaptor_tag] = (this_adaptor, this_request)
 
@@ -101,7 +102,7 @@ def retrieve_list_of_results(self, request: Request) -> list[str]:
             )
         self.mapped_request = self.mapped_requests[0]
 
-        self.context.add_stdout(f"MultiAdaptor, full_request: {self.mapped_request}")
+        self.context.debug(f"MultiAdaptor, full_request: {self.mapped_request}")
 
         sub_adaptors = self.split_adaptors(self.mapped_request)
 
@@ -121,7 +122,7 @@ def retrieve_list_of_results(self, request: Request) -> list[str]:
                 f"{exception_logs}"
             )
 
-        self.context.add_stdout(f"MultiAdaptor, result paths:\n{paths}")
+        self.context.debug(f"MultiAdaptor, result paths:\n{paths}")
 
         return paths
 
@@ -170,9 +171,7 @@ def retrieve_list_of_results(self, request: Request) -> list[str]:
         #   be useful to reduce the repetitive config in each sub-adaptor of adaptor.json
 
         # self.mapped_requests contains the schema-checked, intersected and (top-level mapping) mapped request
-        self.context.add_stdout(
-            f"MultiMarsCdsAdaptor, full_request: {self.mapped_requests}"
-        )
+        self.context.info(f"MultiMarsCdsAdaptor, full_request: {self.mapped_requests}")
 
         # We now split the mapped_request into sub-adaptors
         mapped_requests = []
@@ -183,7 +182,7 @@ def retrieve_list_of_results(self, request: Request) -> list[str]:
                 this_request = self.split_request(
                     mapped_request_piece, this_values, **this_adaptor.config
                 )
-                self.context.add_stdout(
+                self.context.info(
                     f"MultiMarsCdsAdaptor, {adaptor_tag}, this_request: {this_request}"
                 )
 
@@ -192,9 +191,7 @@ def retrieve_list_of_results(self, request: Request) -> list[str]:
                         mapping.apply_mapping(this_request, this_adaptor.mapping)
                     )
 
-        self.context.add_stdout(
-            f"MultiMarsCdsAdaptor, mapped_requests: {mapped_requests}"
-        )
+        self.context.info(f"MultiMarsCdsAdaptor, mapped_requests: {mapped_requests}")
         result = execute_mars(
             mapped_requests,
             context=self.context,

cads_adaptors/adaptors/roocs/__init__.py

@@ -47,7 +47,7 @@ def retrieve(self, request: Request) -> BinaryIO:
             raise RoocsRuntimeError(response.status)
         urls += [response.provenance(), response.provenance_image()]
 
-        self.context.add_stdout(f"DOWNLOAD KWARGS: {download_kwargs}")
+        self.context.debug(f"DOWNLOAD KWARGS: {download_kwargs}")
         paths = url_tools.try_download(urls, context=self.context, **download_kwargs)
 
         return download_tools.DOWNLOAD_FORMATS["zip"](paths)

cads_adaptors/tools/convertors.py

@@ -55,7 +55,7 @@ def convert_format(
     for k, v in runtime_kwargs.items():
         post_processing_kwargs.setdefault(k, {}).update(v)
     post_processing_kwargs.setdefault("target_dir", target_dir)
-    context.add_stdout(
+    context.debug(
         f"Converting result ({result}) to {target_format} with kwargs: {post_processing_kwargs}"
     )
     convertor: None | Callable = CONVERTORS.get(target_format, None)
@@ -69,7 +69,7 @@ def convert_format(
             f"returning in original format: {result}"
         )
         context.add_user_visible_error(message=message)
-        context.add_stderr(message=message)
+        context.error(message=message)
         return ensure_list(result)
 
 
@@ -79,9 +79,6 @@ def result_to_grib_files(
     **kwargs,
 ) -> list[str]:
     """Convert a result of unknown type to grib files."""
-    context.add_stdout(
-        f"Converting result ({result}) to grib files with kwargs: {kwargs}"
-    )
     result_type = type(result)
     if isinstance(result, str):
         return unknown_filetype_to_grib_files(result, context=context, **kwargs)
@@ -138,9 +135,6 @@ def result_to_netcdf_files(
     **kwargs,
 ) -> list[str]:
     """Convert a result of unknown type to netCDF files."""
-    context.add_stdout(
-        f"Converting result ({result}) to netCDF files with kwargs: {kwargs}"
-    )
     result_type = type(result)
     if isinstance(result, str):
         return unknown_filetype_to_netcdf_files(result, context=context, **kwargs)
@@ -199,12 +193,6 @@ def result_to_netcdf_legacy_files(
         "The 'netcdf_legacy' format is deprecated and no longer supported. "
         "Users are encouraged to update workflows to use the updated, and CF compliant, 'netcdf' option."
     )
-    context.add_stdout(
-        f"Converting result ({result}) to legacy netCDF files with grib_to_netcdf.\n"
-        f"filter_rules: {filter_rules}\n"
-        f"command: {command}"
-        f"kwargs: {kwargs}"
-    )
 
     # Check result is a single grib_file or a list/dict of grib_files
     if isinstance(result, str):
@@ -318,7 +306,7 @@ def unknown_filetype_to_netcdf_files(
     if ext.lower() in [".netcdf", ".nc"]:
         return [infile]
     elif ext.lower() in [".grib", ".grib2"]:
-        context.add_stdout(f"Converting {infile} to netCDF files with kwargs: {kwargs}")
+        context.debug(f"Converting {infile} to netCDF files with kwargs: {kwargs}")
         return grib_to_netcdf_files(infile, context=context, **kwargs)
     else:
         add_user_log_and_raise_error(f"Unknown file type: {infile}", context=context)
@@ -333,7 +321,7 @@ def grib_to_netcdf_files(
 ):
     grib_file = os.path.realpath(grib_file)
 
-    context.add_stdout(
+    context.debug(
         f"Converting {grib_file} to netCDF files with:\n"
         f"to_netcdf_kwargs: {kwargs}\n"
         f"open_datasets_kwargs: {open_datasets_kwargs}\n"
@@ -352,9 +340,7 @@ def grib_to_netcdf_files(
             "We are unable to convert this GRIB data to netCDF, "
             "please download as GRIB and convert to netCDF locally.\n"
         )
-        context.add_user_visible_error(message=message)
-        context.add_stderr(message=message)
-        raise CdsFormatConversionError(message)
+        add_user_log_and_raise_error(message, context=context)
 
     out_nc_files = xarray_dict_to_netcdf(datasets, context=context, **kwargs)
 
@@ -396,7 +382,7 @@ def xarray_dict_to_netcdf(
             }
         )
         out_fname = os.path.join(target_dir, f"{out_fname_prefix}{out_fname_base}.nc")
-        context.add_stdout(f"Writing {out_fname} with kwargs:\n{to_netcdf_kwargs}")
+        context.debug(f"Writing {out_fname} with kwargs:\n{to_netcdf_kwargs}")
         dataset.to_netcdf(out_fname, **to_netcdf_kwargs)
         out_nc_files.append(out_fname)
 
@@ -553,7 +539,7 @@ def open_netcdf_as_xarray_dictionary(
         **kwargs,
     }
 
-    context.add_stdout(f"Opening {netcdf_file} with kwargs: {open_datasets_kwargs}")
+    context.debug(f"Opening {netcdf_file} with kwargs: {open_datasets_kwargs}")
     datasets = {fname: xr.open_dataset(netcdf_file, **open_datasets_kwargs)}
 
     datasets = post_open_datasets_modifications(datasets, **post_open_datasets_kwargs)
@@ -599,7 +585,7 @@ def prepare_open_datasets_kwargs_grib(
                 try:
                     _unique_key_values = ekd_ds.unique_values(k)
                 except KeyError:
-                    context.add_stderr(f"key {k} not found in dataset, skipping")
+                    context.error(f"key {k} not found in dataset, skipping")
                 else:
                     # Always split to ensure consistent naming
                     unique_key_values.update(_unique_key_values)
@@ -611,13 +597,13 @@ def prepare_open_datasets_kwargs_grib(
                 try:
                     k1_unique_values: list[str] = ekd_ds.unique_values(k1)[k1]
                 except KeyError:
-                    context.add_stderr(f"key {k1} not found in dataset, skipping")
+                    context.error(f"key {k1} not found in dataset, skipping")
                 else:
                     if len(k1_unique_values) > 1:
                         try:
                             k2_unique_key_values = ekd_ds.unique_values(k2)
                         except KeyError:
-                            context.add_stderr(
+                            context.error(
                                 f"key {k2} not found in dataset, splitting on {k1} instead"
                             )
                             unique_key_values.update(ekd_ds.unique_values(k1))
@@ -679,7 +665,7 @@ def open_grib_file_as_xarray_dictionary(
     if len(open_datasets_kwargs) == 1:
         open_datasets_kwargs[0].setdefault("errors", "raise")
 
-    context.add_stdout(f"Opening {grib_file} with kwargs: {open_datasets_kwargs}")
+    context.debug(f"Opening {grib_file} with kwargs: {open_datasets_kwargs}")
 
     # Open grib file as a dictionary of datasets
     datasets: dict[str, xr.Dataset] = {}
@@ -693,7 +679,7 @@ def open_grib_file_as_xarray_dictionary(
             datasets[f"{fname}_{ds_tag}"] = ds
 
     if len(datasets) == 0:
-        context.add_stderr(
+        context.error(
             "Failed to open any valid hypercube with xarray.open_dataset, "
             "opening with cfgrib.open_datasets instead. "
             f"\nGRIB file={grib_file}"

cads_adaptors/tools/general.py

@@ -42,7 +42,7 @@ def split_requests_on_keys(
         if not mapping_options.get("wants_dates", False):
             split_by_month = False
             if context:
-                context.add_stderr(
+                context.error(
                     "For the time being, split-by-month is only supported for wants_dates=True!"
                 )
 

cads_adaptors/tools/post_processors.py

@@ -77,8 +77,7 @@ def daily_reduce(
     out_xarray_dict = {}
     for in_tag, in_dataset in in_xarray_dict.items():
         out_tag = f"{in_tag}_daily-{how}"
-        context.add_stdout(f"Daily reduction: {how} {kwargs}\n{in_dataset}")
-        context.add_user_visible_log(f"Daily reduction: {how} {kwargs}")
+        context.debug(f"Daily reduction: {how} {kwargs}\n{in_dataset}")
         reduced_data = temporal.daily_reduce(
             in_dataset,
             how=how,
@@ -103,8 +102,7 @@ def monthly_reduce(
     out_xarray_dict = {}
     for in_tag, in_dataset in in_xarray_dict.items():
         out_tag = f"{in_tag}_monthly-{how}"
-        context.add_stdout(f"Temporal reduction: {how} {kwargs}")
-        context.add_user_visible_log(f"Temporal reduction: {how} {kwargs}")
+        context.debug(f"Temporal reduction: {how} {kwargs}")
         reduced_data = temporal.monthly_reduce(
             in_dataset,
             how=how,
@@ -127,7 +125,7 @@ def update_history(
     elif isinstance(history, str):
         history += f"\n{update_text}"
     else:
-        context.add_stderr(
+        context.error(
             f"Unexpected history attribute type in existing xarray: {type(history)}"
         )
         return dataset

cads_adaptors/tools/url_tools.py

@@ -57,7 +57,7 @@ def try_download(
         if dir:
             os.makedirs(dir, exist_ok=True)
         try:
-            context.add_stdout(f"Downloading {url} to {path}")
+            context.debug(f"Downloading {url} to {path}")
             multiurl.download(
                 url,
                 path,
@@ -78,9 +78,9 @@ def try_download(
                     f"\n{yaml.safe_dump(url, indent=2)} "
                 )
             else:
-                context.add_stdout(f"Failed download for URL: {url}\nException: {e}")
+                context.debug(f"Failed download for URL: {url}\nException: {e}")
         except Exception as e:
-            context.add_stdout(f"Failed download for URL: {url}\nException: {e}")
+            context.debug(f"Failed download for URL: {url}\nException: {e}")
         else:
             paths.append(path)