fix: test and fix error handling in open_browser

opensafely/__init__.py

@@ -1,5 +1,6 @@
 import argparse
 import logging
+import os
 import sys
 import tempfile
 from datetime import datetime, timedelta
@@ -151,6 +152,9 @@ def add_subcommand(cmd, module):
     function = kwargs.pop("function")
     debug = kwargs.pop("global_debug")
 
+    if debug:
+        os.environ["DEBUG"] = "true"
+
     try:
         success = function(**kwargs)
     except Exception as exc:

opensafely/jupyter.py

@@ -2,6 +2,7 @@
 import json
 import os
 import subprocess
+import sys
 import time
 from pathlib import Path
 
@@ -46,14 +47,14 @@ def add_arguments(parser):
     )
 
 
-def get_metadata(name):
+def get_metadata(name, timeout=30.0):
     """Read the login token from the generated json file in the container"""
     metadata = None
     metadata_path = "/tmp/.local/share/jupyter/runtime/nbserver-*.json"
 
     # wait for jupyter to be set up
     start = time.time()
-    while metadata is None and time.time() - start < 120.0:
+    while metadata is None and time.time() - start < timeout:
         ps = subprocess.run(
             ["docker", "exec", name, "bash", "-c", f"cat {metadata_path}"],
             text=True,
@@ -80,8 +81,8 @@ def read_metadata_and_open(name, port):
             utils.open_browser(url)
         else:
             utils.debug("could not retrieve login token from jupyter container")
-    except Exception as exc:
-        utils.print_exception_from_thread(exc)
+    except Exception:
+        utils.print_exception_from_thread(*sys.exc_info())
 
 
 def main(directory, name, port, no_browser, jupyter_args):

opensafely/utils.py

@@ -9,25 +9,19 @@
 import threading
 import time
 import webbrowser
-from urllib import request
 
+from opensafely._vendor import requests
 from opensafely._vendor.jobrunner import config
 
 
-# poor mans debugging because debugging threads on windows is hard
-if os.environ.get("DEBUG", False):
-
-    def debug(msg):
+def debug(msg):
+    """Windows threaded debugger."""
+    if os.environ.get("DEBUG", False):
         # threaded output for some reason needs the carriage return or else
         # it doesn't reset the cursor.
         sys.stderr.write("DEBUG: " + msg.replace("\n", "\r\n") + "\r\n")
         sys.stderr.flush()
 
-else:
-
-    def debug(msg):
-        pass
-
 
 def get_default_user():
     try:
@@ -165,41 +159,44 @@ def get_free_port():
     return port
 
 
-def print_exception_from_thread(exc):
-    # reformat exception printing to work from thread
+def print_exception_from_thread(*exc_info):
+    # reformat exception printing to work from thread in windows
     import traceback
 
     sys.stderr.write("Error in background thread:\r\n")
-    tb = traceback.format_exc(exc).replace("\n", "\r\n")
+    tb = "".join(traceback.format_exception(*exc_info)).replace("\n", "\r\n")
     sys.stderr.write(tb)
     sys.stderr.flush()
 
 
-def open_browser(url):
+def open_browser(url, timeout=30.0):
     try:
         debug(f"open_browser: url={url}")
 
         # wait for port to be open
         debug("open_browser: waiting for port")
         start = time.time()
-        while time.time() - start < 60.0:
+        response = None
+        while time.time() - start < timeout:
             try:
-                response = request.urlopen(url, timeout=1)
-            except (request.URLError, OSError):
-                pass
+                response = requests.get(url, timeout=1)
+            except Exception:
+                time.sleep(0.5)
             else:
                 break
 
         if not response:
-            debug("open_browser: open_browser: could not get response")
+            # always write a failure message
+            sys.stderr.write(f"Could not connect to {url} to open browser\r\n")
+            sys.stderr.flush()
             return
 
         # open a webbrowser pointing to the docker container
-        debug("open_browser: open_browser: opening browser window")
+        debug("open_browser: opening browser window")
         webbrowser.open(url, new=2)
 
-    except Exception as exc:
-        print_exception_from_thread(exc)
+    except Exception:
+        print_exception_from_thread(*sys.exc_info())
 
 
 def open_in_thread(target, args):

pyproject.toml

@@ -60,7 +60,7 @@ omit = [
 ]
 
 [tool.coverage.report]
-fail_under = 82
+fail_under = 88
 skip_covered = true
 show_missing = true
 

tests/conftest.py

@@ -2,7 +2,6 @@
 import shlex
 import subprocess
 import sys
-from collections import deque
 from pathlib import Path
 
 # ensure pkg_resources can find the package metadata we have included, as the
@@ -31,7 +30,7 @@
 _actual_run = subprocess.run
 
 
-class SubprocessRunFixture(deque):
+class SubprocessRunFixture(list):
     """Fixture for mocking subprocess.run.
 
     Add expected calls and their responses to subprocess.run:
@@ -56,6 +55,10 @@ class SubprocessRunFixture(deque):
     """
 
     strict = True
+    concurrent = False
+
+    class CommandNotFound(Exception):
+        pass
 
     def expect(
         self,
@@ -75,41 +78,26 @@ def expect(
 
     def run(self, cmd, *args, **kwargs):
         """The replacement run() function."""
-        expected, value, exc, env = self.popleft()
-        # text and check affect the return value and behaviour of run()
-        text = kwargs.get("text", False)
-        check = kwargs.get("check", False)
-        actual_env = kwargs.get("env", None)
-
-        # handle some windows calls being wrapped in winpty
-        winpty = False
-        if sys.platform == "win32":
-            if "winpty" in cmd[0] and cmd[1] == "--":
-                # strip winpty from cmd, do compare the wrapper
-                cmd = cmd[2:]
-                winpty = True
-
-        # first up, do we expect this cmd?
-        cmd_matches = expected == cmd
 
-        # windows/git-bash interative docker commands will always include tty,
-        # so check if we match w/o it
-        if not cmd_matches and winpty and "--tty" in cmd:
-            cmd_no_tty = cmd[:]
-            cmd_no_tty.remove("--tty")
-            cmd_matches = expected == cmd_no_tty
-
-        if not cmd_matches:
+        try:
+            expected, value, exc, env = self.find_cmd(cmd)
+        except self.CommandNotFound:
             if self.strict:
+                expected = "\n".join(str(x[0]) for x in self)
                 raise AssertionError(
                     f"run fixture got unexpected call:\n"
-                    f"Received: {cmd}\n"
-                    f"Expected: {expected}"
+                    f"Received:\n{cmd}\n"
+                    f"Expected:\n{expected}"
                 )
             else:
                 # pass through to system
                 return _actual_run(cmd, *args, **kwargs)
 
+        # text and check affect the return value and behaviour of run()
+        text = kwargs.get("text", False)
+        check = kwargs.get("check", False)
+        actual_env = kwargs.get("env", None)
+
         # next: are we expecting an exception?
         if exc is not None:
             if check:
@@ -146,6 +134,39 @@ def run(self, cmd, *args, **kwargs):
 
         return value
 
+    def find_cmd(self, cmd):
+        """Search list and find command."""
+        for i, (expected, value, exc, env) in enumerate(self):
+            if self.cmd_matches(expected, cmd):
+                del self[i]
+                return expected, value, exc, env
+
+            if not self.concurrent:
+                raise self.CommandNotFound(cmd)
+
+        raise self.CommandNotFound(cmd)
+
+    def cmd_matches(self, expected, cmd):
+        # handle some windows calls being wrapped in winpty
+        winpty = False
+        if sys.platform == "win32":
+            if "winpty" in cmd[0] and cmd[1] == "--":
+                # strip winpty from cmd, do compare the wrapper
+                cmd = cmd[2:]
+                winpty = True
+
+        # first up, do we expect this cmd?
+        matches = expected == cmd
+
+        # windows/git-bash interative docker commands will always include tty,
+        # so check if we match w/o it
+        if not matches and winpty and "--tty" in cmd:
+            cmd_no_tty = cmd[:]
+            cmd_no_tty.remove("--tty")
+            matches = expected == cmd_no_tty
+
+        return matches
+
 
 @pytest.fixture
 def run(monkeypatch):

tests/test_jupyter.py

@@ -1,10 +1,19 @@
 import pathlib
+from unittest import mock
 
-from opensafely import jupyter
+from opensafely import jupyter, utils
 from tests.conftest import run_main
 
 
-def test_jupyter(run, no_user):
+def test_jupyter(run, no_user, monkeypatch):
+    # easier to monkeypatch open_browser that try match the underlying
+    # subprocess calls.
+    mock_open_browser = mock.Mock(spec=utils.open_browser)
+    monkeypatch.setattr(utils, "open_browser", mock_open_browser)
+
+    # these calls are done in different threads, so can come in any order
+    run.concurrent = True
+
     run.expect(
         [
             "docker",
@@ -34,5 +43,18 @@ def test_jupyter(run, no_user):
             "foo",
         ]
     )
+    # fetch the metadata
+    run.expect(
+        [
+            "docker",
+            "exec",
+            "test_jupyter",
+            "bash",
+            "-c",
+            "cat /tmp/.local/share/jupyter/runtime/nbserver-*.json",
+        ],
+        stdout='{"token": "TOKEN"}',
+    )
 
-    assert run_main(jupyter, "--port 1234 --name test_jupyter --no-browser foo") == 0
+    assert run_main(jupyter, "--port 1234 --name test_jupyter foo") == 0
+    mock_open_browser.assert_called_with("http://localhost:1234/?token=TOKEN")

tests/test_rstudio.py

@@ -1,10 +1,11 @@
 import os
 import pathlib
 from sys import platform
+from unittest import mock
 
 import pytest
 
-from opensafely import rstudio
+from opensafely import rstudio, utils
 from tests.conftest import run_main
 
 
@@ -18,6 +19,10 @@ def test_rstudio(run, tmp_path, monkeypatch, gitconfig_exists):
     # windows
     monkeypatch.setitem(os.environ, "USERPROFILE", str(home))
 
+    # mock the open_browser call
+    mock_open_browser = mock.Mock(spec=utils.open_browser)
+    monkeypatch.setattr(utils, "open_browser", mock_open_browser)
+
     if gitconfig_exists:
         (home / ".gitconfig").touch()
 
@@ -55,3 +60,4 @@ def test_rstudio(run, tmp_path, monkeypatch, gitconfig_exists):
     run.expect(expected + ["ghcr.io/opensafely-core/rstudio"])
 
     assert run_main(rstudio, "--port 8787 --name test_rstudio") == 0
+    mock_open_browser.assert_called_with("http://localhost:8787")

tests/test_utils.py

@@ -125,3 +125,44 @@ def test_run_docker_interactive_tty(run, no_user, monkeypatch):
         ],
     )
     utils.run_docker([], "ehrql:v1", [], interactive=True)
+
+
+def test_open_browser_timeout(monkeypatch, capsys):
+    monkeypatch.setitem(os.environ, "DEBUG", "TRUE")
+
+    mock_open = mock.Mock(spec=utils.webbrowser.open)
+    monkeypatch.setattr(utils.webbrowser, "open", mock_open)
+
+    port = utils.get_free_port()
+    url = f"http://localhost:{port}/"
+    utils.open_browser(url, timeout=0.01)
+
+    assert not mock_open.called
+    _, err = capsys.readouterr()
+    assert f"Could not connect to {url}" in err
+
+
+def test_open_browser_error(monkeypatch, capsys):
+    # turn on debug logging
+    monkeypatch.setitem(os.environ, "DEBUG", "TRUE")
+
+    # return successful response from poll
+    mock_get = mock.Mock(spec=utils.requests.get)
+    response = utils.requests.Response()
+    response.status_code = 200
+    mock_get.return_value = response
+    monkeypatch.setattr(utils.requests, "get", mock_get)
+
+    # raise exception when calling webbrowser.open
+    mock_open = mock.Mock(spec=utils.webbrowser.open)
+    mock_open.side_effect = Exception("TEST ERROR")
+    monkeypatch.setattr(utils.webbrowser, "open", mock_open)
+
+    port = utils.get_free_port()
+    url = f"http://localhost:{port}/"
+    utils.open_browser(url, timeout=0.01)
+
+    mock_open.assert_called_with(url, new=2)
+    out, err = capsys.readouterr()
+    assert out == ""
+    assert "TEST ERROR" in err