Printing unparsed test errors in Vim 8 silently fails

[mrnugget]

Behavior

When I run :GoTest on a test file that produces a panic instead of formatted output, I expect to see the contents of the panic. Instead I only see vim-go: <current directory>, highlighted as an error, at the bottom of the screen.

I can use :messages to open the previously printed unparsed test output, but I don't think that's what's intended here.

I think that this behaviour only arises when Vim 8's jobs API is being used.

Steps to reproduce:

1. Open this file in Vim 8:

// main_test.go
package main

import "testing"

func TestCrash(t *testing.T) {
	s := []int{}
	println(s[0])
}

2. Run :GoTest
3. See something like vim-go: /Users/mrnugget/code/go/src/test_vim_go printed at the bottom of the screen.
4. Run :messages to see the previously printed errors: --- FAIL: TestCrash (0.00s) panic: runtime error: index out of range [recovered]

Configuration

% vim --version
VIM - Vi IMproved 8.0 (2016 Sep 12, compiled Jan 12 2017 00:49:27)
MacOS X (unix) version
Included patches: 1-172
Compiled by Homebrew
Huge version with MacVim GUI.  Features included (+) or not (-):
+acl             +find_in_path    -mouse_sysmouse  -tag_any_white
+arabic          +float           +mouse_urxvt     +tcl
+autocmd         +folding         +mouse_xterm     +termguicolors
+balloon_eval    -footer          +multi_byte      +terminfo
+browse          +fork()          +multi_lang      +termresponse
++builtin_terms  +fullscreen      -mzscheme        +textobjects
+byte_offset     -gettext         +netbeans_intg   +timers
+channel         -hangul_input    +num64           +title
+cindent         +iconv           +odbeditor       +toolbar
+clientserver    +insert_expand   +packages        +transparency
+clipboard       +job             +path_extra      +user_commands
+cmdline_compl   +jumplist        +perl            +vertsplit
+cmdline_hist    +keymap          +persistent_undo +virtualedit
+cmdline_info    +lambda          +postscript      +visual
+comments        +langmap         +printer         +visualextra
+conceal         +libcall         +profile         +viminfo
+cryptv          +linebreak       +python          +vreplace
+cscope          +lispindent      -python3         +wildignore
+cursorbind      +listcmds        +quickfix        +wildmenu
+cursorshape     +localmap        +reltime         +windows
+dialog_con_gui  -lua             +rightleft       +writebackup
+diff            +menu            +ruby            -X11
+digraphs        +mksession       +scrollbind      -xfontset
+dnd             +modify_fname    +signs           +xim
-ebcdic          +mouse           +smartindent     -xpm
+emacs_tags      +mouseshape      +startuptime     -xsmp
+eval            +mouse_dec       +statusline      -xterm_clipboard
+ex_extra        -mouse_gpm       -sun_workshop    -xterm_save
+extra_search    -mouse_jsbterm   +syntax
+farsi           +mouse_netterm   +tag_binary
+file_in_path    +mouse_sgr       +tag_old_static
   system vimrc file: "$VIM/vimrc"
     user vimrc file: "$HOME/.vimrc"
 2nd user vimrc file: "~/.vim/vimrc"
      user exrc file: "$HOME/.exrc"
  system gvimrc file: "$VIM/gvimrc"
    user gvimrc file: "$HOME/.gvimrc"
2nd user gvimrc file: "~/.vim/gvimrc"
       defaults file: "$VIMRUNTIME/defaults.vim"
    system menu file: "$VIMRUNTIME/menu.vim"
  fall-back for $VIM: "/Applications/MacVim.app/Contents/Resources/vim"
Compilation: clang -c -I. -Iproto -DHAVE_CONFIG_H -DFEAT_GUI_MACVIM -Wall -Wno-unknown-pragmas -pipe  -DMACOS_X_UNIX  -F/usr/local/opt/python/Frameworks -I/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/include/python2.7 -I/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/include/python2.7 -fno-strict-aliasing -fno-common -dynamic -g -O2 -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -U_FORTIFY_SOURCE -D_FORTIFY_SOURCE=1
Linking: clang   -L. -L/usr/local/lib -L. -L/usr/local/lib -F/usr/local/opt/python/Frameworks -L/usr/local/opt/python/Frameworks/Python.framework/Versions/2.7/lib/python2.7/config -lpython2.7 -framework CoreFoundation -L/usr/local/lib -o Vim -framework Cocoa -framework Carbon       -lm  -lncurses -liconv -framework Cocoa   -fstack-protector  -L/System/Library/Perl/5.18/darwin-thread-multi-2level/CORE -lperl -F/usr/local/opt/python/Frameworks -framework Python  -F/System/Library/Frameworks -framework Tcl -framework CoreFoundation -framework Ruby

% go version
go version go1.7 darwin/amd64

% cd ~/.vim/bundle/vim-go && git rev-parse HEAD && cd -
3eb57ac3a8e02a3d6e2bfba981144c6e1af3545b

Investigation

I traced the the problem down to these two lines:

      call go#util#EchoError(join(self.messages, " "))
      call go#util#EchoError(self.dir)

First the messages that couldn't be parsed are printed, then the directory of the currently running job.

Scanning through go/cmd.vim we can see that if neither neovim nor Vim 8 is being used, the errors are simply printed, without the directory being printed.

      " failed to parse errors, output the original content
      call go#util#EchoError(out)

I'd prefer that to having to type :messages.

But them I'm not sure if the observed behaviour is the intended one. I found default error callback that's being used with Vim 8's jobs API that's supposed to print elapsed time, too. And I don't know if I see that.

Here's the simplest-possible-solution-that-would-work for me:

Remove the mentioned call go#util#EchoError(self.dir) in go/job.vim.

Here's my this-is-perfect-solution:

Change EchoError in such a way that all messages are visible and newlines are escaped! Because at the moment they are not and that makes the output not that readable in :messages.

I could open a PR for the simplest solution, but I'm not really sure what the way forward is here.

Let me know what you think!

[bhcleek]

I've noticed this, too, and started work to parse panic output to populate the errors list. I'd appreciate @fatih's input on this.

[mkleina]

Same thing with GoConvey (https://github.com/smartystreets/goconvey). If test succeeds, :GoTest command displays "vim-go: testing..." status forever. If test fails, after a while "vim-go: <current directory>" highlighted as error appears on status bar, like in @mrnugget case.

I think that issue #1324 shows similar scenario.

[arp242]

There are two problems here:

1. Consecutive messages aren't shown as you would expect with a "Press ENTER or type command to continue" prompt.

2. Panics in :GoTest aren't put in the {location,quickfix} list.

The first problem is due to the way async jobs work. With regular synchronous Vim it's easy to detect that multiple messages will be displayed (just finish running the function), but with async it's not, so Vim can't show the prompt.

This can be fixed with something like this, which captures the messages in the callback:

fun! Test()
	let l:messages = []
	let l:messages_done = 0
	fun! s:exit_cb(job, exitval) closure
		let l:messages = ["one", "two"]
		let l:messages_done = 1
	endfun

	let job = job_start("true", {"exit_cb": funcref('s:exit_cb')})
	while 1
		if job_status(job) != 'run' && l:messages_done == 1
			break
		end
		sleep 100 m
	endwhile

	echom l:messages[0]
	echom l:messages[1]
endfun

The quickfix list can be fixed by tweaking s:parse_errors(). Ideally golang/go#2981 gets done in 1.10 and we can use more structured output from go test, but it looks like that change has been planned for every Go release since 1.1 :-/