Errors in `svn checkout` do not propagate correctly

[fabulous-gopher]

From @spenczar on March 20, 2017 22:41

TestSvnRepo panics for me on the current master:

-> % go test -v -run TestSvnRepo .
=== RUN   TestSvnRepo
--- FAIL: TestSvnRepo (0.05s)
	vcs_repo_test.go:45: Problem checking out repo or SVN CheckLocal is not working
	vcs_repo_test.go:51: Unable to update SVN repo version. Err was unable to update checked out version
	vcs_repo_test.go:57: Error checking checked SVN out version
	vcs_repo_test.go:60: Unable to retrieve checked out version
	vcs_repo_test.go:66: unable to update repository
	vcs_repo_test.go:75: Unable to retrieve checked out version
	vcs_repo_test.go:80: unable to retrieve commit information
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x8 pc=0x13d9ed7]

goroutine 21 [running]:
testing.tRunner.func1(0xc42026a340)
	/Users/snelson/go1.8/src/testing/testing.go:622 +0x29d
panic(0x14b91e0, 0x1a93810)
	/Users/snelson/go1.8/src/runtime/panic.go:489 +0x2cf
github.com/sdboyer/gps.TestSvnRepo(0xc42026a340)
	/Users/snelson/go/src/github.com/sdboyer/gps/vcs_repo_test.go:82 +0x727
testing.tRunner(0xc42026a340, 0x1551ce0)
	/Users/snelson/go1.8/src/testing/testing.go:657 +0x96
created by testing.(*T).Run
	/Users/snelson/go1.8/src/testing/testing.go:697 +0x2ca
exit status 2
FAIL	github.com/sdboyer/gps	2.695s

This panic is happening because even though the err = repo.Get() line at L45 doesn't return an error, it is, in fact, failing. I hacked into the internals to print the command output, and I saw this:

2017/03/20 18:34:20 running command &{%!s(*exec.Cmd=&{/usr/bin/svn [svn checkout https://github.com/Masterminds/VCSTestRepo/trunk /var/folders/07/3tqty4fn0pqdmk8kyscf2g2m0wg_zb/T/go-vcs-svn-tests045048261/VCSTestRepo] []  <nil> 0xc420249800 0xc420249830 [] <nil> <nil> <nil> <nil> <nil> false [] [] [] [] <nil> <nil>}) %!s(time.Duration=120000000000) %!s(*gps.activityBuffer=&{{0 0} 0xc4201a7810 {0 0 <nil>}}) %!s(*gps.activityBuffer=&{{0 0} 0xc4201a7880 {0 0 <nil>}})}
2017/03/20 18:34:20 out=svn: E170013: Unable to connect to a repository at URL 'https://github.com/Masterminds/VCSTestRepo/trunk'
svn: E230001: Server SSL certificate verification failed: issuer is not trusted

Is it that the svn command exits with 0? No, it exits with 1:

-> % svn checkout "https://github.com/Masterminds/VCSTestRepo/trunk" . --non-interactive
svn: E170013: Unable to connect to a repository at URL 'https://github.com/Masterminds/VCSTestRepo/trunk'
svn: E230001: Server SSL certificate verification failed: issuer is not trusted

-> % echo $?
1

So it appears that the failure isn't getting correctly plumbed through.

Copied from original issue: sdboyer/gps#200

[fabulous-gopher]

From @sdboyer on March 22, 2017 11:55

Hmm, odd. (thanks for digging!)

Honestly, I haven't looked closely at the svn stuff (it's recently added, we didn't really support it before). All of the error handling there should follow a pretty standard pattern (that certainly does catch non-0 exit codes), so at first glance, it seems most likely that what we have just doesn't quite follow the pattern correctly.

[fabulous-gopher]

From @jstemmer on April 1, 2017 23:13

There are a few things happening here.

I'm fairly certain that the reason that err didn't return an error even though the command failed was because of a bug in runFromCwd. I've fixed this in #204.

I don't know why you saw an SSL verification error, it works for me currently. You had to dig a bit to find this, because the errors returned from the vcs package don't print the entire error message by default. It stores the error returned from running the command in the Original variable, however this isn't printed in the tests. @sdboyer this might be a case where including the original error in unwrapVcsErr() could be useful, but I'll have to investigate a bit more to be sure.

And finally, the reason for the nil pointer panic is that these tests don't stop when encountering errors, instead of calling t.Error it should actually be calling t.Fatal. I've created #205 to address this.

[fabulous-gopher]

From @sdboyer on April 1, 2017 23:28

@jstemmer yeah, I'm convinced. I was also noting the actual errors not making it through the other night while working on #196. If you make a PR to fix unwrapVcsError(), I'll merge it 😄

[fabulous-gopher]

From @jstemmer on April 1, 2017 23:43

Sorry, it looks like I was mistaken. I've ran a few tests with invalid repo urls and the original error only contains the string exit status 1. The actual error message is already captured from the command output and unwrapVcsErr propagates that correctly. For this particular case it wouldn't add much value to include the original error. I'd be interested to know if it actually contained some useful information for the particular case you mentioned when working on #196.

[fabulous-gopher]

From @sdboyer on April 2, 2017 2:56

Eh...it was late, and I was debugging a massively concurrent test, so I don't remember exactly :/ It may have been that I didn't have the fix from #204 yet at that point (I later adapted it into #196).