Merge pull request #31 from Helithumper/27-logging

Adding in a formal logger

index.py

@@ -1,4 +1,5 @@
 import json
+import logging
 import os
 import time
 import uuid
@@ -34,6 +35,11 @@
 os.environ["OAUTHLIB_INSECURE_TRANSPORT"] = "0"
 ###
 
+logging.basicConfig(level=logging.DEBUG,
+                    format='%(asctime)s - %(levelname)s - %(name)s - %(message)s',
+                    datefmt='%Y-%m-%d %H:%M:%S')
+logger = logging.getLogger(__name__)
+
 options = Options.fetch()
 
 # Initiate FastAPI.
@@ -88,7 +94,7 @@ async def index(request: Request, token: Optional[str] = Cookie(None)):
         user_id: bool = payload.get("id", None)
         infra_email: bool = payload.get("infra_email", None)
     except Exception as e:
-        print(e)
+        logger.exception(e)
         pass
 
     return templates.TemplateResponse(
@@ -113,7 +119,6 @@ async def index(request: Request, token: Optional[str] = Cookie(None)):
 async def oauth_transformer(redir: str = "/join/2"):
     # Open redirect check
     hostname = urlparse(redir).netloc
-    print(hostname)
     if hostname != "" and hostname != options.get("http", {}).get(
         "domain", "my.hackucf.org"
     ):
@@ -199,7 +204,7 @@ async def oauth_transformer_new(
     # BACKPORT: I didn't realize that Snowflakes were strings because of an integer overflow bug.
     # So this will do a query for the "mistaken" value and then fix its data.
     if not query_for_id:
-        print("Beginning Discord ID attribute migration...")
+        logger.info("Beginning Discord ID attribute migration...")
         query_for_id = table.scan(
             FilterExpression=Attr("discord_id").eq(int(discordData["id"]))
         )
@@ -213,7 +218,6 @@ async def oauth_transformer_new(
             )
 
     is_new = False
-    print(query_for_id)
 
     if query_for_id:
         query_for_id = query_for_id[0]
@@ -326,7 +330,6 @@ async def profile(
     # Get data from DynamoDB
     dynamodb = boto3.resource("dynamodb")
     table = dynamodb.Table(options.get("aws").get("dynamodb").get("table"))
-    print(token)
 
     user_data = table.get_item(Key={"id": payload.get("id")}).get("Item", None)
 
@@ -398,4 +401,5 @@ async def favicon():
 if __name__ == "__main__":
     import uvicorn
 
+    logger.info("Starting Server")
     uvicorn.run(app, host="0.0.0.0", port=8000)

routes/admin.py

@@ -164,14 +164,11 @@ async def admin_get_snowflake(
         "Items"
     )
 
-    print(data)
-
     if not data:
         # Try a legacy-user-ID search (deprecated, but still neccesary)
         data = table.scan(FilterExpression=Attr("discord_id").eq(int(discord_id))).get(
             "Items"
         )
-        print(data)
 
         if not data:
             return Errors.generate(request, 404, "User Not Found")

routes/api.py

@@ -96,12 +96,15 @@ async def post_form(
     kennelish_data = Options.get_form_body(num)
     model = Transformer.kennelish_to_pydantic(kennelish_data)
 
+    # Parse and Validate inputs
     try:
         inp = await request.json()
     except json.JSONDecodeError:
         return {"description": "Malformed JSON input."}
 
     try:
+        # this only parses the data into an arbitrary pydantic model,
+        # it doesn't actually validate form field completion as far as I can tell
         validated = model(**inp)
     except error_wrappers.ValidationError:
         return {"description": "Malformed input."}
@@ -110,6 +113,7 @@ async def post_form(
     items_to_update = list(validated.dict().items())
     items_to_keep = []
     for item in items_to_update:
+        # What is Item[0] and Item[1]???
         if item[1] is not None:
             # English -> Boolean
             if item[1] == "Yes" or item[1] == "I promise not to do this.":
@@ -147,21 +151,14 @@ async def post_form(
             UpdateExpression=update_expression,
             ExpressionAttributeValues=expression_attribute_values,
         )
-    except ClientError as e:
+    except ClientError:
         # We need to do a migration on *something*. We know it's a subtype.
         # So we will find it and migrate it.
-        print("MIGRATION TIEM")
-        print(e)
-
         for item in items_to_keep:
             if "." in item[0]:
                 dot_loc = item[0].find(".")
                 key_to_make = item[0][:dot_loc]
 
-                print(update_expression)
-                print(":3")
-                print(expression_attribute_values)
-
                 # Create dictionary
                 table.update_item(
                     Key={"id": user_jwt.get("id")},

routes/infra.py

@@ -1,5 +1,6 @@
 import asyncio
 import json
+import logging
 import os
 from typing import Optional
 
@@ -20,6 +21,8 @@
 from util.limiter import RateLimiter
 from util.options import Options
 
+logger = logging.getLogger(__name__)
+
 options = Options.fetch()
 
 templates = Jinja2Templates(directory="templates")
@@ -43,11 +46,12 @@ def get_shitty_database():
     I lovingly call this the "shitty database."
     """
     data = {}
+    opts_path = "infra_options.json"
     try:
-        with open("infra_options.json", "r") as f:
+        with open(opts_path, "r") as f:
             data = json.loads(f.read())
     except Exception as e:
-        print(e)
+        logger.exception(f"Invalid config file at {opts_path}", e)
         data = {"gbmName": None, "imageId": None}
 
     return data
@@ -57,7 +61,7 @@ async def create_resource(project, callback_discord_id=None):
     shitty_database = get_shitty_database()
     proj_name = project.name
 
-    print(f"Creating resources for {proj_name}...")
+    logger.info(f"Creating resources for {proj_name}...")
 
     tf_vars = {
         "username": options.get("infra", {}).get("ad", {}).get("username"),
@@ -69,9 +73,9 @@ async def create_resource(project, callback_discord_id=None):
     }
     return_code, stdout, stderr = tf.apply(var=tf_vars, skip_plan=True)
     if return_code != 0:
-        print("Terraform failed!")
-        print(f"\treturn: {return_code}")
-        print(f"\tstderr: {stderr}\n")
+        logger.exception("Terraform failed!")
+        logger.debug(f"\treturn: {return_code}")
+        logger.debug(f"\tstderr: {stderr}\n")
 
     # clean up
     try:
@@ -94,67 +98,67 @@ async def create_resource(project, callback_discord_id=None):
 """
         Discord.send_message(callback_discord_id, resource_create_msg)
 
-    print("\tDone!")
+    logger.info("\tDone!")
 
 
 async def teardown():
-    print("Initializing post-GBM teardown...")
+    logger.debug("Initializing post-GBM teardown...")
     death_word = "gbm"
 
     conn = openstack.connect(cloud="hackucf_infra")
 
-    print("\tServers...")
+    logger.debug("\tServers...")
     for resource in conn.compute.servers(all_projects=True):
-        # print("\t" + resource.name)
+        # logger.debug("\t" + resource.name)
         if death_word in resource.name.lower():
-            print(f"\t\tdelete {resource.name}")
+            logger.debug(f"\t\tdelete {resource.name}")
             conn.compute.delete_server(resource)
 
-    print("\tSec Groups...")
+    logger("\tSec Groups...")
     for resource in conn.network.security_groups():
-        # print("\t" + resource.name)
+        # logger.debug("\t" + resource.name)
         if death_word in resource.name.lower():
-            print(f"\t\tdelete {resource.name}")
+            logger.debug(f"\t\tdelete {resource.name}")
             conn.network.delete_security_group(resource)
 
-    print("\tRouters...")
+    logger.debug("\tRouters...")
     for resource in conn.network.routers():
-        # print("\t" + resource.name)
+        # logger.debug("\t" + resource.name)
         if death_word in resource.name.lower():
-            print(f"\t\tdelete {resource.name}")
+            logger.debug(f"\t\tdelete {resource.name}")
             try:
                 conn.network.delete_router(resource)
             except openstack.exceptions.ConflictException as e:
                 port_id_list = str(e).split(": ")[-1].split(",")
                 for port_id in port_id_list:
-                    print(f"\t\t\tdelete/abandon port: {port_id}")
+                    logger.debug(f"\t\t\tdelete/abandon port: {port_id}")
                     conn.network.remove_interface_from_router(resource, port_id=port_id)
                     conn.network.delete_port(port_id)
                 try:
                     conn.network.delete_router(resource)
                 except: # noqa
-                    print("\t\t\t\tFailed and gave up.")
+                    logger.debug("\t\t\t\tFailed and gave up.")
 
-    print("\tNetworks...")
+    logger.debug("\tNetworks...")
     for resource in conn.network.networks():
-        # print("\t" + resource.name)
+        # logger.debug("\t" + resource.name)
         if death_word in resource.name.lower():
-            print(f"\t\tdelete {resource.name}")
+            logger.debug(f"\t\tdelete {resource.name}")
             try:
                 conn.network.delete_network(resource)
             except openstack.exceptions.ConflictException as e:
                 port_id_list = str(e).split(": ")[-1][:-1].split(",")
                 for port_id in port_id_list:
-                    print(f"\t\t\tdelete port: {port_id}")
+                    logger.debug(f"\t\t\tdelete port: {port_id}")
                     try:
                         conn.network.delete_port(port_id)
                     except: # noqa
                         pass
                 try:
                     conn.network.delete_network(resource)
                 except: #noqa
-                    print("\t\t\t\tFailed and gave up.")
-    print("\tDone!")
+                    logger.debug("\t\t\t\tFailed and gave up.")
+    logger.debug("\tDone!")
 
 
 """

routes/stripe.py

@@ -1,3 +1,4 @@
+import logging
 from typing import Optional
 
 import boto3
@@ -15,6 +16,9 @@
 options = Options.fetch()
 templates = Jinja2Templates(directory="templates")
 
+
+logger = logging.getLogger(__name__)
+
 router = APIRouter(prefix="/pay", tags=["API"], responses=Errors.basic_http())
 
 # Set Stripe API key.
@@ -103,11 +107,11 @@ async def webhook(request: Request):
         event = stripe.Webhook.construct_event(payload, sig_header, endpoint_secret)
     except ValueError as e:
         # Invalid payload
-        print(e)
+        logger.error("Malformed Stripe Payload", e)
         return HTTPException(status_code=400, detail="Malformed payload.")
     except stripe.error.SignatureVerificationError as e:
         # Invalid signature
-        print(e)
+        logger.error("Malformed Stripe Payload", e)
         return HTTPException(status_code=400, detail="Malformed payload.")
 
     # Event Handling

util/approve.py

@@ -1,3 +1,4 @@
+import logging
 import os
 
 import boto3
@@ -9,6 +10,8 @@
 from util.horsepass import HorsePass
 from util.options import Options
 
+logger = logging.getLogger()
+
 options = Options.fetch()
 tf = Terraform(working_dir=options.get("infra", {}).get("tf_directory", "./"))
 
@@ -50,15 +53,15 @@ def provision_infra(member_id, user_data=None):
                 user = conn.identity.find_user(username)
                 if user:
                     # Delete user's default project
-                    print(f"user // {user.default_project_id}")
+                    logger.debug(f"user // {user.default_project_id}")
                     proj = conn.identity.get_project(user.default_project_id)
                     proj = conn.identity.delete_project(proj)
 
                     # Delete user
                     conn.identity.delete_user(user)
-                    print(f"{username}: User deleted.")
+                    logger.debug(f"{username}: User deleted.")
                 else:
-                    print(f"{username}: No user.")
+                    logger.debug(f"{username}: No user.")
 
             else:
                 username = (
@@ -116,20 +119,20 @@ def provision_infra(member_id, user_data=None):
 
             return {"username": username, "password": password}
         except Exception as e:
-            print(e)
+            logger.exception(e)
             return None
 
     # !TODO finish the post-sign-up stuff + testing
     def approve_member(member_id):
-        print(f"Re-running approval for {member_id}")
+        logger.info(f"Re-running approval for {member_id}")
         dynamodb = boto3.resource("dynamodb")
         table = dynamodb.Table(options.get("aws").get("dynamodb").get("table"))
 
         user_data = table.get_item(Key={"id": member_id}).get("Item", None)
 
         # If a member was already approved, kill process.
         if user_data.get("is_full_member", False):
-            print("\tAlready full member.")
+            logger.info("\tAlready full member.")
             return True
 
         # Sorry for the long if statement. But we consider someone a "member" iff:
@@ -143,7 +146,7 @@ def approve_member(member_id):
             and user_data.get("did_pay_dues")
             and user_data.get("ethics_form", {}).get("signtime", 0) != 0
         ):
-            print("\tNewly-promoted full member!")
+            logger.info("\tNewly-promoted full member!")
 
             discord_id = user_data.get("discord_id")
 
@@ -194,7 +197,7 @@ def approve_member(member_id):
             )
 
         elif user_data.get("did_pay_dues"):
-            print("\tPaid dues but did not do other step!")
+            logger.info("\tPaid dues but did not do other step!")
             # Send a message on why this check failed.
             fail_msg = f"""Hello {user_data.get('first_name')},
 
@@ -214,6 +217,6 @@ def approve_member(member_id):
             Discord.send_message(discord_id, fail_msg)
 
         else:
-            print("\tDid not pay dues yet.")
+            logger.info("\tDid not pay dues yet.")
 
         return False

util/discord.py

@@ -50,11 +50,11 @@ def send_message(discord_id, message):
         channel_id = Discord.get_dm_channel_id(discord_id)
 
         send_message_body = {"content": message}
-        req = requests.post(
+        res = requests.post(
             f"https://discord.com/api/channels/{channel_id}/messages",
             headers=headers,
             data=json.dumps(send_message_body),
         )
-        print(req.text)
 
-        return req.status_code < 400
+        # Use res.ok()?
+        return res.status_code < 400