e2e-tests: Retry invalid TOTP codes during Google login (#1412)

Closes #1398
UDENG-9619

Author: adombeck

.github/workflows/e2e-tests-run.yaml

@@ -258,9 +258,10 @@ jobs:
           cd "${{ steps.run-tests.outputs.output-dir }}"
           cp "./log.html" "${PAGES_DIR}/log.html"
           cp "./report.html" "${PAGES_DIR}/report.html"
-          # Upload any recordings (.mp4 files), preserving the directory
+
+          # Upload any recordings and images, preserving the directory
           # structure so that the links in the log still work
-          find . -name '*.mp4' -exec cp --parents {} "${PAGES_DIR}/" \;
+          find . \( -name '*.mp4' -o -name '*.webp' \) -exec cp --parents {} "${PAGES_DIR}/" \;
 
           # Add a link to the parent directory to the log and report pages
           for page in "${PAGES_DIR}"/*.html; do

e2e-tests/listener/Listener.py

@@ -1,3 +1,4 @@
+import re
 import sys
 import time
 from datetime import timedelta
@@ -35,6 +36,11 @@
     # Dumping the whole journal on stderr is too noisy. It's already included
     # in the HTML log and stored separately as a .journal file.
     "Journal.Log Journal",
+    # We stream the output of the browser login script continuously to stderr,
+    # and after the script finishes we log the collected output to the
+    # Robot Framework log file. To avoid duplication, we mark the login keyword
+    # as silent so its log messages are not printed to stderr.
+    "Browser.Login",
 ]
 
 def _write(text: str) -> None:
@@ -61,6 +67,13 @@ def _status_colour(status: str) -> str:
     }.get(status, _WHITE)
 
 
+def _sanitize_html(text: str) -> str:
+    """Remove HTML blocks marked with data-skip-stderr to avoid dumping large HTML content to the terminal."""
+    # Match any opening tag carrying the data-skip-stderr attribute and strip
+    # everything from it to the end of the string.
+    return re.sub(r"<\w[^>]*\bdata-skip-stderr\b[^>]*>.*", "", text, flags=re.DOTALL).rstrip()
+
+
 def _fmt_args(args: tuple) -> str:
     """Return a compact, single-line representation of keyword arguments."""
     if not args:
@@ -120,7 +133,8 @@ def start_test(self, data: running.TestCase, result: result.TestCase) -> None:
     def end_test(self, data: running.TestCase, result: result.TestCase) -> None:
         elapsed = time.monotonic() - self._test_start
         colour = _status_colour(result.status)
-        msg = f"  {_DIM}{result.message}{_RESET}" if result.message else ""
+        message = _sanitize_html(result.message) if result.message else ""
+        msg = f"  {_DIM}{message}{_RESET}" if message else ""
         _write(
             f"{colour}{_BOLD}{'PASS' if result.passed else result.status:4}{_RESET}"
             f"  {_BOLD}{data.name}{_RESET}"
@@ -186,7 +200,6 @@ def log_message(self, message: result.Message) -> None:
         # Strip HTML tags if the message is HTML
         text = message.message
         if message.html:
-            import re
             text = re.sub(r"<[^>]+>", "", text)
         _write(f"{indent}{colour}{level_tag}{text}{_RESET}")
 

e2e-tests/resources/Browser.py

@@ -0,0 +1,79 @@
+import os
+import subprocess
+import sys
+import threading
+
+from robot.api.deco import keyword, library  # type: ignore
+from robot.api import logger
+
+SCRIPT_DIR = os.path.dirname(os.path.abspath(__file__))
+BROWSER_LOGIN_DIR = os.path.join(SCRIPT_DIR, "browser_login")
+
+# Map broker names to their broker-specific browser login scripts.
+_BROKER_LOGIN_SCRIPTS = {
+    "authd-msentraid": os.path.join(BROWSER_LOGIN_DIR, "msentraid.py"),
+    "authd-google": os.path.join(BROWSER_LOGIN_DIR, "google.py"),
+}
+
+# Write directly to the real stderr, bypassing Robot Framework's capture.
+# This matches what Listener.py does so the output ends up in the same stream.
+_out = sys.__stderr__
+
+
+def _stream_to_stderr(stream, lines):
+    """Read *stream* line by line, write each line to stderr immediately, and
+    collect all lines into *lines* for later logging via Robot Framework."""
+    for line in stream:
+        stripped = line.rstrip("\n")
+        if stripped:
+            _out.write(stripped + "\n")
+            _out.flush()
+            lines.append(stripped)
+
+
+@library
+class Browser:
+    """Library for browser automation using a headless browser."""
+
+    @keyword
+    def login(self, usercode: str, output_dir: str = "."):
+        """Perform device authentication with the given username, password and
+        usercode using a broker-specific browser automation script. The window
+        opened by the script is run off screen using Xvfb unless ``SHOW_WEBVIEW``
+        is set. Output is streamed to stderr in real time and also logged to the
+        Robot Framework log file after the process completes.
+        The ``BROKER`` environment variable selects which login script to use.
+        """
+        broker = os.environ.get("BROKER")
+        script = _BROKER_LOGIN_SCRIPTS.get(broker)
+        if not script:
+            raise ValueError(
+                f"Unknown broker: {broker!r}. "
+                f"Known brokers: {sorted(_BROKER_LOGIN_SCRIPTS.keys())}"
+            )
+
+        command = [script, usercode, "--output-dir", output_dir]
+        if not os.getenv("SHOW_WEBVIEW"):
+            command = ["/usr/bin/env", "GDK_BACKEND=x11", "xvfb-run", "-a", "--"] + command
+
+        lines = []
+        process = subprocess.Popen(
+            command,
+            stdout=subprocess.PIPE,
+            stderr=subprocess.STDOUT,
+            text=True,
+        )
+        stdout_thread = threading.Thread(
+            target=_stream_to_stderr, args=(process.stdout, lines), daemon=True
+        )
+        stdout_thread.start()
+        process.wait()
+        stdout_thread.join()
+
+        for line in lines:
+            logger.info(line)
+
+        if process.returncode != 0:
+            raise RuntimeError(
+                f"Browser login failed (exit code {process.returncode})"
+            )

e2e-tests/resources/authd/ExecUtils.py e2e-tests/resources/ExecUtils.pye2e-tests/resources/authd/ExecUtils.py renamed to e2e-tests/resources/ExecUtils.py

@@ -54,7 +54,9 @@ async def stop_receiving_journal(self) -> None:
             logger.info("Terminating socat")
             self.socat_process.terminate()
             self.socat_process.wait()
-            logger.info("socat stderr:\n" + self.socat_process.stderr.read().decode())
+            socat_stderr = self.socat_process.stderr.read().decode()
+            socat_stderr_filtered = _filter_socat_stderr(socat_stderr)
+            logger.info("socat stderr:\n" + socat_stderr_filtered)
             self.socat_process = None
             # The systemd-journal-remote process should exit on its own when socat terminates
             try:
@@ -89,7 +91,67 @@ async def log_journal(self) -> None:
         )
 
         html_output = Ansi2HTMLConverter(inline=True).convert(output, full=False)
-        logger.info(html_output, html=True)
+
+        # ansi2html produces a <pre> block; split on newlines so we can wrap each
+        # line in a <span> that JS can toggle.
+        lines = html_output.split('\n')
+        wrapped_lines = ''.join(
+            f'<span class="jline" style="display:block">{line}</span>'
+            for line in lines
+        )
+
+        uid = id(html_output)  # unique enough within a single report
+        container_id = f'journal-{uid}'
+        filter_id = f'journal-filter-{uid}'
+        count_id = f'journal-count-{uid}'
+
+        html = f"""
+            <input id="{filter_id}"
+              type="text"
+              placeholder="Filter journal (plain text or /regex/i)"
+              style="width:60%;padding:4px 6px;font-size:0.9em;box-sizing:border-box;margin:0"
+              oninput="(function(){{
+                var raw = document.getElementById('{filter_id}').value;
+                var pre = document.getElementById('{container_id}');
+                var lines = pre.querySelectorAll('.jline');
+                var re = null;
+                var m = raw.match(/^\\/(.+)\\/([gimsuy]*)$/);
+                if (m) {{
+                  try {{ re = new RegExp(m[1], m[2]); }} catch(e) {{ re = null; }}
+                }}
+                var shown = 0;
+                lines.forEach(function(s) {{
+                  var text = s.textContent;
+                  var visible = raw === '' || (re ? re.test(text) : text.toLowerCase().indexOf(raw.toLowerCase()) !== -1);
+                  s.style.display = visible ? 'block' : 'none';
+                  if (visible) shown++;
+                }});
+                document.getElementById('{count_id}').textContent =
+                  raw === '' ? '' : shown + ' / ' + lines.length + ' lines';
+              }})()">
+            <span id="{count_id}" style="margin-left:8px;font-size:0.85em;color:#888"></span>
+            <pre id="{container_id}" style="background:#1b1b1b;color:#f8f8f2;overflow:auto;max-height:600px;margin:2px 0 0 0">{wrapped_lines}</pre>
+            """
+        BuiltIn().set_test_message(f'*HTML*<h3 data-skip-stderr style="margin-bottom:0">Journal</h3>{html}', append=True, separator='\n')
+
+def _filter_socat_stderr(stderr):
+    """Filter socat stderr, keeping the first write/read line and summarizing the rest."""
+    lines = []
+    skipped = 0
+    first_io_seen = False
+    for line in stderr.splitlines():
+        if "write(" in line:
+            if not first_io_seen:
+                lines.append(line)
+                first_io_seen = True
+            else:
+                skipped += 1
+        else:
+            lines.append(line)
+    if skipped:
+        lines.append(f"... ({skipped} more write lines omitted)")
+    return "\n".join(lines)
+
 
 def stream_journal_from_vm_via_tcp(output_dir, timeout=60):
     vm_name = VMUtils.vm_name()