Fixed logging

Author: Dmytro Trotsko

src/assets/js/indicatorHandler.js

@@ -365,7 +365,6 @@ class IndicatorHandler {
             $("#geographic_value").select2("data"),
             ({ geoType }) => [geoType]
         );
-        console.log(covidCastGeographicValues);
         const fluviewLocations = $("#fluviewLocations").select2("data");
         const nidssFluLocations = $("#nidssFluLocations").select2("data");
         const nidssDengueLocations = $("#nidssDengueLocations").select2("data");
@@ -378,6 +377,7 @@ class IndicatorHandler {
             nidssDengueLocations: nidssDengueLocations,
             flusurvLocations: flusurvLocations,
             apiKey: document.getElementById("apiKey").value,
+            clientId: clientId,
         };
         const csrftoken = Cookies.get("csrftoken");
         $.ajax({
@@ -426,6 +426,7 @@ class IndicatorHandler {
             nidssDengueLocations: nidssDengueLocations,
             flusurvLocations: flusurvLocations,
             apiKey: document.getElementById("apiKey").value,
+            clientId: clientId,
         }
         const csrftoken = Cookies.get("csrftoken");
         $.ajax({
@@ -476,6 +477,7 @@ class IndicatorHandler {
             nidssDengueLocations: nidssDengueLocations,
             flusurvLocations: flusurvLocations,
             apiKey: document.getElementById("apiKey").value,
+            clientId: clientId,
         }
         const csrftoken = Cookies.get("csrftoken");
         $.ajax({
@@ -526,6 +528,7 @@ class IndicatorHandler {
             nidssDengueLocations: nidssDengueLocations,
             flusurvLocations: flusurvLocations,
             apiKey: document.getElementById("apiKey").value,
+            clientId: clientId,
         }
         const csrftoken = Cookies.get("csrftoken");
         var createQueryCodePython = `<h4>PYTHON PACKAGE</h4>`

src/epiportal/settings.py

@@ -342,3 +342,38 @@
 # django docs
 # https://django-docs.readthedocs.io/en/latest/
 DOCS_ROOT = os.path.join(BASE_DIR, 'docs', 'build', 'html')
+
+
+"""
+REVERSE_PROXY_DEPTH is an integer value that indicates how many "chained" and trusted reverse proxies (like nginx) this
+ server instance is running behind.  "chained" refers to proxies forwarding to other proxies, and then ultimately
+ forwarding to the app server itself.  each of these proxies appends the remote address of the request to the
+ "X-Forwarded-For" header.  in many situations, the most externally facing proxy (the first in the chain, the one that
+ faces the "open internet") can and should be set to write its own "X-Forwarded-For" header, ignoring and replacing
+ (or creating anew, if it didnt exist) such a header from the client request -- thus preserving the chain of trusted
+ proxies under our control.
+
+however, in our typical production environment, the most externally facing "proxy" is the AWS application load balancer,
+ which seemingly cannot be configured to provide this trust boundary without losing the referring client address
+ (see: https://docs.aws.amazon.com/elasticloadbalancing/latest/application/x-forwarded-headers.html ).  accordingly, in
+ our current typical production environment, REVERSE_PROXY_DEPTH should be set to "2": one for the AWS application load
+ balancer, and one for our own nginx/haproxy instance.  thus "2" is our default value.
+
+it is important that REVERSE_PROXY_DEPTH is set accurately for two reasons...
+
+setting it too high (or to -1) will respect more of the entries in the "X-Forwarded-For" header than are appropriate.
+ this can allow remote addresses to be "spoofed" when a client fakes this header, carrying security/identity
+ implications.  in dev and testing, it is not particularly dangerous for this variable to be set to -1 (special case
+ for an "infinite" depth, where any and all proxy hops will be trusted).
+
+setting it too low can hinder logging accuracy -- that can cause an intermediate proxy IP address to be used as the
+ "real" client IP address, which could cause requests to be rate-limited inappropriately.
+
+setting REVERSE_PROXY_DEPTH to "0" essentially indicates there are no proxies between this server and the outside
+ world.  in this case, the "X-Forwarded-For" header is ignored.
+"""
+REVERSE_PROXY_DEPTH = int(os.environ.get("PROXY_DEPTH", 4))
+# TODO: ^ this value should be "4" for the prod CC API server processes, and is currently unclear
+#       for prod AWS API server processes (but should be the same or lower)...  when thats properly
+#       determined, set the default to the minimum of the two environments and special case the
+#       other in conf file(s).

src/indicatorsets/utils.py

@@ -8,11 +8,15 @@
 from django.conf import settings
 from django.http import JsonResponse
 from epiweeks import Week
+from delphi_utils import get_structured_logger
 
 from indicatorsets.models import IndicatorSet
 
 FLUVIEW_INDICATORS_MAPPING = {"wili": "%wILI", "ili": "%ILI"}
 
+form_data_logger = get_structured_logger("form_data_logger")
+form_stats_logger = get_structured_logger("form_stats_logger")
+
 
 def list_to_dict(lst):
     result = {}
@@ -633,16 +637,37 @@ def generate_query_code_flusurv(flusurv_geos, start_date, end_date):
     return python_code_blocks, r_code_blocks
 
 
-def get_client_ip(request):
-    x_forwarded_for = request.META.get("HTTP_X_FORWARDED_FOR")
-    return (
-        x_forwarded_for.split(",")[0]
-        if x_forwarded_for
-        else request.META.get("REMOTE_ADDR")
-    )
+def get_real_ip_addr(req):  # `req` should be a Flask.request object
+    if settings.REVERSE_PROXY_DEPTH:
+        # we only expect/trust (up to) "REVERSE_PROXY_DEPTH" number of proxies between this server and the outside world.
+        # a REVERSE_PROXY_DEPTH of 0 means not proxied, i.e. server is globally directly reachable.
+        # a negative proxy depth is a special case to trust the whole chain -- not generally recommended unless the
+        # most-external proxy is configured to disregard "X-Forwarded-For" from outside.
+        # really, ONLY trust the following headers if reverse proxied!!!
+        x_forwarded_for = req.META.get('HTTP_X_FORWARDED_FOR')
+
+        if x_forwarded_for:
+            full_proxy_chain = x_forwarded_for.split(",")
+            # eliminate any extra addresses at the front of this list, as they could be spoofed.
+            if settings.REVERSE_PROXY_DEPTH > 0:
+                depth = settings.REVERSE_PROXY_DEPTH
+            else:
+                # special case for -1/negative: setting `depth` to 0 will not strip any items from the chain
+                depth = 0
+            trusted_proxy_chain = full_proxy_chain[-depth:]
+            # accept the first (or only) address in the remaining trusted part of the chain as the actual remote address
+            return trusted_proxy_chain[0].strip()
+
+        # fall back to "X-Real-Ip" if "X-Forwarded-For" isnt present
+        x_real_ip = req.META.get('HTTP_X_REAL_IP')
+        if x_real_ip:
+            return x_real_ip
+
+    # if we are not proxied (or we are proxied but the headers werent present and we fell through to here), just use the remote ip addr as the true client address
+    return req.META.get('REMOTE_ADDR')
 
 
-def log_form_stats(request, data, form_mode, logger):
+def log_form_stats(request, data, form_mode):
     log_data = {
         "form_mode": form_mode,
         "num_of_indicators": len(data.get("indicators", [])),
@@ -660,14 +685,15 @@ def log_form_stats(request, data, form_mode, logger):
         ),
         "api_key_used": bool(data.get("api_key")),
         "api_key": data.get("api_key", "")[:4] + "..." if data.get("api_key") else "",
-        "user_ip": get_client_ip(request),
+        "user_ip": get_real_ip_addr(request),
         "user_ga_id": data.get("clientId", "") if data.get("clientId") else "",
     }
+    form_stats_logger.info("form_stats", clientId=data.get("clientId", ""))
 
-    logger.info(log_data)
+    form_stats_logger.info("form_stats", **log_data)
 
 
-def log_form_data(request, data, form_mode, logger):
+def log_form_data(request, data, form_mode):
     indicators = data.get("indicators", [])
     indicators = [
         {
@@ -735,7 +761,7 @@ def log_form_data(request, data, form_mode, logger):
         "epiweeks": get_epiweek(data.get("start_date", ""), data.get("end_date", "")) if data.get("start_date") and data.get("end_date") else [],  # fmt: skip
         "api_key_used": bool(data.get("apiKey")),
         "api_key": data.get("apiKey", "") if data.get("apiKey") else "",
-        "user_ip": get_client_ip(request),
+        "user_ip": get_real_ip_addr(request),
         "user_ga_id": data.get("clientId", "") if data.get("clientId") else "",
     }
-    logger.info(log_data)
+    form_data_logger.info("form_data", **log_data)

src/indicatorsets/views.py

@@ -36,15 +36,13 @@
     generate_query_code_nidss_dengue,
     generate_query_code_flusurv,
     log_form_data,
-    log_form_stats
+    log_form_stats,
 )
 
 from delphi_utils import get_structured_logger
 
 indicatorsets_logger = get_structured_logger("indicatorsets_logger")
 
-form_data_logger = get_structured_logger("form_data_logger")
-form_stats_logger = get_structured_logger("form_stats_logger")
 
 HEADER_DESCRIPTION = "Discover, display and download real-time infectious disease indicators (time series) that track a variety of pathogens, diseases and syndromes in a variety of locations (primarily within the USA). Browse the list, or filter it first by locations and pathogens of interest, by surveillance categories, and more. Expand any row to expose and select from a set of related indicators, then hit 'Show Selected Indicators' at bottom to plot or export your selected indicators, or to generate code snippets to retrieve them from the Delphi Epidata API. Most indicators are served from the Delphi Epidata real-time repository, but some may be available only from third parties or may require prior approval."
 
@@ -256,8 +254,8 @@ def epivis(request):
         nidss_flu_locations = data.get("nidssFluLocations", [])
         nidss_dengue_locations = data.get("nidssDengueLocations", [])
         flusurv_locations = data.get("flusurvLocations", [])
-        log_form_stats(request, data, "epivis", form_stats_logger)
-        log_form_data(request, data, "epivis", form_data_logger)
+        log_form_stats(request, data, "epivis")
+        log_form_data(request, data, "epivis")
         for indicator in indicators:
             if indicator["_endpoint"] == "covidcast":
                 datasets.extend(
@@ -306,8 +304,8 @@ def generate_export_data_url(request):
         flusurv_locations = data.get("flusurvLocations", [])
         api_key = data.get("apiKey", None)
 
-        log_form_stats(request, data, "export", form_stats_logger)
-        log_form_data(request, data, "export", form_data_logger)
+        log_form_stats(request, data, "export")
+        log_form_data(request, data, "export")
         data_export_commands.extend(
             generate_covidcast_indicators_export_url(
                 indicators, start_date, end_date, covidcast_geos, api_key
@@ -348,8 +346,8 @@ def generate_export_data_url(request):
 def preview_data(request):
     if request.method == "POST":
         data = json.loads(request.body)
-        log_form_stats(request, data, "preview", form_stats_logger)
-        log_form_data(request, data, "preview", form_data_logger)
+        log_form_stats(request, data, "preview")
+        log_form_data(request, data, "preview")
         start_date = data.get("start_date", "")
         end_date = data.get("end_date", "")
         indicators = data.get("indicators", [])
@@ -392,8 +390,8 @@ def preview_data(request):
 def create_query_code(request):
     if request.method == "POST":
         data = json.loads(request.body)
-        log_form_stats(request, data, "code", form_stats_logger)
-        log_form_data(request, data, "code", form_data_logger)
+        log_form_stats(request, data, "code")
+        log_form_data(request, data, "code")
         start_date = data.get("start_date", "")
         end_date = data.get("end_date", "")
         indicators = data.get("indicators", [])