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.

.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

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()

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()

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,13 +171,16 @@ 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") {
 			continue
 		}
 		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 {

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")

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)

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++
 	}
 }

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,22 +65,31 @@ 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)
 	browsh.Log("---------")
 })
 
 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()
 })

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,31 +224,49 @@ 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 {
 	return utf8.RuneCountInString(text)
 }
 
 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)
 	browsh.Log("---------")
 })
 
 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()
 })