Skip to content

Commit

Permalink
Don't pre-format log messages
Browse files Browse the repository at this point in the history
  • Loading branch information
@ping
ping committed Sep 12, 2023
1 parent 9ba2522 commit 7cd0431
Show file tree
Hide file tree
Showing 7 changed files with 89 additions and 127 deletions.
2 changes: 1 addition & 1 deletion calibre-plugin/config.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -965,4 +965,4 @@ def save_settings(self):
try:
self.plugin_action.apply_settings()
except Exception as err:
logger.warning(f"Error applying settings: {err}")
logger.warning(f"Error applying settings: %s", err)
9 changes: 3 additions & 6 deletions calibre-plugin/hold_actions.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -30,10 +30,9 @@ def __call__(
abort=None,
notifications=None,
):
logger = log
notifications.put((0.5, _("Cancelling")))
libby_client.cancel_hold(hold)
logger.info("Cancelled hold for %s successfully." % get_media_title(hold))
log.info("Cancelled hold for %s successfully." % get_media_title(hold))
return hold


Expand All @@ -48,10 +47,9 @@ def __call__(
abort=None,
notifications=None,
):
logger = log
notifications.put((0.5, _("Updating hold")))
hold = libby_client.suspend_hold(hold, days_to_suspend)
logger.info("Updated hold for %s successfully." % get_media_title(hold))
log.info("Updated hold for %s successfully." % get_media_title(hold))
return hold


Expand All @@ -66,10 +64,9 @@ def __call__(
abort=None,
notifications=None,
):
logger = log
notifications.put((0.5, _("Creating hold")))
hold = libby_client.create_hold(media["id"], card["cardId"])
logger.info(
log.info(
"Created hold for %s at %s successfully."
% (get_media_title(hold), card["advantageKey"])
)
Expand Down
59 changes: 23 additions & 36 deletions calibre-plugin/libby/client.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -419,13 +419,13 @@ def _read_response(self, response, decode: bool = True) -> Union[bytes, str]:
if "identity" in res_obj:
res_obj["identity"] = "*" * int(len(res_obj["identity"]) / 10)
self.logger.debug(
"RES BODY: {0:s}".format(json.dumps(res_obj, separators=(",", ":")))
"RES BODY: %s", json.dumps(res_obj, separators=(",", ":"))
)
except: # noqa
# do nothing
pass
else:
self.logger.debug("RES BODY: {0:s}".format(decoded_res))
self.logger.debug("RES BODY: %s", decoded_res)
return decoded_res

def send_request(
Expand Down Expand Up @@ -495,51 +495,43 @@ def send_request(

for attempt in range(0, self.max_retries + 1):
try:
self.logger.debug(
"REQUEST: {0!s} {1!s}".format(req.get_method(), endpoint_url)
)
self.logger.debug("REQUEST: %s %s", req.get_method(), endpoint_url)
bearer_token = req.headers.get("Authorization", "")
if _scrub_sensitive_data and bearer_token:
bearer_token = bearer_token[: len("Bearer ")] + "*" * int(
len(bearer_token[len("Bearer ") :]) / 10
)
self.logger.debug(
"REQ HEADERS: \n{0!s}".format(
"\n".join(
[
"{}: {}".format(
k, v if k != "Authorization" else bearer_token
)
for k, v in req.headers.items()
]
)
)
"REQ HEADERS: \n%s",
"\n".join(
[
"{}: {}".format(
k, v if k != "Authorization" else bearer_token
)
for k, v in req.headers.items()
]
),
)
if data:
self.logger.debug("REQ BODY: \n{0!s}".format(data))
self.logger.debug("REQ BODY: \n%s", data)
req_opener = self.opener if not no_redirect else self.opener_noredirect
response = req_opener.open(req, timeout=self.timeout)
except HTTPError as e:
if e.code in (301, 302) and no_redirect:
response = e
else:
self.logger.debug("RESPONSE: {0:d} {1:s}".format(e.code, e.url))
self.logger.debug("RESPONSE: %d %s", e.code, e.url)
self.logger.debug(
"RES HEADERS: \n{0!s}".format(
"\n".join(
["{}: {}".format(k, v) for k, v in e.info().items()]
)
)
"RES HEADERS: \n%s",
"\n".join(["{}: {}".format(k, v) for k, v in e.info().items()]),
)
error_response = self._read_response(e)
if (
attempt < self.max_retries and e.code >= 500
): # retry for server 5XX errors
# do nothing, try
self.logger.warning(
"Retrying due to {}: {}".format(
e.__class__.__name__, str(e)
)
"Retrying due to %s: %s", e.__class__.__name__, str(e)
)
self.logger.debug(error_response)
continue
Expand All @@ -555,9 +547,9 @@ def send_request(
) as connection_error:
if attempt < self.max_retries:
self.logger.warning(
"Retrying due to {}: {}".format(
connection_error.__class__.__name__, str(connection_error)
)
"Retrying due to %s: %s",
connection_error.__class__.__name__,
str(connection_error),
)
# do nothing, try
continue
Expand All @@ -567,15 +559,10 @@ def send_request(
)
) from connection_error

self.logger.debug("RESPONSE: %d %s", response.code, response.url)
self.logger.debug(
"RESPONSE: {0:d} {1:s}".format(response.code, response.url)
)
self.logger.debug(
"RES HEADERS: \n{0!s}".format(
"\n".join(
["{}: {}".format(k, v) for k, v in response.info().items()]
)
)
"RES HEADERS: \n%s",
"\n".join(["{}: {}".format(k, v) for k, v in response.info().items()]),
)
if return_response:
return response
Expand Down
6 changes: 2 additions & 4 deletions calibre-plugin/loan_actions.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -30,10 +30,9 @@ def __call__(
abort=None,
notifications=None,
):
logger = log
notifications.put((0.5, _("Returning")))
libby_client.return_loan(loan)
logger.info("Returned %s successfully." % get_media_title(loan))
log.info("Returned %s successfully." % get_media_title(loan))
return loan


Expand All @@ -47,8 +46,7 @@ def __call__(
abort=None,
notifications=None,
):
logger = log
notifications.put((0.5, _("Renewing")))
new_loan = libby_client.renew_loan(loan)
logger.info("Renewed %s successfully." % get_media_title(loan))
log.info("Renewed %s successfully." % get_media_title(loan))
return new_loan
23 changes: 10 additions & 13 deletions calibre-plugin/magazine_download.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -454,7 +454,6 @@ def _custom_download(
abort=None,
notifications=None,
) -> Path:
logger = log
download_progress_fraction = 0.97
meta_progress_fraction = 1.0 - download_progress_fraction
meta_tasks = 3
Expand Down Expand Up @@ -517,7 +516,7 @@ def _custom_download(
and OverDriveClient.extract_type(loan) == LibbyMediaTypes.Magazine
):
msg = _("Magazine has unsupported fixed-layout (pre-paginated) format.")
logger.error(msg)
log.error(msg)
raise UnsupportedException(msg, media_info)

# for finding cover image for magazines
Expand Down Expand Up @@ -585,17 +584,17 @@ def _custom_download(
for i, entry in enumerate(title_content_entries, start=1):
if abort.is_set():
msg = "Abort signal received."
logger.info(msg)
log.info(msg)
raise RuntimeError(msg)
entry_url = entry["url"]
parsed_entry_url = urlparse(entry_url)
title_content_path = Path(parsed_entry_url.path[1:])
logger.info(
log.info(
"Proccesing %d/%d : %s" % (i, total_downloads, title_content_path.name)
)
media_type = guess_mimetype(title_content_path.name)
if not media_type:
logger.warning("Skipped roster entry: %s" % title_content_path.name)
log.warning("Skipped roster entry: %s" % title_content_path.name)
continue
asset_folder = book_content_folder.joinpath(title_content_path.parent)
if media_type == "application/x-dtbncx+xml":
Expand Down Expand Up @@ -671,9 +670,7 @@ def _custom_download(
if not asset_font_path.exists():
css_content = css_content.replace(src_match, "")
except Exception as patch_err:
logger.warning(
"Error while patching font sources: %s" % patch_err
)
log.warning("Error while patching font sources: %s" % patch_err)
with open(asset_file_path, "w", encoding="utf-8") as f_out:
f_out.write(css_content)
elif media_type in ("application/xhtml+xml", "text/html"):
Expand All @@ -682,7 +679,7 @@ def _custom_download(
if script_ele and hasattr(script_ele, "string"):
mobj = contents_re.search(script_ele.string or "")
if not mobj:
logger.warning(
log.warning(
"Unable to extract content string for %s"
% parsed_entry_url.path,
)
Expand Down Expand Up @@ -863,7 +860,7 @@ def _custom_download(
and meta_id.get("content")
and meta_id["content"] != expected_book_identifier
):
logger.debug(
log.debug(
'Replacing identifier in %s: "%s" -> "%s"'
% (
ncx_path.name,
Expand Down Expand Up @@ -998,7 +995,7 @@ def _custom_download(
)
tree = ET.ElementTree(container)
tree.write(container_file_path, xml_declaration=True, encoding="utf-8")
logger.debug('Saved "%s"' % container_file_path)
log.debug('Saved "%s"' % container_file_path)

# create epub zip
with zipfile.ZipFile(
Expand All @@ -1017,8 +1014,8 @@ def _custom_download(
zip_archive_name = zip_archive_file.as_posix()
zip_target_file = book_folder.joinpath(zip_archive_file)
epub_zip.write(zip_target_file, zip_archive_name)
logger.debug(
log.debug(
'epub: Added "%s" as "%s"' % (zip_target_file, zip_archive_name)
)
logger.info('Saved "%s"' % epub_file_path)
log.info('Saved "%s"' % epub_file_path)
return epub_file_path
41 changes: 15 additions & 26 deletions calibre-plugin/overdrive/client.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -157,7 +157,7 @@ def _read_response(self, response, decode: bool = True) -> Union[bytes, str]:
return res

decoded_res = res.decode("utf8")
self.logger.debug("RES BODY: {0:s}".format(decoded_res))
self.logger.debug("RES BODY: %s", decoded_res)
return decoded_res

def send_request(
Expand Down Expand Up @@ -221,32 +221,26 @@ def send_request(

for attempt in range(0, self.max_retries + 1):
try:
self.logger.debug("REQUEST: %s %s", req.get_method(), endpoint_url)
self.logger.debug(
"REQUEST: {0!s} {1!s}".format(req.get_method(), endpoint_url)
)
self.logger.debug(
"REQ HEADERS: \n{0!s}".format(
"\n".join(
["{}: {}".format(k, v) for k, v in req.headers.items()]
)
)
"REQ HEADERS: \n%s",
"\n".join(["{}: {}".format(k, v) for k, v in req.headers.items()]),
)
if data:
self.logger.debug("REQ BODY: \n{0!s}".format(data))
self.logger.debug("REQ BODY: \n%s", data)
response = self.opener.open(req, timeout=self.timeout)
except HTTPError as e:
self.logger.debug("RESPONSE: {0:d} {1:s}".format(e.code, e.url))
self.logger.debug("RESPONSE: %d %s", e.code, e.url)
self.logger.debug(
"RES HEADERS: \n{0!s}".format(
"\n".join(["{}: {}".format(k, v) for k, v in e.info().items()])
)
"RES HEADERS: \n%s",
"\n".join(["{}: {}".format(k, v) for k, v in e.info().items()]),
)
if (
attempt < self.max_retries and e.code >= 500
): # retry for server 5XX errors
# do nothing, try
self.logger.warning(
"Retrying due to {}: {}".format(e.__class__.__name__, str(e))
"Retrying due to %s: %s", e.__class__.__name__, str(e)
)
self.logger.debug(self._read_response(e))
continue
Expand All @@ -263,9 +257,9 @@ def send_request(
if attempt < self.max_retries:
# do nothing, try
self.logger.warning(
"Retrying due to {}: {}".format(
connection_error.__class__.__name__, str(connection_error)
)
"Retrying due to %s: %s",
connection_error.__class__.__name__,
str(connection_error),
)
continue
raise ClientConnectionError(
Expand All @@ -274,15 +268,10 @@ def send_request(
)
) from connection_error

self.logger.debug("RESPONSE: %d %s", response.code, response.url)
self.logger.debug(
"RESPONSE: {0:d} {1:s}".format(response.code, response.url)
)
self.logger.debug(
"RES HEADERS: \n{0!s}".format(
"\n".join(
["{}: {}".format(k, v) for k, v in response.info().items()]
)
)
"RES HEADERS: \n%s",
"\n".join(["{}: {}".format(k, v) for k, v in response.info().items()]),
)
if not decode_response:
return self._read_response(response, decode_response)
Expand Down

0 comments on commit 7cd0431

Please sign in to comment.