diff --git a/.github/ISSUE_TEMPLATE.md b/.github/ISSUE_TEMPLATE.md index fa80b9c4..4cbb15c6 100644 --- a/.github/ISSUE_TEMPLATE.md +++ b/.github/ISSUE_TEMPLATE.md @@ -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 diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 4024c8cb..e88c1e33 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -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 diff --git a/README.md b/README.md index 312e1957..3936b85c 100644 --- a/README.md +++ b/README.md @@ -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 diff --git a/autoload/youcompleteme.vim b/autoload/youcompleteme.vim index c3063aed..776f1d8d 100644 --- a/autoload/youcompleteme.vim +++ b/autoload/youcompleteme.vim @@ -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() command! -nargs=* -complete=custom,youcompleteme#SubCommandsComplete \ YcmCompleter call s:CompleterCommand() @@ -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 diff --git a/doc/youcompleteme.txt b/doc/youcompleteme.txt index ec8f30e4..e64ce937 100644 --- a/doc/youcompleteme.txt +++ b/doc/youcompleteme.txt @@ -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. ------------------------------------------------------------------------------- diff --git a/plugin/youcompleteme.vim b/plugin/youcompleteme.vim index 268a7274..0ac381e9 100644 --- a/plugin/youcompleteme.vim +++ b/plugin/youcompleteme.vim @@ -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', [] ) diff --git a/python/ycm/tests/__init__.py b/python/ycm/tests/__init__.py index 22417b82..b02d1204 100644 --- a/python/ycm/tests/__init__.py +++ b/python/ycm/tests/__init__.py @@ -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 diff --git a/python/ycm/tests/test_utils.py b/python/ycm/tests/test_utils.py index d1733dbd..c8a4d497 100644 --- a/python/ycm/tests/test_utils.py +++ b/python/ycm/tests/test_utils.py @@ -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 diff --git a/python/ycm/tests/vimsupport_test.py b/python/ycm/tests/vimsupport_test.py index ab95d0e5..36e747df 100644 --- a/python/ycm/tests/vimsupport_test.py +++ b/python/ycm/tests/vimsupport_test.py @@ -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' } diff --git a/python/ycm/tests/youcompleteme_test.py b/python/ycm/tests/youcompleteme_test.py index ce306be8..763f39a2 100644 --- a/python/ycm/tests/youcompleteme_test.py +++ b/python/ycm/tests/youcompleteme_test.py @@ -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' ) + ) diff --git a/python/ycm/vimsupport.py b/python/ycm/vimsupport.py index 73351053..10957dd1 100644 --- a/python/ycm/vimsupport.py +++ b/python/ycm/vimsupport.py @@ -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, diff --git a/python/ycm/youcompleteme.py b/python/ycm/youcompleteme.py index 2f5b070e..b6e15e42 100644 --- a/python/ycm/youcompleteme.py +++ b/python/ycm/youcompleteme.py @@ -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 ):