|
5 | 5 | Scope |
6 | 6 | ----- |
7 | 7 | These tests verify the end-to-end behavior of cloudflared pre-checks: |
8 | | -- that the human-readable table written to stdout has the correct structure |
9 | | - and content, |
| 8 | +- that the human-readable table written to the log output has the correct |
| 9 | + structure and content, |
10 | 10 | - that structured JSON log lines are emitted with the expected fields, and |
11 | 11 | - that running the `diag` subcommand against a live tunnel instance produces a |
12 | 12 | zip archive that contains prechecks.json. |
|
25 | 25 | DNS failure and Management API failure cannot be triggered via CLI flags alone; |
26 | 26 | they require network-level intervention outside the component-test harness. |
27 | 27 |
|
28 | | -stdout design |
29 | | -------------- |
30 | | -fmt.Println(report.String()) runs inside a goroutine that is started |
31 | | -concurrently with the tunnel. We poll a --logfile for the "precheck complete" |
32 | | -sentinel before leaving the `with` block, ensuring the goroutine has finished. |
33 | | -We then call cfd.terminate(). After the `with` block exits, the process is |
34 | | -dead and all output has been captured by CloudflaredProcess's background reader |
35 | | -thread (stderr is merged into stdout). We read the accumulated lines from |
36 | | -cfd.stdout_lines. |
| 28 | +stdout/stderr design |
| 29 | +-------------------- |
| 30 | +The pre-checks table is emitted via cliutil.LogTable, which wraps the content |
| 31 | +in an ASCII box and logs each line at Info level through zerolog. zerolog |
| 32 | +writes to stderr, which the test harness merges into stdout (stderr=STDOUT in |
| 33 | +Popen). We poll a --logfile for the "precheck complete" sentinel before |
| 34 | +leaving the `with` block, ensuring the goroutine has finished. We then call |
| 35 | +cfd.terminate(). After the `with` block exits, the process is dead and all |
| 36 | +output has been captured by CloudflaredProcess's background reader thread. We |
| 37 | +read the accumulated lines from cfd.stdout_lines. |
| 38 | +
|
| 39 | +Box format (cliutil.asciiBox with padding=2, title="CONNECTIVITY PRE-CHECKS"): |
| 40 | + +----...----+ |
| 41 | + | CONNECTIVITY PRE-CHECKS | (centered title) |
| 42 | + +----...----+ |
| 43 | + | COMPONENT TARGET ... | (content rows) |
| 44 | + ... |
| 45 | + +----...----+ |
37 | 46 | """ |
38 | 47 |
|
39 | 48 | import json |
|
46 | 55 | from constants import METRICS_PORT |
47 | 56 | from util import LOGGER, start_cloudflared, wait_tunnel_ready |
48 | 57 |
|
49 | | -# stdout table constants |
50 | | -TABLE_WIDTH = 80 |
51 | | -HEADER_LINE = "--- CONNECTIVITY PRE-CHECKS " + "-" * (TABLE_WIDTH - len("--- CONNECTIVITY PRE-CHECKS ") - 1) |
52 | | -COL_HEADER = "COMPONENT" # first token of the column-header row |
53 | | -SEPARATOR = "-" * TABLE_WIDTH |
| 58 | +# ASCII box constants (cliutil.asciiBox, padding=2, title="CONNECTIVITY PRE-CHECKS") |
| 59 | +BOX_TITLE = "CONNECTIVITY PRE-CHECKS" |
| 60 | +BOX_BORDER_RE = re.compile(r"^\+(-+)\+$", re.MULTILINE) # matches +----...----+ |
| 61 | +COL_HEADER = "COMPONENT" # first word of the column-header row |
| 62 | + |
| 63 | +# zerolog console format: "2006-01-02T15:04:05Z LVL <message>" |
| 64 | +_LOG_PREFIX_RE = re.compile(r"^\S+ \w+ ") |
54 | 65 |
|
55 | 66 | # Component names (probes.go: componentXxx) |
56 | 67 | COMP_DNS = "DNS Resolution" |
@@ -164,23 +175,46 @@ def __repr__(self): |
164 | 175 | return f"TableRow({self.component!r}, {self.target!r}, {self.status!r}, {self.details!r})" |
165 | 176 |
|
166 | 177 |
|
| 178 | +def _strip_log_prefix(line: str) -> str: |
| 179 | + """Remove the zerolog console prefix ('2006-01-02T15:04:05Z LVL ') if present.""" |
| 180 | + return _LOG_PREFIX_RE.sub("", line, count=1) |
| 181 | + |
| 182 | + |
| 183 | +def _unbox_line(line: str) -> str: |
| 184 | + """Strip the box border padding from a content line: '| text |' -> 'text'. |
| 185 | +
|
| 186 | + Accepts lines that may still carry a zerolog console prefix; the prefix is |
| 187 | + removed before the box delimiters are stripped. |
| 188 | + """ |
| 189 | + msg = _strip_log_prefix(line) |
| 190 | + if msg.startswith("|") and msg.endswith("|"): |
| 191 | + return msg[1:-1].strip() |
| 192 | + return msg.strip() |
| 193 | + |
| 194 | + |
167 | 195 | def _parse_table(stdout: str) -> list[TableRow]: |
168 | 196 | """ |
169 | 197 | Parse the data rows from a precheck table in stdout. |
170 | 198 |
|
171 | | - text/tabwriter uses padding=2, so columns are separated by two or more |
172 | | - spaces. We skip the column-header row and stop at blank lines, SUMMARY, |
173 | | - separator, ERROR, or WARNING lines. |
| 199 | + The table is now wrapped in an ASCII box by cliutil.LogTable. Each |
| 200 | + content line has the form '| <content> |', optionally preceded by a |
| 201 | + zerolog console prefix. We strip both the prefix and the box borders |
| 202 | + before splitting on two-or-more spaces (text/tabwriter padding=2). |
| 203 | +
|
| 204 | + We skip the column-header row and stop at blank lines, SUMMARY, box |
| 205 | + border lines, ERROR, or WARNING lines. |
174 | 206 | """ |
175 | 207 | rows = [] |
176 | 208 | in_data = False |
177 | | - for line in stdout.splitlines(): |
| 209 | + for raw_line in stdout.splitlines(): |
| 210 | + msg = _strip_log_prefix(raw_line) |
| 211 | + line = _unbox_line(raw_line) |
178 | 212 | if line.startswith("COMPONENT"): |
179 | 213 | in_data = True |
180 | 214 | continue |
181 | 215 | if not in_data: |
182 | 216 | continue |
183 | | - if (line == "" or line.startswith("SUMMARY") or line.startswith("---") |
| 217 | + if (line == "" or line.startswith("SUMMARY") or BOX_BORDER_RE.match(msg) |
184 | 218 | or line.startswith("ERROR") or line.startswith("WARNING")): |
185 | 219 | in_data = False |
186 | 220 | continue |
@@ -261,14 +295,18 @@ def test_prechecks_pass_on_healthy_connection(self, tmp_path, component_tests_co |
261 | 295 | LOGGER.debug(f"[happy-path] stdout:\n{stdout}") |
262 | 296 | LOGGER.debug(f"[happy-path] log_lines:\n{log_lines}") |
263 | 297 |
|
| 298 | + # Strip zerolog console prefixes so pattern matching works on raw messages. |
| 299 | + messages = "\n".join(_strip_log_prefix(l) for l in stdout.splitlines()) |
| 300 | + |
264 | 301 | # ── table structure ────────────────────────────────────────────────── |
265 | | - # stderr is merged into stdout so log lines precede the table. |
266 | | - assert HEADER_LINE in stdout, \ |
267 | | - f"Expected header line in output;\ngot:\n{stdout}" |
268 | | - assert COL_HEADER in stdout, \ |
| 302 | + # zerolog writes to stderr which is merged into stdout by the harness. |
| 303 | + # The table is wrapped in an ASCII box by cliutil.LogTable. |
| 304 | + assert BOX_TITLE in messages, \ |
| 305 | + f"Expected box title '{BOX_TITLE}' in output;\ngot:\n{stdout}" |
| 306 | + assert COL_HEADER in messages, \ |
269 | 307 | f"Expected column header row in output;\ngot:\n{stdout}" |
270 | | - assert SEPARATOR in stdout, \ |
271 | | - f"Expected closing separator in output;\ngot:\n{stdout}" |
| 308 | + assert BOX_BORDER_RE.search(messages), \ |
| 309 | + f"Expected box border line (+---+) in output;\ngot:\n{stdout}" |
272 | 310 |
|
273 | 311 | # ── row content ────────────────────────────────────────────────────── |
274 | 312 | rows = _parse_table(stdout) |
@@ -306,11 +344,11 @@ def test_prechecks_pass_on_healthy_connection(self, tmp_path, component_tests_co |
306 | 344 | assert api_rows[0].details == DETAILS_API_OK, f"API row details wrong: {api_rows[0]}" |
307 | 345 |
|
308 | 346 | # ── no action lines ────────────────────────────────────────────────── |
309 | | - assert PREFIX_ERROR not in stdout, f"Unexpected ERROR action:\n{stdout}" |
310 | | - assert PREFIX_WARNING not in stdout, f"Unexpected WARNING action:\n{stdout}" |
| 347 | + assert PREFIX_ERROR not in messages, f"Unexpected ERROR action:\n{stdout}" |
| 348 | + assert PREFIX_WARNING not in messages, f"Unexpected WARNING action:\n{stdout}" |
311 | 349 |
|
312 | | - # ── exact summary line ─────────────────────────────────────────────── |
313 | | - assert SUMMARY_HEALTHY in stdout, \ |
| 350 | + # ── summary line ───────────────────────────────────────────────────── |
| 351 | + assert SUMMARY_HEALTHY in messages, \ |
314 | 352 | f"Expected healthy summary;\ngot:\n{stdout}" |
315 | 353 |
|
316 | 354 | # ── structured log ─────────────────────────────────────────────────── |
@@ -366,14 +404,18 @@ def test_prechecks_hard_fail_when_edge_unreachable(self, tmp_path, component_tes |
366 | 404 | LOGGER.debug(f"[hard-fail] stdout:\n{stdout}") |
367 | 405 | LOGGER.debug(f"[hard-fail] log_lines:\n{log_lines}") |
368 | 406 |
|
| 407 | + # Strip zerolog console prefixes so pattern matching works on raw messages. |
| 408 | + messages = "\n".join(_strip_log_prefix(l) for l in stdout.splitlines()) |
| 409 | + |
369 | 410 | # ── table structure ────────────────────────────────────────────────── |
370 | | - # stderr is merged into stdout so log lines precede the table. |
371 | | - assert HEADER_LINE in stdout, \ |
372 | | - f"Expected header line in output;\ngot:\n{stdout}" |
373 | | - assert COL_HEADER in stdout, \ |
| 411 | + # zerolog writes to stderr which is merged into stdout by the harness. |
| 412 | + # The table is wrapped in an ASCII box by cliutil.LogTable. |
| 413 | + assert BOX_TITLE in messages, \ |
| 414 | + f"Expected box title '{BOX_TITLE}' in output;\ngot:\n{stdout}" |
| 415 | + assert COL_HEADER in messages, \ |
374 | 416 | f"Expected column header row in output;\ngot:\n{stdout}" |
375 | | - assert SEPARATOR in stdout, \ |
376 | | - f"Expected closing separator in output;\ngot:\n{stdout}" |
| 417 | + assert BOX_BORDER_RE.search(messages), \ |
| 418 | + f"Expected box border line (+---+) in output;\ngot:\n{stdout}" |
377 | 419 |
|
378 | 420 | # ── row content ────────────────────────────────────────────────────── |
379 | 421 | rows = _parse_table(stdout) |
@@ -404,12 +446,12 @@ def test_prechecks_hard_fail_when_edge_unreachable(self, tmp_path, component_tes |
404 | 446 | assert api_rows[0].status == PASS, f"API row not PASS: {api_rows[0]}" |
405 | 447 | assert api_rows[0].details == DETAILS_API_OK, f"API row details wrong: {api_rows[0]}" |
406 | 448 |
|
407 | | - assert f"{PREFIX_ERROR}{ACTION_QUIC_BLOCKED}" in stdout, \ |
| 449 | + assert f"{PREFIX_ERROR}{ACTION_QUIC_BLOCKED}" in messages, \ |
408 | 450 | f"Expected QUIC ERROR action;\ngot:\n{stdout}" |
409 | | - assert f"{PREFIX_ERROR}{ACTION_HTTP2_BLOCKED}" in stdout, \ |
| 451 | + assert f"{PREFIX_ERROR}{ACTION_HTTP2_BLOCKED}" in messages, \ |
410 | 452 | f"Expected HTTP/2 ERROR action;\ngot:\n{stdout}" |
411 | 453 |
|
412 | | - assert SUMMARY_CRITICAL in stdout, \ |
| 454 | + assert SUMMARY_CRITICAL in messages, \ |
413 | 455 | f"Expected critical summary;\ngot:\n{stdout}" |
414 | 456 |
|
415 | 457 | _assert_precheck_summary_log(log_lines, hard_fail=True, suggested_protocol=None) |
|
0 commit comments