From b80238faa18a8ee4e89793ed95b3b49aa39176e2 Mon Sep 17 00:00:00 2001 From: Rostyslav Zatserkovnyi Date: Thu, 9 May 2024 14:51:10 +0300 Subject: [PATCH 1/3] Log HTTP referer and origin --- src/server/_common.py | 6 +++++- tests/server/test_validate.py | 17 +++++++++++++++++ 2 files changed, 22 insertions(+), 1 deletion(-) diff --git a/src/server/_common.py b/src/server/_common.py index 8633d07fd..9c2be2f59 100644 --- a/src/server/_common.py +++ b/src/server/_common.py @@ -125,7 +125,9 @@ def before_request_execute(): real_remote_addr=get_real_ip_addr(request), user_agent=request.user_agent.string, api_key=api_key, - user_id=(user and user.id) + user_id=(user and user.id), + req_referrer=request.referrer, + req_origin=request.environ.get('HTTP_ORIGIN', '') ) if not _is_public_route() and api_key and not user: @@ -171,6 +173,8 @@ def after_request_execute(response): response_status=response.status, content_length=response.calculate_content_length(), elapsed_time_ms=total_time, + req_referrer=request.referrer, + req_origin=request.environ.get('HTTP_ORIGIN', '') ) return response diff --git a/tests/server/test_validate.py b/tests/server/test_validate.py index f06e9e997..ace91d972 100644 --- a/tests/server/test_validate.py +++ b/tests/server/test_validate.py @@ -26,6 +26,7 @@ def setUp(self): app.config["TESTING"] = True app.config["WTF_CSRF_ENABLED"] = False app.config["DEBUG"] = False + self.client = app.test_client() def test_require_all(self): with self.subTest("all given"): @@ -60,3 +61,19 @@ def test_require_any(self): with self.subTest("one options given with is empty but ok"): with app.test_request_context("/?abc="): self.assertTrue(require_any(request, "abc", empty=True)) + + def test_origin_headers(self): + with self.subTest("referer and origin"): + with self.assertLogs("server_api", level='INFO') as logs: + self.client.get("/signal_dashboard_status", headers={ + "Referer": "https://test.com/test", + "Origin": "https://test.com" + }) + output = logs.output + self.assertEqual(len(output), 2) # [before_request, after_request] + self.assertIn("Received API request", output[0]) + self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[0]) + self.assertIn("\"req_origin\": \"https://test.com\"", output[0]) + self.assertIn("Served API request", output[1]) + self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[1]) + self.assertIn("\"req_origin\": \"https://test.com\"", output[1]) From 8df87d84ccf46088202295465e6d06c1f1443cef Mon Sep 17 00:00:00 2001 From: Rostyslav Zatserkovnyi Date: Fri, 10 May 2024 16:19:56 +0300 Subject: [PATCH 2/3] Post review tweaks --- src/server/_common.py | 40 ++++------------------------------- tests/server/test_validate.py | 26 ++++++++++++++++++++--- 2 files changed, 27 insertions(+), 39 deletions(-) diff --git a/src/server/_common.py b/src/server/_common.py index 9c2be2f59..410f7f405 100644 --- a/src/server/_common.py +++ b/src/server/_common.py @@ -68,6 +68,7 @@ def log_info_with_request(message, **kwargs): remote_addr=request.remote_addr, real_remote_addr=get_real_ip_addr(request), user_agent=request.user_agent.string, + req_referrer=request.referrer or request.origin, api_key=resolve_auth_token(), user_id=(current_user and current_user.id), **kwargs @@ -115,20 +116,7 @@ def before_request_execute(): api_key = resolve_auth_token() # TODO: replace this next call with: log_info_with_request("Received API request") - get_structured_logger("server_api").info( - "Received API request", - method=request.method, - url=request.url, - form_args=request.form, - req_length=request.content_length, - remote_addr=request.remote_addr, - real_remote_addr=get_real_ip_addr(request), - user_agent=request.user_agent.string, - api_key=api_key, - user_id=(user and user.id), - req_referrer=request.referrer, - req_origin=request.environ.get('HTTP_ORIGIN', '') - ) + log_info_with_request("Received API request") if not _is_public_route() and api_key and not user: # if this is a privleged endpoint, and an api key was given but it does not look up to a user, raise exception: @@ -152,30 +140,10 @@ def after_request_execute(response): # Convert to milliseconds total_time *= 1000 - api_key = resolve_auth_token() - update_key_last_time_used(current_user) - # TODO: replace this next call with: log_info_with_request_and_response("Served API request", response, elapsed_time_ms=total_time) - get_structured_logger("server_api").info( - "Served API request", - method=request.method, - url=request.url, - form_args=request.form, - req_length=request.content_length, - remote_addr=request.remote_addr, - real_remote_addr=get_real_ip_addr(request), - user_agent=request.user_agent.string, - api_key=api_key, - values=request.values.to_dict(flat=False), - blueprint=request.blueprint, - endpoint=request.endpoint, - response_status=response.status, - content_length=response.calculate_content_length(), - elapsed_time_ms=total_time, - req_referrer=request.referrer, - req_origin=request.environ.get('HTTP_ORIGIN', '') - ) + log_info_with_request_and_response("Served API request", response, elapsed_time_ms=total_time) + return response diff --git a/tests/server/test_validate.py b/tests/server/test_validate.py index ace91d972..80e104e5c 100644 --- a/tests/server/test_validate.py +++ b/tests/server/test_validate.py @@ -63,7 +63,29 @@ def test_require_any(self): self.assertTrue(require_any(request, "abc", empty=True)) def test_origin_headers(self): - with self.subTest("referer and origin"): + with self.subTest("referer only"): + with self.assertLogs("server_api", level='INFO') as logs: + self.client.get("/signal_dashboard_status", headers={ + "Referer": "https://test.com/test" + }) + output = logs.output + self.assertEqual(len(output), 2) # [before_request, after_request] + self.assertIn("Received API request", output[0]) + self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[0]) + self.assertIn("Served API request", output[1]) + self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[1]) + with self.subTest("origin only"): + with self.assertLogs("server_api", level='INFO') as logs: + self.client.get("/signal_dashboard_status", headers={ + "Origin": "https://test.com" + }) + output = logs.output + self.assertEqual(len(output), 2) # [before_request, after_request] + self.assertIn("Received API request", output[0]) + self.assertIn("\"req_referrer\": \"https://test.com\"", output[0]) + self.assertIn("Served API request", output[1]) + self.assertIn("\"req_referrer\": \"https://test.com\"", output[1]) + with self.subTest("referer overrides origin"): with self.assertLogs("server_api", level='INFO') as logs: self.client.get("/signal_dashboard_status", headers={ "Referer": "https://test.com/test", @@ -73,7 +95,5 @@ def test_origin_headers(self): self.assertEqual(len(output), 2) # [before_request, after_request] self.assertIn("Received API request", output[0]) self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[0]) - self.assertIn("\"req_origin\": \"https://test.com\"", output[0]) self.assertIn("Served API request", output[1]) self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[1]) - self.assertIn("\"req_origin\": \"https://test.com\"", output[1]) From 40d14a6ca6ed1cc4a2409548c519be851c90fc22 Mon Sep 17 00:00:00 2001 From: Rostyslav Zatserkovnyi Date: Mon, 13 May 2024 16:06:22 +0300 Subject: [PATCH 3/3] Post review tweaks again --- src/server/_common.py | 3 +-- tests/server/test_validate.py | 12 ++++++------ 2 files changed, 7 insertions(+), 8 deletions(-) diff --git a/src/server/_common.py b/src/server/_common.py index 410f7f405..33a3f9c48 100644 --- a/src/server/_common.py +++ b/src/server/_common.py @@ -68,7 +68,7 @@ def log_info_with_request(message, **kwargs): remote_addr=request.remote_addr, real_remote_addr=get_real_ip_addr(request), user_agent=request.user_agent.string, - req_referrer=request.referrer or request.origin, + referrer=request.referrer or request.origin, api_key=resolve_auth_token(), user_id=(current_user and current_user.id), **kwargs @@ -115,7 +115,6 @@ def before_request_execute(): user = current_user api_key = resolve_auth_token() - # TODO: replace this next call with: log_info_with_request("Received API request") log_info_with_request("Received API request") if not _is_public_route() and api_key and not user: diff --git a/tests/server/test_validate.py b/tests/server/test_validate.py index 80e104e5c..eff7e9c9e 100644 --- a/tests/server/test_validate.py +++ b/tests/server/test_validate.py @@ -71,9 +71,9 @@ def test_origin_headers(self): output = logs.output self.assertEqual(len(output), 2) # [before_request, after_request] self.assertIn("Received API request", output[0]) - self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[0]) + self.assertIn("\"referrer\": \"https://test.com/test\"", output[0]) self.assertIn("Served API request", output[1]) - self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[1]) + self.assertIn("\"referrer\": \"https://test.com/test\"", output[1]) with self.subTest("origin only"): with self.assertLogs("server_api", level='INFO') as logs: self.client.get("/signal_dashboard_status", headers={ @@ -82,9 +82,9 @@ def test_origin_headers(self): output = logs.output self.assertEqual(len(output), 2) # [before_request, after_request] self.assertIn("Received API request", output[0]) - self.assertIn("\"req_referrer\": \"https://test.com\"", output[0]) + self.assertIn("\"referrer\": \"https://test.com\"", output[0]) self.assertIn("Served API request", output[1]) - self.assertIn("\"req_referrer\": \"https://test.com\"", output[1]) + self.assertIn("\"referrer\": \"https://test.com\"", output[1]) with self.subTest("referer overrides origin"): with self.assertLogs("server_api", level='INFO') as logs: self.client.get("/signal_dashboard_status", headers={ @@ -94,6 +94,6 @@ def test_origin_headers(self): output = logs.output self.assertEqual(len(output), 2) # [before_request, after_request] self.assertIn("Received API request", output[0]) - self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[0]) + self.assertIn("\"referrer\": \"https://test.com/test\"", output[0]) self.assertIn("Served API request", output[1]) - self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[1]) + self.assertIn("\"referrer\": \"https://test.com/test\"", output[1])