style: add logging to WHERE filter work #260

datagateway_api/src/search_api/filters.py

@@ -23,19 +23,36 @@ class SearchAPIWhereFilter(PythonICATWhereFilter):
     def __init__(self, field, value, operation, search_api_query=None):
         self.search_api_query = search_api_query
         super().__init__(field, value, operation)
+        log.info("SearchAPIWhereFilter created: %s", repr(self))
 
     def apply_filter(self, query):
+        log.info("Applying SearchAPIWhereFilter to: %s", type(query))
+        log.debug("Current WHERE filter data: %s", repr(self))
+
         panosc_field_names = self.field.split(".")
         icat_field_names = []
         panosc_mapping_name = query.panosc_entity_name
 
+        log.debug(
+            "Converting PaNOSC where input to ICAT using: %s (PaNOSC field names) and"
+            " %s (PaNOSC mapping name)",
+            panosc_field_names,
+            panosc_mapping_name,
+        )
+
         # Convert PaNOSC field names to ICAT field names
         for field_name in panosc_field_names:
             panosc_mapping_name, icat_field_name = self.get_icat_mapping(
                 panosc_mapping_name, field_name,
             )
             icat_field_names.append(icat_field_name)
 
+        log.debug(
+            "PaNOSC to ICAT translation for where filter: %s (PaNOSC), %s (ICAT)",
+            panosc_field_names,
+            icat_field_names,
+        )
+
         # Once we have got ICAT field names we no longer need the PaNOSC versions so
         # overwriting them is all good. ICAT version needs to be in `self.field` due to
         # code written in `PythonICATWhereFilter.apply_filter()`
@@ -66,8 +83,14 @@ def get_icat_mapping(self, panosc_entity_name, field_name):
         :raises FilterError: If a valid mapping cannot be found
         """
 
+        log.info(
+            "Searching mapping file to find ICAT translation for %s",
+            f"{panosc_entity_name}.{field_name}",
+        )
+
         try:
             icat_mapping = mappings.mappings[panosc_entity_name][field_name]
+            log.debug("ICAT mapping/translation found: %s", icat_mapping)
         except KeyError as e:
             raise FilterError(f"Bad PaNOSC to ICAT mapping: {e.args}")
 
@@ -93,6 +116,10 @@ def get_icat_mapping(self, panosc_entity_name, field_name):
                 self.value = str(self.value)
                 icat_field_name = icat_mapping[1]
 
+        log.debug(
+            "Output of get_icat_mapping(): %s, %s", panosc_entity_name, icat_field_name,
+        )
+
         return (panosc_entity_name, icat_field_name)
 
     def __str__(self):
@@ -102,6 +129,7 @@ def __str__(self):
         """
 
         if isinstance(self.search_api_query, SearchAPIQuery):
+            log.info("__str__ for SearchAPIWhereFilter, SearchAPIQuery found")
             query = self.search_api_query
 
             self.apply_filter(query)
@@ -120,6 +148,10 @@ def __str__(self):
             except IndexError:
                 raise FilterError("Condition could not be found in Python ICAT query")
         else:
+            log.info(
+                "__str__ for SearchAPIWhereFilter, no query found so repr() will be"
+                " returned",
+            )
             return repr(self)
 
     def __repr__(self):

datagateway_api/src/search_api/nested_where_filters.py

@@ -59,21 +59,29 @@ def set_search_api_query(query_filter, search_api_query):
         """
 
         log.debug(
-            "Query filter: %s, Search API query: %s",
+            "Setting SearchAPIQuery for NestedWhereFilters. Query filter: %s, Search"
+            " API query: %s",
             repr(query_filter),
             search_api_query,
         )
 
         if isinstance(query_filter, SearchAPIWhereFilter):
             query_filter.search_api_query = search_api_query
         elif isinstance(query_filter, NestedWhereFilters):
+            log.debug(
+                "Calling set_search_api_query(), with LHS and RHS from"
+                " NestedWhereFilters object (one per call)",
+            )
             NestedWhereFilters.set_search_api_query(
                 query_filter.lhs, search_api_query,
             )
             NestedWhereFilters.set_search_api_query(
                 query_filter.rhs, search_api_query,
             )
         elif isinstance(query_filter, list):
+            log.debug(
+                "List of WHERE filters found, calling set_search_api_query() for each",
+            )
             for where_filter in query_filter:
                 NestedWhereFilters.set_search_api_query(
                     where_filter, search_api_query,

datagateway_api/src/search_api/panosc_mappings.py

@@ -1,8 +1,11 @@
 import json
+import logging
 from pathlib import Path
 
 from datagateway_api.src.common.exceptions import SearchAPIError
 
+log = logging.getLogger()
+
 
 class PaNOSCMappings:
     def __init__(
@@ -11,6 +14,7 @@ def __init__(
         """Load contents of `search_api_mapping.json` into this class"""
         try:
             with open(path, encoding="utf-8") as target:
+                log.info("Loading PaNOSC to ICAT mappings from %s", path)
                 self.mappings = json.load(target)
         except IOError as e:
             raise SearchAPIError(e)

datagateway_api/src/search_api/query_filter_factory.py

@@ -39,27 +39,33 @@ def get_query_filter(request_filter, entity_name=None):
             log.debug("Filter: %s", request_filter["filter"])
             for filter_name, filter_input in request_filter["filter"].items():
                 if filter_name == "where":
+                    log.info("where JSON object found")
                     query_filters.extend(
                         SearchAPIQueryFilterFactory.get_where_filter(
                             filter_input, entity_name,
                         ),
                     )
                 elif filter_name == "include":
+                    log.info("include JSON object found")
                     query_filters.extend(
                         SearchAPIQueryFilterFactory.get_include_filter(
                             filter_input, entity_name,
                         ),
                     )
                 elif filter_name == "limit":
+                    log.info("limit JSON object found")
                     query_filters.append(SearchAPILimitFilter(filter_input))
                 elif filter_name == "skip":
+                    log.info("skip JSON object found")
                     query_filters.append(SearchAPISkipFilter(filter_input))
                 else:
                     raise FilterError(
-                        "No valid filter name given within filter query param",
+                        "No valid filter name given within filter query param:"
+                        f" {filter_name}",
                     )
         elif query_param_name == "where":
             # For the count endpoints
+            log.info("where query param found, likely for count endpoint")
             query_filters.extend(
                 SearchAPIQueryFilterFactory.get_query_filter(
                     {"filter": request_filter}, entity_name,
@@ -101,6 +107,7 @@ def get_where_filter(where_filter_input, entity_name):
             list(where_filter_input.keys())[0] == "and"
             or list(where_filter_input.keys())[0] == "or"
         ):
+            log.debug("and/or operators found: %s", list(where_filter_input.keys())[0])
             boolean_operator = list(where_filter_input.keys())[0]
             conditions = list(where_filter_input.values())[0]
             conditional_where_filters = []
@@ -124,6 +131,7 @@ def get_where_filter(where_filter_input, entity_name):
             )
             where_filters.append(nested)
         elif list(where_filter_input.keys())[0] == "text":
+            log.debug("Text operator found within JSON where object")
             try:
                 search_api_models = importlib.import_module(
                     "datagateway_api.src.search_api.models",
@@ -138,9 +146,17 @@ def get_where_filter(where_filter_input, entity_name):
             try:
                 or_conditional_filters = []
                 field_names = entity_class._text_operator_fields
+                log.debug(
+                    "Text operators found for PaNOSC %s: %s", entity_name, field_names,
+                )
                 if not field_names:
                     # No text operator fields present, raise KeyError to be caught in
                     # this try/except block
+                    log.warning(
+                        "No text operator fields found for PaNOSC entity %s, will"
+                        " ignore",
+                        entity_name,
+                    )
                     raise KeyError()
                 for field_name in field_names:
                     or_conditional_filters.append(
@@ -161,6 +177,7 @@ def get_where_filter(where_filter_input, entity_name):
                 # text_operator_fields dict.
                 pass
         else:
+            log.info("Basic where filter found, extracting field, value and operation")
             filter_data = SearchAPIQueryFilterFactory.get_condition_values(
                 where_filter_input,
             )
@@ -198,6 +215,7 @@ def get_include_filter(include_filter_input, entity_name):
 
             nested_include = False
             if "scope" in related_model:
+                log.info("Scope found in include JSON object")
                 if "limit" in related_model["scope"]:
                     raise FilterError(
                         "Bad Include filter: Scope filter cannot have a limit filter",
@@ -257,10 +275,15 @@ def get_condition_values(conditions_dict):
 
         if isinstance(filter_data, str):
             # Format: {"where": {"property": "value"}}
+            log.debug("Format of WHERE filter: {'where': {'property': 'value'}}")
             value = conditions_dict[field]
             operation = "eq"
         elif isinstance(filter_data, dict):
             # Format: {"where": {"property": {"operator": "value"}}}
+            log.debug(
+                "Format of WHERE filter:"
+                " {'where': {'property': {'operator': 'value'}}}",
+            )
             value = list(conditions_dict[field].values())[0]
             operation = list(conditions_dict[field].keys())[0]