@@ -164,7 +164,14 @@ async def perform_handshake1( |
164 | 164 | session, url, data=payload |
165 | 165 | ) |
166 | 166 |
|
167 | | - cookie = self.jar.filter_cookies(url).get(self.TP_SESSION_COOKIE_NAME) |
| 167 | + if _LOGGER.isEnabledFor(logging.DEBUG): |
| 168 | + _LOGGER.debug( |
| 169 | + "Handshake1 posted at %s. Host is %s, Response status is %s, Request was %s", |
| 170 | + datetime.datetime.now(), |
| 171 | + self.host, |
| 172 | + response_status, |
| 173 | + payload and payload.hex(), |
| 174 | + ) |
168 | 175 |
|
169 | 176 | if response_status != 200: |
170 | 177 | raise AuthenticationException( |
@@ -175,16 +182,16 @@ async def perform_handshake1( |
175 | 182 | remote_seed = response_data[0:16] |
176 | 183 | server_hash = response_data[16:] |
177 | 184 |
|
178 | | - cookie = self.jar.filter_cookies(url).get(self.TP_SESSION_COOKIE_NAME) |
179 | | - _LOGGER.debug( |
180 | | - 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()}" |
181 | | - ) |
182 | | - |
183 | | - _LOGGER.debug( |
184 | | - "Server remote_seed is: %s, server hash is: %s", |
185 | | - remote_seed.hex(), |
186 | | - server_hash.hex(), |
187 | | - ) |
| 185 | + if _LOGGER.isEnabledFor(logging.DEBUG): |
| 186 | + cookie = self.jar.filter_cookies(url).get(self.TP_SESSION_COOKIE_NAME) |
| 187 | + _LOGGER.debug( |
| 188 | + "Handshake1 success at %s. Host is %s, Cookie is %s, Server remote_seed is: %s, server hash is: %s", |
| 189 | + datetime.datetime.now(), |
| 190 | + self.host, |
| 191 | + cookie, |
| 192 | + remote_seed.hex(), |
| 193 | + server_hash.hex(), |
| 194 | + ) |
188 | 195 |
|
189 | 196 | local_seed_auth_hash = self._sha256(self._local_seed + self.local_auth_hash) |
190 | 197 |
|
@@ -242,10 +249,15 @@ async def perform_handshake2(self, session, remote_seed, auth_hash) -> None: |
242 | 249 | session, url, data=payload |
243 | 250 | ) |
244 | 251 |
|
245 | | - cookie = self.jar.filter_cookies(url).get(self.TP_SESSION_COOKIE_NAME) |
246 | | - _LOGGER.debug( |
247 | | - f"Handshake2 posted {datetime.datetime.now()}. Host is {self.host}, Session cookie is {cookie}, Response status is {response_status}, Request was {payload!r}" |
248 | | - ) |
| 252 | + if _LOGGER.isEnabledFor(logging.DEBUG): |
| 253 | + _LOGGER.debug( |
| 254 | + "Handshake2 posted %s. Host is %s, Session cookie is %s, Response status is %s, Request was %s", |
| 255 | + datetime.datetime.now(), |
| 256 | + self.host, |
| 257 | + self.jar.filter_cookies(url).get(self.TP_SESSION_COOKIE_NAME), |
| 258 | + response_status, |
| 259 | + payload.hex(), |
| 260 | + ) |
249 | 261 |
|
250 | 262 | if response_status != 200: |
251 | 263 | self.authentication_failed = True |
@@ -336,7 +348,8 @@ async def _execute_query(self, request: str, retry_count: int) -> Dict: |
336 | 348 |
|
337 | 349 | except AuthenticationException as auex: |
338 | 350 | _LOGGER.debug( |
339 | | - f"Unable to complete handshake for device {self.host}, authentication failed" |
| 351 | + "Unable to complete handshake for device %s, authentication failed", |
| 352 | + self.host, |
340 | 353 | ) |
341 | 354 | raise auex |
342 | 355 |
|
@@ -352,10 +365,10 @@ async def _execute_query(self, request: str, retry_count: int) -> Dict: |
352 | 365 | session, url, params={"seq": seq}, data=payload |
353 | 366 | ) |
354 | 367 |
|
| 368 | + 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}" |
355 | 369 | if response_status != 200: |
356 | | - _LOGGER.error( |
357 | | - 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}" |
358 | | - ) |
| 370 | + if _LOGGER.isEnabledFor(logging.ERROR): |
| 371 | + _LOGGER.error("Query failed after succesful authentication " + msg) |
359 | 372 | # If we failed with a security error, force a new handshake next time. |
360 | 373 | if response_status == 403: |
361 | 374 | self.handshake_done = False |
@@ -369,9 +382,8 @@ async def _execute_query(self, request: str, retry_count: int) -> Dict: |
369 | 382 | % (self.host, response_status, seq) |
370 | 383 | ) |
371 | 384 | else: |
372 | | - _LOGGER.debug( |
373 | | - 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}" |
374 | | - ) |
| 385 | + if _LOGGER.isEnabledFor(logging.DEBUG): |
| 386 | + _LOGGER.debug("Query posted " + msg) |
375 | 387 |
|
376 | 388 | self.handle_cookies(session, url) |
377 | 389 |
|
@@ -383,7 +395,11 @@ async def _execute_query(self, request: str, retry_count: int) -> Dict: |
383 | 395 |
|
384 | 396 | json_payload = json_loads(decrypted_response) |
385 | 397 |
|
386 | | - _LOGGER.debug("%s << %s", self.host, pf(json_payload)) |
| 398 | + _LOGGER.debug( |
| 399 | + "%s << %s", |
| 400 | + self.host, |
| 401 | + _LOGGER.isEnabledFor(logging.DEBUG) and pf(json_payload), |
| 402 | + ) |
387 | 403 |
|
388 | 404 | return json_payload |
389 | 405 |
|
|