From d53bca49d7bca97ffa12c307f0efc3cc38e33f70 Mon Sep 17 00:00:00 2001 From: jm Date: Mon, 5 Oct 2026 21:57:34 +0200 Subject: [PATCH 1/2] fix(client): log expected 401/404 fetch failures as concise warnings fetch_resource logged every non-200 response as ERROR together with the whole response body. In production (TUL DSpace) this produced alarming ERROR lines for two situations that are handled and harmless: - 401 "Authentication is required": the session token expired; the calling application re-authenticates and retries successfully. - 404 on /core/items//bundles: the item was deleted from DSpace; get_bundles already turns that into an empty result. Both are now a one-line WARNING naming the status and the request path (not the body). Every other status still logs ERROR, now with the status code and path, and the body capped at 500 characters so one failure cannot flood the log. Recording the failing response in _last_err is unchanged. --- dspace_rest_client/client.py | 17 +++++++++++++- tests/test_client_read.py | 45 ++++++++++++++++++++++++++++++++++++ 2 files changed, 61 insertions(+), 1 deletion(-) diff --git a/dspace_rest_client/client.py b/dspace_rest_client/client.py index 061680f..154f275 100644 --- a/dspace_rest_client/client.py +++ b/dspace_rest_client/client.py @@ -17,6 +17,7 @@ import json import logging import os +from urllib.parse import urlparse from uuid import UUID import requests @@ -26,6 +27,9 @@ __all__ = ['DSpaceClient'] +# cap on the response body echoed into an error log line +_ERR_BODY_MAX = 500 + _logger = logging.getLogger("dspace.client") # A library must not configure the root logger - that is the consuming # application's job. Attach a NullHandler (once) so records are dropped unless @@ -522,7 +526,18 @@ def fetch_resource(self, url, params=None): # record the failing response so callers can tell a 404 (the # resource is gone) from a transient 5xx before we drop the body self._last_err = r - _logger.error(f'Error encountered fetching resource: {r.text}') + path = urlparse(r.url).path + if r.status_code == 401: + _logger.warning( + f'DSpace returned 401 for [{path}] - session token probably ' + 'expired, the caller re-authenticates') + elif r.status_code == 404: + _logger.warning( + f'DSpace returned 404 for [{path}] - resource not found (deleted?)') + else: + _logger.error( + f'Error encountered fetching resource: {r.status_code} for ' + f'[{path}]: {r.text[:_ERR_BODY_MAX]}') return None # ValueError / JSON handling moved to static method return parse_json(r) diff --git a/tests/test_client_read.py b/tests/test_client_read.py index f48b04a..2efcc4c 100644 --- a/tests/test_client_read.py +++ b/tests/test_client_read.py @@ -337,6 +337,51 @@ def test_404_returns_none_and_records_last_err(self): self.assertIsNone(c.fetch_resource(url)) self.assertEqual(c.last_err.status_code, 404) + def test_401_logs_warning_with_path_not_body(self): + # an expired session token: the caller re-authenticates and retries, + # so this is not an ERROR and the JSON body is noise + c = make_client() + url = f"{API}/core/items/{ITEM_UUID}/bundles" + with requests_mock.Mocker() as m: + m.get(url, status_code=401, + json={"status": 401, "message": "Authentication is required"}) + with self.assertLogs("dspace.client", level="WARNING") as logs: + self.assertIsNone(c.fetch_resource(url, params={"size": 10})) + self.assertEqual(c.last_err.status_code, 401) + self.assertEqual(logs.output, [ + "WARNING:dspace.client:DSpace returned 401 for " + f"[/server/api/core/items/{ITEM_UUID}/bundles] - session token " + "probably expired, the caller re-authenticates"]) + + def test_404_logs_warning_with_path_not_body(self): + c = make_client() + url = f"{API}/core/items/{ITEM_UUID}/bundles" + with requests_mock.Mocker() as m: + m.get(url, status_code=404, json={"timestamp": "2026-01-01"}) + with self.assertLogs("dspace.client", level="WARNING") as logs: + self.assertIsNone(c.fetch_resource(url)) + self.assertEqual(logs.output, [ + "WARNING:dspace.client:DSpace returned 404 for " + f"[/server/api/core/items/{ITEM_UUID}/bundles] - resource not " + "found (deleted?)"]) + + def test_other_error_logs_error_with_truncated_body(self): + c = make_client() + url = f"{API}/core/items/{ITEM_UUID}/bundles" + with requests_mock.Mocker() as m: + m.get(url, status_code=500, text="boom" + "x" * 5000) + with self.assertLogs("dspace.client", level="WARNING") as logs: + self.assertIsNone(c.fetch_resource(url)) + self.assertEqual(c.last_err.status_code, 500) + self.assertEqual(len(logs.records), 1) + rec = logs.records[0] + self.assertEqual(rec.levelname, "ERROR") + msg = rec.getMessage() + self.assertIn("500", msg) + self.assertIn(f"/server/api/core/items/{ITEM_UUID}/bundles", msg) + self.assertIn("boom", msg) + self.assertLess(len(msg), 1000) + if __name__ == "__main__": unittest.main() From d1343a53d25db1eae52bf837672083561d700e79 Mon Sep 17 00:00:00 2001 From: jm Date: Mon, 5 Oct 2026 22:35:46 +0200 Subject: [PATCH 2/2] fix(client): neutral 401 wording, keep the query in logged paths Review follow-up. The 401 warning claimed that the caller re-authenticates, which the library cannot know, and ignored clients that never logged in. It now reads "authentication required (session expired or not logged in)". The logged path keeps the query string for 401, 404 and other errors. On search endpoints such as /authz/resourcepolicies/search/resource the uuid in the query is the only identifier of the failing resource. --- dspace_rest_client/client.py | 8 +++++--- tests/test_client_read.py | 23 +++++++++++------------ 2 files changed, 16 insertions(+), 15 deletions(-) diff --git a/dspace_rest_client/client.py b/dspace_rest_client/client.py index 154f275..259db32 100644 --- a/dspace_rest_client/client.py +++ b/dspace_rest_client/client.py @@ -526,11 +526,13 @@ def fetch_resource(self, url, params=None): # record the failing response so callers can tell a 404 (the # resource is gone) from a transient 5xx before we drop the body self._last_err = r - path = urlparse(r.url).path + # keep the query: on search endpoints it holds the only resource id + u = urlparse(r.url) + path = f'{u.path}?{u.query}' if u.query else u.path if r.status_code == 401: _logger.warning( - f'DSpace returned 401 for [{path}] - session token probably ' - 'expired, the caller re-authenticates') + f'DSpace returned 401 for [{path}] - authentication required ' + '(session expired or not logged in)') elif r.status_code == 404: _logger.warning( f'DSpace returned 404 for [{path}] - resource not found (deleted?)') diff --git a/tests/test_client_read.py b/tests/test_client_read.py index 2efcc4c..ffa058e 100644 --- a/tests/test_client_read.py +++ b/tests/test_client_read.py @@ -338,8 +338,7 @@ def test_404_returns_none_and_records_last_err(self): self.assertEqual(c.last_err.status_code, 404) def test_401_logs_warning_with_path_not_body(self): - # an expired session token: the caller re-authenticates and retries, - # so this is not an ERROR and the JSON body is noise + # expired session token or a client that never logged in c = make_client() url = f"{API}/core/items/{ITEM_UUID}/bundles" with requests_mock.Mocker() as m: @@ -350,20 +349,21 @@ def test_401_logs_warning_with_path_not_body(self): self.assertEqual(c.last_err.status_code, 401) self.assertEqual(logs.output, [ "WARNING:dspace.client:DSpace returned 401 for " - f"[/server/api/core/items/{ITEM_UUID}/bundles] - session token " - "probably expired, the caller re-authenticates"]) + f"[/server/api/core/items/{ITEM_UUID}/bundles?size=10] - " + "authentication required (session expired or not logged in)"]) - def test_404_logs_warning_with_path_not_body(self): + def test_404_logs_warning_with_path_and_query_not_body(self): + # on search endpoints the query carries the only id of the resource c = make_client() - url = f"{API}/core/items/{ITEM_UUID}/bundles" + url = f"{API}/authz/resourcepolicies/search/resource" with requests_mock.Mocker() as m: m.get(url, status_code=404, json={"timestamp": "2026-01-01"}) with self.assertLogs("dspace.client", level="WARNING") as logs: - self.assertIsNone(c.fetch_resource(url)) + self.assertIsNone(c.fetch_resource(url, params={"uuid": ITEM_UUID})) self.assertEqual(logs.output, [ "WARNING:dspace.client:DSpace returned 404 for " - f"[/server/api/core/items/{ITEM_UUID}/bundles] - resource not " - "found (deleted?)"]) + f"[/server/api/authz/resourcepolicies/search/resource?uuid={ITEM_UUID}]" + " - resource not found (deleted?)"]) def test_other_error_logs_error_with_truncated_body(self): c = make_client() @@ -371,17 +371,16 @@ def test_other_error_logs_error_with_truncated_body(self): with requests_mock.Mocker() as m: m.get(url, status_code=500, text="boom" + "x" * 5000) with self.assertLogs("dspace.client", level="WARNING") as logs: - self.assertIsNone(c.fetch_resource(url)) + self.assertIsNone(c.fetch_resource(url, params={"size": 10})) self.assertEqual(c.last_err.status_code, 500) self.assertEqual(len(logs.records), 1) rec = logs.records[0] self.assertEqual(rec.levelname, "ERROR") msg = rec.getMessage() self.assertIn("500", msg) - self.assertIn(f"/server/api/core/items/{ITEM_UUID}/bundles", msg) + self.assertIn(f"[/server/api/core/items/{ITEM_UUID}/bundles?size=10]", msg) self.assertIn("boom", msg) self.assertLess(len(msg), 1000) - if __name__ == "__main__": unittest.main()