diff --git a/CHANGELOG.md b/CHANGELOG.md index 4a40a394..c2ae2dc5 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -120,12 +120,13 @@ floor on the release that ships them): when the count is only known to the display service. - The Logs tab has a **Plugin errors** panel: per-plugin counts, repeating errors and a Clear button. -- Redacting `user:password@` from URLs in exception text (`src/redaction.py`) - takes time proportional to the text, not its square. A plugin error quoting - a long unbroken run of letters or digits (a hex digest, an ID) used to stall - every thread of the display service for up to seconds each time the snapshot - was published: about 0.5s for 20k characters of hex. What gets redacted is - unchanged. +- Credential redaction in exception text (`src/redaction.py`) takes time + proportional to the text, not its square. Two patterns were quadratic: URL + `user:password@`, on a long unbroken run of letters or digits (a hex digest, + an ID), and `Authorization:` followed by a long run of whitespace. Either + used to stall every thread of the display service for up to seconds each + time the snapshot was published: about 0.5s for 20k characters of hex, 8s + for 20k spaces. What gets redacted is unchanged. ### Removed diff --git a/src/redaction.py b/src/redaction.py index 2d674be5..a1294309 100644 --- a/src/redaction.py +++ b/src/redaction.py @@ -24,8 +24,13 @@ _REDACT_CREDENTIAL = re.compile( # silently leak the ones nobody thought of. Not covered by the generic pattern # above, whose value part stops at whitespace and so would keep the credential # once a space follows the scheme. +# +# The opening quote and the whitespace after it are one optional unit. Written +# `\s*["\']?\s*`, a whitespace run with no quote in it could be split between +# the two `\s*` in every possible way, and a header with no credential after +# it tried them all: quadratic, 8s for 20k spaces. _REDACT_AUTH_HEADER = re.compile( - r'((?:proxy-)?authorization["\']?\s*[=:]\s*["\']?\s*' + r'((?:proxy-)?authorization["\']?\s*[=:]\s*(?:["\']\s*)?' r'(?:[A-Za-z][\w.+-]*[ \t]+)?)' # optional scheme name, kept r'([^\s,"\'<>}]+)', # the credential, redacted re.IGNORECASE, diff --git a/test/test_redaction.py b/test/test_redaction.py index 8c0befb6..5f59d696 100644 --- a/test/test_redaction.py +++ b/test/test_redaction.py @@ -1,15 +1,20 @@ """redact_credentials must stay linear in the length of its input. -Regression under test: the URL-userinfo pattern (`scheme://user:password@`) -could start a match at every letter of a run of scheme characters, and each -attempt read to the end of the run looking for `://`. A 20k-character run took -1.6s; the display service redacts every message, stack trace and context value -it publishes in the error snapshot, and re.sub holds the GIL throughout, so an +Regressions under test, both quadratic regexes in src/redaction.py: + +- The URL-userinfo pattern (`scheme://user:password@`) could start a match at + every letter of a run of scheme characters, and each attempt read to the end + of the run looking for `://`: 1.6s for a 20k-character run. +- The Authorization-header pattern had two `\\s*` separated only by an + optional quote, so a header followed by whitespace and no credential tried + every split of that whitespace between them: 8s for 20k spaces. + +The display service redacts every message, stack trace and context value it +publishes in the error snapshot, and re.sub holds the GIL throughout, so an exception quoting a hex digest or a long ID stalled the render loop with it. test_error_snapshot_cross_process.py's snapshot-size test spent 140s here. -The anchored pattern has to redact exactly what the old one did, including a -scheme that begins after digits or `+.-` in the same run. +The fixed patterns have to redact exactly what the old ones did. """ import time @@ -18,6 +23,17 @@ import pytest from src.redaction import redact_credentials +# Each timed input took seconds before the fix and takes about a millisecond +# after it; the bound leaves CI plenty of headroom while still failing on a +# quadratic pattern. +_TIME_LIMIT = 1.0 + + +def _timed(text): + start = time.perf_counter() + result = redact_credentials(text) + return result, time.perf_counter() - start + class TestUrlUserinfo: @pytest.mark.parametrize("text,expected", [ @@ -43,21 +59,52 @@ class TestUrlUserinfo: assert redact_credentials(text) == text +class TestAuthorizationHeader: + @pytest.mark.parametrize("text,expected", [ + ("Authorization: Bearer eyJ.SECRET.sig", "Authorization: Bearer "), + ("Proxy-Authorization: Basic dXNlcg==", "Proxy-Authorization: Basic "), + ("authorization: barecredential", "authorization: "), + # Whitespace and an opening quote around the value, in either order. + ('authorization=" Bearer tok"', 'authorization=" Bearer "'), + ("authorization: ' tok'", "authorization: ' '"), + ("authorization:\n\tBearer tok", "authorization:\n\tBearer "), + ]) + def test_credential_is_redacted_and_the_rest_kept(self, text, expected): + assert redact_credentials(text) == expected + + @pytest.mark.parametrize("text", ["authorization: ", "authorization: , next"]) + def test_a_header_without_a_credential_is_untouched(self, text): + assert redact_credentials(text) == text + + class TestLinearTime: - # Each of these took seconds before the fix (letters ~10s at this size) - # and takes about a millisecond after it; the bound leaves CI plenty of - # headroom while still failing on a quadratic pattern. @pytest.mark.parametrize("unit", ["x", "0123456789abcdef", "1a", "a+", "1"]) def test_long_scheme_character_runs(self, unit): text = (unit * 50_000)[:50_000] - start = time.perf_counter() - assert redact_credentials(text) == text - elapsed = time.perf_counter() - start - assert elapsed < 1.0, f"{elapsed:.2f}s to redact {len(text)} chars of {unit!r}" + result, elapsed = _timed(text) + assert result == text + assert elapsed < _TIME_LIMIT, f"{elapsed:.2f}s to redact {len(text)} chars of {unit!r}" def test_a_credential_after_a_long_run_is_still_found(self): run = "ab12" * 10_000 - text = f"{run} https://user:hunter2@example.com" - start = time.perf_counter() - assert redact_credentials(text) == f"{run} https://user:@example.com" - assert time.perf_counter() - start < 1.0 + result, elapsed = _timed(f"{run} https://user:hunter2@example.com") + assert result == f"{run} https://user:@example.com" + assert elapsed < _TIME_LIMIT + + @pytest.mark.parametrize("header,whitespace", [ + ("authorization:", " "), + ("Proxy-Authorization:", "\t"), + ("authorization=", "\n"), + ]) + def test_a_header_followed_by_long_whitespace(self, header, whitespace): + text = header + whitespace * 20_000 + "," + result, elapsed = _timed(text) + assert result == text + assert elapsed < _TIME_LIMIT, ( + f"{elapsed:.2f}s to redact {header!r} and {len(text) - len(header)} more chars") + + def test_a_credential_after_long_whitespace_is_still_found(self): + gap = " " * 20_000 + result, elapsed = _timed(f"authorization:{gap}Bearer tok") + assert result == f"authorization:{gap}Bearer " + assert elapsed < _TIME_LIMIT