Auto merge of #572 - micbou:shutdown-logfiles, r=micbou

[READY] Properly remove logfiles at program termination

With this PR, we now remove `ycmd` logfiles at program termination and not only when receiving the `SIGTERM` or `SIGINT` signals. This fixes the long-standing bug where logfiles were never removed on Windows and the regression where they were not removed anymore on Unix platforms when receiving the `shutdown` request or through the watchdog plugin.

In addition, when shutting down a sub-server in a completer, we always wait for its process to be terminated before removing the logfiles. We need this on Windows because we cannot remove a file that it still used by a process on this platform. Most of the completers were already waiting but not the Python and C♯ completers.

Shutdown tests are updated to check if the logfiles are removed.

<!-- Reviewable:start -->
---
This change is [<img src="https://reviewable.io/review_button.svg" height="34" align="absmiddle" alt="Reviewable"/>](https://reviewable.io/reviews/valloric/ycmd/572)
<!-- Reviewable:end -->

ycmd/__main__.py

@@ -32,6 +32,7 @@
 standard_library.install_aliases()
 from builtins import *  # noqa
 
+import atexit
 import sys
 import logging
 import json
@@ -53,31 +54,33 @@ def YcmCoreSanityCheck():
 
 # We manually call sys.exit() on SIGTERM and SIGINT so that atexit handlers are
 # properly executed.
-def SetUpSignalHandler( stdout, stderr, keep_logfiles ):
+def SetUpSignalHandler():
   def SignalHandler( signum, frame ):
-    # We reset stderr & stdout, just in case something tries to use them
-    if stderr:
-      tmp = sys.stderr
-      sys.stderr = sys.__stderr__
-      tmp.close()
-    if stdout:
-      tmp = sys.stdout
-      sys.stdout = sys.__stdout__
-      tmp.close()
-
-    if not keep_logfiles:
-      if stderr:
-        utils.RemoveIfExists( stderr )
-      if stdout:
-        utils.RemoveIfExists( stdout )
-
     sys.exit()
 
   for sig in [ signal.SIGTERM,
                signal.SIGINT ]:
     signal.signal( sig, SignalHandler )
 
 
+def CleanUpLogfiles( stdout, stderr, keep_logfiles ):
+  # We reset stderr & stdout, just in case something tries to use them
+  if stderr:
+    tmp = sys.stderr
+    sys.stderr = sys.__stderr__
+    tmp.close()
+  if stdout:
+    tmp = sys.stdout
+    sys.stdout = sys.__stdout__
+    tmp.close()
+
+  if not keep_logfiles:
+    if stderr:
+      utils.RemoveIfExists( stderr )
+    if stdout:
+      utils.RemoveIfExists( stdout )
+
+
 def PossiblyDetachFromTerminal():
   # If not on windows, detach from controlling terminal to prevent
   # SIGINT from killing us.
@@ -172,7 +175,13 @@ def Main():
   handlers.UpdateUserOptions( options )
   handlers.SetHmacSecret( hmac_secret )
   handlers.KeepSubserversAlive( args.check_interval_seconds )
-  SetUpSignalHandler( args.stdout, args.stderr, args.keep_logfiles )
+  SetUpSignalHandler()
+  # Functions registered by the atexit module are called at program termination
+  # in last in, first out order.
+  atexit.register( CleanUpLogfiles, args.stdout,
+                                    args.stderr,
+                                    args.keep_logfiles )
+  atexit.register( handlers.ServerCleanup )
   handlers.app.install( WatchdogPlugin( args.idle_suicide_seconds,
                                         args.check_interval_seconds ) )
   handlers.app.install( HmacPlugin( hmac_secret ) )

ycmd/completers/cs/cs_completer.py

@@ -27,7 +27,6 @@
 
 from collections import defaultdict
 import os
-import time
 import re
 from ycmd.completers.completer import Completer
 from ycmd.utils import ForceSemanticCompletion, CodepointOffsetToByteOffset
@@ -72,10 +71,9 @@ def __init__( self, user_options ):
 
 
   def Shutdown( self ):
-    if ( self.user_options[ 'auto_stop_csharp_server' ] ):
+    if self.user_options[ 'auto_stop_csharp_server' ]:
       for solutioncompleter in itervalues( self._completer_per_solution ):
-        if solutioncompleter._ServerIsRunning():
-          solutioncompleter._StopServer()
+        solutioncompleter._StopServer()
 
 
   def SupportedFiletypes( self ):
@@ -411,39 +409,24 @@ def _StartServer( self ):
   def _StopServer( self ):
     """ Stop the OmniSharp server using a lock. """
     with self._server_state_lock:
-      if not self._ServerIsRunning():
-        return
-
-      self._logger.info( 'Stopping OmniSharp server' )
-
-      self._TryToStopServer()
-
-      # Kill it if it's still up
       if self._ServerIsRunning():
-        self._logger.info( 'Killing OmniSharp server' )
-        self._omnisharp_phandle.kill()
-
-      self._CleanupAfterServerStop()
-
-      self._logger.info( 'Stopped OmniSharp server' )
-
+        self._logger.info( 'Stopping OmniSharp server with PID {0}'.format(
+                               self._omnisharp_phandle.pid ) )
+        self._GetResponse( '/stopserver' )
+        try:
+          utils.WaitUntilProcessIsTerminated( self._omnisharp_phandle,
+                                              timeout = 5 )
+          self._logger.info( 'OmniSharp server stopped' )
+        except RuntimeError:
+          self._logger.exception( 'Error while stopping OmniSharp server' )
 
-  def _TryToStopServer( self ):
-    for _ in range( 5 ):
-      try:
-        self._GetResponse( '/stopserver', timeout = .1 )
-      except:
-        pass
-      for _ in range( 10 ):
-        if not self._ServerIsRunning():
-          return
-        time.sleep( .1 )
+      self._CleanUp()
 
 
-  def _CleanupAfterServerStop( self ):
+  def _CleanUp( self ):
     self._omnisharp_port = None
     self._omnisharp_phandle = None
-    if ( not self._keep_logfiles ):
+    if not self._keep_logfiles:
       if self._filename_stdout:
         utils.RemoveIfExists( self._filename_stdout )
         self._filename_stdout = None

ycmd/completers/go/go_completer.py

@@ -141,6 +141,7 @@ def ComputeCandidatesInner( self, request_data ):
                              request_data[ 'start_column' ] )
 
     stdoutdata = self._ExecuteCommand( [ self._gocode_binary_path,
+                                         '-sock', 'tcp',
                                          '-addr', self._gocode_address,
                                          '-f=json', 'autocomplete',
                                          filename, str( offset ) ],
@@ -232,27 +233,33 @@ def _StartServer( self ):
   def _StopServer( self ):
     """Stop the Gocode server."""
     with self._gocode_lock:
-      _logger.info( 'Stopping Gocode server' )
-
       if self._ServerIsRunning():
+        _logger.info( 'Stopping Gocode server with PID {0}'.format(
+                          self._gocode_handle.pid ) )
         self._ExecuteCommand( [ self._gocode_binary_path,
+                                '-sock', 'tcp',
                                 '-addr', self._gocode_address,
                                 'close' ] )
-        self._gocode_handle.terminate()
-        self._gocode_handle.wait()
+        try:
+          utils.WaitUntilProcessIsTerminated( self._gocode_handle, timeout = 5 )
+          _logger.info( 'Gocode server stopped' )
+        except RuntimeError:
+          _logger.exception( 'Error while stopping Gocode server' )
 
-      self._gocode_handle = None
-      self._gocode_port = None
-      self._gocode_address = None
+      self._CleanUp()
 
-      if not self._keep_logfiles:
-        if self._gocode_stdout:
-          utils.RemoveIfExists( self._gocode_stdout )
-          self._gocode_stdout = None
 
-        if self._gocode_stderr:
-          utils.RemoveIfExists( self._gocode_stderr )
-          self._gocode_stderr = None
+  def _CleanUp( self ):
+    self._gocode_handle = None
+    self._gocode_port = None
+    self._gocode_address = None
+    if not self._keep_logfiles:
+      if self._gocode_stdout:
+        utils.RemoveIfExists( self._gocode_stdout )
+        self._gocode_stdout = None
+      if self._gocode_stderr:
+        utils.RemoveIfExists( self._gocode_stderr )
+        self._gocode_stderr = None
 
 
   def _RestartServer( self ):
@@ -312,6 +319,7 @@ def ServerIsHealthy( self ):
 
     try:
       self._ExecuteCommand( [ self._gocode_binary_path,
+                              '-sock', 'tcp',
                               '-addr', self._gocode_address,
                               'status' ] )
       return True

ycmd/completers/javascript/tern_completer.py

@@ -438,16 +438,17 @@ def _RestartServer( self ):
   def _StopServer( self ):
     with self._server_state_mutex:
       if self._ServerIsRunning():
-        _logger.info( 'Stopping Tern server with PID '
-                      + str( self._server_handle.pid )
-                      + '...' )
-
+        _logger.info( 'Stopping Tern server with PID {0}'.format(
+                          self._server_handle.pid ) )
         self._server_handle.terminate()
-        self._server_handle.wait()
-
-        _logger.info( 'Tern server terminated.' )
+        try:
+          utils.WaitUntilProcessIsTerminated( self._server_handle,
+                                              timeout = 5 )
+          _logger.info( 'Tern server stopped' )
+        except RuntimeError:
+          _logger.exception( 'Error while stopping Tern server' )
 
-        self._Reset()
+      self._Reset()
 
 
   def _ServerIsRunning( self ):

ycmd/completers/python/jedi_completer.py

@@ -91,8 +91,7 @@ def SupportedFiletypes( self ):
 
 
   def Shutdown( self ):
-    if self._ServerIsRunning():
-      self._StopServer()
+    self._StopServer()
 
 
   def ServerIsHealthy( self ):
@@ -130,17 +129,28 @@ def RestartServer( self, binary = None ):
 
   def _StopServer( self ):
     with self._server_lock:
-      self._logger.info( 'Stopping JediHTTP' )
-      if self._jedihttp_phandle:
+      if self._ServerIsRunning():
+        self._logger.info( 'Stopping JediHTTP server with PID {0}'.format(
+                               self._jedihttp_phandle.pid ) )
         self._jedihttp_phandle.terminate()
-        self._jedihttp_phandle = None
-        self._jedihttp_port = None
-
-      if not self._keep_logfiles:
-        utils.RemoveIfExists( self._logfile_stdout )
-        self._logfile_stdout = None
-        utils.RemoveIfExists( self._logfile_stderr )
-        self._logfile_stderr = None
+        try:
+          utils.WaitUntilProcessIsTerminated( self._jedihttp_phandle,
+                                              timeout = 5 )
+          self._logger.info( 'JediHTTP server stopped' )
+        except RuntimeError:
+          self._logger.exception( 'Error while stopping JediHTTP server' )
+
+      self._CleanUp()
+
+
+  def _CleanUp( self ):
+    self._jedihttp_phandle = None
+    self._jedihttp_port = None
+    if not self._keep_logfiles:
+      utils.RemoveIfExists( self._logfile_stdout )
+      self._logfile_stdout = None
+      utils.RemoveIfExists( self._logfile_stderr )
+      self._logfile_stderr = None
 
 
   def _StartServer( self ):

ycmd/completers/rust/rust_completer.py

@@ -332,21 +332,29 @@ def ServerIsHealthy( self ):
   def _StopServer( self ):
     with self._server_state_lock:
       if self._racerd_phandle:
+        _logger.info( 'Stopping Racerd with PID {0}'.format(
+                          self._racerd_phandle.pid ) )
         self._racerd_phandle.terminate()
-        self._racerd_phandle.wait()
-        self._racerd_phandle = None
-        self._racerd_host = None
-
-      if not self._keep_logfiles:
-        # Remove stdout log
-        if self._server_stdout:
-          utils.RemoveIfExists( self._server_stdout )
-          self._server_stdout = None
-
-        # Remove stderr log
-        if self._server_stderr:
-          utils.RemoveIfExists( self._server_stderr )
-          self._server_stderr = None
+        try:
+          utils.WaitUntilProcessIsTerminated( self._racerd_phandle,
+                                              timeout = 5 )
+          _logger.info( 'Racerd stopped' )
+        except RuntimeError:
+          _logger.exception( 'Error while stopping Racerd' )
+
+      self._CleanUp()
+
+
+  def _CleanUp( self ):
+    self._racerd_phandle = None
+    self._racerd_host = None
+    if not self._keep_logfiles:
+      if self._server_stdout:
+        utils.RemoveIfExists( self._server_stdout )
+        self._server_stdout = None
+      if self._server_stderr:
+        utils.RemoveIfExists( self._server_stderr )
+        self._server_stderr = None
 
 
   def _RestartServer( self ):

ycmd/completers/typescript/typescript_completer.py

@@ -253,7 +253,7 @@ def _WriteRequest( self, request ):
         self._tsserver_handle.stdin.write( serialized_request )
         self._tsserver_handle.stdin.flush()
       # IOError is an alias of OSError in Python 3.
-      except IOError:
+      except ( AttributeError, IOError ):
         _logger.exception( SERVER_NOT_RUNNING_MESSAGE )
         raise RuntimeError( SERVER_NOT_RUNNING_MESSAGE )
 
@@ -536,15 +536,25 @@ def _RestartServer( self, request_data ):
 
   def _StopServer( self ):
     with self._server_lock:
-      if not self._ServerIsRunning():
-        return
+      if self._ServerIsRunning():
+        _logger.info( 'Stopping TSServer with PID {0}'.format(
+                          self._tsserver_handle.pid ) )
+        self._SendCommand( 'exit' )
+        try:
+          utils.WaitUntilProcessIsTerminated( self._tsserver_handle,
+                                              timeout = 5 )
+          _logger.info( 'TSServer stopped' )
+        except RuntimeError:
+          _logger.exception( 'Error while stopping TSServer' )
 
-      self._SendCommand( 'exit' )
-      self._tsserver_handle.wait()
+      self._CleanUp()
 
-      if not self.user_options[ 'server_keep_logfiles' ]:
-        utils.RemoveIfExists( self._logfile )
-        self._logfile = None
+
+  def _CleanUp( self ):
+    self._tsserver_handle = None
+    if not self.user_options[ 'server_keep_logfiles' ]:
+      utils.RemoveIfExists( self._logfile )
+      self._logfile = None
 
 
   def Shutdown( self ):

ycmd/handlers.py

@@ -23,7 +23,6 @@
 standard_library.install_aliases()
 from builtins import *  # noqa
 
-import atexit
 import bottle
 import json
 import logging
@@ -282,7 +281,6 @@ def Terminator():
   terminator.start()
 
 
-@atexit.register
 def ServerCleanup():
   if _server_state:
     _server_state.Shutdown()