fix: use AppConfig to configure logging for server (#720)

* fix: use AppConfig to configure logging for server

* set test config

* remove dictConfig from ecs/app.py

* set default debug and verbose to False in CLI launcher.

Add comments regarding the relationship between verbose and debug

* silence werkzeurg logger

* fix logging for ecs

* reverse logic

---------

Co-authored-by: Seve Badajoz <sbadajoz@chanzuckerberg.com>

client/__tests__/e2e/test_config.yaml

@@ -2,8 +2,8 @@ server:
   app:
     force_https: true
     port: 5005
-    debug: true
-    verbose: true
+    debug: false
+    verbose: false
 
   gene_info:
     api_base: "https://api.cellxgene.dev.single-cell.czi.technology/gene_info/v1"

server/app/app.py

@@ -15,6 +15,7 @@
 from server.app.api.v3 import register_api_v3
 from server.app.logging import configure_logging
 from server.app.request_id import generate_request_id, get_request_id
+from server.common.config.app_config import AppConfig
 from server.common.errors import (
     DatasetAccessError,
     DatasetNotFoundError,
@@ -27,8 +28,6 @@
 from server.common.utils.utils import Float32JSONEncoder, path_join
 from server.dataset.matrix_loader import DataLoader
 
-configure_logging()
-
 
 @webbp.errorhandler(RequestException)
 def handle_request_exception(error):
@@ -152,7 +151,9 @@ def _before_adding_routes(app, app_config):
         """will be called before routes are added, during __init__.  Subclass protocol"""
         pass
 
-    def __init__(self, app_config):
+    def __init__(self, app_config: AppConfig):
+        log_level = logging.INFO if app_config.server__app__verbose else logging.ERROR
+        configure_logging(log_level)
         self.app = Flask(__name__, static_folder=None)
         handle_api_base_url(self.app, app_config)
         self._before_adding_routes(self.app, app_config)

server/app/logging.py

@@ -17,9 +17,11 @@ def format_log_string(fields: List[str]) -> str:
 DATETIME_FORMAT = "%Y-%m-%dT%H:%M:%S.%03dZ"
 
 
-def configure_logging():
+def configure_logging(log_level: int = logging.INFO):
     logHandler = logging.StreamHandler()
     formatter = jsonlogger.JsonFormatter(fmt=LOG_FORMAT, datefmt=DATETIME_FORMAT)
     logHandler.setFormatter(formatter)
     logHandler.addFilter(RequestIdFilter())
-    logging.basicConfig(level=logging.INFO, handlers=[logHandler], force=True)
+    logging.basicConfig(level=log_level, handlers=[logHandler], force=True)
+    logging.getLogger("werkzeug").setLevel(log_level)
+    logging.info(f"Configure logging: {log_level=}")

server/cli/launch.py

@@ -1,9 +1,9 @@
 import errno
 import functools
+import logging
 import os
 import sys
 import webbrowser
-from logging import ERROR, Logger, getLogger
 
 import click
 
@@ -13,7 +13,6 @@
 from server.default_config import default_config
 from server.tests.unit import TestServer
 
-log: Logger = getLogger("werkzeug")
 DEFAULT_CONFIG = AppConfig()
 
 
@@ -68,16 +67,16 @@ def server_args(func):
         "--debug",
         "-d",
         is_flag=True,
-        default=DEFAULT_CONFIG.server__app__debug,
+        default=False,
         show_default=True,
         help="Run in debug mode. This is helpful for cellxgene developers, "
-        "or when you want more information about an error condition.",
+        "or when you want more information about an error condition. This will automatically set verbose mode.",
     )
     @click.option(
         "--verbose",
         "-v",
         is_flag=True,
-        default=DEFAULT_CONFIG.server__app__verbose,
+        default=False,
         show_default=True,
         help="Provide verbose output, including warnings and all server requests.",
     )
@@ -220,7 +219,7 @@ def launch(
     config_file: str = config_file if config_file else test_config_file
 
     if not os.path.isdir(dataroot):
-        log.error(f"{dataroot} is not a directory -- please provide the root directory for your dataset(s)")
+        logging.error(f"{dataroot} is not a directory -- please provide the root directory for your dataset(s)")
         sys.exit(1)
 
     if dump_default_config:
@@ -229,9 +228,6 @@ def launch(
     # Startup message
     click.echo("[cellxgene] Starting the development server...")
 
-    # app config
-    app_config: AppConfig = AppConfig()
-
     try:
         app_config: AppConfig = AppConfig(config_file)
 
@@ -269,9 +265,6 @@ def launch(
     # create the server
     server: TestServer = TestServer(app_config)
 
-    if not app_config.server__app__verbose:
-        log.setLevel(ERROR)
-
     cellxgene_url: str = f"http://{app_config.server__app__host}:{app_config.server__app__port}"
     if app_config.server__app__open_browser:
         click.echo(f"[cellxgene] Launching! Opening your browser to {cellxgene_url} now.")

server/default_config.py

@@ -5,6 +5,7 @@
   app:
     verbose: false
     debug: false
+    # if debug mode is enabled, then the server will not open a browser, and verbose mode will be enabled.
     host: localhost
     port : null
     open_browser: false

server/ecs/app.py

@@ -3,7 +3,6 @@
 import logging
 import os
 import sys
-from logging.config import dictConfig
 from urllib.parse import urlparse
 
 from flask import json
@@ -13,28 +12,9 @@
 SERVERDIR = os.path.dirname(os.path.realpath(__file__))
 sys.path.append(SERVERDIR)
 
-
-dictConfig(
-    {
-        "version": 1,
-        "formatters": {
-            "default": {
-                "format": "[%(asctime)s] %(levelname)s in %(module)s: %(message)s",
-            }
-        },
-        "handlers": {
-            "wsgi": {
-                "class": "logging.StreamHandler",
-                "stream": "ext://flask.logging.wsgi_errors_stream",
-                "formatter": "default",
-            }
-        },
-        "root": {"level": "INFO", "handlers": ["wsgi"]},
-    }
-)
-
 try:
     from server.app.app import Server
+    from server.app.logging import configure_logging
     from server.common.config.app_config import AppConfig
     from server.common.utils.data_locator import DataLocator, discover_s3_region_name
 except Exception:
@@ -143,7 +123,7 @@ def get_csp_hashes(app, app_config):
 
 
 try:
-    app_config = False
+    configure_logging()
     # config file: look first for "config.yaml" in the current working directory
     config_file = "config.yaml"
     config_location = DataLocator(config_file)