[autotest] Let log socket server use an unused port

BUG=chromium:383370
TEST=unittest

Change-Id: I56df36cb230d4f4f81f8ce1525b417a132c15aaf
Reviewed-on: https://chromium-review.googlesource.com/203542
Tested-by: Dan Shi <dshi@chromium.org>
Reviewed-by: Jiaxi Luo <jiaxiluo@chromium.org>
Reviewed-by: Prashanth B <beeps@chromium.org>
Commit-Queue: Dan Shi <dshi@chromium.org>
diff --git a/frontend/afe/json_rpc/serviceHandler.py b/frontend/afe/json_rpc/serviceHandler.py
index ede705c..b0d9e84 100644
--- a/frontend/afe/json_rpc/serviceHandler.py
+++ b/frontend/afe/json_rpc/serviceHandler.py
@@ -96,8 +96,8 @@
         timer = stats.Timer('rpc')
 
         try:
-            meth = self.findServiceEndpoint(methName)
             timer.start()
+            meth = self.findServiceEndpoint(methName)
             results['result'] = self.invokeServiceEndpoint(meth, args)
         except Exception, err:
             results['err_traceback'] = traceback.format_exc()
diff --git a/site_utils/log_socket_server.py b/site_utils/log_socket_server.py
index 697e83b..21bbf9a 100644
--- a/site_utils/log_socket_server.py
+++ b/site_utils/log_socket_server.py
@@ -19,6 +19,9 @@
 import struct
 import time
 
+import common
+from autotest_lib.client.bin import utils
+
 class LogRecordStreamHandler(SocketServer.StreamRequestHandler):
     """Handler for a streaming logging request.
 
@@ -79,13 +82,15 @@
 
     allow_reuse_address = 1
 
-    def __init__(self, host='localhost',
-                 port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,
+    def __init__(self, host='localhost', port=None,
                  handler=LogRecordStreamHandler):
+        if not port:
+            port = utils.get_unused_port()
         SocketServer.ThreadingTCPServer.__init__(self, (host, port), handler)
         self.abort = 0
         self.timeout = 1
         self.logname = None
+        self.port = port
 
 
     def serve_until_stopped(self):
@@ -105,6 +110,7 @@
     """A wrapper class to start and stop a TCP server for logging."""
 
     process = None
+    port = None
 
     @staticmethod
     def start(**kwargs):
@@ -117,21 +123,28 @@
         if LogSocketServer.process:
             raise Exception('Log Record Socket Receiver is already running.')
         server_started = multiprocessing.Value(ctypes.c_bool, False)
+        port = multiprocessing.Value(ctypes.c_int, 0)
         LogSocketServer.process = multiprocessing.Process(
-                target=LogSocketServer._start_server, args=(server_started,),
+                target=LogSocketServer._start_server,
+                args=(server_started, port),
                 kwargs=kwargs)
         LogSocketServer.process.start()
         while not server_started.value:
             time.sleep(0.1)
-        print 'Log Record Socket Server is started.'
+        LogSocketServer.port = port.value
+        print 'Log Record Socket Server is started at port %d.' % port.value
 
 
     @staticmethod
-    def _start_server(server_started, **kwargs):
+    def _start_server(server_started, port, **kwargs):
         """Start the TCP server to receive log.
 
+        @param server_started: True if socket log server is started.
+        @param port: Port used by socket log server.
         @param kwargs: log configuration, e.g., format, filename.
         """
+        # Clear all existing log handlers.
+        logging.getLogger().handlers = []
         if not kwargs:
             logging.basicConfig(
                     format='%(asctime)s - %(levelname)s - %(message)s')
@@ -141,6 +154,7 @@
         tcp_server = LogRecordSocketReceiver()
         print('Starting TCP server...')
         server_started.value = True
+        port.value = tcp_server.port
         tcp_server.serve_until_stopped()
 
 
@@ -151,3 +165,4 @@
         if LogSocketServer.process:
             LogSocketServer.process.terminate()
             LogSocketServer.process = None
+            LogSocketServer.port = None
diff --git a/site_utils/log_socket_server_unittest.py b/site_utils/log_socket_server_unittest.py
index 73485d7..1ebbf0c 100644
--- a/site_utils/log_socket_server_unittest.py
+++ b/site_utils/log_socket_server_unittest.py
@@ -19,14 +19,14 @@
     """
 
 
-    def log_call(self, value):
+    def log_call(self, value, port):
         """Method to be called in a new process to log to a socket server.
 
         @param value: Data to be logged.
+        @param port: Port used by log socket server.
         """
         logging.getLogger().handlers = []
-        socketHandler = logging.handlers.SocketHandler('localhost',
-                logging.handlers.DEFAULT_TCP_LOGGING_PORT)
+        socketHandler = logging.handlers.SocketHandler('localhost', port)
         logging.getLogger().addHandler(socketHandler)
         logging.getLogger().level = logging.INFO
         logging.info(value)
@@ -41,8 +41,10 @@
                                                 level=logging.INFO)
         processes = []
         process_number = 10
+        port = log_socket_server.LogSocketServer.port
         for i in range(process_number):
-            process = multiprocessing.Process(target=self.log_call, args=(i,))
+            process = multiprocessing.Process(target=self.log_call,
+                                              args=(i, port))
             process.start()
             processes.append(process)
 
@@ -64,4 +66,4 @@
 
 
 if __name__ == "__main__":
-    unittest.main()
\ No newline at end of file
+    unittest.main()
diff --git a/site_utils/rpm_control_system/rpm_dispatcher.py b/site_utils/rpm_control_system/rpm_dispatcher.py
index f7d2b92..f050a3f 100755
--- a/site_utils/rpm_control_system/rpm_dispatcher.py
+++ b/site_utils/rpm_control_system/rpm_dispatcher.py
@@ -288,8 +288,7 @@
       print 'Usage: ./%s, no arguments available.' % sys.argv[0]
       sys.exit(1)
     rpm_logging_config.start_log_server(LOG_FILENAME_FORMAT)
-    rpm_logging_config.set_up_logging(log_filename_format=LOG_FILENAME_FORMAT,
-                                      use_log_server=True)
+    rpm_logging_config.set_up_logging(use_log_server=True)
 
     # Get the local ip _address and set the server to utilize it.
     address = socket.gethostbyname(socket.gethostname())
diff --git a/site_utils/rpm_control_system/rpm_logging_config.py b/site_utils/rpm_control_system/rpm_logging_config.py
index c341ce3..152d438 100644
--- a/site_utils/rpm_control_system/rpm_logging_config.py
+++ b/site_utils/rpm_control_system/rpm_logging_config.py
@@ -86,7 +86,7 @@
     """
     if use_log_server:
         socketHandler = logging.handlers.SocketHandler(
-                'localhost', logging.handlers.DEFAULT_TCP_LOGGING_PORT)
+                'localhost', log_socket_server.LogSocketServer.port)
         logging.getLogger().addHandler(socketHandler)
     else:
         log_filename = get_log_filename(log_filename_format)