feat: is_authenticated request logging + cleanup (#7893)

* chore: nginx log is s, not ms

* chore: log seconds from gunicorn too

* chore: drop X-Real-IP header / log

* style: Black

* style: single -> double quotes

* feat: add is-authenticated header

* feat: log is-authenticated header

* chore: update nginx-auth.conf to match

ietf/middleware.py

@@ -17,45 +17,61 @@ def sql_log_middleware(get_response):
     def sql_log(request):
         response = get_response(request)
         for q in connection.queries:
-            if re.match('(update|insert)', q['sql'], re.IGNORECASE):
-                log(q['sql'])
+            if re.match("(update|insert)", q["sql"], re.IGNORECASE):
+                log(q["sql"])
         return response
+
     return sql_log
 
+
 class SMTPExceptionMiddleware(object):
     def __init__(self, get_response):
         self.get_response = get_response
+
     def __call__(self, request):
         return self.get_response(request)
+
     def process_exception(self, request, exception):
         if isinstance(exception, smtplib.SMTPException):
             (extype, value, tb) = log_smtp_exception(exception)
-            return render(request, 'email_failed.html',
-                          {'exception': extype, 'args': value, 'traceback': "".join(tb)} )
+            return render(
+                request,
+                "email_failed.html",
+                {"exception": extype, "args": value, "traceback": "".join(tb)},
+            )
         return None
 
+
 class Utf8ExceptionMiddleware(object):
     def __init__(self, get_response):
         self.get_response = get_response
+
     def __call__(self, request):
         return self.get_response(request)
+
     def process_exception(self, request, exception):
         if isinstance(exception, OperationalError):
             extype, e, tb = exc_parts()
             if e.args[0] == 1366:
                 log("Database 4-byte utf8 exception: %s: %s" % (extype, e))
-                return render(request, 'utf8_4byte_failed.html',
-                              {'exception': extype, 'args': e.args, 'traceback': "".join(tb)} )
+                return render(
+                    request,
+                    "utf8_4byte_failed.html",
+                    {"exception": extype, "args": e.args, "traceback": "".join(tb)},
+                )
         return None
 
+
 def redirect_trailing_period_middleware(get_response):
     def redirect_trailing_period(request):
         response = get_response(request)
         if response.status_code == 404 and request.path.endswith("."):
             return HttpResponsePermanentRedirect(request.path.rstrip("."))
         return response
+
     return redirect_trailing_period
 
+
 def unicode_nfkc_normalization_middleware(get_response):
     def unicode_nfkc_normalization(request):
         """Do Unicode NFKC normalization to turn ligatures into individual characters.
@@ -65,9 +81,21 @@ def unicode_nfkc_normalization(request):
         There are probably other elements of a request which may need this normalization
         too, but let's put that in as it comes up, rather than guess ahead.
         """
-        request.META["PATH_INFO"] = unicodedata.normalize('NFKC', request.META["PATH_INFO"])
-        request.path_info = unicodedata.normalize('NFKC', request.path_info)
+        request.META["PATH_INFO"] = unicodedata.normalize(
+            "NFKC", request.META["PATH_INFO"]
+        )
+        request.path_info = unicodedata.normalize("NFKC", request.path_info)
         response = get_response(request)
         return response
+
     return unicode_nfkc_normalization
-
+
+
+def is_authenticated_header_middleware(get_response):
+    """Middleware to add an is-authenticated header to the response"""
+    def add_header(request):
+        response = get_response(request)
+        response["X-Datatracker-Is-Authenticated"] = "yes" if request.user.is_authenticated else "no"
+        return response
+
+    return add_header

ietf/settings.py

@@ -401,24 +401,25 @@ def skip_unreadable_post(record):
 
 
 MIDDLEWARE = [
-    'django.middleware.csrf.CsrfViewMiddleware',
-    'corsheaders.middleware.CorsMiddleware', # see docs on CORS_REPLACE_HTTPS_REFERER before using it
-    'django.middleware.common.CommonMiddleware',
-    'django.contrib.sessions.middleware.SessionMiddleware',
-    'django.contrib.auth.middleware.AuthenticationMiddleware',
-    'django.contrib.messages.middleware.MessageMiddleware',
-    'django.middleware.http.ConditionalGetMiddleware',
-    'simple_history.middleware.HistoryRequestMiddleware',
+    "django.middleware.csrf.CsrfViewMiddleware",
+    "corsheaders.middleware.CorsMiddleware", # see docs on CORS_REPLACE_HTTPS_REFERER before using it
+    "django.middleware.common.CommonMiddleware",
+    "django.contrib.sessions.middleware.SessionMiddleware",
+    "django.contrib.auth.middleware.AuthenticationMiddleware",
+    "django.contrib.messages.middleware.MessageMiddleware",
+    "django.middleware.http.ConditionalGetMiddleware",
+    "simple_history.middleware.HistoryRequestMiddleware",
     # comment in this to get logging of SQL insert and update statements:
-    #'ietf.middleware.sql_log_middleware',
-    'ietf.middleware.SMTPExceptionMiddleware',
-    'ietf.middleware.Utf8ExceptionMiddleware',
-    'ietf.middleware.redirect_trailing_period_middleware',
-    'django_referrer_policy.middleware.ReferrerPolicyMiddleware',
-    'django.middleware.clickjacking.XFrameOptionsMiddleware',
-    'django.middleware.security.SecurityMiddleware',
- #   'csp.middleware.CSPMiddleware',
-    'ietf.middleware.unicode_nfkc_normalization_middleware',
+    #"ietf.middleware.sql_log_middleware",
+    "ietf.middleware.SMTPExceptionMiddleware",
+    "ietf.middleware.Utf8ExceptionMiddleware",
+    "ietf.middleware.redirect_trailing_period_middleware",
+    "django_referrer_policy.middleware.ReferrerPolicyMiddleware",
+    "django.middleware.clickjacking.XFrameOptionsMiddleware",
+    "django.middleware.security.SecurityMiddleware",
+    #"csp.middleware.CSPMiddleware",
+    "ietf.middleware.unicode_nfkc_normalization_middleware",
+    "ietf.middleware.is_authenticated_header_middleware",
 ]
 
 ROOT_URLCONF = 'ietf.urls'

ietf/utils/jsonlogger.py

@@ -23,12 +23,12 @@ def add_fields(self, log_record, record, message_dict):
         log_record.setdefault("referer", record.args["f"])
         log_record.setdefault("user_agent", record.args["a"])
         log_record.setdefault("len_bytes", record.args["B"])
-        log_record.setdefault("duration_ms", record.args["M"])
+        log_record.setdefault("duration_s", record.args["L"])  # decimal seconds
         log_record.setdefault("host", record.args["{host}i"])
         log_record.setdefault("x_request_start", record.args["{x-request-start}i"])
-        log_record.setdefault("x_real_ip", record.args["{x-real-ip}i"])
         log_record.setdefault("x_forwarded_for", record.args["{x-forwarded-for}i"])
         log_record.setdefault("x_forwarded_proto", record.args["{x-forwarded-proto}i"])
         log_record.setdefault("cf_connecting_ip", record.args["{cf-connecting-ip}i"])
         log_record.setdefault("cf_connecting_ipv6", record.args["{cf-connecting-ipv6}i"])
         log_record.setdefault("cf_ray", record.args["{cf-ray}i"])
+        log_record.setdefault("is_authenticated", record.args["{x-datatracker-is-authenticated}i"])

k8s/nginx-auth.conf

@@ -32,7 +32,7 @@ server {
         proxy_set_header Connection close;
         proxy_set_header X-Request-Start "t=$${keepempty}msec";
         proxy_set_header X-Forwarded-For $${keepempty}proxy_add_x_forwarded_for;
-        proxy_set_header X-Real-IP $${keepempty}remote_addr;
+        proxy_hide_header X-Datatracker-Is-Authenticated; # hide this from the outside world
         proxy_pass http://localhost:8000;
         # Set timeouts longer than Cloudflare proxy limits
         proxy_connect_timeout 60;  # nginx default (Cf = 15)

k8s/nginx-datatracker.conf

@@ -21,7 +21,7 @@ server {
         proxy_set_header Connection close;
         proxy_set_header X-Request-Start "t=$${keepempty}msec";
         proxy_set_header X-Forwarded-For $${keepempty}proxy_add_x_forwarded_for;
-        proxy_set_header X-Real-IP $${keepempty}remote_addr;
+        proxy_hide_header X-Datatracker-Is-Authenticated; # hide this from the outside world
         proxy_pass http://localhost:8000;
         # Set timeouts longer than Cloudflare proxy limits
         proxy_connect_timeout 60;  # nginx default (Cf = 15)

k8s/nginx-logging.conf

@@ -9,7 +9,7 @@ log_format  ietfjson  escape=json
     '"method":"$${keepempty}request_method",'
     '"status":"$${keepempty}status",'
     '"len_bytes":"$${keepempty}body_bytes_sent",'
-    '"duration_ms":"$${keepempty}request_time",'
+    '"duration_s":"$${keepempty}request_time",'
     '"referer":"$${keepempty}http_referer",'
     '"user_agent":"$${keepempty}http_user_agent",'
     '"x_forwarded_for":"$${keepempty}http_x_forwarded_for",'