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

fix when async job finishes before AsyncRun_Job_Start() sets async_state=1 #92

Merged
merged 1 commit into from
Feb 8, 2018
Merged

Conversation

antoinemadec
Copy link

Fixes #25 .
This issue is that sometimes -when system() is busy for instance- the execution can go like that:
1- AsyncRun_Job_OnExit() finishes (s:async_state=2)
2- AsyncRun_Job_OnClose() finishes (s:async_state=6)
3- AsyncRun_Job_Start() let s:async_state = 1

Hence, s:async_state is never equal to 7 and AsyncRun_Job_OnFinish() is never called
by AsyncRun_Job_OnTimer().

Could you please merge this PR ?
Thanks in advance !

@skywind3000
Copy link
Owner

Thanks for the PR, I'd like to merge it.
and I have a question, could any of the callbacks happen before AsyncRun_Job_Start exiting ?

The callbacks are supposed to be invoked by vim's event loop, the event loop will pause when it is calling functions and will continue when function returns.

In this case, AsyncRun_Job_Start hasn't finished, how can vim's event loop call the job callbacks ??

@antoinemadec
Copy link
Author

antoinemadec commented Feb 7, 2018

Yes, that what I meant by 1- 2- 3-.
With the following .vimrc:

call plug#begin('~/.vim/plugins_by_vimplug')
Plug 'skywind3000/asyncrun.vim'
call plug#end()
set nocompatible

autocmd BufWinEnter * call system("sleep 5")

When running :copen | AsyncRun echo foo, here are some debug messages:
DBG: call AsyncRun_Job_Start() at 13:31:47
DBG: call job_start() in AsyncRun_Job_Start() at 13:31:47
DBG: job_start() is done in AsyncRun_Job_Start() at 13:31:47
DBG: call setqflist() in AsyncRun_Job_Start() at 13:31:47
DBG: call AsyncRun_Job_OnClose() at 13:31:47
DBG: call AsyncRun_Job_OnExit() at 13:31:47
DBG: AsyncRun_Job_OnExit() is done at 13:31:47
DBG: AsyncRun_Job_OnClose() is done at 13:31:47
DBG: setqflist() is done in AsyncRun_Job_Start() at 13:31:52
DBG: set async_state = 1 in AsyncRun_Job_Start() at 13:31:52
DBG: AsyncRun_Job_Start() is done at 13:31:52

setqflist() takes 5 seconds to execute, since job_start() is executed before it and let s:async_state=1 after it, the callbacks are called before async_state=1 yes.
job_start() does not wait for the callbacks execution to return, so there is no mechanism guaranteeing that the callbacks will be executed after AsyncRun_Job_Start() finishes.

@skywind3000
Copy link
Owner

I can't reproduce it by a very simple vimscript:

function! Job_OnExit(job, code)
        caddexpr "[finished]"
        cbottom
endfunc

function! Job_OnCallback(channel, text)
        caddexpr "output: ". a:text
        cbottom
endfunc

copen 10
cexpr ""
wincmd w
cbottom

let opt = {'exit_cb': 'Job_OnExit', 'callback': 'Job_OnCallback'}
let job = job_start(['/bin/sh', '-c', 'echo 1 2 3'], opt)

caddexpr "[start]"

After running many times,
it appears that output and [finished] can't come before [start].

@antoinemadec
Copy link
Author

antoinemadec commented Feb 7, 2018

@skywind3000 , please try to reproduce using the .vimrc I provided you with:

call plug#begin('~/.vim/plugins_by_vimplug')
Plug 'skywind3000/asyncrun.vim'
call plug#end()
set nocompatible

autocmd BufWinEnter * call system("sleep 5")

And then run :copen | AsyncRun echo foo

In your example, nothing is consuming time between job_start() and caddexpr "[start]".
With the real plugin and the .vimrc above:
1- job_start() returns
2- setqflist() will take 5 sec; meanwhile the callbacks will be executed
3- then, let s:async_state=1

Please let me know if you have any issue reproducing my testcase.

Cheers,
Antoine

@antoinemadec
Copy link
Author

Here is a modified version of your script to show the issue, I just added sleep 1 between job_start() and caddexpr "[start]":

function! Job_OnExit(job, code)
        caddexpr "[finished]"
        cbottom
endfunc

function! Job_OnCallback(channel, text)
        caddexpr "output: ". a:text
        cbottom
endfunc

copen 10
cexpr ""
wincmd w
cbottom

let opt = {'exit_cb': 'Job_OnExit', 'callback': 'Job_OnCallback'}
let job = job_start(['/bin/sh', '-c', 'echo 1 2 3'], opt)

sleep 1

caddexpr "[start]"

Here is the output of the quickfix window:

|| output: 1 2 3                                                                                                     
|| [finished]
|| [start]

@skywind3000 skywind3000 merged commit 2214a3c into skywind3000:master Feb 8, 2018
@skywind3000
Copy link
Owner

thanks very much

@antoinemadec
Copy link
Author

No problem, thanks for the great plugin 😉

@skywind3000
Copy link
Owner

skywind3000 commented Feb 8, 2018

I have changed the order of some variable assigment for better state handling. Please update.

I am curious why did the second setqflist cost 5 seconds in your case, do you have any autocmd listening on QuickFixCmdPre or QuickFixCmdPost ??

What plugin in your vimrc will stuck setqflist for 5 seconds ? Is there something they need to wait ?

@antoinemadec
Copy link
Author

It was it the .vimrc I gave you:
autocmd BufWinEnter * call system("sleep 5")

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