timer callback 内で起動した job の exit-cb 実行が遅れることがある

[ichizok]

質問・報告の内容

timer callback 内で job を起動すると、exit-cb の実行が最大で updatetime の時間分遅れます。

再現手順

ある程度大きなテキストファイルを用意する。

sample.txt

$ yes | head -c 100000 > sample.txt

sample.vim

fu! Task()
  call substitute(join(readfile('sample.txt'), ''), '.', 'x', 'g')
endfu

fu! ExitCb(job, status)
  let elapsed = reltimestr(reltime(s:starttime))
  echom printf('EXIT: %s', elapsed)
endfu

fu! JobStart(...)
  let s:starttime = reltime()
  let s:job = job_start('echo', {'exit_cb': 'ExitCb'})
  call Task()
endfu

call timer_start(100, 'JobStart')

vim --clean -S sample.vim

何も入力せずに放置する。

EXIT:   3.969833

コマンドは echo なので即座に終了するはずだが、おおよそ updatetime 経過後に exit-cb が実行される。

再現しない場合は sample.txt のサイズを増やして試してみてください。

OSの種類/ディストリ/バージョン

macOS と Linux の TUI で確認。GUI は (おそらく) 問題ない。

原因

timer callback 内部で job-channel が close されてしまうため。

1. 入力を受け付けるため mch_inchar() に入る
   この場合、job の exit-cb (終了検知) は以下の parse_queued_message() 内で実行される
   https://github.com/vim/vim/blob/master/src/os_unix.c#L419
2. 実行中の job はないので has_pending_job() は FALSE
   https://github.com/vim/vim/blob/master/src/os_unix.c#L469-L470
   よって、WaitForChar() で wait_time = updatetime 時間分入力を待つ
3. 100ms 後、WaitForChar() → ui_wait_for_chars_or_timer() 内で timer callback が実行される
   https://github.com/vim/vim/blob/master/src/ui.c#L234
4. timer callback (JobStart()) 内で job が起動する
5. Task() 内の substitute() 内で job-channel が読み取られ (EOF到達で) close される
6. そのため WaitForChar() から戻る契機が (ユーザ入力以外) なくなり、updatetime 経過でタイムアウトするまで parse_queued_message() が実行されない

ポイントは substitute() 内で job-channel が閉じられてしまう点。
関数内部の line_breakcheck() から RealWaitForChar() が呼ばれ、この中で channel_read() が実行されています。
再現サンプルでは、substitute() 実行中に job のプロセス (echo) を終了させるためにある程度大きなファイルを処理させて時間を稼いでいます。

substitute() 以外でも、内部で RealWaitForChar() 呼び出しが発生するような処理を置くことで同様に再現すると思います。

[ichizok]

https://github.com/vim/vim/compare/master...ichizok:fix/job-in-timer.diff

os_unix.c の mch_breakcheck() で、RealWaitForChar() が呼ばれた後に parse_queued_messages() を呼んで job/channel をチェックする。