vim/YouCompleteMe
1
0
Fork 0
Code Issues Pull Requests Releases Wiki Activity

Auto merge of #2430 - micbou:client-logfile, r=Valloric

Browse Source 
[READY] Add client logfile

We have a lot of issue reports with Python exceptions that interrupt user workflow or even worse make the editor unusable and force users to restart it (e.g. issue https://github.com/Valloric/YouCompleteMe/issues/2192). We really want to avoid that but at the same time we can't just silence these exceptions because they are useful to debug the issue. Logging them to Vim `:messages` is not practical because we can't write to it without displaying messages in the status line which, in addition to distract users, may lead to various issues like the infamous `Press ENTER or type command to continue` message. This is why a logfile is needed.

For now, only server crashes are logged but more logging will be added: connection issues with the server (`ConnectTimeout`, `ReadTimeout`, etc. exceptions), UltiSnips unavailability, requests sent to the server, etc.

The behavior of the `:YcmToggleLogs` command is changed to accept multiple arguments where each argument is a logfile name. Each of these files is opened in a separate window or closed if already open. When no argument is given, the list of available logfiles is displayed to the user. Example:
```
Available logfiles are:
ycm_pz83u7.log
ycmd_23830_stderr_gf6j3i.log
ycmd_23830_stdout_gmpa_k.log
```

With this change and PR #2342, we will add the completers logfiles to the list of files that can be opened with the `:YcmToggleLogs` command.

A bunch of tests are added that cover almost all changes introduced by this PR.

<!-- Reviewable:start -->

---
This change is [<img src="https://reviewable.io/review_button.svg" height="34" align="absmiddle" alt="Reviewable"/>](https://reviewable.io/reviews/valloric/youcompleteme/2430)
<!-- Reviewable:end -->
This commit is contained in:
Homu 2016-11-28 00:30:18 +09:00
commit 39be8b1aad
12 changed files with 469 additions and 237 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
.github/ISSUE_TEMPLATE.md vendored
View File

@ -12,8 +12,8 @@ the brackets) _before_ filing your issue:**
search.][search])
- [ ] If filing a bug report, I have included the output of `vim --version`.
- [ ] If filing a bug report, I have included the output of `:YcmDebugInfo`.
- [ ] If filing a bug report, I have included the output of
`:YcmToggleLogs stderr`.
- [ ] If filing a bug report, I have attached the contents of the logfiles using
the `:YcmToggleLogs` command.
- [ ] If filing a bug report, I have included which OS (including specific OS
version) I am using.
- [ ] If filing a bug report, I have included a minimal test case that reproduces

16
CONTRIBUTING.md
View File

@ -45,16 +45,16 @@ Here are the things you should do when creating an issue:
1. **Write a step-by-step procedure that when performed repeatedly reproduces
your issue.** If we can't reproduce the issue, then we can't fix it. It's
that simple.
2. Put the following options in your vimrc:
2. Add the output of [the `:YcmDebugInfo` command][ycm-debug-info-command].
3. Put the following options in your vimrc:
```viml
let g:ycm_server_keep_logfiles = 1
let g:ycm_server_log_level = 'debug'
let g:ycm_keep_logfiles = 1
let g:ycm_log_level = 'debug'
```
Run `:YcmToggleLogs stderr` in vim to open the logfile. Attach the contents
of this file to your issue.
3. Add the output of the `:YcmDebugInfo` command.
Reproduce your issue and attach the contents of the logfiles. Use [the
`:YcmToggleLogs` command][ycm-toggle-logs-command] to directly open them in
Vim.
4. **Create a test case for your issue**. This is critical. Don't talk about how
"when I have X in my file" or similar, _create a file with X in it_ and put
the contents inside code blocks in your issue description. Try to make this
@ -112,3 +112,5 @@ Creating good pull requests
[build-bots]: https://travis-ci.org/Valloric/YouCompleteMe
[ycm-users]: https://groups.google.com/forum/?hl=en#!forum/ycm-users
[gitter]: https://gitter.im/Valloric/YouCompleteMe
[ycm-debug-info-command]: https://github.com/Valloric/YouCompleteMe#the-ycmdebuginfo-command
[ycm-toggle-logs-command]: https://github.com/Valloric/YouCompleteMe#the-ycmtogglelogs-command

34
README.md
View File

@ -1152,12 +1152,9 @@ completion engine.
### The `:YcmToggleLogs` command
This command automatically opens in windows the stdout and stderr logfiles
written by the [ycmd server][ycmd]. If one or both logfiles are already opened,
they are automatically closed. `stderr` or `stdout` can be specified as an
argument of this command to only open the corresponding logfile instead of both.
If this logfile is already opened, it will be closed. Only for debugging
purpose.
This command opens in separate windows the logfiles given as arguments or closes
them if they are already open in the editor. When no argument is given, list the
available logfiles. Only for debugging purpose.
### The `:YcmCompleter` command
@ -2022,23 +2019,24 @@ Default: `''`
let g:ycm_server_python_interpreter = ''
```
### The `g:ycm_server_keep_logfiles` option
### The `g:ycm_keep_logfiles` option
When this option is set to `1`, the [ycmd completion server][ycmd] will keep the
logfiles around after shutting down (they are deleted on shutdown by default).
When this option is set to `1`, YCM and the [ycmd completion server][ycmd] will
keep the logfiles around after shutting down (they are deleted on shutdown by
default).
To see where the logfiles are, call `:YcmDebugInfo`.
Default: `0`
```viml
let g:ycm_server_keep_logfiles = 0
let g:ycm_keep_logfiles = 0
```
### The `g:ycm_server_log_level` option
### The `g:ycm_log_level` option
The logging level that the [ycmd completion server][ycmd] uses. Valid values are
the following, from most verbose to least verbose:
The logging level that YCM and the [ycmd completion server][ycmd] use. Valid
values are the following, from most verbose to least verbose:
- `debug`
- `info`
- `warning`
@ -2050,7 +2048,7 @@ Note that `debug` is _very_ verbose.
Default: `info`
```viml
let g:ycm_server_log_level = 'info'
let g:ycm_log_level = 'info'
```
### The `g:ycm_auto_start_csharp_server` option
@ -2499,10 +2497,10 @@ the message log if it encounters problems. It's likely you misconfigured
something and YCM is complaining about it.
Also, you may want to run the `:YcmDebugInfo` command; it will make YCM spew out
various debugging information, including the [ycmd][] logfile paths and the
compile flags for the current file if the file is a C-family language file and
you have compiled in Clang support. Logfiles can be automatically opened in the
editor using the `:YcmToggleLogs` command.
various debugging information, including the YCM and [ycmd][] logfile paths and
the compile flags for the current file if the file is a C-family language file
and you have compiled in Clang support. Logfiles can be opened in the editor
using [the `:YcmToggleLogs` command](#the-ycmtogglelogs-command).
### Sometimes it takes much longer to get semantic completions than normal

14
autoload/youcompleteme.vim
View File

@ -374,7 +374,7 @@ function! s:SetUpCommands()
command! YcmRestartServer call s:RestartServer()
command! YcmShowDetailedDiagnostic call s:ShowDetailedDiagnostic()
command! YcmDebugInfo call s:DebugInfo()
command! -nargs=? -complete=custom,youcompleteme#LogsComplete
command! -nargs=* -complete=custom,youcompleteme#LogsComplete
\ YcmToggleLogs call s:ToggleLogs(<f-args>)
command! -nargs=* -complete=custom,youcompleteme#SubCommandsComplete
\ YcmCompleter call s:CompleterCommand(<f-args>)
@ -454,6 +454,7 @@ function! s:OnBufferReadPre(filename)
endif
endfunction
function! s:OnBufferRead()
" We need to do this even when we are not allowed to complete in the current
" buffer because we might be allowed to complete in the future! The canonical
@ -787,11 +788,7 @@ endfunction
function! s:ToggleLogs(...)
let stderr = a:0 == 0 || a:1 !=? 'stdout'
let stdout = a:0 == 0 || a:1 !=? 'stderr'
exec s:python_command "ycm_state.ToggleLogs("
\ "stdout = vimsupport.GetBoolValue( 'l:stdout' ),"
\ "stderr = vimsupport.GetBoolValue( 'l:stderr' ) )"
exec s:python_command "ycm_state.ToggleLogs( *vim.eval( 'a:000' ) )"
endfunction
@ -827,13 +824,12 @@ endfunction
function! youcompleteme#LogsComplete( arglead, cmdline, cursorpos )
return "stdout\nstderr"
return join( s:Pyeval( 'list( ycm_state.GetLogfiles() )' ), "\n" )
endfunction
function! youcompleteme#SubCommandsComplete( arglead, cmdline, cursorpos )
return join( s:Pyeval( 'ycm_state.GetDefinedSubcommands()' ),
\ "\n")
return join( s:Pyeval( 'ycm_state.GetDefinedSubcommands()' ), "\n" )
endfunction

38
doc/youcompleteme.txt
View File

@ -100,8 +100,8 @@ Contents ~
21. The |g:ycm_seed_identifiers_with_syntax| option
22. The |g:ycm_extra_conf_vim_data| option
23. The |g:ycm_server_python_interpreter| option
24. The |g:ycm_server_keep_logfiles| option
25. The |g:ycm_server_log_level| option
24. The |g:ycm_keep_logfiles| option
25. The |g:ycm_log_level| option
26. The |g:ycm_auto_start_csharp_server| option
27. The |g:ycm_auto_stop_csharp_server| option
28. The |g:ycm_csharp_server_port| option
@ -1418,12 +1418,9 @@ semantic completion engine.
-------------------------------------------------------------------------------
The *:YcmToggleLogs* command
This command automatically opens in windows the stdout and stderr logfiles
written by the ycmd server [43]. If one or both logfiles are already opened,
they are automatically closed. 'stderr' or 'stdout' can be specified as an
argument of this command to only open the corresponding logfile instead of
both. If this logfile is already opened, it will be closed. Only for debugging
purpose.
This command opens in separate windows the logfiles given as arguments or
closes them if they are already open in the editor. When no argument is given,
list the available logfiles. Only for debugging purpose.
-------------------------------------------------------------------------------
The *:YcmCompleter* command
@ -2285,29 +2282,30 @@ Default: "''"
let g:ycm_server_python_interpreter = ''
<
-------------------------------------------------------------------------------
The *g:ycm_server_keep_logfiles* option
The *g:ycm_keep_logfiles* option
When this option is set to '1', the ycmd completion server [43] will keep the
logfiles around after shutting down (they are deleted on shutdown by default).
When this option is set to '1', YCM and the ycmd completion server [43] will
keep the logfiles around after shutting down (they are deleted on shutdown by
default).
To see where the logfiles are, call |:YcmDebugInfo|.
Default: '0'
>
let g:ycm_server_keep_logfiles = 0
let g:ycm_keep_logfiles = 0
<
-------------------------------------------------------------------------------
The *g:ycm_server_log_level* option
The *g:ycm_log_level* option
The logging level that the ycmd completion server [43] uses. Valid values are
the following, from most verbose to least verbose: - 'debug' - 'info' -
'warning' - 'error' - 'critical'
The logging level that YCM and the ycmd completion server [43] use. Valid
values are the following, from most verbose to least verbose: - 'debug' -
'info' - 'warning' - 'error' - 'critical'
Note that 'debug' is _very_ verbose.
Default: 'info'
>
let g:ycm_server_log_level = 'info'
let g:ycm_log_level = 'info'
<
-------------------------------------------------------------------------------
The *g:ycm_auto_start_csharp_server* option
@ -2741,9 +2739,9 @@ to the message log if it encounters problems. It's likely you misconfigured
something and YCM is complaining about it.
Also, you may want to run the |:YcmDebugInfo| command; it will make YCM spew
out various debugging information, including the ycmd [43] logfile paths and
the compile flags for the current file if the file is a C-family language file
and you have compiled in Clang support. Logfiles can be automatically opened in
out various debugging information, including the YCM and ycmd [43] logfile
paths and the compile flags for the current file if the file is a C-family
language file and you have compiled in Clang support. Logfiles can be opened in
the editor using the |:YcmToggleLogs| command.
-------------------------------------------------------------------------------

10
plugin/youcompleteme.vim
View File

@ -80,11 +80,13 @@ let g:ycm_key_detailed_diagnostics =
let g:ycm_cache_omnifunc =
\ get( g:, 'ycm_cache_omnifunc', 1 )
let g:ycm_server_log_level =
\ get( g:, 'ycm_server_log_level', 'info' )
let g:ycm_log_level =
\ get( g:, 'ycm_log_level',
\ get( g:, 'ycm_server_log_level', 'info' ) )
let g:ycm_server_keep_logfiles =
\ get( g:, 'ycm_server_keep_logfiles', 0 )
let g:ycm_keep_logfiles =
\ get( g:, 'ycm_keep_logfiles',
\ get( g:, 'ycm_server_keep_logfiles', 0 ) )
let g:ycm_extra_conf_vim_data =
\ get( g:, 'ycm_extra_conf_vim_data', [] )

18
python/ycm/tests/__init__.py
View File

@ -40,7 +40,8 @@ from ycmd.utils import WaitUntilProcessIsTerminated
# thus are not part of default_options.json, but are required for a working
# YouCompleteMe object.
DEFAULT_CLIENT_OPTIONS = {
'server_log_level': 'info',
'log_level': 'info',
'keep_logfiles': 0,
'extra_conf_vim_data': [],
'show_diagnostics_ui': 1,
'enable_diagnostic_signs': 1,
@ -80,6 +81,14 @@ def _WaitUntilReady( timeout = 5 ):
time.sleep( 0.1 )
def StopServer( ycm ):
try:
ycm.OnVimLeave()
WaitUntilProcessIsTerminated( ycm._server_popen )
except Exception:
pass
def YouCompleteMeInstance( custom_options = {} ):
"""Defines a decorator function for tests that passes a unique YouCompleteMe
instance as a parameter. This instance is initialized with the default options
@ -92,8 +101,8 @@ def YouCompleteMeInstance( custom_options = {} ):
from ycm.tests import YouCompleteMeInstance
@YouCompleteMeInstance( { 'server_log_level': 'debug',
'server_keep_logfiles': 1 } )
@YouCompleteMeInstance( { 'log_level': 'debug',
'keep_logfiles': 1 } )
def Debug_test( ycm ):
...
"""
@ -105,7 +114,6 @@ def YouCompleteMeInstance( custom_options = {} ):
try:
test( ycm, *args, **kwargs )
finally:
ycm.OnVimLeave()
WaitUntilProcessIsTerminated( ycm._server_popen )
StopServer( ycm )
return Wrapper
return Decorator

4
python/ycm/tests/test_utils.py
View File

@ -176,7 +176,7 @@ def MockVimCommand( command ):
class VimBuffer( object ):
"""An object that looks like a vim.buffer object:
- |name| : full path of the buffer;
- |name| : full path of the buffer with symbolic links resolved;
- |number| : buffer number;
- |contents|: list of lines representing the buffer contents;
- |filetype|: buffer filetype. Empty string if no filetype is set;
@ -191,7 +191,7 @@ class VimBuffer( object ):
modified = True,
window = None,
omnifunc = '' ):
self.name = name
self.name = os.path.realpath( name ) if name else ''
self.number = number
self.contents = contents
self.filetype = filetype

155
python/ycm/tests/vimsupport_test.py
View File

@ -32,7 +32,7 @@ MockVimModule()
from ycm import vimsupport
from nose.tools import eq_
from hamcrest import assert_that, calling, equal_to, has_entry, none, raises
from hamcrest import assert_that, calling, equal_to, has_entry, raises
from mock import MagicMock, call, patch
from ycmd.utils import ToBytes
import os
@ -727,13 +727,14 @@ def ReplaceChunks_SingleFile_Open_test( vim_command,
get_buffer_number_for_filename,
set_fitting_height,
variable_exists ):
single_buffer_name = os.path.realpath( 'single_file' )
chunks = [
_BuildChunk( 1, 1, 2, 1, 'replacement', 'single_file' )
_BuildChunk( 1, 1, 2, 1, 'replacement', single_buffer_name )
]
result_buffer = VimBuffer(
'single_file',
single_buffer_name,
contents = [
'line1',
'line2',
@ -755,14 +756,14 @@ def ReplaceChunks_SingleFile_Open_test( vim_command,
# raise a warning)
# - once whilst applying the changes
get_buffer_number_for_filename.assert_has_exact_calls( [
call( 'single_file', False ),
call( 'single_file', False ),
call( single_buffer_name, False ),
call( single_buffer_name, False ),
] )
# BufferIsVisible is called twice for the same reasons as above
buffer_is_visible.assert_has_exact_calls( [
call( 1 ),
call( 1 ),
call( 1 ),
call( 1 ),
] )
# we don't attempt to open any files
@ -770,25 +771,25 @@ def ReplaceChunks_SingleFile_Open_test( vim_command,
# But we do set the quickfix list
vim_eval.assert_has_exact_calls( [
call( 'setqflist( {0} )'.format( json.dumps( [ {
'bufnr': 1,
'filename': 'single_file',
'lnum': 1,
'col': 1,
'text': 'replacement',
'type': 'F'
} ] ) ) ),
call( 'setqflist( {0} )'.format( json.dumps( [ {
'bufnr': 1,
'filename': single_buffer_name,
'lnum': 1,
'col': 1,
'text': 'replacement',
'type': 'F'
} ] ) ) ),
] )
vim_command.assert_has_exact_calls( [
call( 'botright copen' ),
call( 'silent! wincmd p' )
call( 'botright copen' ),
call( 'silent! wincmd p' )
] )
set_fitting_height.assert_called_once_with()
# And it is ReplaceChunks that prints the message showing the number of
# changes
post_vim_message.assert_has_exact_calls( [
call( 'Applied 1 changes', warning = False ),
call( 'Applied 1 changes', warning = False ),
] )
@ -817,13 +818,14 @@ def ReplaceChunks_SingleFile_NotOpen_test( vim_command,
get_buffer_number_for_filename,
set_fitting_height,
variable_exists ):
single_buffer_name = os.path.realpath( 'single_file' )
chunks = [
_BuildChunk( 1, 1, 2, 1, 'replacement', 'single_file' )
_BuildChunk( 1, 1, 2, 1, 'replacement', single_buffer_name )
]
result_buffer = VimBuffer(
'single_file',
single_buffer_name,
contents = [
'line1',
'line2',
@ -852,9 +854,9 @@ def ReplaceChunks_SingleFile_NotOpen_test( vim_command,
# - once whilst applying the changes (-1 return)
# - finally after calling OpenFilename (1 return)
get_buffer_number_for_filename.assert_has_exact_calls( [
call( 'single_file', False ),
call( 'single_file', False ),
call( 'single_file', False ),
call( single_buffer_name, False ),
call( single_buffer_name, False ),
call( single_buffer_name, False ),
] )
# BufferIsVisible is called 3 times for the same reasons as above, with the
@ -866,7 +868,7 @@ def ReplaceChunks_SingleFile_NotOpen_test( vim_command,
] )
# We open 'single_file' as expected.
open_filename.assert_called_with( 'single_file', {
open_filename.assert_called_with( single_buffer_name, {
'focus': True,
'fix': True,
'size': 10
@ -886,7 +888,7 @@ def ReplaceChunks_SingleFile_NotOpen_test( vim_command,
call( '&previewheight' ),
call( 'setqflist( {0} )'.format( json.dumps( [ {
'bufnr': 1,
'filename': 'single_file',
'filename': single_buffer_name,
'lnum': 1,
'col': 1,
'text': 'replacement',
@ -929,13 +931,14 @@ def ReplaceChunks_User_Declines_To_Open_File_test(
# Same as above, except the user selects Cancel when asked if they should
# allow us to open lots of (ahem, 1) file.
single_buffer_name = os.path.realpath( 'single_file' )
chunks = [
_BuildChunk( 1, 1, 2, 1, 'replacement', 'single_file' )
_BuildChunk( 1, 1, 2, 1, 'replacement', single_buffer_name )
]
result_buffer = VimBuffer(
'single_file',
single_buffer_name,
contents = [
'line1',
'line2',
@ -963,7 +966,7 @@ def ReplaceChunks_User_Declines_To_Open_File_test(
# - once to the check if we would require opening the file (so that we can
# raise a warning) (-1 return)
get_buffer_number_for_filename.assert_has_exact_calls( [
call( 'single_file', False ),
call( single_buffer_name, False ),
] )
# BufferIsVisible is called once for the above file, which wasn't visible.
@ -1009,13 +1012,14 @@ def ReplaceChunks_User_Aborts_Opening_File_test(
# Same as above, except the user selects Abort or Quick during the
# "swap-file-found" dialog
single_buffer_name = os.path.realpath( 'single_file' )
chunks = [
_BuildChunk( 1, 1, 2, 1, 'replacement', 'single_file' )
_BuildChunk( 1, 1, 2, 1, 'replacement', single_buffer_name )
]
result_buffer = VimBuffer(
'single_file',
single_buffer_name,
contents = [
'line1',
'line2',
@ -1026,10 +1030,10 @@ def ReplaceChunks_User_Aborts_Opening_File_test(
with patch( 'vim.buffers', [ None, result_buffer, None ] ):
assert_that( calling( vimsupport.ReplaceChunks ).with_args( chunks ),
raises( RuntimeError,
'Unable to open file: single_file\nFixIt/Refactor operation '
'aborted prior to completion. Your files have not been '
'fully updated. Please use undo commands to revert the '
'applied changes.' ) )
'Unable to open file: .+single_file\n'
'FixIt/Refactor operation aborted prior to completion. '
'Your files have not been fully updated. '
'Please use undo commands to revert the applied changes.' ) )
# We checked if it was OK to open the file
confirm.assert_has_exact_calls( [
@ -1044,7 +1048,7 @@ def ReplaceChunks_User_Aborts_Opening_File_test(
] )
# We tried to open this file
open_filename.assert_called_with( "single_file", {
open_filename.assert_called_with( single_buffer_name, {
'focus': True,
'fix': True,
'size': 10
@ -1059,10 +1063,10 @@ def ReplaceChunks_User_Aborts_Opening_File_test(
@patch( 'ycm.vimsupport.SetFittingHeightForCurrentWindow' )
@patch( 'ycm.vimsupport.GetBufferNumberForFilename', side_effect = [
22, # first_file (check)
-1, # another_file (check)
-1, # second_file (check)
22, # first_file (apply)
-1, # another_file (apply)
19, # another_file (check after open)
-1, # second_file (apply)
19, # second_file (check after open)
],
new_callable = ExtendedMock )
@patch( 'ycm.vimsupport.BufferIsVisible', side_effect = [
@ -1094,14 +1098,16 @@ def ReplaceChunks_MultiFile_Open_test( vim_command,
variable_exists ):
# Chunks are split across 2 files, one is already open, one isn't
first_buffer_name = os.path.realpath( '1_first_file' )
second_buffer_name = os.path.realpath( '2_second_file' )
chunks = [
_BuildChunk( 1, 1, 2, 1, 'first_file_replacement ', '1_first_file' ),
_BuildChunk( 2, 1, 2, 1, 'second_file_replacement ', '2_another_file' ),
_BuildChunk( 1, 1, 2, 1, 'first_file_replacement ', first_buffer_name ),
_BuildChunk( 2, 1, 2, 1, 'second_file_replacement ', second_buffer_name ),
]
first_file = VimBuffer(
'1_first_file',
first_buffer_name,
number = 22,
contents = [
'line1',
@ -1109,8 +1115,8 @@ def ReplaceChunks_MultiFile_Open_test( vim_command,
'line3',
]
)
another_file = VimBuffer(
'2_another_file',
second_file = VimBuffer(
second_buffer_name,
number = 19,
contents = [
'another line1',
@ -1120,18 +1126,18 @@ def ReplaceChunks_MultiFile_Open_test( vim_command,
vim_buffers = [ None ] * 23
vim_buffers[ 22 ] = first_file
vim_buffers[ 19 ] = another_file
vim_buffers[ 19 ] = second_file
with patch( 'vim.buffers', vim_buffers ):
vimsupport.ReplaceChunks( chunks )
# We checked for the right file names
get_buffer_number_for_filename.assert_has_exact_calls( [
call( '1_first_file', False ),
call( '2_another_file', False ),
call( '1_first_file', False ),
call( '2_another_file', False ),
call( '2_another_file', False ),
call( first_buffer_name, False ),
call( second_buffer_name, False ),
call( first_buffer_name, False ),
call( second_buffer_name, False ),
call( second_buffer_name, False ),
] )
# We checked if it was OK to open the file
@ -1140,7 +1146,7 @@ def ReplaceChunks_MultiFile_Open_test( vim_command,
] )
# Ensure that buffers are updated
eq_( another_file.GetLines(), [
eq_( second_file.GetLines(), [
'another line1',
'second_file_replacement ACME line2',
] )
@ -1149,8 +1155,8 @@ def ReplaceChunks_MultiFile_Open_test( vim_command,
'line3',
] )
# We open '2_another_file' as expected.
open_filename.assert_called_with( '2_another_file', {
# We open '2_second_file' as expected.
open_filename.assert_called_with( second_buffer_name, {
'focus': True,
'fix': True,
'size': 10
@ -1170,14 +1176,14 @@ def ReplaceChunks_MultiFile_Open_test( vim_command,
call( '&previewheight' ),
call( 'setqflist( {0} )'.format( json.dumps( [ {
'bufnr': 22,
'filename': '1_first_file',
'filename': first_buffer_name,
'lnum': 1,
'col': 1,
'text': 'first_file_replacement ',
'type': 'F'
}, {
'bufnr': 19,
'filename': '2_another_file',
'filename': second_buffer_name,
'lnum': 2,
'col': 1,
'text': 'second_file_replacement ',
@ -1320,34 +1326,10 @@ def WriteToPreviewWindow_JumpFail_MultiLine_test( vim_current, vim_command ):
vim_current.buffer.options.__setitem__.assert_not_called()
def CheckFilename_test():
assert_that(
calling( vimsupport.CheckFilename ).with_args( None ),
raises( RuntimeError, "'None' is not a valid filename" )
)
assert_that(
calling( vimsupport.CheckFilename ).with_args( 'nonexistent_file' ),
raises( RuntimeError,
"filename 'nonexistent_file' cannot be opened. "
"No such file or directory." )
)
assert_that( vimsupport.CheckFilename( __file__ ), none() )
def BufferIsVisibleForFilename_test():
vim_buffers = [
VimBuffer(
os.path.realpath( 'visible_filename' ),
number = 1,
window = 1
),
VimBuffer(
os.path.realpath( 'hidden_filename' ),
number = 2,
window = None
)
VimBuffer( 'visible_filename', number = 1, window = 1 ),
VimBuffer( 'hidden_filename', number = 2, window = None )
]
with patch( 'vim.buffers', vim_buffers ):
@ -1361,14 +1343,8 @@ def BufferIsVisibleForFilename_test():
new_callable = ExtendedMock )
def CloseBuffersForFilename_test( vim_command, *args ):
vim_buffers = [
VimBuffer(
os.path.realpath( 'some_filename' ),
number = 2
),
VimBuffer(
os.path.realpath( 'some_filename' ),
number = 5
)
VimBuffer( 'some_filename', number = 2 ),
VimBuffer( 'some_filename', number = 5 )
]
with patch( 'vim.buffers', vim_buffers ):
@ -1383,10 +1359,11 @@ def CloseBuffersForFilename_test( vim_command, *args ):
@patch( 'vim.command', new_callable = ExtendedMock )
@patch( 'vim.current', new_callable = ExtendedMock )
def OpenFilename_test( vim_current, vim_command ):
# Options used to open a logfile
# Options used to open a logfile.
options = {
'size': vimsupport.GetIntValue( '&previewheight' ),
'fix': True,
'focus': False,
'watch': True,
'position': 'end'
}

203
python/ycm/tests/youcompleteme_test.py
View File

@ -23,11 +23,15 @@ from future import standard_library
standard_library.install_aliases()
from builtins import * # noqa
from ycm.tests.test_utils import MockVimModule
from ycm.tests import StopServer
from ycm.tests.test_utils import ( ExtendedMock, MockVimBuffers, MockVimModule,
VimBuffer )
MockVimModule()
import os
import sys
from hamcrest import assert_that, is_in, is_not
from hamcrest import assert_that, is_in, is_not, has_length, matches_regexp
from mock import call, MagicMock, patch
from ycm.tests import YouCompleteMeInstance
@ -35,3 +39,198 @@ from ycm.tests import YouCompleteMeInstance
@YouCompleteMeInstance()
def YouCompleteMe_YcmCoreNotImported_test( ycm ):
assert_that( 'ycm_core', is_not( is_in( sys.modules ) ) )
@YouCompleteMeInstance()
@patch( 'ycm.vimsupport.PostVimMessage', new_callable = ExtendedMock )
def RunNotifyUserIfServerCrashed( ycm, test, post_vim_message ):
StopServer( ycm )
ycm._logger = MagicMock( autospec = True )
ycm._server_popen = MagicMock( autospec = True )
ycm._server_popen.poll.return_value = test[ 'return_code' ]
ycm._server_popen.stderr.read.return_value = test[ 'stderr_output' ]
ycm._NotifyUserIfServerCrashed()
assert_that( ycm._logger.method_calls,
has_length( len( test[ 'expected_logs' ] ) ) )
ycm._logger.error.assert_has_calls(
[ call( log ) for log in test[ 'expected_logs' ] ] )
post_vim_message.assert_has_exact_calls( [
call( test[ 'expected_vim_message' ] )
] )
def YouCompleteMe_NotifyUserIfServerCrashed_UnexpectedCore_test():
message = ( "The ycmd server SHUT DOWN (restart with ':YcmRestartServer'). "
"Unexpected error while loading the YCM core library. "
"Use the ':YcmToggleLogs' command to check the logs." )
RunNotifyUserIfServerCrashed( {
'return_code': 3,
'stderr_output' : '',
'expected_logs': [ message ],
'expected_vim_message': message
} )
def YouCompleteMe_NotifyUserIfServerCrashed_MissingCore_test():
message = ( "The ycmd server SHUT DOWN (restart with ':YcmRestartServer'). "
"YCM core library not detected; you need to compile YCM before "
"using it. Follow the instructions in the documentation." )
RunNotifyUserIfServerCrashed( {
'return_code': 4,
'stderr_output': '',
'expected_logs': [ message ],
'expected_vim_message': message
} )
def YouCompleteMe_NotifyUserIfServerCrashed_Python2Core_test():
message = ( "The ycmd server SHUT DOWN (restart with ':YcmRestartServer'). "
"YCM core library compiled for Python 2 but loaded in Python 3. "
"Set the 'g:ycm_server_python_interpreter' option to a Python 2 "
"interpreter path." )
RunNotifyUserIfServerCrashed( {
'return_code': 5,
'stderr_output': '',
'expected_logs': [ message ],
'expected_vim_message': message
} )
def YouCompleteMe_NotifyUserIfServerCrashed_Python3Core_test():
message = ( "The ycmd server SHUT DOWN (restart with ':YcmRestartServer'). "
"YCM core library compiled for Python 3 but loaded in Python 2. "
"Set the 'g:ycm_server_python_interpreter' option to a Python 3 "
"interpreter path." )
RunNotifyUserIfServerCrashed( {
'return_code': 6,
'stderr_output': '',
'expected_logs': [ message ],
'expected_vim_message': message
} )
def YouCompleteMe_NotifyUserIfServerCrashed_OutdatedCore_test():
message = ( "The ycmd server SHUT DOWN (restart with ':YcmRestartServer'). "
"YCM core library too old; PLEASE RECOMPILE by running the "
"install.py script. See the documentation for more details." )
RunNotifyUserIfServerCrashed( {
'return_code': 7,
'stderr_output': '',
'expected_logs': [ message ],
'expected_vim_message': message
} )
def YouCompleteMe_NotifyUserIfServerCrashed_UnexpectedExitCode_test():
message = ( "The ycmd server SHUT DOWN (restart with ':YcmRestartServer'). "
"Unexpected exit code 1. Use the ':YcmToggleLogs' command to "
"check the logs." )
RunNotifyUserIfServerCrashed( {
'return_code': 1,
'stderr_output': 'First line\r\n'
'Second line',
'expected_logs': [ 'First line\n'
'Second line',
message ],
'expected_vim_message': message
} )
@YouCompleteMeInstance()
def YouCompleteMe_DebugInfo_ServerRunning_test( ycm ):
current_buffer = VimBuffer( 'current_buffer' )
with MockVimBuffers( [ current_buffer ], current_buffer ):
assert_that(
ycm.DebugInfo(),
matches_regexp(
'Client logfile: .+\n'
'Server has Clang support compiled in: (True|False)\n'
'(Clang version: .+\n)?'
'Server running at: .+\n'
'Server process ID: \d+\n'
'Server logfiles:\n'
' .+\n'
' .+' )
)
@YouCompleteMeInstance()
def YouCompleteMe_DebugInfo_ServerNotRunning_test( ycm ):
StopServer( ycm )
current_buffer = VimBuffer( 'current_buffer' )
with MockVimBuffers( [ current_buffer ], current_buffer ):
assert_that(
ycm.DebugInfo(),
matches_regexp(
'Client logfile: .+\n'
'Server crashed, no debug info from server\n'
'Server running at: .+\n'
'Server process ID: \d+\n'
'Server logfiles:\n'
' .+\n'
' .+' )
)
@YouCompleteMeInstance()
def YouCompleteMe_OnVimLeave_RemoveClientLogfileByDefault_test( ycm ):
client_logfile = ycm._client_logfile
assert_that( os.path.isfile( client_logfile ),
'Logfile {0} does not exist.'.format( client_logfile ) )
ycm.OnVimLeave()
assert_that( not os.path.isfile( client_logfile ),
'Logfile {0} was not removed.'.format( client_logfile ) )
@YouCompleteMeInstance( { 'keep_logfiles': 1 } )
def YouCompleteMe_OnVimLeave_KeepClientLogfile_test( ycm ):
client_logfile = ycm._client_logfile
assert_that( os.path.isfile( client_logfile ),
'Logfile {0} does not exist.'.format( client_logfile ) )
ycm.OnVimLeave()
assert_that( os.path.isfile( client_logfile ),
'Logfile {0} was removed.'.format( client_logfile ) )
@YouCompleteMeInstance()
@patch( 'ycm.vimsupport.CloseBuffersForFilename', new_callable = ExtendedMock )
@patch( 'ycm.vimsupport.OpenFilename', new_callable = ExtendedMock )
def YouCompleteMe_ToggleLogs_WithParameters_test( ycm,
open_filename,
close_buffers_for_filename ):
logfile_buffer = VimBuffer( ycm._client_logfile, window = 1 )
with MockVimBuffers( [ logfile_buffer ], logfile_buffer ):
ycm.ToggleLogs( os.path.basename( ycm._client_logfile ),
'nonexisting_logfile',
os.path.basename( ycm._server_stdout ) )
open_filename.assert_has_exact_calls( [
call( ycm._server_stdout, { 'size': 12,
'watch': True,
'fix': True,
'focus': False,
'position': 'end' } )
] )
close_buffers_for_filename.assert_has_exact_calls( [
call( ycm._client_logfile )
] )
@YouCompleteMeInstance()
@patch( 'ycm.vimsupport.PostVimMessage' )
def YouCompleteMe_ToggleLogs_WithoutParameters_test( ycm, post_vim_message ):
ycm.ToggleLogs()
assert_that(
# Argument passed to PostVimMessage.
post_vim_message.call_args[ 0 ][ 0 ],
matches_regexp(
'Available logfiles are:\n'
'ycm_.+.log\n'
'ycmd_\d+_stderr_.+.log\n'
'ycmd_\d+_stdout_.+.log' )
)

17
python/ycm/vimsupport.py
View File

@ -937,20 +937,6 @@ def WriteToPreviewWindow( message ):
PostVimMessage( message, warning = False )
def CheckFilename( filename ):
"""Check if filename is openable."""
try:
# We don't want to check for encoding issues when trying to open the file
# so we open it in binary mode.
open( filename, mode = 'rb' ).close()
except TypeError:
raise RuntimeError( "'{0}' is not a valid filename".format( filename ) )
except IOError as error:
raise RuntimeError(
"filename '{0}' cannot be opened. {1}.".format( filename,
error.strerror ) )
def BufferIsVisibleForFilename( filename ):
"""Check if a buffer exists for a specific file."""
buffer_number = GetBufferNumberForFilename( filename, False )
@ -998,8 +984,7 @@ def OpenFilename( filename, options = {} ):
else:
previous_tab = None
# Open the file
CheckFilename( filename )
# Open the file.
try:
vim.command( '{0}{1} {2}'.format( size, command, filename ) )
# When the file we are trying to jump to has a swap file,

193
python/ycm/youcompleteme.py
View File

@ -25,12 +25,13 @@ standard_library.install_aliases()
from builtins import * # noqa
from future.utils import iteritems
import os
import vim
import base64
import json
import logging
import os
import re
import signal
import base64
import vim
from subprocess import PIPE
from tempfile import NamedTemporaryFile
from ycm import base, paths, vimsupport
@ -77,13 +78,12 @@ signal.signal( signal.SIGINT, signal.SIG_IGN )
HMAC_SECRET_LENGTH = 16
SERVER_SHUTDOWN_MESSAGE = (
"The ycmd server SHUT DOWN (restart with ':YcmRestartServer')." )
STDERR_FILE_MESSAGE = (
"Run ':YcmToggleLogs stderr' to check the logs." )
STDERR_FILE_DELETED_MESSAGE = (
"Logfile was deleted; set 'g:ycm_server_keep_logfiles' to see errors "
"in the future." )
EXIT_CODE_UNEXPECTED_MESSAGE = (
"Unexpected exit code {code}. "
"Use the ':YcmToggleLogs' command to check the logs." )
CORE_UNEXPECTED_MESSAGE = (
'Unexpected error while loading the YCM core library.' )
"Unexpected error while loading the YCM core library. "
"Use the ':YcmToggleLogs' command to check the logs." )
CORE_MISSING_MESSAGE = (
'YCM core library not detected; you need to compile YCM before using it. '
'Follow the instructions in the documentation.' )
@ -100,7 +100,12 @@ CORE_OUTDATED_MESSAGE = (
'script. See the documentation for more details.' )
SERVER_IDLE_SUICIDE_SECONDS = 10800 # 3 hours
DIAGNOSTIC_UI_FILETYPES = set( [ 'cpp', 'cs', 'c', 'objc', 'objcpp' ] )
LOGFILE_FORMAT = 'ycmd_{port}_{std}_'
CLIENT_LOGFILE_FORMAT = 'ycm_'
SERVER_LOGFILE_FORMAT = 'ycmd_{port}_{std}_'
# Flag to set a file handle inheritable by child processes on Windows. See
# https://msdn.microsoft.com/en-us/library/ms724935.aspx
HANDLE_FLAG_INHERIT = 0x00000001
class YouCompleteMe( object ):
@ -113,11 +118,14 @@ class YouCompleteMe( object ):
self._latest_file_parse_request = None
self._latest_completion_request = None
self._latest_diagnostics = []
self._logger = logging.getLogger( 'ycm' )
self._client_logfile = None
self._server_stdout = None
self._server_stderr = None
self._server_popen = None
self._filetypes_with_keywords_loaded = set()
self._ycmd_keepalive = YcmdKeepalive()
self._SetupLogging()
self._SetupServer()
self._ycmd_keepalive.Start()
self._complete_done_hooks = {
@ -134,6 +142,8 @@ class YouCompleteMe( object ):
options_dict = dict( self._user_options )
options_dict[ 'hmac_secret' ] = utils.ToUnicode(
base64.b64encode( hmac_secret ) )
options_dict[ 'server_keep_logfiles' ] = self._user_options[
'keep_logfiles' ]
json.dump( options_dict, options_file )
options_file.flush()
@ -141,18 +151,18 @@ class YouCompleteMe( object ):
paths.PathToServerScript(),
'--port={0}'.format( server_port ),
'--options_file={0}'.format( options_file.name ),
'--log={0}'.format( self._user_options[ 'server_log_level' ] ),
'--log={0}'.format( self._user_options[ 'log_level' ] ),
'--idle_suicide_seconds={0}'.format(
SERVER_IDLE_SUICIDE_SECONDS ) ]
self._server_stdout = utils.CreateLogfile(
LOGFILE_FORMAT.format( port = server_port, std = 'stdout' ) )
SERVER_LOGFILE_FORMAT.format( port = server_port, std = 'stdout' ) )
self._server_stderr = utils.CreateLogfile(
LOGFILE_FORMAT.format( port = server_port, std = 'stderr' ) )
SERVER_LOGFILE_FORMAT.format( port = server_port, std = 'stderr' ) )
args.append( '--stdout={0}'.format( self._server_stdout ) )
args.append( '--stderr={0}'.format( self._server_stderr ) )
if self._user_options[ 'server_keep_logfiles' ]:
if self._user_options[ 'keep_logfiles' ]:
args.append( '--keep_logfiles' )
self._server_popen = utils.SafePopen( args, stdin_windows = PIPE,
@ -163,10 +173,48 @@ class YouCompleteMe( object ):
self._NotifyUserIfServerCrashed()
def _SetupLogging( self ):
def FreeFileFromOtherProcesses( file_object ):
if utils.OnWindows():
from ctypes import windll
import msvcrt
file_handle = msvcrt.get_osfhandle( file_object.fileno() )
windll.kernel32.SetHandleInformation( file_handle,
HANDLE_FLAG_INHERIT,
0 )
self._client_logfile = utils.CreateLogfile( CLIENT_LOGFILE_FORMAT )
log_level = self._user_options[ 'log_level' ]
numeric_level = getattr( logging, log_level.upper(), None )
if not isinstance( numeric_level, int ):
raise ValueError( 'Invalid log level: {0}'.format( log_level ) )
self._logger.setLevel( numeric_level )
handler = logging.FileHandler( self._client_logfile )
# On Windows and Python prior to 3.4, file handles are inherited by child
# processes started with at least one replaced standard stream, which is the
# case when we start the ycmd server (we are redirecting all standard
# outputs into a pipe). These files cannot be removed while the child
# processes are still up. This is not desirable for a logfile because we
# want to remove it at Vim exit without having to wait for the ycmd server
# to be completely shut down. We need to make the logfile handle
# non-inheritable. See https://www.python.org/dev/peps/pep-0446 for more
# details.
FreeFileFromOtherProcesses( handler.stream )
formatter = logging.Formatter( '%(asctime)s - %(levelname)s - %(message)s' )
handler.setFormatter( formatter )
self._logger.addHandler( handler )
def IsServerAlive( self ):
returncode = self._server_popen.poll()
return_code = self._server_popen.poll()
# When the process hasn't finished yet, poll() returns None.
return returncode is None
return return_code is None
def _NotifyUserIfServerCrashed( self ):
@ -174,27 +222,27 @@ class YouCompleteMe( object ):
return
self._user_notified_about_crash = True
try:
vimsupport.CheckFilename( self._server_stderr )
stderr_message = STDERR_FILE_MESSAGE
except RuntimeError:
stderr_message = STDERR_FILE_DELETED_MESSAGE
message = SERVER_SHUTDOWN_MESSAGE
return_code = self._server_popen.poll()
if return_code == server_utils.CORE_UNEXPECTED_STATUS:
message += ' ' + CORE_UNEXPECTED_MESSAGE + ' ' + stderr_message
error_message = CORE_UNEXPECTED_MESSAGE
elif return_code == server_utils.CORE_MISSING_STATUS:
message += ' ' + CORE_MISSING_MESSAGE
error_message = CORE_MISSING_MESSAGE
elif return_code == server_utils.CORE_PYTHON2_STATUS:
message += ' ' + CORE_PYTHON2_MESSAGE
error_message = CORE_PYTHON2_MESSAGE
elif return_code == server_utils.CORE_PYTHON3_STATUS:
message += ' ' + CORE_PYTHON3_MESSAGE
error_message = CORE_PYTHON3_MESSAGE
elif return_code == server_utils.CORE_OUTDATED_STATUS:
message += ' ' + CORE_OUTDATED_MESSAGE
error_message = CORE_OUTDATED_MESSAGE
else:
message += ' ' + stderr_message
vimsupport.PostVimMessage( message )
error_message = EXIT_CODE_UNEXPECTED_MESSAGE.format( code = return_code )
server_stderr = '\n'.join( self._server_popen.stderr.read().splitlines() )
if server_stderr:
self._logger.error( server_stderr )
error_message = SERVER_SHUTDOWN_MESSAGE + ' ' + error_message
self._logger.error( error_message )
vimsupport.PostVimMessage( error_message )
def ServerPid( self ):
@ -209,7 +257,6 @@ class YouCompleteMe( object ):
def RestartServer( self ):
self._CloseLogs()
vimsupport.PostVimMessage( 'Restarting ycmd server...' )
self._ShutdownServer()
self._SetupServer()
@ -340,8 +387,16 @@ class YouCompleteMe( object ):
self._diag_interface.OnCursorMoved()
def _CleanLogfile( self ):
logging.shutdown()
if not self._user_options[ 'keep_logfiles' ]:
if self._client_logfile:
utils.RemoveIfExists( self._client_logfile )
def OnVimLeave( self ):
self._ShutdownServer()
self._CleanLogfile()
def OnCurrentIdentifierFinished( self ):
@ -592,61 +647,73 @@ class YouCompleteMe( object ):
def DebugInfo( self ):
debug_info = ''
if self._client_logfile:
debug_info += 'Client logfile: {0}\n'.format( self._client_logfile )
if self.IsServerAlive():
debug_info = BaseRequest.PostDataToHandler( BuildRequestData(),
'debug_info' )
debug_info += BaseRequest.PostDataToHandler( BuildRequestData(),
'debug_info' )
else:
debug_info = 'Server crashed, no debug info from server'
debug_info += '\nServer running at: {0}'.format(
debug_info += 'Server crashed, no debug info from server'
debug_info += '\nServer running at: {0}\n'.format(
BaseRequest.server_location )
debug_info += '\nServer process ID: {0}'.format( self._server_popen.pid )
debug_info += 'Server process ID: {0}\n'.format( self._server_popen.pid )
if self._server_stderr or self._server_stdout:
debug_info += '\nServer logfiles:\n {0}\n {1}'.format(
self._server_stdout,
self._server_stderr )
debug_info += ( 'Server logfiles:\n'
' {0}\n'
' {1}'.format( self._server_stdout,
self._server_stderr ) )
return debug_info
def _OpenLogs( self, stdout = True, stderr = True ):
def GetLogfiles( self ):
logfiles_list = [ self._client_logfile,
self._server_stdout,
self._server_stderr ]
logfiles = {}
for logfile in logfiles_list:
logfiles[ os.path.basename( logfile ) ] = logfile
return logfiles
def _OpenLogfile( self, logfile ):
# Open log files in a horizontal window with the same behavior as the
# preview window (same height and winfixheight enabled). Automatically
# watch for changes. Set the cursor position at the end of the file.
options = {
'size': vimsupport.GetIntValue( '&previewheight' ),
'fix': True,
'focus': False,
'watch': True,
'position': 'end'
}
if stdout:
vimsupport.OpenFilename( self._server_stdout, options )
if stderr:
vimsupport.OpenFilename( self._server_stderr, options )
vimsupport.OpenFilename( logfile, options )
def _CloseLogs( self, stdout = True, stderr = True ):
if stdout:
vimsupport.CloseBuffersForFilename( self._server_stdout )
if stderr:
vimsupport.CloseBuffersForFilename( self._server_stderr )
def _CloseLogfile( self, logfile ):
vimsupport.CloseBuffersForFilename( logfile )
def ToggleLogs( self, stdout = True, stderr = True ):
if ( stdout and
vimsupport.BufferIsVisibleForFilename( self._server_stdout ) or
stderr and
vimsupport.BufferIsVisibleForFilename( self._server_stderr ) ):
return self._CloseLogs( stdout = stdout, stderr = stderr )
def ToggleLogs( self, *filenames ):
logfiles = self.GetLogfiles()
if not filenames:
vimsupport.PostVimMessage(
'Available logfiles are:\n'
'{0}'.format( '\n'.join( sorted( list( logfiles ) ) ) ) )
return
# Close hidden logfile buffers if any to keep a clean state
self._CloseLogs( stdout = stdout, stderr = stderr )
for filename in set( filenames ):
if filename not in logfiles:
continue
try:
self._OpenLogs( stdout = stdout, stderr = stderr )
except RuntimeError as error:
vimsupport.PostVimMessage( 'YouCompleteMe encountered an error when '
'opening logs: {0}.'.format( error ) )
logfile = logfiles[ filename ]
if not vimsupport.BufferIsVisibleForFilename( logfile ):
self._OpenLogfile( logfile )
continue
self._CloseLogfile( logfile )
def CurrentFiletypeCompletionEnabled( self ):