Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

testdriver: improve debug logging #236

Merged
merged 1 commit into from Jul 6, 2019

Conversation

milesbxf
Copy link
Collaborator

This makes it easier to debug issues with the govim tests, by allowing
users to log more information with a general -debugLog flag. This
enables Vim debug logging, and sends Vim startup output to the normal
Govim log. If Vim fails to start, it prints out the contents of the log,
which should hopefully contain some useful information. It also prints a
full command to run Vim with the temporary home directory.

Since the call to NewTestDriver was getting a bit unwieldy with over 10
args, I refactored that out into a Config struct.

@milesbxf milesbxf requested a review from myitcv May 19, 2019 08:37
@milesbxf milesbxf force-pushed the testdriver-debug-logging branch 2 times, most recently from 64fb247 to e27c545 Compare May 20, 2019 10:48
@milesbxf milesbxf force-pushed the testdriver-debug-logging branch 2 times, most recently from 71ac8b7 to a475c1a Compare May 27, 2019 11:07
@myitcv myitcv changed the title Improve testdriver debugging logging testdriver: improve debugging logging May 28, 2019
@myitcv
Copy link
Member

myitcv commented May 28, 2019

One small request: with commits, PRs and issues, please can you follow the following approach?

https://golang.org/doc/contribute.html#commit_messages

Specifically:

The first line of the change description is conventionally a short one-line summary of the change, prefixed by the primary affected package.

For example, here are the commits in master:

https://github.com/myitcv/govim/commits/master

It just means it's then trivial to create a relatively brief log of what's happened between versions:

$ git log --pretty=format:'* %s'
* cmd/govim: allow undo before format-on-save (#252)
* cmd/govim: change default of GOVIM_DISABLE_INCREMENTALSYNC to true (#250)
* cmd/govim: add support for delta-based buffer updates (#239)
* scripts: tidy and fully add Neovim image and flavor (#249)
* github: add funding details as a test (#246)
* ci: make GH_USER and GH_TOKEN optional (#245)
...

@milesbxf milesbxf force-pushed the testdriver-debug-logging branch 7 times, most recently from f96806f to 24bade2 Compare June 15, 2019 13:03
@milesbxf milesbxf changed the title testdriver: improve debugging logging testdriver: improve debug logging Jun 15, 2019
Copy link
Member

@myitcv myitcv left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@milesbxf very much like the direction of the changes. I'd just look to make this less noisy by default, amongst a couple of other comments

govim_test.go Outdated
if err != nil {
t.Fatalf("failed to create new driver: %v", err)
}
fmt.Printf("Vim home path is at %s\n", home)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These lines make the output of go test very noisy, which doesn't make much sense because it ends up outputting one of these lines per testscript. e.g. in the module root:

$ go test
Vim home path is at /tmp/go-test-script913401979/script-autocmd/home
Vim home path is at /tmp/go-test-script913401979/script-feedkeys_working/home
Vim home path is at /tmp/go-test-script913401979/script-redraw/home
Vim home path is at /tmp/go-test-script913401979/script-version/home
Vim home path is at /tmp/go-test-script913401979/script-range_function/home
Vim home path is at /tmp/go-test-script913401979/script-normal/home
Vim home path is at /tmp/go-test-script913401979/script-unscheduled/home
Vim home path is at /tmp/go-test-script913401979/script-function/home
Running testdriver for script-version
Running testdriver for script-function
Running testdriver for script-unscheduled
Running testdriver for script-normal
Running testdriver for script-range_function
Running testdriver for script-redraw
Running testdriver for script-feedkeys_working
Running testdriver for script-autocmd
Testdriver init finished for script-function
Setup complete for script-function
Testdriver init finished for script-version
Setup complete for script-version
Testdriver init finished for script-normal
Setup complete for script-normal
Testdriver init finished for script-unscheduled
Setup complete for script-unscheduled
Testdriver init finished for script-redraw
Setup complete for script-redraw
Testdriver init finished for script-feedkeys_working
Setup complete for script-feedkeys_working
Testdriver init finished for script-autocmd
Setup complete for script-autocmd
Testdriver init finished for script-range_function
Setup complete for script-range_function
Vim home path is at /tmp/go-test-script913401979/script-condition_vim/home
Vim home path is at /tmp/go-test-script913401979/script-feedkeys_broken/home
Vim home path is at /tmp/go-test-script913401979/script-expr/home
Vim home path is at /tmp/go-test-script913401979/script-ex/home
Running testdriver for script-condition_vim
Running testdriver for script-feedkeys_broken
Vim home path is at /tmp/go-test-script913401979/script-call/home
Vim home path is at /tmp/go-test-script913401979/script-command/home
Vim home path is at /tmp/go-test-script913401979/script-bad_function/home
Running testdriver for script-ex
Running testdriver for script-expr
Testdriver init finished for script-feedkeys_broken
Setup complete for script-feedkeys_broken
Testdriver init finished for script-condition_vim
Setup complete for script-condition_vim
Running testdriver for script-command
Running testdriver for script-call
Running testdriver for script-bad_function
Testdriver init finished for script-expr
Setup complete for script-expr
Testdriver init finished for script-ex
Setup complete for script-ex
Testdriver init finished for script-call
Setup complete for script-call
Testdriver init finished for script-bad_function
Setup complete for script-bad_function
Testdriver init finished for script-command
Setup complete for script-command

Would it not make sense to make this debug lines, and only have them output with -debugLog?

Could create a logf function or similar to keep things succinct

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, very good point - I'll go through and vet the printf calls

@@ -60,7 +63,22 @@ type TestDriver struct {
closed bool
}

func NewTestDriver(name string, govimPath, testHomePath, testPluginPath string, env *testscript.Env, plug govim.Plugin) (*TestDriver, error) {
type Config struct {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Much neater, thanks

govim_test.go Show resolved Hide resolved
func (d *TestDriver) LogStripANSI(r io.Reader) {
buf := bufio.NewReader(r)
for {
l, err := buf.ReadString('\n')
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Beware! In #299 I effectively fell foul of this default bufio buffer overflowing because of long lines. What do you actually use this output for?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, good catch, though I haven't come across this in testing.

I've found this very useful when debugging Vim startup errors


return res, nil
}

func (d *TestDriver) Logf(format string, a ...interface{}) {
fmt.Fprintf(d.Log, format+"\n", a...)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Again, only output if debugging enabled?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This should only be going to d.Log, which by default only logs to an error file

@milesbxf milesbxf requested a review from myitcv July 6, 2019 07:50
This makes it easier to debug issues with the govim tests, by allowing
users to log more information with a general -debugLog flag. This
enables Vim debug logging, and sends Vim startup output to the normal
Govim log. If Vim fails to start, it prints out the contents of the log,
which should hopefully contain some useful information. It also prints a
full command to run Vim with the temporary home directory.

Since the call to NewTestDriver was getting a bit unwieldy with over 10
args, I refactored that out into a Config struct.
Copy link
Member

@myitcv myitcv left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@milesbxf milesbxf merged commit a339394 into govim:master Jul 6, 2019
@milesbxf milesbxf deleted the testdriver-debug-logging branch July 6, 2019 18:04
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants