diff --git a/scripts/hotmail_helper.py b/scripts/hotmail_helper.py index 0a21d10..806ecad 100644 --- a/scripts/hotmail_helper.py +++ b/scripts/hotmail_helper.py @@ -76,8 +76,11 @@ def json_response(handler, status, payload): handler.send_header("Access-Control-Allow-Origin", "*") handler.send_header("Access-Control-Allow-Headers", "Content-Type") handler.send_header("Access-Control-Allow-Methods", "POST, OPTIONS") - handler.end_headers() - handler.wfile.write(body) + try: + handler.end_headers() + handler.wfile.write(body) + except (BrokenPipeError, ConnectionResetError) as exc: + log_info(f"response aborted by client status={status} detail={compact_text(exc)}") def read_json_payload(handler): @@ -120,6 +123,45 @@ def log_info(message): print(f"[HotmailHelper] {message}", flush=True) +def get_proxy_debug_context(): + names = ["all_proxy", "http_proxy", "https_proxy", "ALL_PROXY", "HTTP_PROXY", "HTTPS_PROXY"] + parts = [] + for name in names: + value = str(os.environ.get(name) or "").strip() + if value: + parts.append(f"{name}={value}") + return ",".join(parts) if parts else "direct" + + +def classify_token_refresh_failure(result): + detail = str(result.get("error") or "").strip().lower() + if "invalid_grant" in detail or "aadsts70000" in detail: + return "invalid_grant" + if "proxy authentication required" in detail: + return "proxy_auth_failed" + if "connection refused" in detail: + return "proxy_connect_failed" if get_proxy_debug_context() != "direct" else "connection_refused" + if "eof occurred in violation of protocol" in detail or "wrong version number" in detail: + return "proxy_tls_failed" if get_proxy_debug_context() != "direct" else "tls_failed" + if "timed out" in detail or "timeout" in detail: + return "network_timeout" + return "request_failed" + + +def log_token_refresh_failure_diagnosis(result): + category = classify_token_refresh_failure(result) + message = ( + "token refresh diagnosis " + f"endpoint={result['endpoint']} " + f"category={category}" + ) + if category.startswith("proxy_"): + message += f" proxy={get_proxy_debug_context()}" + elif category == "invalid_grant": + message += " hint=refresh_token_or_scope_invalid" + log_info(message) + + def append_account_log(email_addr, password, status, recorded_at="", reason=""): normalized_email = str(email_addr or "").strip() normalized_password = str(password or "").strip() @@ -320,6 +362,7 @@ def refresh_access_token(client_id, refresh_token, strategy_names=None): f"elapsedMs={result['elapsed_ms']} " f"detail={result['error']}" ) + log_token_refresh_failure_diagnosis(result) details = " | ".join( f"{item['endpoint']}({item['status']}): {item['error']}" @@ -532,12 +575,12 @@ def normalize_outlook_message(message, mailbox): def fetch_graph_messages(access_token, mailbox="INBOX", top=FETCH_LIMIT_DEFAULT): mailbox_id = normalize_mailbox_id(mailbox) - url = ( - f"{GRAPH_API_ORIGIN}/v1.0/me/mailFolders/{mailbox_id}/messages" - f"?$top={max(1, min(int(top or FETCH_LIMIT_DEFAULT), 30))}" - f"&$select=id,internetMessageId,subject,from,bodyPreview,receivedDateTime" - f"&$orderby=receivedDateTime desc" - ) + query = urlencode({ + "$top": max(1, min(int(top or FETCH_LIMIT_DEFAULT), 30)), + "$select": "id,internetMessageId,subject,from,bodyPreview,receivedDateTime", + "$orderby": "receivedDateTime desc", + }) + url = f"{GRAPH_API_ORIGIN}/v1.0/me/mailFolders/{mailbox_id}/messages?{query}" try: _, payload = get_json(url, headers={ "Accept": "application/json", @@ -555,12 +598,12 @@ def fetch_graph_messages(access_token, mailbox="INBOX", top=FETCH_LIMIT_DEFAULT) def fetch_outlook_api_messages(access_token, mailbox="INBOX", top=FETCH_LIMIT_DEFAULT): mailbox_id = normalize_mailbox_id(mailbox) - url = ( - f"{OUTLOOK_API_ORIGIN}/api/v2.0/me/mailfolders/{mailbox_id}/messages" - f"?$top={max(1, min(int(top or FETCH_LIMIT_DEFAULT), 30))}" - f"&$select=Id,Subject,From,BodyPreview,ReceivedDateTime" - f"&$orderby=ReceivedDateTime desc" - ) + query = urlencode({ + "$top": max(1, min(int(top or FETCH_LIMIT_DEFAULT), 30)), + "$select": "Id,Subject,From,BodyPreview,ReceivedDateTime", + "$orderby": "ReceivedDateTime desc", + }) + url = f"{OUTLOOK_API_ORIGIN}/api/v2.0/me/mailfolders/{mailbox_id}/messages?{query}" try: _, payload = get_json(url, headers={ "Accept": "application/json", diff --git a/tests/hotmail_helper_logging_test.py b/tests/hotmail_helper_logging_test.py new file mode 100644 index 0000000..dade9e4 --- /dev/null +++ b/tests/hotmail_helper_logging_test.py @@ -0,0 +1,73 @@ +import importlib.util +import io +import unittest +from contextlib import redirect_stdout +from pathlib import Path +from unittest import mock + + +def load_hotmail_helper(): + module_path = Path(__file__).resolve().parents[1] / "scripts" / "hotmail_helper.py" + spec = importlib.util.spec_from_file_location("hotmail_helper", module_path) + module = importlib.util.module_from_spec(spec) + spec.loader.exec_module(module) + return module + + +hotmail_helper = load_hotmail_helper() + + +class HotmailHelperLoggingTest(unittest.TestCase): + def test_refresh_access_token_logs_invalid_grant_and_direct_connection_refused_separately(self): + failures = [ + { + "ok": False, + "endpoint": "entra-common-delegated", + "url": "https://login.microsoftonline.com/common/oauth2/v2.0/token", + "status": 400, + "error": '{"error":"invalid_grant","error_description":"AADSTS70000"}', + "elapsed_ms": 101, + }, + { + "ok": False, + "endpoint": "entra-consumers-delegated", + "url": "https://login.microsoftonline.com/consumers/oauth2/v2.0/token", + "status": None, + "error": "Token request failed: ", + "elapsed_ms": 88, + }, + ] + + with mock.patch.object(hotmail_helper, "try_refresh_access_token", side_effect=failures): + output = io.StringIO() + with redirect_stdout(output): + with self.assertRaises(RuntimeError): + hotmail_helper.refresh_access_token( + "client-id-demo", + "refresh-token-demo", + ["entra-common-delegated", "entra-consumers-delegated"], + ) + + rendered = output.getvalue() + self.assertIn("category=invalid_grant", rendered) + self.assertIn("category=connection_refused", rendered) + + def test_graph_and_outlook_message_urls_are_encoded(self): + captured_urls = [] + + def fake_get_json(url, headers=None): + captured_urls.append(url) + return 200, {"value": []} + + with mock.patch.object(hotmail_helper, "get_json", side_effect=fake_get_json): + hotmail_helper.fetch_graph_messages("access-token-demo", mailbox="INBOX", top=5) + hotmail_helper.fetch_outlook_api_messages("access-token-demo", mailbox="INBOX", top=5) + + self.assertEqual(len(captured_urls), 2) + self.assertTrue(all(" " not in url for url in captured_urls)) + self.assertIn("%24orderby=receivedDateTime+desc", captured_urls[0]) + self.assertIn("%24orderby=ReceivedDateTime+desc", captured_urls[1]) + + +if __name__ == "__main__": + unittest.main()