From 7f79da11e696b05c2b859b588b277e4393088fba Mon Sep 17 00:00:00 2001 From: Alex <25013571+alexhb1@users.noreply.github.com> Date: Wed, 11 Mar 2026 19:59:12 +0000 Subject: [PATCH] Activity routes logging (#736) - Added specific logging for activity routes errors - Fixed scrollbars --- shelfmark/core/activity_routes.py | 122 ++++++++++++++++++++++++- src/frontend/src/styles.css | 4 + tests/core/test_activity_routes_api.py | 34 +++++++ 3 files changed, 155 insertions(+), 5 deletions(-) diff --git a/shelfmark/core/activity_routes.py b/shelfmark/core/activity_routes.py index 05357d22..7cd557e2 100644 --- a/shelfmark/core/activity_routes.py +++ b/shelfmark/core/activity_routes.py @@ -39,10 +39,15 @@ def _log_activity_rejection( *, status_code: int, reason: str, + auth_mode: Any = None, + viewer_scope: Any = None, item_type: Any = None, item_key: Any = None, item_count: int | None = None, missing_item_keys: list[str] | None = None, + owner_user_id: Any = None, + final_status: Any = None, + request_id: Any = None, ) -> None: parts = [ f"Activity {action} rejected", @@ -54,6 +59,10 @@ def _log_activity_rejection( f"db_user_id={_normalize_log_field(session.get('db_user_id'))}", f"is_admin={bool(session.get('is_admin', False))}", ] + if auth_mode is not None: + parts.append(f"auth_mode={_normalize_log_field(auth_mode)}") + if viewer_scope is not None: + parts.append(f"viewer_scope={_normalize_log_field(viewer_scope)}") if item_type is not None: parts.append(f"item_type={_normalize_log_field(item_type)}") if item_key is not None: @@ -62,6 +71,12 @@ def _log_activity_rejection( parts.append(f"item_count={item_count}") if missing_item_keys: parts.append(f"missing_item_keys={','.join(missing_item_keys)}") + if owner_user_id is not None: + parts.append(f"owner_user_id={_normalize_log_field(owner_user_id)}") + if final_status is not None: + parts.append(f"final_status={_normalize_log_field(final_status)}") + if request_id is not None: + parts.append(f"request_id={_normalize_log_field(request_id)}") logger.warning(" ".join(parts)) @@ -71,19 +86,29 @@ def _activity_error_response( status_code: int, error: str, code: str | None = None, + auth_mode: Any = None, + viewer_scope: Any = None, item_type: Any = None, item_key: Any = None, item_count: int | None = None, missing_item_keys: list[str] | None = None, + owner_user_id: Any = None, + final_status: Any = None, + request_id: Any = None, ): _log_activity_rejection( action, status_code=status_code, reason=error, + auth_mode=auth_mode, + viewer_scope=viewer_scope, item_type=item_type, item_key=item_key, item_count=item_count, missing_item_keys=missing_item_keys, + owner_user_id=owner_user_id, + final_status=final_status, + request_id=request_id, ) payload: dict[str, Any] = {"error": error} @@ -99,7 +124,12 @@ def _require_authenticated(resolve_auth_mode: Callable[[], str], *, action: str) if auth_mode == "none": return None if "user_id" not in session: - return _activity_error_response(action, status_code=401, error="Unauthorized") + return _activity_error_response( + action, + status_code=401, + error="Unauthorized", + auth_mode=auth_mode, + ) return None @@ -108,6 +138,7 @@ def _resolve_db_user_id( *, user_db: UserDB | None = None, action: str | None = None, + auth_mode: str | None = None, ): raw_db_user_id = session.get("db_user_id") if raw_db_user_id is None: @@ -118,6 +149,7 @@ def _resolve_db_user_id( status_code=403, error="User identity unavailable for activity workflow", code="user_identity_unavailable", + auth_mode=auth_mode, ) try: parsed_db_user_id = int(raw_db_user_id) @@ -129,6 +161,7 @@ def _resolve_db_user_id( status_code=403, error="User identity unavailable for activity workflow", code="user_identity_unavailable", + auth_mode=auth_mode, ) if parsed_db_user_id < 1: @@ -139,6 +172,7 @@ def _resolve_db_user_id( status_code=403, error="User identity unavailable for activity workflow", code="user_identity_unavailable", + auth_mode=auth_mode, ) if user_db is not None: @@ -155,6 +189,7 @@ def _resolve_db_user_id( status_code=403, error="User identity unavailable for activity workflow", code="user_identity_unavailable", + auth_mode=auth_mode, ) return parsed_db_user_id, None @@ -178,7 +213,8 @@ def _resolve_activity_actor( Returns (actor, error_response). On success actor is non-None. """ - if resolve_auth_mode() == "none": + auth_mode = resolve_auth_mode() + if auth_mode == "none": return _ActorContext( db_user_id=None, is_no_auth=True, @@ -187,7 +223,11 @@ def _resolve_activity_actor( viewer_scope=NOAUTH_VIEWER_SCOPE, ), None - db_user_id, db_gate = _resolve_db_user_id(user_db=user_db, action=action) + db_user_id, db_gate = _resolve_db_user_id( + user_db=user_db, + action=action, + auth_mode=auth_mode, + ) if db_user_id is None: return None, db_gate @@ -234,6 +274,21 @@ def _check_terminal_request(row: dict[str, Any]) -> Any | None: return None +def _download_row_log_context(row: dict[str, Any]) -> dict[str, Any]: + return { + "owner_user_id": normalize_positive_int(row.get("user_id")), + "final_status": row.get("final_status"), + "request_id": normalize_positive_int(row.get("request_id")), + } + + +def _request_row_log_context(row: dict[str, Any]) -> dict[str, Any]: + return { + "owner_user_id": normalize_positive_int(row.get("user_id")), + "request_id": normalize_positive_int(row.get("id")), + } + + def _list_visible_requests(user_db: UserDB, *, is_admin: bool, db_user_id: int | None) -> list[dict[str, Any]]: if is_admin: request_rows = user_db.list_requests() @@ -490,6 +545,8 @@ def register_activity_routes( "dismiss", status_code=400, error="item_key must be in the format download:", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="download", item_key=item_key, ) @@ -500,6 +557,8 @@ def register_activity_routes( "dismiss", status_code=404, error="Download not found", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="download", item_key=f"download:{task_id}", ) @@ -510,8 +569,11 @@ def register_activity_routes( "dismiss", status_code=403, error=ownership_error, + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="download", item_key=f"download:{task_id}", + **_download_row_log_context(existing), ) terminal_error = _check_terminal_download(existing) if terminal_error is not None: @@ -519,8 +581,11 @@ def register_activity_routes( "dismiss", status_code=409, error=terminal_error, + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="download", item_key=f"download:{task_id}", + **_download_row_log_context(existing), ) activity_view_state_service.dismiss( @@ -537,6 +602,8 @@ def register_activity_routes( "dismiss", status_code=400, error="item_key must be in the format request:", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="request", item_key=item_key, ) @@ -547,8 +614,11 @@ def register_activity_routes( "dismiss", status_code=404, error="Request not found", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="request", item_key=f"request:{request_id}", + request_id=request_id, ) ownership_error = _check_item_ownership(actor, request_row) @@ -557,8 +627,11 @@ def register_activity_routes( "dismiss", status_code=403, error=ownership_error, + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="request", item_key=f"request:{request_id}", + **_request_row_log_context(request_row), ) terminal_error = _check_terminal_request(request_row) if terminal_error is not None: @@ -566,8 +639,11 @@ def register_activity_routes( "dismiss", status_code=409, error=terminal_error, + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="request", item_key=f"request:{request_id}", + **_request_row_log_context(request_row), ) activity_view_state_service.dismiss( @@ -581,6 +657,8 @@ def register_activity_routes( "dismiss", status_code=400, error="item_type must be one of: download, request", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type=item_type, item_key=item_key, ) @@ -615,10 +693,22 @@ def register_activity_routes( data = request.get_json(silent=True) if not isinstance(data, dict): - return _activity_error_response("dismiss_many", status_code=400, error="Invalid payload") + return _activity_error_response( + "dismiss_many", + status_code=400, + error="Invalid payload", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, + ) items = data.get("items") if not isinstance(items, list): - return _activity_error_response("dismiss_many", status_code=400, error="items must be an array") + return _activity_error_response( + "dismiss_many", + status_code=400, + error="items must be an array", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, + ) dismissal_items: list[dict[str, str]] = [] missing_item_keys: list[str] = [] @@ -629,6 +719,8 @@ def register_activity_routes( "dismiss_many", status_code=400, error="items must contain objects", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_count=len(items), ) @@ -642,6 +734,8 @@ def register_activity_routes( "dismiss_many", status_code=400, error="download item_key must be in the format download:", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="download", item_key=item_key, item_count=len(items), @@ -656,9 +750,12 @@ def register_activity_routes( "dismiss_many", status_code=403, error=ownership_error, + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="download", item_key=f"download:{task_id}", item_count=len(items), + **_download_row_log_context(existing), ) terminal_error = _check_terminal_download(existing) if terminal_error is not None: @@ -666,9 +763,12 @@ def register_activity_routes( "dismiss_many", status_code=409, error=terminal_error, + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="download", item_key=f"download:{task_id}", item_count=len(items), + **_download_row_log_context(existing), ) dismissal_items.append({"item_type": "download", "item_key": f"download:{task_id}"}) continue @@ -680,6 +780,8 @@ def register_activity_routes( "dismiss_many", status_code=400, error="request item_key must be in the format request:", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="request", item_key=item_key, item_count=len(items), @@ -694,9 +796,12 @@ def register_activity_routes( "dismiss_many", status_code=403, error=ownership_error, + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="request", item_key=f"request:{request_id}", item_count=len(items), + **_request_row_log_context(request_row), ) terminal_error = _check_terminal_request(request_row) if terminal_error is not None: @@ -704,9 +809,12 @@ def register_activity_routes( "dismiss_many", status_code=409, error=terminal_error, + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type="request", item_key=f"request:{request_id}", item_count=len(items), + **_request_row_log_context(request_row), ) dismissal_items.append({"item_type": "request", "item_key": f"request:{request_id}"}) continue @@ -715,6 +823,8 @@ def register_activity_routes( "dismiss_many", status_code=400, error="item_type must be one of: download, request", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_type=item_type, item_key=item_key, item_count=len(items), @@ -725,6 +835,8 @@ def register_activity_routes( "dismiss_many", status_code=404, error="One or more activity items were not found", + auth_mode=resolve_auth_mode(), + viewer_scope=actor.viewer_scope, item_count=len(items), missing_item_keys=missing_item_keys, ) diff --git a/src/frontend/src/styles.css b/src/frontend/src/styles.css index 371f5bdb..7dc47be4 100644 --- a/src/frontend/src/styles.css +++ b/src/frontend/src/styles.css @@ -22,6 +22,10 @@ ::file-selector-button { border-color: var(--color-gray-200, currentcolor); } + + html { + scrollbar-gutter: stable; + } } @theme inline { diff --git a/tests/core/test_activity_routes_api.py b/tests/core/test_activity_routes_api.py index 841347f1..d890eb6d 100644 --- a/tests/core/test_activity_routes_api.py +++ b/tests/core/test_activity_routes_api.py @@ -701,6 +701,40 @@ class TestActivityRoutes: assert f"user={admin['username']}" in log_message assert "is_admin=True" in log_message + def test_dismiss_many_logs_actor_and_row_context_for_forbidden_download(self, main_module, client): + owner = _create_user(main_module, prefix="owner") + intruder = _create_user(main_module, prefix="intruder") + _set_session(client, user_id=intruder["username"], db_user_id=intruder["id"], is_admin=False) + + _record_terminal_download( + main_module, + task_id="forbidden-download-task", + user_id=owner["id"], + username=owner["username"], + request_id=321, + final_status="complete", + ) + + with patch.object(main_module, "get_auth_mode", return_value="builtin"): + with patch("shelfmark.core.activity_routes.logger.warning") as mock_warning: + response = client.post( + "/api/activity/dismiss-many", + json={"items": [{"item_type": "download", "item_key": "download:forbidden-download-task"}]}, + ) + + assert response.status_code == 403 + assert response.json["error"] == "Forbidden" + mock_warning.assert_called_once() + log_message = mock_warning.call_args.args[0] + assert "Activity dismiss_many rejected" in log_message + assert "status=403" in log_message + assert "reason=Forbidden" in log_message + assert "auth_mode=builtin" in log_message + assert f"viewer_scope=user:{intruder['id']}" in log_message + assert f"owner_user_id={owner['id']}" in log_message + assert "final_status=complete" in log_message + assert "request_id=321" in log_message + def test_snapshot_backfills_undismissed_terminal_download_from_download_history(self, main_module, client): user = _create_user(main_module, prefix="reader") _set_session(client, user_id=user["username"], db_user_id=user["id"], is_admin=False)