Merge pull request #521 from mozilla-iam/logging

Improve logging with Google Cloud Logs

Dockerfile

@@ -32,4 +32,4 @@ ENTRYPOINT ["gunicorn", "dashboard.app:app"]
 # by cloud deploy. In general, these should match the
 # args used in cloud deploy dev environment
 # Default command arguments
-CMD ["--worker-class", "gevent", "--bind", "0.0.0.0:8000", "--workers=2", "--max-requests=1000", "--max-requests-jitter=50", "--graceful-timeout=30", "--timeout=60", "--log-level=debug", "--error-logfile=-", "--reload", "--reload-extra-file=/dashboard/data/apps.yml"]
+CMD ["--worker-class=gevent", "--bind=0.0.0.0:8000", "--workers=3", "--graceful-timeout=30", "--timeout=60", "--log-config=dashboard/logging.ini", "--reload", "--reload-extra-file=/dashboard/data/apps.yml"]

clouddeploy/sso-dashboard-dev.template.yaml

@@ -33,18 +33,14 @@ spec:
       - name: 'sso-dashboard'
         image: 'app'
         command:
-          - gunicorn
+          - 'gunicorn'
           - 'dashboard.app:app'
         args:
-          - '--worker-class'
-          - gevent
-          - '--bind'
-          - '0.0.0.0:8000'
+          - '--worker-class=gevent'
+          - '--bind=0.0.0.0:8000'
           - '--workers=3'
           - '--graceful-timeout=30'
           - '--timeout=60'
-          - '--log-level=debug'
-          - '--error-logfile=-'
           - '--reload'
           - '--reload-extra-file=/dashboard/data/apps.yml'
         ports:
@@ -54,7 +50,7 @@ spec:
           - name: 'TARGET'
             value: 'Staging'
           - name: SSO-DASHBOARD_DEBUG
-            value: False
+            value: True
           - name: SSO-DASHBOARD_TESTING
             value: False
           - name: SSO-DASHBOARD_CSRF_ENABLED
@@ -65,8 +61,6 @@ spec:
             value: 86400
           - name: SSO-DASHBOARD_SESSION_COOKIE_HTTPONLY
             value: True
-          - name: SSO-DASHBOARD_LOGGER_NAME
-            value: sso-dashboard
           - name: SSO-DASHBOARD_PREFERRED_URL_SCHEME
             value: https
           - name: SSO-DASHBOARD_OIDC_CLIENT_ID

clouddeploy/sso-dashboard-prod.template.yaml

@@ -33,18 +33,14 @@ spec:
       - name: 'sso-dashboard'
         image: 'app'
         command:
-          - gunicorn
+          - 'gunicorn'
           - 'dashboard.app:app'
         args:
-          - '--worker-class'
-          - gevent
-          - '--bind'
-          - '0.0.0.0:8000'
+          - '--worker-class=gevent'
+          - '--bind=0.0.0.0:8000'
           - '--workers=3'
           - '--graceful-timeout=30'
           - '--timeout=60'
-          - '--log-level=debug'
-          - '--error-logfile=-'
           - '--reload'
           - '--reload-extra-file=/dashboard/data/apps.yml'
         ports:
@@ -65,8 +61,6 @@ spec:
             value: 86400
           - name: SSO-DASHBOARD_SESSION_COOKIE_HTTPONLY
             value: True
-          - name: SSO-DASHBOARD_LOGGER_NAME
-            value: sso-dashboard
           - name: SSO-DASHBOARD_PREFERRED_URL_SCHEME
             value: https
           - name: SSO-DASHBOARD_OIDC_CLIENT_ID

clouddeploy/sso-dashboard-staging.template.yaml

@@ -33,18 +33,14 @@ spec:
       - name: 'sso-dashboard'
         image: 'app'
         command:
-          - gunicorn
+          - 'gunicorn'
           - 'dashboard.app:app'
         args:
-          - '--worker-class'
-          - gevent
-          - '--bind'
-          - '0.0.0.0:8000'
+          - '--worker-class=gevent'
+          - '--bind=0.0.0.0:8000'
           - '--workers=3'
           - '--graceful-timeout=30'
           - '--timeout=60'
-          - '--log-level=debug'
-          - '--error-logfile=-'
           - '--reload'
           - '--reload-extra-file=/dashboard/data/apps.yml'
         ports:
@@ -65,8 +61,6 @@ spec:
             value: 86400
           - name: SSO-DASHBOARD_SESSION_COOKIE_HTTPONLY
             value: True
-          - name: SSO-DASHBOARD_LOGGER_NAME
-            value: sso-dashboard
           - name: SSO-DASHBOARD_PREFERRED_URL_SCHEME
             value: https
           - name: SSO-DASHBOARD_OIDC_CLIENT_ID

compose.yml

@@ -5,9 +5,6 @@ services:
   sso-dashboard:
     build: .
     env_file: envfile
-    environment:
-      - FLASK_DEBUG=True
-      - FLASK_APP=dashboard/app.py
     ports:
       - 8000:8000
     volumes:

dashboard/__init__.py

@@ -2,7 +2,6 @@
 
 from everett.manager import ConfigManager
 from everett.manager import ConfigOSEnv
-from everett.ext.inifile import ConfigIniEnv
 
 # -*- coding: utf-8 -*-
 
@@ -17,15 +16,4 @@
 
 
 def get_config():
-    return ConfigManager(
-        [
-            ConfigIniEnv(
-                [
-                    os.environ.get("DASHBOARD_CONFIG_INI"),
-                    "~/.sso-dashboard.ini",
-                    "/etc/sso-dashboard.ini",
-                ]
-            ),
-            ConfigOSEnv(),
-        ]
-    )
+    return ConfigManager([ConfigOSEnv()])

dashboard/api/idp.py

@@ -7,7 +7,7 @@
 from jose import jwt
 from dashboard.api.exceptions import AuthError
 
-logger = logging.getLogger(__name__)
+logger = logging.getLogger()
 
 
 class AuthorizeAPI(object):

dashboard/app.py

@@ -1,10 +1,11 @@
 """SSO Dashboard App File."""
 
 import json
-import logging.config
+import logging
 import mimetypes
 import os
 import redis
+import traceback
 import yaml
 
 from flask import Flask
@@ -37,17 +38,14 @@
 from dashboard.models.tile import CDNTransfer
 
 
-logging.basicConfig(level=logging.INFO)
+logging.config.fileConfig("dashboard/logging.ini")
 
-with open("dashboard/logging.yml", "r") as log_config:
-    config_yml = log_config.read()
-    config_dict = yaml.safe_load(config_yml)
-    logging.config.dictConfig(config_dict)
-
-logger = logging.getLogger("sso-dashboard")
+if config.Config(None).settings.DEBUG:
+    # Set the log level to DEBUG for all defined loggers
+    for logger_name in logging.root.manager.loggerDict.keys():
+        logging.getLogger(logger_name).setLevel("DEBUG")
 
 app = Flask(__name__)
-everett_config = get_config()
 
 talisman = Talisman(app, content_security_policy=DASHBOARD_CSP, force_https=False)
 
@@ -116,13 +114,27 @@ def claim():
     return redirect("https://github.com/mozilla-iam/cis/blob/master/cis/schema.json", code=302)
 
 
+# Flask Error Handlers
 @app.errorhandler(404)
 def page_not_found(error):
     if request.url is not None:
-        logger.error("A 404 has been generated for {route}".format(route=request.url))
+        app.logger.error("A 404 has been generated for {route}".format(route=request.url))
     return render_template("404.html"), 404
 
 
+@app.errorhandler(Exception)
+def handle_exception(e):
+
+    # Capture the traceback
+    tb_str = traceback.format_exc()
+
+    # Log the error with traceback
+    app.logger.error("An error occurred: %s\n%s", str(e), tb_str)
+
+    response = {"error": "An internal error occurred", "message": str(e)}
+    return jsonify(response), 500
+
+
 @app.route("/forbidden")
 def forbidden():
     """Route to render error page."""
@@ -162,15 +174,15 @@ def showautologinsettings():
 
 @app.route("/signout.html")
 def signout():
-    logger.info("Signout messaging displayed.")
+    app.logger.info("Signout messaging displayed.")
     return render_template("signout.html")
 
 
 @app.route("/dashboard")
 @oidc.oidc_auth("default")
 def dashboard():
     """Primary dashboard the users will interact with."""
-    logger.info("User: {} authenticated proceeding to dashboard.".format(session.get("id_token")["sub"]))
+    app.logger.info("User: {} authenticated proceeding to dashboard.".format(session.get("id_token")["sub"]))
 
     # TODO: Refactor rules later to support full id_conformant session
     session["userinfo"]["user_id"] = session.get("id_token")["sub"]

dashboard/config.py

@@ -21,18 +21,18 @@ def _init_env(self):
 class DefaultConfig(object):
     """Defaults for the configuration objects."""
 
-    DEBUG = bool(CONFIG("debug", namespace="sso-dashboard", default="True"))
-    TESTING = bool(CONFIG("testing", namespace="sso-dashboard", default="False"))
-    PROPAGATE_EXCEPTIONS = bool(CONFIG("propagate_exceptions", namespace="sso-dashboard", default="True"))
+    DEBUG = bool(CONFIG("debug", namespace="sso-dashboard", parser=bool, default="False"))
+    TESTING = bool(CONFIG("testing", namespace="sso-dashboard", parser=bool, default="False"))
 
-    CSRF_ENABLED = bool(CONFIG("csrf_enabled", default="True"))
-    PERMANENT_SESSION = bool(CONFIG("permanent_session", namespace="sso-dashboard", default="True"))
+    CSRF_ENABLED = bool(CONFIG("csrf_enabled", parser=bool, default="True"))
+    PERMANENT_SESSION = bool(CONFIG("permanent_session", namespace="sso-dashboard", parser=bool, default="True"))
     seconds = int(CONFIG("permanent_session_lifetime", namespace="sso-dashboard", default="86400"))
     PERMANENT_SESSION_LIFETIME = datetime.timedelta(seconds=seconds)
 
     SESSION_COOKIE_SAMESITE = CONFIG("session_cookie_samesite", namespace="sso-dashboard", default="lax")
-    SESSION_COOKIE_HTTPONLY = bool(CONFIG("session_cookie_httponly", namespace="sso-dashboard", default="True"))
-    LOGGER_NAME = CONFIG("logger_name", namespace="sso-dashboard", default="sso-dashboard")
+    SESSION_COOKIE_HTTPONLY = bool(
+        CONFIG("session_cookie_httponly", namespace="sso-dashboard", parser=bool, default="True")
+    )
 
     SECRET_KEY = CONFIG("secret_key", namespace="sso-dashboard")
     SERVER_NAME = CONFIG("server_name", namespace="sso-dashboard", default="localhost:8000")

dashboard/logging.ini

@@ -0,0 +1,45 @@
+[loggers]
+keys=root,gunicorn.error,gunicorn.access,flask_app,werkzeug
+
+[handlers]
+keys=console
+
+[formatters]
+keys=json
+
+[logger_root]
+level=INFO
+handlers=console
+disable_existing_loggers=False
+
+[logger_gunicorn.error]
+level=INFO
+qualname=gunicorn.error
+propagate=0
+handlers=console
+
+[logger_gunicorn.access]
+level=INFO
+qualname=gunicorn.access
+propagate=0
+handlers=console
+
+[logger_flask_app]
+level=INFO
+qualname=flask_app
+propagate=0
+handlers=console
+
+[logger_werkzeug]
+level=INFO
+qualname=werkzeug
+propagate=0
+handlers=console
+
+[handler_console]
+class=logging.StreamHandler
+formatter=json
+args=(sys.stderr,)
+
+[formatter_json]
+format={"time": "%(asctime)s", "level": "%(levelname)s", "process_id": %(process)d, "message": "%(message)s", "name": "%(filename)s:%(name)s:%(funcName)s:%(lineno)s"}