Various improvements to integration tests

This has been a long time coming, but it's still not perfect. Basically
I'm trying to reset the entire environment as much as possible so that
each spec runs in a clean room. Mostly in this commit Firefox is being
killed and restarted for every spec, which has made a lot of
improvements.

12 files changed, 161 insertions, 47 deletions

diff --git a/.travis.yml b/.travis.yml
index bb8f4fa..aac01f5 100644
--- a/.travis.yml
+++ b/.travis.yml
@@ -5,7 +5,7 @@ go:
 
 addons:
   # Use the full version number with ".0" if needed. This value is scraped by setup scripts.
-  firefox: "66.0.4"
+  firefox: "67.0.1"
   apt:
     packages:
       - rpm
@@ -37,8 +37,8 @@ install:
 script:
   - cd $REPO_ROOT/webext && npm test
   - cd $REPO_ROOT/interfacer && go test $(find src/browsh -name *.go | grep -v windows)
-  - cd $REPO_ROOT/interfacer && go test test/tty/*.go -v -ginkgo.flakeAttempts=3
-  - cd $REPO_ROOT/interfacer && go test test/http-server/*.go -v
+  - cd $REPO_ROOT/interfacer && go test test/tty/*.go -v -ginkgo.slowSpecThreshold=30 -ginkgo.flakeAttempts=3
+  - cd $REPO_ROOT/interfacer && go test test/http-server/*.go -v -ginkgo.slowSpecThreshold=30 -ginkgo.flakeAttempts=3
 after_failure:
   - cat $REPO_ROOT/interfacer/test/tty/debug.log
   - cat $REPO_ROOT/interfacer/test/http-server/debug.log
diff --git a/interfacer/src/browsh/browsh.go b/interfacer/src/browsh/browsh.go
index 2f18af0..d3f2dc5 100644
--- a/interfacer/src/browsh/browsh.go
+++ b/interfacer/src/browsh/browsh.go
@@ -23,7 +23,7 @@ import (
 
 var (
 	logo = `
- ////  ////
+////  ////
  / /   / /
  //    //
  //    //    ,,,,,,,,
@@ -138,9 +138,9 @@ func Shell(command string) string {
 	parts = parts[1:]
 	out, err := exec.Command(head, parts...).CombinedOutput()
 	if err != nil {
-		Log(fmt.Sprintf(
-			"Browsh tried to run `%s` but failed with: %s", command, string(out)))
-		Shutdown(err)
+		errorMessge := fmt.Sprintf(
+			"Browsh tried to run `%s` but failed with: %s", command, string(out))
+		Shutdown(errors.New(errorMessge))
 	}
 	return strings.TrimSpace(string(out))
 }
@@ -151,7 +151,7 @@ func TTYStart(injectedScreen tcell.Screen) {
 	setupTcell()
 	writeString(1, 0, logo, tcell.StyleDefault)
 	writeString(0, 15, "Starting Browsh v"+browshVersion+", the modern text-based web browser.", tcell.StyleDefault)
-	startFirefox()
+	StartFirefox()
 	Log("Starting Browsh CLI client")
 	go readStdin()
 	startWebSocketServer()
diff --git a/interfacer/src/browsh/comms.go b/interfacer/src/browsh/comms.go
index 4199eca..27a92c5 100644
--- a/interfacer/src/browsh/comms.go
+++ b/interfacer/src/browsh/comms.go
@@ -6,6 +6,7 @@ import (
 	"net/http"
 	"strings"
 
+	"github.com/go-errors/errors"
 	"github.com/gorilla/websocket"
 	"github.com/spf13/viper"
 )
@@ -17,7 +18,7 @@ var (
 		WriteBufferSize: 1024,
 	}
 	stdinChannel              = make(chan string)
-	isConnectedToWebExtension = false
+	IsConnectedToWebExtension = false
 )
 
 type incomingRawText struct {
@@ -29,13 +30,14 @@ func startWebSocketServer() {
 	serverMux := http.NewServeMux()
 	serverMux.HandleFunc("/", webSocketServer)
 	port := viper.GetString("browsh.websocket-port")
-	if err := http.ListenAndServe(":"+port, serverMux); err != nil {
-		Shutdown(err)
+	Log("Starting websocket server...")
+	if netErr := http.ListenAndServe(":"+port, serverMux); netErr != nil {
+		Shutdown(errors.New(fmt.Errorf("Error starting websocket server: %v", netErr)))
 	}
 }
 
 func sendMessageToWebExtension(message string) {
-	if !isConnectedToWebExtension {
+	if !IsConnectedToWebExtension {
 		Log("Webextension not connected. Message not sent: " + message)
 		return
 	}
@@ -55,6 +57,11 @@ func webSocketReader(ws *websocket.Conn) {
 				triggerSocketWriterClose()
 				return
 			}
+			if websocket.IsUnexpectedCloseError(err, websocket.CloseGoingAway) {
+				Log("Socket reader detected that the connection unexpectedly dissapeared")
+				triggerSocketWriterClose()
+				return
+			}
 			Shutdown(err)
 		}
 	}
@@ -125,9 +132,10 @@ func webSocketWriter(ws *websocket.Conn) {
 		if err := ws.WriteMessage(websocket.TextMessage, []byte(message)); err != nil {
 			if err == websocket.ErrCloseSent {
 				Log("Socket writer detected that the browser closed the websocket")
-				return
+			} else {
+				Log("Socket writer detected unexpected closure of websocket")
 			}
-			Shutdown(err)
+			return
 		}
 	}
 }
@@ -138,7 +146,7 @@ func webSocketServer(w http.ResponseWriter, r *http.Request) {
 	if err != nil {
 		Shutdown(err)
 	}
-	isConnectedToWebExtension = true
+	IsConnectedToWebExtension = true
 	go webSocketWriter(ws)
 	go webSocketReader(ws)
 	sendConfigToWebExtension()
diff --git a/interfacer/src/browsh/firefox.go b/interfacer/src/browsh/firefox.go
index 3154c35..b0dcf30 100644
--- a/interfacer/src/browsh/firefox.go
+++ b/interfacer/src/browsh/firefox.go
@@ -52,8 +52,8 @@ var (
 )
 
 func startHeadlessFirefox() {
-	checkIfFirefoxIsAlreadyRunning()
 	Log("Starting Firefox in headless mode")
+	checkIfFirefoxIsAlreadyRunning()
 	firefoxPath := ensureFirefoxBinary()
 	ensureFirefoxVersion(firefoxPath)
 	args := []string{"--marionette"}
@@ -149,6 +149,10 @@ func versionOrdinal(version string) string {
 // extension.
 func startWERFirefox() {
 	Log("Attempting to start headless Firefox with `web-ext`")
+	if IsConnectedToWebExtension {
+		Shutdown(errors.New("There appears to already be an existing Web Extension connection"))
+	}
+	checkIfFirefoxIsAlreadyRunning()
 	var rootDir = Shell("git rev-parse --show-toplevel")
 	args := []string{
 		"run",
@@ -158,7 +162,6 @@ func startWERFirefox() {
 	}
 	firefoxProcess := exec.Command(rootDir+"/webext/node_modules/.bin/web-ext", args...)
 	firefoxProcess.Dir = rootDir + "/webext/dist/"
-	defer firefoxProcess.Process.Kill()
 	stdout, err := firefoxProcess.StdoutPipe()
 	if err != nil {
 		Shutdown(err)
@@ -168,6 +171,8 @@ func startWERFirefox() {
 	}
 	in := bufio.NewScanner(stdout)
 	for in.Scan() {
+		if strings.Contains(in.Text(), "Connected to the remote Firefox debugger") {
+		}
 		if strings.Contains(in.Text(), "JavaScript strict") ||
 			strings.Contains(in.Text(), "D-BUS") ||
 			strings.Contains(in.Text(), "dbus") {
@@ -175,6 +180,7 @@ func startWERFirefox() {
 		}
 		Log("FF-CONSOLE: " + in.Text())
 	}
+	Log("WER Firefox unexpectedly closed")
 }
 
 // Connect to Firefox's Marionette service.
@@ -294,7 +300,7 @@ func setupFirefox() {
 	installWebextension()
 }
 
-func startFirefox() {
+func StartFirefox() {
 	if !viper.GetBool("firefox.use-existing") {
 		writeString(0, 16, "Waiting for Firefox to connect...", tcell.StyleDefault)
 		if IsTesting {
diff --git a/interfacer/src/browsh/raw_text_server.go b/interfacer/src/browsh/raw_text_server.go
index 684bd08..b878e79 100644
--- a/interfacer/src/browsh/raw_text_server.go
+++ b/interfacer/src/browsh/raw_text_server.go
@@ -66,7 +66,7 @@ type rawTextResponse struct {
 // it will return:
 // `Something                                                                    `
 func HTTPServerStart() {
-	startFirefox()
+	StartFirefox()
 	go startWebSocketServer()
 	Log("Starting Browsh HTTP server")
 	bind := viper.GetString("http-server.bind")
diff --git a/interfacer/src/browsh/tab.go b/interfacer/src/browsh/tab.go
index 1b330dd..19461a5 100644
--- a/interfacer/src/browsh/tab.go
+++ b/interfacer/src/browsh/tab.go
@@ -29,6 +29,13 @@ type tab struct {
 	frame         frame
 }
 
+func ResetTabs() {
+	Tabs = make(map[int]*tab)
+	CurrentTab = nil
+	tabsOrder = nil
+	tabsDeleted = nil
+}
+
 func ensureTabExists(id int) {
 	if _, ok := Tabs[id]; !ok {
 		newTab(id)
diff --git a/interfacer/src/browsh/ui.go b/interfacer/src/browsh/ui.go
index d178182..973bb5d 100644
--- a/interfacer/src/browsh/ui.go
+++ b/interfacer/src/browsh/ui.go
@@ -37,7 +37,7 @@ func writeString(x, y int, str string, style tcell.Style) {
 			x = xOriginal
 			continue
 		}
-		screen.SetContent(x, y, c, nil, style)
+		screen.SetCell(x, y, style, c)
 		x++
 	}
 }
diff --git a/interfacer/test/http-server/setup.go b/interfacer/test/http-server/setup.go
index e3d3d91..e50796c 100644
--- a/interfacer/test/http-server/setup.go
+++ b/interfacer/test/http-server/setup.go
@@ -21,11 +21,21 @@ func startStaticFileServer() {
 	http.ListenAndServe(":"+staticFileServerPort, serverMux)
 }
 
-func startBrowsh() {
+func initBrowsh() {
 	browsh.IsTesting = true
 	browsh.Initialise()
 	viper.Set("http-server-mode", true)
-	browsh.HTTPServerStart()
+}
+
+func waitUntilConnectedToWebExtension(maxTime time.Duration) {
+	start := time.Now()
+	for time.Since(start) < maxTime {
+		if browsh.IsConnectedToWebExtension {
+			return
+		}
+		time.Sleep(50 * time.Millisecond)
+	}
+	panic("Didn't connect to webextension in time")
 }
 
 func getBrowshServiceBase() string {
@@ -55,7 +65,17 @@ func getPath(path string, mode string) string {
 	}
 }
 
+func stopFirefox() {
+	browsh.IsConnectedToWebExtension = false
+	browsh.Shell(rootDir + "/webext/contrib/firefoxheadless.sh kill")
+	time.Sleep(500 * time.Millisecond)
+}
+
 var _ = ginkgo.BeforeEach(func() {
+	stopFirefox()
+	browsh.ResetTabs()
+	browsh.StartFirefox()
+	waitUntilConnectedToWebExtension(15 * time.Second)
 	browsh.IsMonochromeMode = false
 	browsh.Log("\n---------")
 	browsh.Log(ginkgo.CurrentGinkgoTestDescription().FullTestText)
@@ -63,14 +83,13 @@ var _ = ginkgo.BeforeEach(func() {
 })
 
 var _ = ginkgo.BeforeSuite(func() {
+	initBrowsh()
+	stopFirefox()
 	go startStaticFileServer()
-	go startBrowsh()
-	time.Sleep(15 * time.Second)
-	// Allow the browser to sort its sizing out, because sometimes the first test catches the
-	// browser before it's completed its resizing.
-	getPath("/smorgasbord", "plain")
+	go browsh.HTTPServerStart()
+	time.Sleep(1 * time.Second)
 })
 
 var _ = ginkgo.AfterSuite(func() {
-	browsh.Shell(rootDir + "/webext/contrib/firefoxheadless.sh kill")
+	stopFirefox()
 })
diff --git a/interfacer/test/tty/setup.go b/interfacer/test/tty/setup.go
index 71ec079..b5b0b01 100644
--- a/interfacer/test/tty/setup.go
+++ b/interfacer/test/tty/setup.go
@@ -1,7 +1,10 @@
 package test
 
 import (
+	"fmt"
 	"net/http"
+	"os"
+	"path/filepath"
 	"strconv"
 	"time"
 	"unicode/utf8"
@@ -22,6 +25,8 @@ var perTestTimeout = 2000 * time.Millisecond
 var rootDir = browsh.Shell("git rev-parse --show-toplevel")
 var testSiteURL = "http://localhost:" + staticFileServerPort
 var ti *terminfo.Terminfo
+var dir, _ = os.Getwd()
+var framesLogFile = fmt.Sprintf(filepath.Join(dir, "frames.log"))
 
 func initTerm() {
 	// The tests check for true colour RGB values. The only downside to forcing true colour
@@ -48,11 +53,25 @@ func GetFrame() string {
 			line = 0
 		}
 	}
+	writeFrameLog("================================================")
+	writeFrameLog(ginkgo.CurrentGinkgoTestDescription().FullTestText)
+	writeFrameLog("================================================\n")
 	log = "\n" + log + styleDefault
-	ginkgo.GinkgoWriter.Write([]byte(log))
+	writeFrameLog(log)
 	return frame
 }
 
+func writeFrameLog(log string) {
+	f, err := os.OpenFile(framesLogFile, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0600)
+	if err != nil {
+		panic(err)
+	}
+	defer f.Close()
+	if _, err = f.WriteString(log); err != nil {
+		panic(err)
+	}
+}
+
 // Trigger the key definition specified by name
 func triggerUserKeyFor(name string) {
 	key := viper.GetStringSlice(name)
@@ -110,7 +129,7 @@ func WaitForPageLoad() {
 
 func sleepUntilPageLoad(maxTime time.Duration) {
 	start := time.Now()
-	time.Sleep(50 * time.Millisecond)
+	time.Sleep(1000 * time.Millisecond)
 	for time.Since(start) < maxTime {
 		if browsh.CurrentTab != nil {
 			if browsh.CurrentTab.PageState == "parsing_complete" {
@@ -132,6 +151,12 @@ func GotoURL(url string) {
 	// TODO: Looking for the URL isn't optimal because it could be the same URL
 	// as the previous test.
 	gomega.Expect(url).To(BeInFrameAt(0, 1))
+	// TODO: hack to work around bug where text sometimes doesn't render on page load.
+	// Clicking with the mouse triggers a reparse by the web extension
+	mouseClick(3, 6)
+	time.Sleep(100 * time.Millisecond)
+	mouseClick(3, 6)
+	time.Sleep(500 * time.Millisecond)
 }
 
 func mouseClick(x, y int) {
@@ -199,11 +224,18 @@ func startStaticFileServer() {
 	http.ListenAndServe(":"+staticFileServerPort, serverMux)
 }
 
-func startBrowsh() {
+func initBrowsh() {
 	browsh.IsTesting = true
 	simScreen = tcell.NewSimulationScreen("UTF-8")
 	browsh.Initialise()
-	browsh.TTYStart(simScreen)
+
+}
+
+func stopFirefox() {
+	browsh.Log("Attempting to kill all firefox processes")
+	browsh.IsConnectedToWebExtension = false
+	browsh.Shell(rootDir + "/webext/contrib/firefoxheadless.sh kill")
+	time.Sleep(500 * time.Millisecond)
 }
 
 func runeCount(text string) int {
@@ -211,6 +243,11 @@ func runeCount(text string) int {
 }
 
 var _ = ginkgo.BeforeEach(func() {
+	browsh.Log("Attempting to restart WER Firefox...")
+	stopFirefox()
+	browsh.ResetTabs()
+	browsh.StartFirefox()
+	sleepUntilPageLoad(startupWait)
 	browsh.IsMonochromeMode = false
 	browsh.Log("\n---------")
 	browsh.Log(ginkgo.CurrentGinkgoTestDescription().FullTestText)
@@ -218,12 +255,18 @@ var _ = ginkgo.BeforeEach(func() {
 })
 
 var _ = ginkgo.BeforeSuite(func() {
+	os.Truncate(framesLogFile, 0)
 	initTerm()
+	initBrowsh()
+	stopFirefox()
 	go startStaticFileServer()
-	go startBrowsh()
-	sleepUntilPageLoad(startupWait)
+	go browsh.TTYStart(simScreen)
+	// Firefox seems to take longer to die after its first run
+	time.Sleep(500 * time.Millisecond)
+	stopFirefox()
+	time.Sleep(5000 * time.Millisecond)
 })
 
 var _ = ginkgo.AfterSuite(func() {
-	browsh.Shell(rootDir + "/webext/contrib/firefoxheadless.sh kill")
+	stopFirefox()
 })
diff --git a/webext/contrib/firefoxheadless.sh b/webext/contrib/firefoxheadless.sh
index 82f3fdf..7a3be08 100755
--- a/webext/contrib/firefoxheadless.sh
+++ b/webext/contrib/firefoxheadless.sh
@@ -1,7 +1,13 @@
 #!/usr/bin/env bash
 
 if [[ "$1" = "kill" ]]; then
-  kill $(ps aux|grep headless|grep 'profile /tmp'| tr -s ' ' | cut -d ' ' -f2)
+  pids=$(ps aux|grep headless|grep 'profile /tmp'| tr -s ' ' | cut -d ' ' -f2)
+  if [[ $pids =~ [^0-9] ]] ; then
+    kill $pids
+  fi
+  if [[ "$CI" == "true" ]]; then
+    pkill -9 firefox || true
+  fi
 else
   FIREFOX_BIN=${FIREFOX:-firefox}
   $FIREFOX_BIN --headless "$@"
diff --git a/webext/package-lock.json b/webext/package-lock.json
index ca9e84d..1ca1b85 100644
--- a/webext/package-lock.json
+++ b/webext/package-lock.json
@@ -4591,7 +4591,8 @@
         "ansi-regex": {
           "version": "2.1.1",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         },
         "aproba": {
           "version": "1.2.0",
@@ -4612,12 +4613,14 @@
         "balanced-match": {
           "version": "1.0.0",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         },
         "brace-expansion": {
           "version": "1.1.11",
           "bundled": true,
           "dev": true,
+          "optional": true,
           "requires": {
             "balanced-match": "^1.0.0",
             "concat-map": "0.0.1"
@@ -4632,17 +4635,20 @@
         "code-point-at": {
           "version": "1.1.0",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         },
         "concat-map": {
           "version": "0.0.1",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         },
         "console-control-strings": {
           "version": "1.1.0",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         },
         "core-util-is": {
           "version": "1.0.2",
@@ -4759,7 +4765,8 @@
         "inherits": {
           "version": "2.0.3",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         },
         "ini": {
           "version": "1.3.5",
@@ -4771,6 +4778,7 @@
           "version": "1.0.0",
           "bundled": true,
           "dev": true,
+          "optional": true,
           "requires": {
             "number-is-nan": "^1.0.0"
           }
@@ -4785,6 +4793,7 @@
           "version": "3.0.4",
           "bundled": true,
           "dev": true,
+          "optional": true,
           "requires": {
             "brace-expansion": "^1.1.7"
           }
@@ -4792,12 +4801,14 @@
         "minimist": {
           "version": "0.0.8",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         },
         "minipass": {
           "version": "2.2.4",
           "bundled": true,
           "dev": true,
+          "optional": true,
           "requires": {
             "safe-buffer": "^5.1.1",
             "yallist": "^3.0.0"
@@ -4816,6 +4827,7 @@
           "version": "0.5.1",
           "bundled": true,
           "dev": true,
+          "optional": true,
           "requires": {
             "minimist": "0.0.8"
           }
@@ -4896,7 +4908,8 @@
         "number-is-nan": {
           "version": "1.0.1",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         },
         "object-assign": {
           "version": "4.1.1",
@@ -4908,6 +4921,7 @@
           "version": "1.4.0",
           "bundled": true,
           "dev": true,
+          "optional": true,
           "requires": {
             "wrappy": "1"
           }
@@ -4993,7 +5007,8 @@
         "safe-buffer": {
           "version": "5.1.1",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         },
         "safer-buffer": {
           "version": "2.1.2",
@@ -5029,6 +5044,7 @@
           "version": "1.0.2",
           "bundled": true,
           "dev": true,
+          "optional": true,
           "requires": {
             "code-point-at": "^1.0.0",
             "is-fullwidth-code-point": "^1.0.0",
@@ -5048,6 +5064,7 @@
           "version": "3.0.1",
           "bundled": true,
           "dev": true,
+          "optional": true,
           "requires": {
             "ansi-regex": "^2.0.0"
           }
@@ -5091,12 +5108,14 @@
         "wrappy": {
           "version": "1.0.2",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         },
         "yallist": {
           "version": "3.0.2",
           "bundled": true,
-          "dev": true
+          "dev": true,
+          "optional": true
         }
       }
     },
diff --git a/webext/src/dom/commands_mixin.js b/webext/src/dom/commands_mixin.js
index 6692632..f037c57 100644
--- a/webext/src/dom/commands_mixin.js
+++ b/webext/src/dom/commands_mixin.js
@@ -150,6 +150,12 @@ export default MixinBase =>
 
     _triggerKeyPress(key) {
       let el = document.activeElement;
+      if (el == null) {
+        this.log(
+          `Not pressing '${key.char}(${key.key})' as there is no active element`
+        );
+        return;
+      }
       const key_object = {
         key: key.char,
         keyCode: key.key