Merge pull request #465 from xchem/m2ms-1240-achristie

Reduce ISPyB exception logging

api/security.py

@@ -3,6 +3,7 @@
 import os
 import time
 from pathlib import Path
+from typing import Optional, Union
 from wsgiref.util import FileWrapper
 
 from django.db.models import Q
@@ -37,7 +38,7 @@
 # response = view(request)
 
 
-def get_remote_conn():
+def get_remote_conn() -> Optional[SSHConnector]:
     ispyb_credentials = {
         "user": os.environ.get("ISPYB_USER"),
         "pw": os.environ.get("ISPYB_PASSWORD"),
@@ -64,17 +65,20 @@ def get_remote_conn():
         return None
 
     # Try to get an SSH connection (aware that it might fail)
-    conn = None
+    conn: SSHConnector = None
     try:
         conn = SSHConnector(**ispyb_credentials)
-    except:
-        logger.info("ispyb_credentials=%s", ispyb_credentials)
-        logger.exception("Exception creating SSHConnector")
+    except Exception:
+        # Log the exception if DEBUG level or lower/finer?
+        # The following wil not log if the level is set to INFO for example.
+        if logging.DEBUG >= logger.level:
+            logger.info("ispyb_credentials=%s", ispyb_credentials)
+            logger.exception("Got the following exception creating SSHConnector...")
 
     return conn
 
 
-def get_conn():
+def get_conn() -> Optional[Connector]:
     credentials = {
         "user": os.environ.get("ISPYB_USER"),
         "pw": os.environ.get("ISPYB_PASSWORD"),
@@ -83,19 +87,21 @@ def get_conn():
         "db": "ispyb",
         "conn_inactivity": 360,
     }
-
-    # Caution: Credentials may not be set in the environment.
-    #          Assume the credentials are invalid if there is no password
+    # Caution: Credentials may not have been set in the environment.
+    #          Assume the credentials are invalid if there is no host.
     #          If a host is not defined other properties are useless.
     if not credentials["host"]:
         return None
 
     conn = None
     try:
         conn = Connector(**credentials)
-    except:
-        logger.info("credentials=%s", credentials)
-        logger.exception("Exception creating Connector")
+    except Exception:
+        # Log the exception if DEBUG level or lower/finer?
+        # The following wil not log if the level is set to INFO for example.
+        if logging.DEBUG >= logger.level:
+            logger.info("credentials=%s", credentials)
+            logger.exception("Got the following exception creating Connector...")
 
     return conn
 
@@ -184,7 +190,7 @@ def get_proposals_for_user_from_ispyb(self, user):
         logger.info("user=%s needs_updating=%s", user.username, needs_updating)
 
         if needs_updating:
-            conn = None
+            conn: Optional[Union[Connector, SSHConnector]] = None
             if connector == 'ispyb':
                 conn = get_conn()
             elif connector == 'ssh_ispyb':

viewer/services.py

@@ -4,9 +4,11 @@
 import os
 from concurrent import futures
 from enum import Enum
+from typing import Optional
 
 import requests
 from frag.utils.network_utils import get_driver
+from ispyb.connector.mysqlsp.main import ISPyBMySQLSPConnector as Connector
 from pydiscourse import DiscourseClient
 
 from api import security
@@ -15,6 +17,8 @@
 logger = logging.getLogger(__name__)
 
 DELAY = 10
+# Default timeout for any request calls
+REQUEST_TIMEOUT_S = 5
 
 
 class State(str, Enum):
@@ -127,7 +131,9 @@ async def wrapper_service_query(*args, **kwargs):
                         state = State.OK
 
             except TimeoutError:
-                logger.error("Service query '%s' timed out", func.__name__)
+                # Timeout is an "expected" condition for a service that's expected
+                # to be running but may be degraded so we don't log it unless debugging.
+                logger.debug("Service query '%s' timed out", func.__name__)
                 state = State.TIMEOUT
             except Exception as exc:
                 # unknown error with the query
@@ -144,7 +150,7 @@ async def wrapper_service_query(*args, **kwargs):
 
 
 @service_query
-def ispyb(func_id, name, ispyb_host=None):
+def ispyb(func_id, name, ispyb_host=None) -> Optional[Connector]:
     # Unused arguments
     del func_id, name, ispyb_host
 
@@ -153,7 +159,7 @@ def ispyb(func_id, name, ispyb_host=None):
 
 
 @service_query
-def discourse(func_id, name, key=None, url=None, user=None):
+def discourse(func_id, name, key=None, url=None, user=None) -> DiscourseClient:
     # Unused arguments
     del func_id, name
 
@@ -168,7 +174,7 @@ def discourse(func_id, name, key=None, url=None, user=None):
 
 
 @service_query
-def squonk(func_id, name, squonk_pwd=None):
+def squonk(func_id, name, squonk_pwd=None) -> bool:
     # Unused arguments
     del func_id, name, squonk_pwd
 
@@ -177,7 +183,7 @@ def squonk(func_id, name, squonk_pwd=None):
 
 
 @service_query
-def fragmentation_graph(func_id, name, url=None):
+def fragmentation_graph(func_id, name, url=None) -> bool:
     # Unused arguments
     del func_id, name, url
 
@@ -194,14 +200,14 @@ def fragmentation_graph(func_id, name, url=None):
 
 
 @service_query
-def keycloak(func_id, name, url=None, secret=None):
+def keycloak(func_id, name, url=None, secret=None) -> bool:
     # Unused arguments
     del func_id, name, secret
 
     logger.debug("+ keycloak")
     keycloak_realm = os.environ.get(url, None)
     if not keycloak_realm:
         return False
-    response = requests.get(keycloak_realm)
+    response = requests.get(keycloak_realm, timeout=REQUEST_TIMEOUT_S)
     logger.debug("keycloak response: %s", response)
     return response.ok

viewer/squonk2_agent.py

@@ -69,6 +69,9 @@
 # True if the code's in Test Mode
 _TEST_MODE: bool = False
 
+# Default timeout for any request calls
+REQUEST_TIMEOUT_S: int = 5
+
 
 class Squonk2Agent:
     """Helper class that simplifies access to the Squonk2 Python client.
@@ -882,8 +885,10 @@ def ping(self) -> Squonk2AgentRv:
         assert self.__CFG_SQUONK2_UI_URL
         url: str = self.__CFG_SQUONK2_UI_URL
         try:
-            resp = requests.head(url, verify=self.__verify_certificates)
-        except:
+            resp = requests.head(
+                url, verify=self.__verify_certificates, timeout=REQUEST_TIMEOUT_S
+            )
+        except Exception:
             _LOGGER.error('Exception checking UI at %s', url)
         if resp is None or resp.status_code != 200:
             msg = f'Squonk2 UI is not responding from {url}'
@@ -893,8 +898,10 @@ def ping(self) -> Squonk2AgentRv:
         resp = None
         url = f'{self.__CFG_SQUONK2_DMAPI_URL}/api'
         try:
-            resp = requests.head(url, verify=self.__verify_certificates)
-        except Exception:  # pylint: disable=broad-except
+            resp = requests.head(
+                url, verify=self.__verify_certificates, timeout=REQUEST_TIMEOUT_S
+            )
+        except Exception:
             _LOGGER.error('Exception checking DM at %s', url)
         if resp is None or resp.status_code != 308:
             msg = f'Squonk2 DM is not responding from {url}'
@@ -904,8 +911,10 @@ def ping(self) -> Squonk2AgentRv:
         resp = None
         url = f'{self.__CFG_SQUONK2_ASAPI_URL}/api'
         try:
-            resp = requests.head(url, verify=self.__verify_certificates)
-        except:
+            resp = requests.head(
+                url, verify=self.__verify_certificates, timeout=REQUEST_TIMEOUT_S
+            )
+        except Exception:
             _LOGGER.error('Exception checking AS at %s', url)
         if resp is None or resp.status_code != 308:
             msg = f'Squonk2 AS is not responding from {url}'