Make all klap logging lazy

python-kasa · Sep 15, 2023 · 9ec0799 · 9ec0799
1 parent d759c82
commit 9ec0799
Showing 1 changed file with 39 additions and 23 deletions.
diff --git a/kasa/klapprotocol.py b/kasa/klapprotocol.py
@@ -164,7 +164,14 @@ async def perform_handshake1(
             session, url, data=payload
         )
 
-        cookie = self.jar.filter_cookies(url).get(self.TP_SESSION_COOKIE_NAME)
+        if _LOGGER.isEnabledFor(logging.DEBUG):
+            _LOGGER.debug(
+                "Handshake1 posted at %s. Host is %s, Response status is %s, Request was %s",
+                datetime.datetime.now(),
+                self.host,
+                response_status,
+                payload and payload.hex(),
+            )
 
         if response_status != 200:
             raise AuthenticationException(
@@ -175,16 +182,16 @@ async def perform_handshake1(
         remote_seed = response_data[0:16]
         server_hash = response_data[16:]
 
-        cookie = self.jar.filter_cookies(url).get(self.TP_SESSION_COOKIE_NAME)
-        _LOGGER.debug(
-            f"Handshake1 posted at {datetime.datetime.now()}.  Host is {self.host}, Session cookie is {cookie}, Response status is {response_status}, Request was {self.local_auth_hash.hex()}"
-        )
-
-        _LOGGER.debug(
-            "Server remote_seed is: %s, server hash is: %s",
-            remote_seed.hex(),
-            server_hash.hex(),
-        )
+        if _LOGGER.isEnabledFor(logging.DEBUG):
+            cookie = self.jar.filter_cookies(url).get(self.TP_SESSION_COOKIE_NAME)
+            _LOGGER.debug(
+                "Handshake1 success at %s. Host is %s, Cookie is %s, Server remote_seed is: %s, server hash is: %s",
+                datetime.datetime.now(),
+                self.host,
+                cookie,
+                remote_seed.hex(),
+                server_hash.hex(),
+            )
 
         local_seed_auth_hash = self._sha256(self._local_seed + self.local_auth_hash)
 
@@ -242,10 +249,15 @@ async def perform_handshake2(self, session, remote_seed, auth_hash) -> None:
             session, url, data=payload
         )
 
-        cookie = self.jar.filter_cookies(url).get(self.TP_SESSION_COOKIE_NAME)
-        _LOGGER.debug(
-            f"Handshake2 posted {datetime.datetime.now()}.  Host is {self.host}, Session cookie is {cookie}, Response status is {response_status}, Request was {payload!r}"
-        )
+        if _LOGGER.isEnabledFor(logging.DEBUG):
+            _LOGGER.debug(
+                "Handshake2 posted %s.  Host is %s, Session cookie is %s, Response status is %s, Request was %s",
+                datetime.datetime.now(),
+                self.host,
+                self.jar.filter_cookies(url).get(self.TP_SESSION_COOKIE_NAME),
+                response_status,
+                payload.hex(),
+            )
 
         if response_status != 200:
             self.authentication_failed = True
@@ -336,7 +348,8 @@ async def _execute_query(self, request: str, retry_count: int) -> Dict:
 
                 except AuthenticationException as auex:
                     _LOGGER.debug(
-                        f"Unable to complete handshake for device {self.host}, authentication failed"
+                        "Unable to complete handshake for device %s, authentication failed",
+                        self.host,
                     )
                     raise auex
 
@@ -352,10 +365,10 @@ async def _execute_query(self, request: str, retry_count: int) -> Dict:
                 session, url, params={"seq": seq}, data=payload
             )
 
+            msg = f"at {datetime.datetime.now()}.  Host is {self.host}, Session cookie is {cookie}, Retry count is {retry_count}, Sequence is {seq}, Response status is {response_status}, Request was {request}"
             if response_status != 200:
-                _LOGGER.error(
-                    f"Query failed after succesful authentication at {datetime.datetime.now()}.  Host is {self.host}, Session cookie is {cookie}, Retry count is {retry_count}, Sequence is {seq}, Response status is {response_status}, Request was {request}"
-                )
+                if _LOGGER.isEnabledFor(logging.ERROR):
+                    _LOGGER.error("Query failed after succesful authentication " + msg)
                 # If we failed with a security error, force a new handshake next time.
                 if response_status == 403:
                     self.handshake_done = False
@@ -369,9 +382,8 @@ async def _execute_query(self, request: str, retry_count: int) -> Dict:
                         % (self.host, response_status, seq)
                     )
             else:
-                _LOGGER.debug(
-                    f"Query posted at {datetime.datetime.now()}.  Host is {self.host}, Session cookie is {cookie}, Retry count is {retry_count}, Sequence is {seq}, Response status is {response_status}, Request was {request}"
-                )
+                if _LOGGER.isEnabledFor(logging.DEBUG):
+                    _LOGGER.debug("Query posted " + msg)
 
                 self.handle_cookies(session, url)
 
@@ -383,7 +395,11 @@ async def _execute_query(self, request: str, retry_count: int) -> Dict:
 
                 json_payload = json_loads(decrypted_response)
 
-                _LOGGER.debug("%s << %s", self.host, pf(json_payload))
+                _LOGGER.debug(
+                    "%s << %s",
+                    self.host,
+                    _LOGGER.isEnabledFor(logging.DEBUG) and pf(json_payload),
+                )
 
                 return json_payload