tests: create gists from artefacts (logs) of failed CI tests (#650)

Very often we get "useful" failures on CI that are hard to reproduce
locally. Given the headless nature of CI it's impossible to then extract
the log files from those failures. This is very frustrating.

This commit causes test failures on Travis to create a gist with a
base64 encoded .tar.gz of the log files from all tests that have, to
that point, run. For convenience, a command is echo-ed that can be
copy-pasted into your shell that will change to a new temp dir and
untar the log files ready for inspection.

.travis.yml

@@ -20,6 +20,7 @@ env:
   global:
     - GO111MODULE=on
     - GOPROXY=https://proxy.golang.org
+    - ARTEFACTS=$HOME/artefacts
   matrix:
     - GO_VERSION="go1.12.14" VIM_FLAVOR="vim" VIM_VERSION="v8.1.1711" VIM_COMMAND="vim"
     - GO_VERSION="go1.13.5" VIM_FLAVOR="vim" VIM_VERSION="v8.1.1711" VIM_COMMAND="vim"
@@ -53,3 +54,6 @@ before_install:
 
 script:
   - ./_scripts/runDockerRun.sh
+
+after_failure:
+  - ./_scripts/afterFailure.sh

_scripts/afterFailure.sh

@@ -0,0 +1,23 @@
+#!/usr/bin/env bash
+
+source "${BASH_SOURCE%/*}/common.bash"
+
+if [ "${CI:-}" != "true" ]
+then
+	exit
+fi
+
+# The ARTEFACTS variable set by .travis.yml cannot expand
+# variables so we do that here
+ARTEFACTS=$(echo $ARTEFACTS)
+
+cd $ARTEFACTS
+
+# Remove all the big directories first
+sudo find . -type d \( -name .vim -o -name gopath \) -prune -exec rm -rf '{}' \;
+
+# Now prune the files we don't want
+sudo find . -type f -not -path "*/_tmp/govim_log" -and -not -path "*/_tmp/gopls_log" -and -not -path "*/_tmp/vim_channel_log" -exec rm '{}' \;
+
+url=$(echo "{ \"public\": false, \"files\": { \"logs.base64\": { \"content\": \"$(find . -type f -print0 | tar -zc --null -T - | base64 | sed ':a;N;$!ba;s/\n/\\n/g')\" } } }" | curl -s -H "Content-Type: application/json" -u $GH_USER:$GH_TOKEN --request POST --data-binary "@-" https://api.github.com/gists | jq -r '.files."logs.base64".raw_url')
+echo 'cd $(mktemp -d) && curl -s '$url' | base64 -d | tar -zx'

_scripts/dockerRun.sh

@@ -2,6 +2,9 @@
 
 source "${BASH_SOURCE%/*}/common.bash"
 
+# This ensures that Travis properly runs the after_failure script
+trap 'set +ev' EXIT
+
 if [ "${VIM_COMMAND:-}" == "" ]
 then
 	eval "VIM_COMMAND=\"\$DEFAULT_${VIM_FLAVOR^^}_COMMAND\""

_scripts/genconfig.go

@@ -237,6 +237,7 @@ env:
   global:
     - GO111MODULE=on
     - GOPROXY=https://proxy.golang.org
+    - ARTEFACTS=$HOME/artefacts
   matrix:
 {{range . -}}{{.}}
 {{end}}
@@ -253,6 +254,9 @@ before_install:
 
 script:
   - ./_scripts/runDockerRun.sh
+
+after_failure:
+  - ./_scripts/afterFailure.sh
 `
 
 const maxVersions = `# Code generated by genconfig. DO NOT EDIT.

_scripts/runDockerRun.sh

@@ -6,13 +6,20 @@ doBranchCheck
 
 cd "${BASH_SOURCE%/*}/../"
 
+# The ARTEFACTS variable set by .travis.yml cannot expand
+# variables so we do that here
+ARTEFACTS=$(echo $ARTEFACTS)
+
 proxy=""
 
 if [ "${CI:-}" != "true" ]
 then
 	go mod download
 	modcache="$(go env GOPATH | sed -e 's/:/\n/' | head -n 1)/pkg/mod/cache/download"
 	proxy="-v $modcache:/cache -e GOPROXY=file:///cache"
+else
+	mkdir -p $ARTEFACTS
+	artefacts="-v $ARTEFACTS:/artefacts -e GOVIM_TESTSCRIPT_WORKDIR_ROOT=/artefacts"
 fi
 
-docker run $proxy --env-file ./_scripts/.docker_env_file -e "VIM_FLAVOR=${VIM_FLAVOR:-vim}" -v $PWD:/home/$USER/govim -w /home/$USER/govim --rm govim ./_scripts/dockerRun.sh
+docker run $proxy --env-file ./_scripts/.docker_env_file -e "VIM_FLAVOR=${VIM_FLAVOR:-vim}" $artefacts -v $PWD:/home/$USER/govim -w /home/$USER/govim --rm govim ./_scripts/dockerRun.sh

cmd/govim/main.go

@@ -106,7 +106,7 @@ func launch(goplspath string, in io.ReadCloser, out io.WriteCloser) error {
 
 	d := newplugin(goplspath, nil, nil, nil)
 
-	tf, err := createLogFile("govim_log")
+	tf, err := d.createLogFile("govim_log")
 	if err != nil {
 		return err
 	}
@@ -130,21 +130,21 @@ func launch(goplspath string, in io.ReadCloser, out io.WriteCloser) error {
 	return d.tomb.Wait()
 }
 
-func createLogFile(prefix string) (*os.File, error) {
+func (g *govimplugin) createLogFile(prefix string) (*os.File, error) {
 	var tf *os.File
 	var err error
-	logfiletmpl := os.Getenv(testsetup.EnvLogfileTmpl)
+	logfiletmpl := getEnvVal(g.goplsEnv, testsetup.EnvLogfileTmpl)
 	if logfiletmpl == "" {
 		logfiletmpl = "%v_%v_%v"
 	}
 	logfiletmpl = strings.Replace(logfiletmpl, "%v", prefix, 1)
 	logfiletmpl = strings.Replace(logfiletmpl, "%v", time.Now().Format("20060102_1504_05"), 1)
 	if strings.Contains(logfiletmpl, "%v") {
 		logfiletmpl = strings.Replace(logfiletmpl, "%v", "*", 1)
-		tf, err = ioutil.TempFile("", logfiletmpl)
+		tf, err = ioutil.TempFile(g.tmpDir, logfiletmpl)
 	} else {
 		// append to existing file
-		tf, err = os.OpenFile(filepath.Join(os.TempDir(), logfiletmpl), os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
+		tf, err = os.OpenFile(filepath.Join(g.tmpDir, logfiletmpl), os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
 	}
 	if err != nil {
 		err = fmt.Errorf("failed to create log file: %v", err)
@@ -156,6 +156,9 @@ type govimplugin struct {
 	plugin.Driver
 	vimstate *vimstate
 
+	// tmpDir is the temp directory within which log files will be created
+	tmpDir string
+
 	// goplsEnv is the environment with which to start gopls. This is
 	// set in os/exec.Command.Env
 	goplsEnv []string
@@ -207,6 +210,13 @@ type govimplugin struct {
 }
 
 func newplugin(goplspath string, goplsEnv []string, defaults, user *config.Config) *govimplugin {
+	if goplsEnv == nil {
+		goplsEnv = os.Environ()
+	}
+	tmpDir := getEnvVal(goplsEnv, "TMPDIR")
+	if tmpDir == "" {
+		tmpDir = os.TempDir()
+	}
 	if defaults == nil {
 		defaults = &config.Config{
 			FormatOnSave:            vimconfig.FormatOnSaveVal(config.FormatOnSaveGoImports),
@@ -222,6 +232,7 @@ func newplugin(goplspath string, goplsEnv []string, defaults, user *config.Confi
 	}
 	d := plugin.NewDriver(PluginPrefix)
 	res := &govimplugin{
+		tmpDir:                    tmpDir,
 		rawDiagnostics:            make(map[span.URI]*protocol.PublishDiagnosticsParams),
 		goplsEnv:                  goplsEnv,
 		goplspath:                 goplspath,
@@ -286,7 +297,7 @@ func (g *govimplugin) Init(gg govim.Govim, errCh chan error) error {
 
 	g.isGui = g.ParseInt(g.ChannelExpr(`has("gui_running")`)) == 1
 
-	logfile, err := createLogFile("gopls_log")
+	logfile, err := g.createLogFile("gopls_log")
 	if err != nil {
 		return err
 	}
@@ -456,3 +467,12 @@ func (g *govimplugin) defineHighlights() {
 	}
 	g.vimstate.BatchEnd()
 }
+
+func getEnvVal(env []string, varname string) string {
+	for i := len(env) - 1; i >= 0; i-- {
+		if strings.HasPrefix(env[i], varname+"=") {
+			return strings.TrimPrefix(env[i], varname+"=")
+		}
+	}
+	return ""
+}

cmd/govim/main_test.go

@@ -32,7 +32,6 @@ const (
 )
 
 var (
-	fDebugLog  = flag.Bool("debugLog", false, "Whether to log debugging info from vim, govim and the test shim")
 	fGoplsPath = flag.String("gopls", "", "Path to the gopls binary for use in scenario tests. If unset, gopls is built from a tagged version.")
 )
 
@@ -48,6 +47,18 @@ func TestMain(m *testing.M) {
 }
 
 func TestScripts(t *testing.T) {
+	// TODO our approach with setting the workdir root via os.Setenv("GOTMPDIR")
+	// is hacky and gross. Working out a cleaner approach with rogpeppe, likely
+	// passing in such a value via Params
+	var workdir string
+	if envworkdir := os.Getenv(testsetup.EnvTestscriptWorkdirRoot); envworkdir == "" {
+		// i.e. we are not going to call os.Setenv below
+		t.Parallel()
+	} else {
+		workdir = filepath.Join(envworkdir, "cmd", "govim"+raceOrNot())
+		defer os.Setenv("GOTMPDIR", os.Getenv("GOTMPDIR"))
+	}
+
 	var waitLock sync.Mutex
 	var waitList []func() error
 
@@ -77,9 +88,18 @@ func TestScripts(t *testing.T) {
 		if !entry.IsDir() || !strings.HasPrefix(entry.Name(), "scenario_") {
 			continue
 		}
+		workdir := workdir
+		if workdir != "" {
+			workdir = filepath.Join(workdir, entry.Name())
+			os.MkdirAll(workdir, 0777)
+			os.Setenv("GOTMPDIR", workdir)
+		}
 		t.Run(entry.Name(), func(t *testing.T) {
+			// Do not call t.Parallel here. We currently rely on this being
+			// run on the test goroutine in order that os.Setenv is not racey
 			params := testscript.Params{
-				Dir: filepath.Join("testdata", entry.Name()),
+				TestWork: workdir != "",
+				Dir:      filepath.Join("testdata", entry.Name()),
 				Cmds: map[string]func(ts *testscript.TestScript, neg bool, args []string){
 					"sleep":       testdriver.Sleep,
 					"errlogmatch": testdriver.ErrLogMatch,
@@ -101,6 +121,9 @@ func TestScripts(t *testing.T) {
 						"PLUGIN_PATH="+govimPath,
 						"CURRENT_GOPATH="+strings.TrimSpace(runCmd(t, "go", "env", "GOPATH")),
 					)
+					if workdir != "" {
+						e.Vars = append(e.Vars, "GOVIM_LOGFILE_TMPL=%v")
+					}
 					testPluginPath := filepath.Join(home, ".vim", "pack", "plugins", "start", "govim")
 
 					errLog := new(testdriver.LockingBuffer)
@@ -112,14 +135,27 @@ func TestScripts(t *testing.T) {
 						outputs = append(outputs, os.Stderr)
 					}
 
-					if *fDebugLog {
-						tf, err := ioutil.TempFile("", "govim_test_script_govim_log*")
+					var err error
+					var tf *os.File
+					if workdir == "" {
+						tf, err = ioutil.TempFile(tmp, "govim_log*")
 						if err != nil {
 							t.Fatalf("failed to create govim log file: %v", err)
 						}
-						outputs = append(outputs, tf)
-						t.Logf("logging %v to %v\n", filepath.Base(e.WorkDir), tf.Name())
+					} else {
+						// create a "plain"-named logfile because as above we set
+						// GOVIM_LOGFILE_TMPL=%v
+						tf, err = os.OpenFile(filepath.Join(tmp, "govim_log"), os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0666)
+						if err != nil {
+							t.Fatalf("failed to create non-tmp govim log file: %v", err)
+						}
 					}
+					e.Defer(func() {
+						if err := tf.Close(); err != nil {
+							panic(fmt.Errorf("failed to close govim logfile %v: %v", tf.Name(), err))
+						}
+					})
+					outputs = append(outputs, tf)
 
 					defaultsPath := filepath.Join("testdata", entry.Name(), "default_config.json")
 					defaults, err := readConfig(defaultsPath)

govim_test.go

@@ -35,22 +35,46 @@ func TestMain(m *testing.M) {
 }
 
 func TestScripts(t *testing.T) {
+	// TODO our approach with setting the workdir root via os.Setenv("GOTMPDIR")
+	// is hacky and gross. Working out a cleaner approach with rogpeppe, likely
+	// passing in such a value via Params
+	workdir := os.Getenv(testsetup.EnvTestscriptWorkdirRoot)
+	if workdir == "" {
+		// i.e. we are not going to call os.Setenv below
+		t.Parallel()
+	} else {
+		os.MkdirAll(workdir, 0777)
+		os.Setenv("GOTMPDIR", workdir)
+		defer os.Setenv("GOTMPDIR", os.Getenv("GOTMPDIR"))
+	}
+
 	var waitLock sync.Mutex
 	var waitList []func() error
 
 	t.Run("scripts", func(t *testing.T) {
 		testscript.Run(t, testscript.Params{
-			Dir: "testdata",
+			TestWork: workdir != "",
+			Dir:      "testdata",
 			Cmds: map[string]func(ts *testscript.TestScript, neg bool, args []string){
 				"sleep":       testdriver.Sleep,
 				"errlogmatch": testdriver.ErrLogMatch,
 			},
 			Condition: testdriver.Condition,
 			Setup: func(e *testscript.Env) error {
+				// Set a special temp dir to make identifying it easier for log
+				// scraping
+				tmp := filepath.Join(e.WorkDir, "_tmp")
+				if err := os.MkdirAll(tmp, 0777); err != nil {
+					return fmt.Errorf("failed to create temp dir %v: %v", tmp, err)
+				}
 				home := filepath.Join(e.WorkDir, ".home")
 				e.Vars = append(e.Vars,
 					"HOME="+home,
+					"TMPDIR="+tmp,
 				)
+				if workdir != "" {
+					e.Vars = append(e.Vars, "GOVIM_LOGFILE_TMPL=%v")
+				}
 				testPluginPath := filepath.Join(home, ".vim", "pack", "plugins", "start", "govim")
 
 				var vimDebugLogPath, govimDebugLogPath string

testsetup/testsetup.go

@@ -14,13 +14,14 @@ import (
 
 // dev environment variables
 const (
-	EnvTestSocket       = "GOVIMTEST_SOCKET"
-	EnvVimFlavor        = "VIM_FLAVOR"
-	EnvVimCommand       = "VIM_COMMAND"
-	EnvGithubUser       = "GH_USER"
-	EnvGithubToken      = "GH_TOKEN"
-	EnvLoadTestAPI      = "GOVIM_LOAD_TEST_API"
-	EnvTestscriptStderr = "GOVIM_TESTSCRIPT_STDERR"
+	EnvTestSocket            = "GOVIMTEST_SOCKET"
+	EnvVimFlavor             = "VIM_FLAVOR"
+	EnvVimCommand            = "VIM_COMMAND"
+	EnvGithubUser            = "GH_USER"
+	EnvGithubToken           = "GH_TOKEN"
+	EnvLoadTestAPI           = "GOVIM_LOAD_TEST_API"
+	EnvTestscriptStderr      = "GOVIM_TESTSCRIPT_STDERR"
+	EnvTestscriptWorkdirRoot = "GOVIM_TESTSCRIPT_WORKDIR_ROOT"
 )
 
 // user environment variables