feat: logging improvements

Author: Brooke-white

redshift_connector/__init__.py

@@ -338,7 +338,7 @@ def connect(
     _logger.debug(make_divider_block())
     _logger.debug("Connection arguments following validation and IAM auth (if applicable)")
     _logger.debug(make_divider_block())
-    _logger.debug(mask_secure_info_in_props(info).__str__())
+    _logger.debug(mask_secure_info_in_props(info))
     _logger.debug(make_divider_block())
 
     return Connection(

redshift_connector/auth/aws_credentials_provider.py

@@ -57,13 +57,16 @@ def get_credentials(
             try:
                 self.refresh()
             except Exception as e:
-                _logger.error("Refreshing IdP credentials failed: {}".format(str(e)))
+                exec_msg: str = "Refreshing IdP credentials failed"
+                _logger.debug(exec_msg)
                 raise InterfaceError(e)
 
         credentials: typing.Union[AWSDirectCredentialsHolder, AWSProfileCredentialsHolder] = self.cache[key]
 
         if credentials is None:
-            raise InterfaceError("Unable to load AWS credentials")
+            exec_msg = "Unable to load AWS credentials from cache"
+            _logger.debug(exec_msg)
+            raise InterfaceError(exec_msg)
 
         return credentials
 

redshift_connector/core.py

@@ -152,7 +152,7 @@ def get_expiration(self: "CredentialsHolder") -> datetime.datetime:
         return self.expiration
 
     def is_expired(self: "CredentialsHolder") -> bool:
-        _logger.debug("Credentials will expire at {} (UTC)".format(self.expiration))
+        _logger.debug("AWS Credentials will expire at %s (UTC)", self.expiration)
 
         return datetime.datetime.now(datetime.timezone.utc) > self.expiration
 
@@ -174,6 +174,7 @@ def get_auto_create(self: "CredentialsHolder.IamMetadata") -> bool:
             return self.auto_create
 
         def set_auto_create(self: "CredentialsHolder.IamMetadata", auto_create: str) -> None:
+            _logger.debug("CredentialsHolder.IamMetadata.set_auto_create %s", auto_create)
             if auto_create.lower() == "true":
                 self.auto_create = True
             else:
@@ -183,6 +184,7 @@ def get_db_user(self: "CredentialsHolder.IamMetadata") -> typing.Optional[str]:
             return self.db_user
 
         def set_db_user(self: "CredentialsHolder.IamMetadata", db_user: str) -> None:
+            _logger.debug("CredentialsHolder.IamMetadata.set_db_user %s", db_user)
             self.db_user = db_user
 
         def get_saml_db_user(
@@ -191,6 +193,7 @@ def get_saml_db_user(
             return self.saml_db_user
 
         def set_saml_db_user(self: "CredentialsHolder.IamMetadata", saml_db_user: str) -> None:
+            _logger.debug("CredentialsHolder.IamMetadata.set_saml_db_user %s", saml_db_user)
             self.saml_db_user = saml_db_user
 
         def get_profile_db_user(
@@ -199,18 +202,21 @@ def get_profile_db_user(
             return self.profile_db_user
 
         def set_profile_db_user(self: "CredentialsHolder.IamMetadata", profile_db_user: str) -> None:
+            _logger.debug("CredentialsHolder.IamMetadata.set_profile_db_user %s", profile_db_user)
             self.profile_db_user = profile_db_user
 
         def get_db_groups(self: "CredentialsHolder.IamMetadata") -> typing.List[str]:
             return self.db_groups
 
         def set_db_groups(self: "CredentialsHolder.IamMetadata", db_groups: typing.List[str]) -> None:
+            _logger.debug("CredentialsHolder.IamMetadata.set_db_groups %s", db_groups)
             self.db_groups = db_groups
 
         def get_allow_db_user_override(self: "CredentialsHolder.IamMetadata") -> bool:
             return self.allow_db_user_override
 
         def set_allow_db_user_override(self: "CredentialsHolder.IamMetadata", allow_db_user_override: str) -> None:
+            _logger.debug("CredentialsHolder.IamMetadata.set_allow_db_user_override %s", allow_db_user_override)
             if allow_db_user_override.lower() == "true":
                 self.allow_db_user_override = True
             else:
@@ -220,6 +226,7 @@ def get_force_lowercase(self: "CredentialsHolder.IamMetadata") -> bool:
             return self.force_lowercase
 
         def set_force_lowercase(self: "CredentialsHolder.IamMetadata", force_lowercase: str) -> None:
+            _logger.debug("CredentialsHolder.IamMetadata.set_allow_db_user_override %s", force_lowercase)
             if force_lowercase.lower() == "true":
                 self.force_lowercase = True
             else:

redshift_connector/credentials_holder.py

@@ -106,7 +106,7 @@ def __init__(self: "Cursor", connection: "Connection", paramstyle=None) -> None:
         else:
             self.paramstyle = paramstyle
 
-        _logger.debug("Cursor.paramstyle={}".format(self.paramstyle))
+        _logger.debug("Cursor.paramstyle=%s", self.paramstyle)
 
     def __enter__(self: "Cursor") -> "Cursor":
         return self
@@ -239,7 +239,12 @@ def execute(self: "Cursor", operation, args=None, stream=None, merge_socket_read
                 self._c.execute(self, "begin transaction", None)
             self._c.merge_socket_read = merge_socket_read
             self._c.execute(self, operation, args)
-        except AttributeError as e:
+        except Exception as e:
+            try:
+                _logger.debug("Cursor's connection._usock state: %s", self.connection._usock.__dict__)  # type: ignore
+                _logger.debug("Cursor's connection._sock is closed: %s", self.connection._sock.closed)  # type: ignore
+            except:
+                pass
             raise e
         return self
 
@@ -339,7 +344,7 @@ def insert_data_bulk(
                     self.execute(insert_stmt, values_list)
 
         except Exception as e:
-            raise InterfaceError(e)
+            raise e
         finally:
             # reset paramstyle to it's original value
             self.paramstyle = orig_paramstyle