Skip to content

Commit 7fe90e8

Browse files
mkleczekmkleczek
committed
test(refactor): make debug output testing more robust
DISCLAIMER: This commit was authored entirely by a human without the assistance of LLMs. This change introduces a match_log function, that implements lenient matching of log output lines. Tests of log output are retrofited to use the function.
1 parent ae7d4d2 commit 7fe90e8

1 file changed

Lines changed: 52 additions & 45 deletions

File tree

‎test/io/test_io.py‎

Lines changed: 52 additions & 45 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,19 @@
2121
)
2222

2323

24+
def match_log(output, matchers):
25+
ito = iter(output)
26+
itm = iter(matchers)
27+
nextMatcher = next(itm, None)
28+
while nextMatcher is not None and (line := next(ito, None)) is not None:
29+
if re.match(nextMatcher, line) is not None:
30+
nextMatcher = next(itm, None)
31+
if nextMatcher is not None:
32+
raise AssertionError(
33+
f"Expected log line matching {nextMatcher} not found in output"
34+
)
35+
36+
2437
def test_connect_with_dburi(dburi, defaultenv):
2538
"Connecting with db-uri instead of LIPQ* environment variables should work."
2639
defaultenv_without_libpq = {
@@ -701,54 +714,44 @@ def test_log_level(level, defaultenv):
701714
response = postgrest.session.get("/")
702715
assert response.status_code == 200
703716

704-
output = sorted(postgrest.read_stdout(nlines=7))
717+
output = postgrest.read_stdout(nlines=7)
705718

706719
if level == "crit":
707720
assert len(output) == 0
708721
elif level == "error":
709-
assert re.match(
710-
r'- - - \[.+\] "GET / HTTP/1.1" 500 \d+ "" "python-requests/.+"',
711-
output[0],
722+
match_log(
723+
output,
724+
[r'- - - \[.+\] "GET / HTTP/1.1" 500 \d+ "" "python-requests/.+"'],
712725
)
713726
assert len(output) == 1
714727
elif level == "warn":
715-
assert re.match(
716-
r'- - - \[.+\] "GET / HTTP/1.1" 500 \d+ "" "python-requests/.+"',
717-
output[0],
718-
)
719-
assert re.match(
720-
r'- - postgrest_test_anonymous \[.+\] "GET /unknown HTTP/1.1" 404 \d+ "" "python-requests/.+"',
721-
output[1],
728+
match_log(
729+
output,
730+
[
731+
r'- - - \[.+\] "GET / HTTP/1.1" 500 \d+ "" "python-requests/.+"',
732+
r'- - postgrest_test_anonymous \[.+\] "GET /unknown HTTP/1.1" 404 \d+ "" "python-requests/.+"',
733+
],
722734
)
723735
assert len(output) == 2
724736
elif level == "info":
725-
assert re.match(
726-
r'- - - \[.+\] "GET / HTTP/1.1" 500 \d+ "" "python-requests/.+"',
727-
output[0],
728-
)
729-
assert re.match(
730-
r'- - postgrest_test_anonymous \[.+\] "GET / HTTP/1.1" 200 \d+ "" "python-requests/.+"',
731-
output[1],
732-
)
733-
assert re.match(
734-
r'- - postgrest_test_anonymous \[.+\] "GET /unknown HTTP/1.1" 404 \d+ "" "python-requests/.+"',
735-
output[2],
737+
match_log(
738+
output,
739+
[
740+
r'- - - \[.+\] "GET / HTTP/1.1" 500 \d+ "" "python-requests/.+"',
741+
r'- - postgrest_test_anonymous \[.+\] "GET /unknown HTTP/1.1" 404 \d+ "" "python-requests/.+"',
742+
r'- - postgrest_test_anonymous \[.+\] "GET / HTTP/1.1" 200 \d+ "" "python-requests/.+"',
743+
],
736744
)
737745
assert len(output) == 3
738746
elif level == "debug":
739-
assert re.match(
740-
r'- - - \[.+\] "GET / HTTP/1.1" 500 \d+ "" "python-requests/.+"',
741-
output[0],
747+
match_log(
748+
output,
749+
[
750+
r'- - - \[.+\] "GET / HTTP/1.1" 500 \d+ "" "python-requests/.+"',
751+
r'- - postgrest_test_anonymous \[.+\] "GET /unknown HTTP/1.1" 404 \d+ "" "python-requests/.+"',
752+
r'- - postgrest_test_anonymous \[.+\] "GET / HTTP/1.1" 200 \d+ "" "python-requests/.+"',
753+
],
742754
)
743-
assert re.match(
744-
r'- - postgrest_test_anonymous \[.+\] "GET / HTTP/1.1" 200 \d+ "" "python-requests/.+"',
745-
output[1],
746-
)
747-
assert re.match(
748-
r'- - postgrest_test_anonymous \[.+\] "GET /unknown HTTP/1.1" 404 \d+ "" "python-requests/.+"',
749-
output[2],
750-
)
751-
752755
assert len(output) == 7
753756
assert any("Connection" and "is available" in line for line in output)
754757
assert any("Connection" and "is used" in line for line in output)
@@ -1386,16 +1389,21 @@ def test_db_error_logging_to_stderr(level, defaultenv, metapostgrest):
13861389
assert response.status_code == 500
13871390

13881391
# ensure the message appears on the logs
1389-
output = sorted(postgrest.read_stdout(nlines=6))
1392+
output = postgrest.read_stdout(nlines=6)
13901393

13911394
if level == "crit":
13921395
assert len(output) == 0
13931396
elif level == "debug":
1394-
assert " 500 " in output[0]
1395-
assert "canceling statement due to statement timeout" in output[5]
1397+
match_log(
1398+
output,
1399+
[
1400+
r".*canceling statement due to statement timeout.*",
1401+
r".*500.*",
1402+
],
1403+
)
13961404
else:
1397-
assert " 500 " in output[0]
1398-
assert "canceling statement due to statement timeout" in output[1]
1405+
assert " 500 " in output[1]
1406+
assert "canceling statement due to statement timeout" in output[0]
13991407

14001408
reset_statement_timeout(metapostgrest, role)
14011409

@@ -1589,18 +1597,17 @@ def test_log_pool_req_observation(level, defaultenv):
15891597

15901598
headers = jwtauthheader({"role": "postgrest_test_author"}, SECRET)
15911599

1592-
pool_req = "Trying to borrow a connection from pool"
1593-
pool_req_fullfill = "Borrowed a connection from the pool"
1600+
pool_req = r".*Trying to borrow a connection from pool.*"
1601+
pool_req_fullfill = r".*Borrowed a connection from the pool.*"
15941602

15951603
with run(env=env) as postgrest:
15961604

15971605
postgrest.session.get("/authors_only", headers=headers)
15981606

15991607
if level == "debug":
1600-
output = postgrest.read_stdout(nlines=5)
1601-
assert pool_req in output[1]
1602-
assert pool_req_fullfill in output[4]
1603-
assert len(output) == 5
1608+
output = postgrest.read_stdout(nlines=7)
1609+
assert len(output) == 6
1610+
match_log(output, [pool_req, pool_req_fullfill])
16041611
elif level == "info":
16051612
output = postgrest.read_stdout(nlines=4)
16061613
assert len(output) == 1

0 commit comments

Comments
 (0)