[serve] Make pywebsocket honor log_level config

Previously, `wpt serve` always starts pywebsocket with hard-coded
the default "debug" log level regardless of config.json, although it
does pass the log level from the config to wptserve. This leads to
inconsistent logging levels when a non-default log level is specified in
config.json, and makes it impossible for users to silence `wpt serve`
(pywebsocket also happens to be quite spammy).

The implementation is unfortunately hacky (double configurations) in
order to work around an earlier workaround which reloads the logging
module (#13091).

Author: Hexcles

tools/serve/serve.py

@@ -308,6 +308,7 @@ def _script_replacement(self, key, value):
 
 rewrites = [("GET", "/resources/WebIDLParser.js", "/resources/webidl2/lib/webidl2.js")]
 
+
 class RoutesBuilder(object):
     def __init__(self):
         self.forbidden_override = [("GET", "/tools/runner/*", handlers.file_handler),
@@ -501,7 +502,7 @@ def make_hosts_file(config, host):
 def start_servers(host, ports, paths, routes, bind_address, config, **kwargs):
     servers = defaultdict(list)
     for scheme, ports in ports.items():
-        assert len(ports) == {"http":2}.get(scheme, 1)
+        assert len(ports) == {"http": 2}.get(scheme, 1)
 
         # If trying to start HTTP/2.0 server, check compatibility
         if scheme == 'http2' and not http2_compatible():
@@ -512,11 +513,11 @@ def start_servers(host, ports, paths, routes, bind_address, config, **kwargs):
         for port in ports:
             if port is None:
                 continue
-            init_func = {"http":start_http_server,
-                         "https":start_https_server,
-                         "http2":start_http2_server,
-                         "ws":start_ws_server,
-                         "wss":start_wss_server}[scheme]
+            init_func = {"http": start_http_server,
+                         "https": start_https_server,
+                         "http2": start_http2_server,
+                         "ws": start_ws_server,
+                         "wss": start_wss_server}[scheme]
 
             server_proc = ServerProc(scheme=scheme)
             server_proc.start(init_func, host, port, paths, routes, bind_address,
@@ -570,6 +571,8 @@ def start_http2_server(host, port, paths, routes, bind_address, config, **kwargs
                                  encrypt_after_connect=config.ssl_config["encrypt_after_connect"],
                                  latency=kwargs.get("latency"),
                                  http2=True)
+
+
 class WebSocketDaemon(object):
     def __init__(self, host, port, doc_root, handlers_root, log_level, bind_address,
                  ssl_config):
@@ -601,6 +604,17 @@ def __init__(self, host, port, doc_root, handlers_root, log_level, bind_address,
         opts, args = pywebsocket._parse_args_and_config(cmd_args)
         opts.cgi_directories = []
         opts.is_executable_method = None
+
+        # Logging needs to be configured both before and after reloading,
+        # because some modules store loggers as global variables.
+        pywebsocket._configure_logging(opts)
+        # Ensure that when we start this in a new process we have the global
+        # lock in the logging module unlocked.
+        reload_module(logging)
+        release_mozlog_lock()
+        pywebsocket._configure_logging(opts)
+        # DO NOT LOG BEFORE THIS LINE.
+
         self.server = pywebsocket.WebSocketServer(opts)
         ports = [item[0].getsockname()[1] for item in self.server._sockets]
         assert all(item == ports[0] for item in ports)
@@ -647,29 +661,21 @@ def release_mozlog_lock():
 
 
 def start_ws_server(host, port, paths, routes, bind_address, config, **kwargs):
-    # Ensure that when we start this in a new process we have the global lock
-    # in the logging module unlocked
-    reload_module(logging)
-    release_mozlog_lock()
     return WebSocketDaemon(host,
                            str(port),
                            repo_root,
                            config.paths["ws_doc_root"],
-                           "debug",
+                           config.log_level.lower(),
                            bind_address,
-                           ssl_config = None)
+                           ssl_config=None)
 
 
 def start_wss_server(host, port, paths, routes, bind_address, config, **kwargs):
-    # Ensure that when we start this in a new process we have the global lock
-    # in the logging module unlocked
-    reload_module(logging)
-    release_mozlog_lock()
     return WebSocketDaemon(host,
                            str(port),
                            repo_root,
                            config.paths["ws_doc_root"],
-                           "debug",
+                           config.log_level.lower(),
                            bind_address,
                            config.ssl_config)
 
@@ -726,9 +732,11 @@ def build_config(override_path=None, **kwargs):
 
     return rv
 
+
 def _make_subdomains_product(s, depth=2):
     return {u".".join(x) for x in chain(*(product(s, repeat=i) for i in range(1, depth+1)))}
 
+
 _subdomains = {u"www",
                u"www1",
                u"www2",
@@ -745,7 +753,8 @@ def _make_subdomains_product(s, depth=2):
 class ConfigBuilder(config.ConfigBuilder):
     """serve config
 
-    this subclasses wptserve.config.ConfigBuilder to add serve config options"""
+    This subclasses wptserve.config.ConfigBuilder to add serve config options.
+    """
 
     _default = {
         "browser_host": "web-platform.test",