logging has CQL + SCB-download at DEBUG and CQL args at TRACE levels (#…

…141)

logging has CQL + SCB-download at DEBUG and CQL args at TRACE levels

src/cassio/config/bundle_download.py

@@ -2,6 +2,7 @@
 Facilities to manage the download of a secure-connect-bundle from an Astra DB
 token.
 """
+import logging
 import requests  # type: ignore
 from typing import Optional
 
@@ -11,6 +12,9 @@
 )
 
 
+logger = logging.getLogger(__name__)
+
+
 def get_astra_bundle_url(
     database_id: str, token: str, bundle_url_template: Optional[str] = None
 ) -> str:
@@ -23,10 +27,11 @@ def get_astra_bundle_url(
     if not bundle_url_template:
         bundle_url_template = DEFAULT_GET_BUNDLE_URL_TEMPLATE
     url = bundle_url_template.format(database_id=database_id)
-
     headers = {"Authorization": f"Bearer {token}", "Content-Type": "application/json"}
 
+    logger.debug(f"Obtaining SCB URL from: {url}")
     response = requests.post(url, headers=headers)
+    logger.debug(f"SCB URL response: {response.text}")
 
     response_json = response.json()
     # Print the response
@@ -67,6 +72,7 @@ def download_astra_bundle_url(
     bundle_url = get_astra_bundle_url(
         database_id=database_id, token=token, bundle_url_template=bundle_url_template
     )
+    logger.debug(f"Downloading SCB from: {bundle_url}")
     bundle_data = requests.get(bundle_url)
     with open(out_file_path, "wb") as f:
         f.write(bundle_data.content)

src/cassio/table/base_table.py

@@ -1,5 +1,6 @@
 import asyncio
 from asyncio import InvalidStateError, Task
+import logging
 from typing import (
     Any,
     cast,
@@ -34,6 +35,21 @@
 from cassio.table.utils import call_wrapped_async
 
 
+class CustomLogger(logging.Logger):
+    def trace(self, msg: str, *args: Any, **kwargs: Any) -> None:
+        if self.isEnabledFor(5):
+            self._log(5, msg, args, **kwargs)
+
+
+logging.addLevelName(5, "TRACE")
+
+
+logging.setLoggerClass(CustomLogger)
+
+
+logger = logging.getLogger(__name__)
+
+
 class BaseTable:
     ordering_in_partition: Optional[str] = None
 
@@ -374,6 +390,7 @@ def _obtain_prepared_statement(self, final_cql: str) -> PreparedStatement:
         _preparable_cql = final_cql.replace("%s", "?")
         # handle the cache of prepared statements
         if _preparable_cql not in self._prepared_statements:
+            logger.debug(f'Preparing statement "{_preparable_cql}"')
             self._prepared_statements[_preparable_cql] = self.session.prepare(
                 _preparable_cql
             )
@@ -389,12 +406,16 @@ def execute_cql(
         #
         if op_type == CQLOpType.SCHEMA and self.skip_provisioning:
             # these operations are not executed for this instance:
+            logger.debug(f'Not executing statement "{final_cql}"')
             return []
         if op_type == CQLOpType.SCHEMA:
             # schema operations are not to be 'prepared'
             statement = SimpleStatement(final_cql)
+            logger.debug(f'Executing statement "{final_cql}" as simple (unprepared)')
         else:
             statement = self._obtain_prepared_statement(final_cql)
+            logger.debug(f'Executing statement "{final_cql}" as prepared')
+        logger.trace(f'Statement "{final_cql}" has args: "{str(args)}"')  # type: ignore
         return cast(Iterable[RowType], self.session.execute(statement, args))
 
     def execute_cql_async(
@@ -408,6 +429,8 @@ def execute_cql_async(
         if op_type == CQLOpType.SCHEMA:
             raise RuntimeError("Schema operations cannot be asynchronous")
         statement = self._obtain_prepared_statement(final_cql)
+        logger.debug(f'Executing_async statement "{final_cql}" as prepared')
+        logger.trace(f'Statement "{final_cql}" has args: "{str(args)}"')  # type: ignore
         return self.session.execute_async(statement, args)
 
     async def aexecute_cql(
@@ -420,12 +443,16 @@ async def aexecute_cql(
         #
         if op_type == CQLOpType.SCHEMA and self.skip_provisioning:
             # these operations are not executed for this instance:
+            logger.debug(f'Not aexecuting statement "{final_cql}"')
             return []
         if op_type == CQLOpType.SCHEMA:
             # schema operations are not to be 'prepared'
             statement = SimpleStatement(final_cql)
+            logger.debug(f'aExecuting statement "{final_cql}" as simple (unprepared)')
         else:
             statement = self._obtain_prepared_statement(final_cql)
+            logger.debug(f'aExecuting statement "{final_cql}" as prepared')
+        logger.trace(f'Statement "{final_cql}" has args: "{str(args)}"')  # type: ignore
         return cast(
             Iterable[RowType],
             await call_wrapped_async(self.session.execute_async, statement, args),