fatih / vim-go

Go development plugin for Vim
https://www.patreon.com/bhcleek
Other
16.02k stars 1.45k forks source link

vim freezes for a couple of seconds when saving go files #144

Closed mhfs closed 10 years ago

mhfs commented 10 years ago

Hey there, first of all thanks for all the work on vim-go.

I started using it a few days ago and something weird that's happening is that every time I save a file vim freezes for a couple of seconds and then gets back to normal business.

Is this something other people experience or is it something with my setup? If the later, would you be able to help me debug where the slowness is?

I'd really appreciate any help.

Thanks!

fatih commented 10 years ago

Hm that might due goimports (I've heard it searches for all pkg if you have global variables) or syntax highlighting. Can you try to change :

let g:go_fmt_command = "gofmt"

If it's still slow can you test it with bare goimports on terminal and see how it works? If you believe that's really slow I think asking on golang-nuts mailing list would be much better.

mhfs commented 10 years ago

Thanks for answering so quickly.

So, if I run both goimports and gofmt in the console for the same file I'm editing, I get pretty quick responses:

➜ time ~/.vim-go/goimports main.go
~/.vim-go/goimports main.go  0.02s user 0.01s system 99% cpu 0.027 total

➜ time gofmt main.go
gofmt main.go  0.00s user 0.00s system 65% cpu 0.012 total

If I run :GoFmt from within vim (with or without the setting you suggested) I get the couple of seconds of wait. Could it have to do with the time it takes to shell out?

fatih commented 10 years ago

That one, plus it's doing double execution because otherwise Vim just destroys the history (doing a undo puts your cursor to the top of the file). The whole logic is here:

https://github.com/fatih/vim-go/blob/master/ftplugin/go/fmt.vim#L75

Have a look maybe you can catch something that i couldn't see. There are also some comments.

mhfs commented 10 years ago

Alright, I'll try to take a look tonight and get back to you.

porjo commented 10 years ago

I'm seeing this issue also. Top shows vim process chewing 100% CPU while the pause is happening.

fatih commented 10 years ago

Is there a way I could get a demo file for testing? It seems I can't reproduce because of my machine.

steino commented 10 years ago

I'm having the same issue. It seems to be running GoBuild after saving the file.

fatih commented 10 years ago

That's impossible. There is no single case where vim-go does it. Do you guys use https://github.com/scrooloose/syntastic ?

steino commented 10 years ago

Ah, yes. Thats the culprit, sorry about that.

fatih commented 10 years ago

@mhfs and @porjo do you also use https://github.com/scrooloose/syntastic ?

porjo commented 10 years ago

@fatih I'm no longer able to reproduce this issue. I had been using syntastic prior to vim-go but I'm fairly sure I wasn't using them together. I've since re-installed my OS so it's impossible to say...sorry, I can't be more help.

hoffoo commented 10 years ago

I use syntastic, usually I set to passive with :SynasticToggleMode unless I want it do its thing.

fatih commented 10 years ago

I'm going to close it but waiting for @mhfs. Let's clarify things here.

mhfs commented 10 years ago

@fatih I don't use syntastic. Also, I can see the delay by doing :GoFmt alone.

Unfortunately I didn't have the chance to explore the code yet.

mhfs commented 10 years ago

Also, the file content doesn't matter. A simple hello world takes a couple of seconds.

package main

import (
    "fmt"
)

func main() {
    fmt.Println("hello")
}
fatih commented 10 years ago

There must be definitely a problem on your system. Otherwise I would received a lot of complaints. vim-go is used already by thousands of people.

kristian-puccio commented 10 years ago

I'm getting this issue occasionally now.

I'm not using syntastic and it doesn't happen in every file.

I'll do some research and let you know.

kristian-puccio commented 10 years ago

Looks like maybe this is related to having undefined variables.

I was in the process of renaming a variable (which was a struct), while I hadn't finished saving took about 2s. After the variables had finished being renamed the save took under 0.5s.

My thinking on this is that goimport sees the badname.Data and notices that there is no variable definition for it so it tries to find a matching package, which I guess has it searching for a while.

I can't see how this is vim-go's fault but still the pause is annoying.

fatih commented 10 years ago

That's why I've changed the default from goimports to gofmt. To avoid problems like this.

jacobstr commented 10 years ago

I'm seeing this as well. Profiling around a :w shows:

FUNCTIONS SORTED ON SELF TIME
count  total (s)   self (s)  function
    1   0.016096   0.015837  278()
    2   3.201723   0.003541  SyntasticMake()
    2              0.002080  222()
    1   0.001067   0.000977  279()
    1              0.000702  <SNR>89_Highlight_Matching_Pair()
    1   3.207184   0.000652  <SNR>62_CacheErrors()
    5              0.000616  Pl#Statusline()
    1   0.020517   0.000581  260()
    5              0.000443  Powerline#Functions#GetFilepath()
    1   0.000670   0.000440  246()
    5              0.000415  Powerline#Functions#GetMode()
    1   0.001434   0.000395  219()
    3              0.000361  223()
    1   3.203138   0.000356  SyntaxCheckers_go_go_GetLocList()
   20              0.000345  syntastic#util#var()
    1   0.001556   0.000332  261()
   24   0.000498   0.000324  syntastic#log#debug()
    1   3.228451   0.000319  <SNR>62_UpdateErrors()
   15              0.000303  212()
    5   0.000661   0.000288  211()

Syntastic shells out to GoFmt. I was scratching my head about why vim-go was seemingly ignoring my:

let g:go_fmt_autosave = 0

Nope, it wasn't.

In my case I simply short-circuited the SyntaxCheckers_go_go_GetLocList() function in my syntastic ~/.vim/bundle folder by adding a return [] and yep - problem went away.

It appears to shell out to gofmt -l. Cool. That part's fast ... except if there are no errors it runs go build. So you get this behaviour where it saves quickly while it's linting with gomft and slows down when your source is clean.

kristian-puccio commented 10 years ago

I was just having a play around with liteIDE and noticed that there is a setting for gofmt timeout. By default it is set to 0.5s.

I wonder if implementing a timeout would be a good solution? If goimport takes longer than 0.5s then there probably was an error.

mhfs commented 10 years ago

In case it helps someone, this is what I'm seeing profiling a :w.

FUNCTIONS SORTED ON SELF TIME
count  total (s)   self (s)  function
    1   0.998373   0.002030  <SNR>96_GoFormat()
   13              0.001455  airline#check_mode()
    3              0.001270  fugitive#reload_status()
   12   0.001226   0.000939  airline#extensions#whitespace#check()
   73              0.000597  airline#util#wrap()
   24              0.000433  airline#util#append()
   12   0.001159   0.000388  airline#extensions#branch#get_head()
    1              0.000338  UltiSnips#CursorMoved()
   13              0.000314  airline#statusline()
    1              0.000295  <SNR>2_StripTrailingWhitespaces()
    2              0.000287  <SNR>82_check_mixed_indent()
   12   0.000771   0.000217  airline#extensions#branch#head()
   12              0.000209  airline#parts#ffenc()
    1              0.000196  <SNR>81_check_in_path()
    2              0.000178  <SNR>65_Highlight_Matching_Pair()
    1   0.000149   0.000127  <SNR>46_repo_head_ref()
   12              0.000120  airline#parts#iminsert()
    1              0.000089  BuffergatorUpdateMRU()
    2              0.000085  <SNR>46_repo()
   12              0.000071  airline#parts#mode()
FUNCTION  <SNR>96_GoFormat()
Called 1 time
Total time:   0.998373
 Self time:   0.002030

count  total (s)   self (s)
    1              0.000008     let l:curw=winsaveview()
    1              0.000007     let l:tmpname=tempname()
    1              0.000303     call writefile(getline(1,'$'), l:tmpname)

    1              0.000009     let command = g:go_fmt_command . ' ' . g:go_fmt_options
    1   0.544253   0.000351     let out = system(command . " " . l:tmpname)

                                "if there is no error on the temp file, gofmt our original file
    1              0.000011     if v:shell_error == 0
    1              0.000013         try | silent undojoin | catch | endtry
    1   0.453612   0.001171         silent execute "%!" . command

                                    " only clear quickfix if it was previously set, this prevents closing
                                    " other quickfixs
    1              0.000009         if s:got_fmt_error
                                        let s:got_fmt_error = 0
                                        call setqflist([])
                                        cwindow
                                    endif
    1              0.000002     elseif g:go_fmt_fail_silently == 0
                                    "otherwise get the errors and put them to quickfix window
                                    let errors = []
                                    for line in split(out, '\n')
                                        let tokens = matchlist(line, '^\(.\{-}\):\(\d\+\):\(\d\+\)\s*\(.*\)')
                                        if !empty(tokens)
                                            call add(errors, {"filename": @%,"lnum":     tokens[2],"col":      tokens[3],"text":     tokens[4]})
                                        endif
                                    endfor
                                    if empty(errors)
                                        % | " Couldn't detect gofmt error format, output errors
                                    endif
                                    if !empty(errors)
                                        call setqflist(errors, 'r')
                                        echohl Error | echomsg "Gofmt returned error" | echohl None
                                    endif
                                    let s:got_fmt_error = 1
                                    cwindow
                                endif

    1              0.000063     call delete(l:tmpname)
    1              0.000013     call winrestview(l:curw)
phuna commented 9 years ago

Hi, I got the same problem that saving go file makes vim freeze for around 3 seconds. I'm trying to profile :w but don't know how to do yet. In profile help there're file and func profile but still don't know how to apply them for :w. Could you help? Thank you

bwiggs commented 9 years ago

Also seeing slowness on save due to syntastic. :GoFmt is speedy, but with SyntasticToggleMode set to true it really slows down.

FUNCTIONS SORTED ON TOTAL TIME
count  total (s)   self (s)  function
    1   8.455450   0.000031  <SNR>53_BufWritePostHook()
    1   8.455407   0.000166  <SNR>53_UpdateErrors()
    1   8.454063   0.000287  <SNR>53_CacheErrors()
    1   8.453097   0.000024  155()
    1   8.452995   0.000075  154()
    1   8.452778   0.000175  SyntaxCheckers_go_go_GetLocList()
    2   8.452195   0.001466  SyntasticMake()
    1   0.569477   0.002985  go#fmt#Format()
    3   0.052557   0.000922  <SNR>118_AutoUpdate()
    1   0.050932   0.004340  <SNR>118_ProcessFile()
    1   0.023980   0.000209  <SNR>118_ExecuteCtagsOnFile()
    1   0.023612   0.000285  <SNR>118_ExecuteCtags()
   57   0.014923   0.011349  <SNR>118_ParseTagline()
    3   0.008139   0.000372  <SNR>118_SortTags()
   15   0.006782   0.003099  airline#extensions#whitespace#check()
    1   0.005190   0.000014  290()
  241   0.004479             <SNR>118_CompareByKind()
   15   0.004004             airline#check_mode()
    3   0.003683             <SNR>89_check_mixed_indent()
    2   0.003430   0.000263  <SNR>105_OnCursorMovedNormalMode()

@phuna You can profile using the following:

:profile start profile.log
:profile func *
:profile file *
" At this point do slow actions
:profile pause

Then quit vim to write out the profile.log file. See here

phuna commented 9 years ago

@bawigga This slowness problem has gone few weeks ago after I updated all plugins. I'll keep the link for later check if problem occurs again. Thank you for pointing it out.

cachance7 commented 9 years ago

I, too, was encountering a substantial delay. Was able to resolve my issue by setting the vim shell to bash; I use fish otherwise.

ernestas-poskus commented 9 years ago

For my case 'vim slowdown' was in a form of constant recompilation of binary when working with compilable (main) package. This was caused by scrooloose/syntastic - disabling it helped.

vlad-doru commented 9 years ago

Shout out to @ernestas-poskus .. Vim-go does not play well with syntastic.

ernestas-poskus commented 9 years ago

You are right, found the issue myself, Syntastic was recompiling Go project every time on save. Redefining g:syntastic_go_checkers checkers helped.

let g:syntastic_go_checkers = ['golint', 'govet', 'errcheck']
mckelvin commented 9 years ago

@ernestas-poskus :+1: for let g:syntastic_go_checkers = ['golint', 'govet', 'errcheck']

leonlee commented 9 years ago

@ernestas-poskus +1

ibash commented 8 years ago

Thanks @ernestas-poskus!

tsirolnik commented 8 years ago

I've reproduced this issue.

For anyone looking for the problem - It's probably syntastic (This was the problem for me)

Edit: It turns out that the biggest problem was that go compiles sqlite3 every time... So check your go build -x to see if that's the problem

rkuska commented 3 years ago

I am running into the same issue. I have a clean installation of nvim together with vim-go. There is anything in my config file besides Plug .... for vim-go. On save nvim freezes for 20 seconds.

I can see that most time spent is in promise.vim

FUNCTION  <SNR>49_await()
    Defined: ~/.vim/plugged/vim-go/autoload/go/promise.vim:37
Called 2 times
Total time:  20.056251
 Self time:  20.056072

count  total (s)   self (s)
    2              0.000025   let l:timer = timer_start(a:timeout, function('s:setretval', [a:default], self))
  395              0.004176   while !has_key(self, 'retval')
  393  20.049193  20.049015     sleep 50m
  395              0.002525   endwhile
    2              0.000026   call timer_stop(l:timer)

    2              0.000021   if get(self, 'exception', 0)
                                throw self.retval
    2              0.000003   endif
    2              0.000018   return self.retval

And promise is used twice from lsp.vim:


                              " await the result to avoid any race conditions among autocmds (e.g.
                              " BufWritePre and BufWritePost)
    1  10.004114   0.000025   call l:handler.await()

There is another call like this. I am not sure what is it waiting for though. lsp is executed by gofmt (lsp#Format and lsp#Imports)

rkuska commented 3 years ago

I see the same behavior in both vim and nvim.

rkuska commented 3 years ago

I figured out this one, I ran vim -V12log to get some logs to follow and I saw plenty of calls go#path#ToURI so I started thinking that 10s is maybe some sort of timeout. That's when I figured that I actually never built my project (I fresh installed my laptop) and I have some private repositories.

Got the necessary stuff to get private repository going, did go mod tidy and I have freezing no more.

carpet-stain commented 2 years ago

Running into the same issue describes above: `FUNCTION 353_await() Defined: ~/dev/dotfiles/vim/pack/03_plugins/start/go/autoload/go/promise.vim:37 Called 2 times Total time: 20.045644 Self time: 19.998178

count total (s) self (s) 2 0.000013 let l:timer = timer_start(a:timeout, function('s:setretval', [a:default], self)) 396 0.003118 while !has_key(self, 'retval') 394 20.040039 19.992573 sleep 50m 396 0.002180 endwhile 2 0.000008 call timer_stop(l:timer)

2              0.000005   if get(self, 'exception', 0)
                            throw self.retval
2              0.000001   endif
2              0.000003   return self.retval

`

I have tried doing a go mod tidy on my basic hello, world project but no dice.

shydefoo commented 1 year ago

@carpet-stain I'm facing the same issue also with the promise.vim file. Did you manage to resolve this issue eventually? If so how?