Log slack door open time

inventory-app/api.py

@@ -1,6 +1,7 @@
 import os
 import re
 import const
+import time
 import threading
 from datetime import datetime, timedelta
 from functools import wraps
@@ -62,6 +63,7 @@ def get_group_cards():
 
 @page_api.route("/api/slack/doorboy", methods=['POST'])
 def view_slack_doorboy():
+    begin_time = time.perf_counter()
     if request.form.get("token") != const.SLACK_VERIFICATION_TOKEN:
         return "Invalid token was supplied"
     if request.form.get("channel_id") not in ("C01CWPF5H8W", "CDL9H8Q9W"):
@@ -98,12 +100,13 @@ def view_slack_doorboy():
 
     threading.Thread(target=handle_slack_door_event, args=(doors, approved, member, door, status, subject)).start()
 
-    if approved:
-        return "Opening %s for %s" % (door, subject)
-    else:
-        return "Permission denied"
+    return_message = "Opening %s for %s" % (door, subject) if approved else "Permission denied"
+    end_time = time.perf_counter()
+    print(f"view_slack_doorboy done in {end_time - begin_time:.4f} seconds")
+    return return_message
 
 def handle_slack_door_event(doors, approved, member, door, status, subject):
+    begin_time = time.perf_counter()
     for d in doors:
         db.eventlog.insert_one({
             "method": "slack",
@@ -119,3 +122,5 @@ def handle_slack_door_event(doors, approved, member, door, status, subject):
 
     msg = "%s %s door access for %s via Slack bot" % (status, door, subject)
     slack_post(msg, "doorboy")
+    end_time = time.perf_counter()
+    print(f"handle_slack_door_event done in {end_time - begin_time:.4f} seconds")