diff --git a/add_links/api.py b/add_links/api.py index 0742fe2..4b9abc5 100644 --- a/add_links/api.py +++ b/add_links/api.py @@ -1,3 +1,5 @@ +import os +from pathlib import Path import re import sys import typing @@ -8,6 +10,7 @@ from simplejson.scanner import JSONDecodeError from .language import get_current_language from .util import is_disambig +from .wikimedia_api_logging import WikimediaApiLogConfig, logged_request StrDict = dict[str, typing.Any] @@ -15,6 +18,15 @@ ua = ( "find-link/2.2 " + "(https://github.com/EdwardBetts/find_link; contact: edward@4angle.com)" ) +wikimedia_log_config = WikimediaApiLogConfig( + tool="missinglink", + log_path=Path( + os.environ.get( + "MISSINGLINK_WIKIMEDIA_API_LOG", "/var/log/missinglink/wikimedia-api.jsonl" + ) + ), + user_agent=ua, +) re_disambig = re.compile(r"^(.*) \((.*)\)$") @@ -73,23 +85,22 @@ webpage_error = ( ) -def _get_active_session() -> requests.sessions.Session: - """Return OAuth session if one is available in Flask context, else plain session.""" +def _get_active_session() -> tuple[requests.sessions.Session, str]: + """Return active session and auth mode.""" try: from flask import g if hasattr(g, "oauth_session") and g.oauth_session is not None: - return g.oauth_session # type: ignore[return-value] + return g.oauth_session, "oauth" # type: ignore[return-value] except RuntimeError: pass print("WARNING: using unauthenticated session", file=sys.stderr) - return get_session() + return get_session(), "anon" def api_get(params: StrDict) -> StrDict: """Make call to Wikipedia API.""" - s = _get_active_session() - - r = s.get(get_query_url(), params=params) + s, _auth = _get_active_session() + r = logged_request(s, wikimedia_log_config, "GET", get_query_url(), params=params) try: ret: StrDict = r.json() except JSONDecodeError: @@ -287,8 +298,8 @@ def call_get_diff(title: str, section_num: int, section_text: str) -> str: "rvdifftotext": section_text.strip(), } - s = _get_active_session() - r = s.post(get_query_url(), data=data) + s, _auth = _get_active_session() + r = logged_request(s, wikimedia_log_config, "POST", get_query_url(), data=data) try: ret = r.json() except JSONDecodeError: diff --git a/add_links/mediawiki_api_old.py b/add_links/mediawiki_api_old.py index 0196207..851a43b 100644 --- a/add_links/mediawiki_api_old.py +++ b/add_links/mediawiki_api_old.py @@ -4,6 +4,9 @@ from typing import Any import requests +from .api import wikimedia_log_config +from .wikimedia_api_logging import logged_request + wiki_hostname = "en.wikipedia.org" wiki_api_php = f"https://{wiki_hostname}/w/api.php" user_agent = "dab-mechanic/0.1" @@ -27,8 +30,10 @@ def parse_page(enwiki: str) -> dict[str, Any]: def get(params: dict[str, str | int]) -> dict[str, Any]: """Make GET request to mediawiki API.""" - data: dict[str, Any] = requests.get( - wiki_api_php, headers={"User-Agent": user_agent}, params=params + session = requests.Session() + session.headers = {"User-Agent": user_agent} + data: dict[str, Any] = logged_request( + session, wikimedia_log_config, "GET", wiki_api_php, params=params ).json() return data diff --git a/add_links/mediawiki_oauth.py b/add_links/mediawiki_oauth.py index 12ebd58..69f7d9c 100644 --- a/add_links/mediawiki_oauth.py +++ b/add_links/mediawiki_oauth.py @@ -9,7 +9,8 @@ import requests from flask import current_app, session from requests_oauthlib import OAuth1Session -from .api import ua +from .api import ua, wikimedia_log_config +from .wikimedia_api_logging import logged_request wiki_hostname = "en.wikipedia.org" api_url = f"https://{wiki_hostname}/w/api.php" @@ -44,7 +45,15 @@ def api_post_request(params: dict[str, str | int], timeout: int = 4) -> requests ) oauth.headers.update({"User-Agent": ua}) proxies = get_edit_proxy() - return oauth.post(api_url, data=params, timeout=timeout, proxies=proxies) + return logged_request( + oauth, + wikimedia_log_config, + "POST", + api_url, + data=params, + timeout=timeout, + proxies=proxies, + ) def raw_request(params: typing.Mapping[str, str | int]) -> requests.Response: @@ -63,8 +72,13 @@ def raw_request(params: typing.Mapping[str, str | int]) -> requests.Response: ) oauth.headers.update({"User-Agent": ua}) proxies = get_edit_proxy() - return oauth.get( - api_url + "?" + urllib.parse.urlencode(params), timeout=4, proxies=proxies + return logged_request( + oauth, + wikimedia_log_config, + "GET", + api_url + "?" + urllib.parse.urlencode(params), + timeout=4, + proxies=proxies, ) diff --git a/add_links/wikimedia_api_logging.py b/add_links/wikimedia_api_logging.py new file mode 100644 index 0000000..8936930 --- /dev/null +++ b/add_links/wikimedia_api_logging.py @@ -0,0 +1,222 @@ +"""JSONL logging helpers for Wikimedia API request metrics.""" + +import json +import logging +import os +import socket +import time +from collections.abc import Mapping +from dataclasses import dataclass +from datetime import UTC, datetime +from pathlib import Path +from types import TracebackType +from urllib.parse import parse_qs, urlparse + +import requests + + +@dataclass(frozen=True) +class WikimediaApiLogConfig: + """Configuration for Wikimedia API request logging.""" + + tool: str + log_path: Path + user_agent: str + + +@dataclass(frozen=True) +class WikimediaApiRequestMetric: + """Details of one Wikimedia API request.""" + + tool: str + url: str + method: str + status_code: int | None + elapsed_ms: int + user_agent: str + request_params: Mapping[str, object] | None = None + error: str | None = None + + +_logger_cache: dict[Path, logging.Logger] = {} + + +def setup_wikimedia_api_logger(log_path: Path) -> logging.Logger: + """Create a JSONL logger for Wikimedia API request metrics.""" + if log_path in _logger_cache: + return _logger_cache[log_path] + + logger_name = f"wikimedia_api_metrics.{log_path}" + logger = logging.getLogger(logger_name) + logger.setLevel(logging.INFO) + logger.propagate = False + + if not logger.handlers: + try: + log_path.parent.mkdir(parents=True, exist_ok=True) + handler: logging.Handler = logging.FileHandler(log_path) + except OSError: + handler = logging.NullHandler() + handler.setFormatter(logging.Formatter("%(message)s")) + logger.addHandler(handler) + + _logger_cache[log_path] = logger + return logger + + +def get_mediawiki_action( + url: str, request_params: Mapping[str, object] | None = None +) -> str | None: + """Extract the MediaWiki API action from params or a URL, if present.""" + if request_params is not None: + action = request_params.get("action") + if isinstance(action, str): + return action + + parsed = urlparse(url) + query = parse_qs(parsed.query) + values = query.get("action") + + if not values: + return None + + return values[0] + + +def get_flask_request_context() -> tuple[str | None, str | None]: + """Return Flask endpoint and browser URL when running in a request.""" + try: + from flask import has_request_context, request + + if not has_request_context(): + return None, None + return request.endpoint, request.url + except RuntimeError: + return None, None + + +def build_log_record(metric: WikimediaApiRequestMetric) -> dict[str, object]: + """Build a JSON-serialisable log record for one API request.""" + parsed = urlparse(metric.url) + flask_endpoint, flask_url = get_flask_request_context() + + record: dict[str, object] = { + "ts": datetime.now(UTC).isoformat(), + "tool": metric.tool, + "host": socket.gethostname(), + "pid": os.getpid(), + "method": metric.method, + "api_host": parsed.netloc, + "path": parsed.path, + "action": get_mediawiki_action(metric.url, metric.request_params), + "status_code": metric.status_code, + "elapsed_ms": metric.elapsed_ms, + "user_agent": metric.user_agent, + "flask_endpoint": flask_endpoint, + "flask_url": flask_url, + } + + if metric.error is not None: + record["error"] = metric.error + + return record + + +def log_wikimedia_api_request( + logger: logging.Logger, + metric: WikimediaApiRequestMetric, +) -> None: + """Write one Wikimedia API request metric as a JSONL log line.""" + record = build_log_record(metric) + logger.info(json.dumps(record, separators=(",", ":"), sort_keys=True)) + + +class WikimediaRequestTimer: + """Context manager for timing and logging a Wikimedia API request.""" + + def __init__( + self, + config: WikimediaApiLogConfig, + method: str, + url: str, + request_params: Mapping[str, object] | None = None, + ) -> None: + self.config = config + self.method = method + self.url = url + self.request_params = request_params + self.started = 0.0 + self.logger = setup_wikimedia_api_logger(config.log_path) + + def __enter__(self) -> "WikimediaRequestTimer": + """Start timing a request.""" + self.started = time.monotonic() + return self + + def __exit__( + self, + exc_type: type[BaseException] | None, + exc: BaseException | None, + traceback: TracebackType | None, + ) -> bool: + """Log failed requests when an exception escapes.""" + if exc is None: + return False + + elapsed_ms = int((time.monotonic() - self.started) * 1000) + + log_wikimedia_api_request( + self.logger, + WikimediaApiRequestMetric( + tool=self.config.tool, + url=self.url, + method=self.method, + status_code=None, + elapsed_ms=elapsed_ms, + user_agent=self.config.user_agent, + request_params=self.request_params, + error=type(exc).__name__, + ), + ) + + return False + + def log_response(self, status_code: int, final_url: str | None = None) -> None: + """Log a completed request.""" + elapsed_ms = int((time.monotonic() - self.started) * 1000) + + log_wikimedia_api_request( + self.logger, + WikimediaApiRequestMetric( + tool=self.config.tool, + url=final_url or self.url, + method=self.method, + status_code=status_code, + elapsed_ms=elapsed_ms, + user_agent=self.config.user_agent, + request_params=self.request_params, + ), + ) + + +def logged_request( + session: requests.sessions.Session, + config: WikimediaApiLogConfig, + method: str, + url: str, + **kwargs: object, +) -> requests.Response: + """Make a Wikimedia API request and log one JSONL metric line.""" + request_params = kwargs.get("params") or kwargs.get("data") + if not isinstance(request_params, Mapping): + request_params = None + + with WikimediaRequestTimer( + config, method.upper(), url, request_params=request_params + ) as timer: + response = getattr(session, method.lower())(url, **kwargs) + final_url = getattr(response, "url", None) + timer.log_response( + response.status_code, final_url if isinstance(final_url, str) else None + ) + return response diff --git a/test_api.py b/test_api.py index 14968ca..abfd292 100644 --- a/test_api.py +++ b/test_api.py @@ -19,7 +19,7 @@ class ApiGetTests(unittest.TestCase): session = Mock() session.get.return_value = response - with patch("add_links.api._get_active_session", return_value=session): + with patch("add_links.api._get_active_session", return_value=(session, "anon")): with self.assertRaises(api.MediawikiError) as ctx: api.api_get({"action": "query"})