test: expired JWT shows empty role in logs

test/io/test_auth.py

@@ -7,7 +7,7 @@ import time
 import pytest
 
 from config import BASEDIR, CONFIGSDIR, FIXTURES, SECRET
-from util import authheader, jwtauthheader, parse_server_timings_header
+from util import authheader, jwtauthheader, parse_server_timings_header, relativeSeconds
 from postgrest import (
     run,
     sleep_until_postgrest_config_reload,
@@ -72,9 +72,6 @@ def test_jwt_errors(defaultenv):
 
     env = {**defaultenv, "PGRST_JWT_SECRET": SECRET, "PGRST_JWT_AUD": "io tests"}
 
-    def relativeSeconds(sec):
-        return int((datetime.now(timezone.utc) + timedelta(seconds=sec)).timestamp())
-
     with run(env=env) as postgrest:
         headers = jwtauthheader({}, "other secret")
         response = postgrest.session.get("/", headers=headers)

test/io/test_io.py

@@ -8,7 +8,7 @@ import time
 import pytest
 
 from config import CONFIGSDIR, FIXTURES, SECRET
-from util import Thread, jwtauthheader, parse_server_timings_header
+from util import Thread, jwtauthheader, parse_server_timings_header, relativeSeconds
 from postgrest import (
     freeport,
     is_ipv6,
@@ -1028,6 +1028,25 @@ def test_log_query(level, defaultenv):
             assert len(pre_reqs) == 1
 
 
+def test_expired_jwt_log_lacks_role(defaultenv):
+    "Expired JWT requests are logged without a role."
+
+    env = {**defaultenv, "PGRST_JWT_SECRET": SECRET}
+    headers = jwtauthheader({"exp": relativeSeconds(-35)}, SECRET)
+
+    with run(env=env) as postgrest:
+        response = postgrest.session.get("/authors_only", headers=headers)
+        assert response.status_code == 401
+
+        output = postgrest.read_stdout(nlines=1)
+
+    assert len(output) == 1
+    assert re.match(
+        r'- - - \[.+\] "GET /authors_only HTTP/1.1" 401 \d+ "" "python-requests/.+"',
+        output[0],
+    )
+
+
 def test_no_pool_connection_required_on_bad_http_logic(defaultenv):
     "no pool connection should be consumed for failing on invalid http logic"
 

test/io/util.py

@@ -1,5 +1,6 @@
 import threading
 import jwt
+from datetime import datetime, timedelta, timezone
 
 
 class Thread(threading.Thread):
@@ -31,6 +32,10 @@ def jwtauthheader(claim, secret):
     return authheader(jwt.encode(claim, secret))
 
 
+def relativeSeconds(sec):
+    return int((datetime.now(timezone.utc) + timedelta(seconds=sec)).timestamp())
+
+
 def parse_server_timings_header(header):
     """Parse the Server-Timing header into a dict of metric names to values.