Simple logging. (#16)

* Simple logging. I don't know if this will show up in the docker logs like inver wanted, so it probably needs testing in prod.

* log level via hasattr/getattr, basicConfig instead of custom handlers

* removing the empty string log call

4 files changed, 39 insertions, 15 deletions

diff --git a/pysite/__init__.py b/pysite/__init__.py
index 9bad5790..3e7aad42 100644
--- a/pysite/__init__.py
+++ b/pysite/__init__.py
@@ -1 +1,18 @@
 # coding=utf-8
+import logging
+import os
+
+
+# region Logging
+# Get the log level from environment
+log_level = os.environ.get("LOG_LEVEL", "info").upper()
+formatter = logging.Formatter('[%(asctime)s] [%(levelname)s] %(message)s')
+
+if hasattr(logging, log_level):
+    log_level = getattr(logging, log_level)
+else:
+    raise RuntimeError("LOG_LEVEL environment variable has an invalid value.")
+
+# This handler will ensure we log to stdout and stderr
+logging.basicConfig(format=formatter, level=log_level)
+# endregion
diff --git a/pysite/database.py b/pysite/database.py
index d3506062..589b77d1 100644
--- a/pysite/database.py
+++ b/pysite/database.py
@@ -1,6 +1,7 @@
 # coding=utf-8
-
+import logging
 import os
+
 from typing import Any, Callable, Dict, Iterator, List, Optional, Union
 
 from flask import abort
@@ -16,6 +17,7 @@ class RethinkDB:
         self.host = os.environ.get("RETHINKDB_HOST", "127.0.0.1")
         self.port = os.environ.get("RETHINKDB_PORT", "28016")
         self.database = os.environ.get("RETHINKDB_DATABASE", "pythondiscord")
+        self.log = logging.getLogger()
         self.conn = None
 
         rethinkdb.set_loop_type(loop_type)
@@ -23,9 +25,9 @@ class RethinkDB:
         with self.get_connection(connect_database=False) as conn:
             try:
                 rethinkdb.db_create(self.database).run(conn)
-                print(f"Database created: '{self.database}'")
+                self.log.debug(f"Database created: '{self.database}'")
             except rethinkdb.RqlRuntimeError:
-                print(f"Database found: '{self.database}'")
+                self.log.debug(f"Database found: '{self.database}'")
 
     def get_connection(self, connect_database: bool=True) -> DefaultConnection:
         """
@@ -82,7 +84,7 @@ class RethinkDB:
             all_tables = rethinkdb.db(self.database).table_list().run(conn)
 
             if table_name in all_tables:
-                print(f"Table found: '{table_name}' ({len(all_tables)} tables in total)")
+                self.log.debug(f"Table found: '{table_name}' ({len(all_tables)} tables in total)")
                 return False
 
             # Use a kwargs dict because the driver doesn't check the value
@@ -99,7 +101,7 @@ class RethinkDB:
 
             rethinkdb.db(self.database).table_create(table_name, **kwargs).run(conn)
 
-            print(f"Table created: '{table_name}'")
+            self.log.debug(f"Table created: '{table_name}'")
             return True
 
     def drop_table(self, table_name: str):
diff --git a/pysite/route_manager.py b/pysite/route_manager.py
index b3f71643..6c55d0f3 100644
--- a/pysite/route_manager.py
+++ b/pysite/route_manager.py
@@ -1,6 +1,7 @@
 # coding=utf-8
 import importlib
 import inspect
+import logging
 import os
 
 from flask import Blueprint, Flask
@@ -25,6 +26,7 @@ class RouteManager:
         self.sockets = Sockets(self.app)
 
         self.db = RethinkDB()
+        self.log = logging.getLogger()
         self.app.secret_key = os.environ.get("WEBPAGE_SECRET_KEY", "super_secret")
         self.app.config["SERVER_NAME"] = os.environ.get("SERVER_NAME", "pythondiscord.com:8080")
         self.app.before_request(self.db.before_request)
@@ -32,26 +34,24 @@ class RouteManager:
 
         # Load the main blueprint
         self.main_blueprint = Blueprint("main", __name__)
-        print(f"Loading Blueprint: {self.main_blueprint.name}")
+        self.log.debug(f"Loading Blueprint: {self.main_blueprint.name}")
         self.load_views(self.main_blueprint, "pysite/views/main")
         self.app.register_blueprint(self.main_blueprint)
-        print("")
+        self.log.debug("")
 
         # Load the subdomains
         self.subdomains = ['api', 'staff']
 
         for sub in self.subdomains:
             sub_blueprint = Blueprint(sub, __name__, subdomain=sub)
-
-            print(f"Loading Blueprint: {sub_blueprint.name}")
+            self.log.debug(f"Loading Blueprint: {sub_blueprint.name}")
             self.load_views(sub_blueprint, f"pysite/views/{sub}")
             self.app.register_blueprint(sub_blueprint)
-            print("")
 
         # Load the websockets
         self.ws_blueprint = Blueprint("ws", __name__)
 
-        print("Loading websocket routes...")
+        self.log.debug("Loading websocket routes...")
         self.load_views(self.ws_blueprint, "pysite/views/ws")
         self.sockets.register_blueprint(self.ws_blueprint, url_prefix="/ws")
 
@@ -89,4 +89,4 @@ class RouteManager:
                             )
                     ):
                         cls.setup(self, blueprint)
-                        print(f">> View loaded: {cls.name: <15} ({module.__name__}.{cls_name})")
+                        self.log.debug(f">> View loaded: {cls.name: <15} ({module.__name__}.{cls_name})")
diff --git a/pysite/views/ws/echo.py b/pysite/views/ws/echo.py
index 135adfcf..2776fa6b 100644
--- a/pysite/views/ws/echo.py
+++ b/pysite/views/ws/echo.py
@@ -1,4 +1,6 @@
 # coding=utf-8
+import logging
+
 from pysite.websockets import Websocket
 
 
@@ -6,13 +8,16 @@ class EchoWebsocket(Websocket):
     path = "/echo"
     name = "ws_echo"
 
+    def __init__(self):
+        self.log = logging.getLogger()
+
     def on_open(self):
-        print("Echo | WS opened.")
+        self.log.debug("Echo | WS opened.")
         self.send("Hey, welcome!")
 
     def on_message(self, message):
-        print(f"Echo | Message: {message}")
+        self.log.debug(f"Echo | Message: {message}")
         self.send(message)
 
     def on_close(self):
-        print("Echo | WS closed.")
+        self.log.debug("Echo | WS closed.")