Merge pull request #33 from factly/feat/add_pref_logs

add pref logs

app/utils/tasks.py

@@ -31,8 +31,7 @@ def prefetch_profile(
     start_time = time.perf_counter()
     dataframe = get_dataframe(url)
     logger.info(f"Prefetching Profile for: {url}")
-    fetch_time = time.perf_counter() - start_time
-    logger.info(f"Time taken to fetch the dataset: {fetch_time:0.4f} seconds")
+    fetch_end = time.perf_counter()
 
     if dataframe.shape[0] < 100:
         logger.info(f"Dataset has less than 100 rows: {dataframe.shape[0]}")
@@ -51,20 +50,25 @@ def prefetch_profile(
     profile_segment = ProfileSegments(profile, columns=list(dataframe.columns))
 
     description = profile_segment.description()
-    profile_time = time.perf_counter() - fetch_time
+    profile_end = time.perf_counter()
     # Add `url` to the description before saving to MongoDB
     description["url"] = url
     description["trigger_id"] = trigger_id
-    logger.info(
-        f"Time taken to generate the profile: {profile_time:0.4f} seconds"
-    )
 
     # Upsert a json-encoded description into MongoDB
     sync_profiles_collection.update_one(
         {"url": url}, {"$set": jsonable_encoder(description)}, upsert=True
     )
     logger.info(f"Profile Prefetched for: {url}")
-    upsert_time = time.perf_counter() - profile_time
+    upsert_end = time.perf_counter()
+
+    fetch_time = fetch_end - start_time
+    profile_time = profile_end - fetch_end
+    upsert_time = upsert_end - profile_end
+    logger.info(f"Time taken to fetch the dataset: {fetch_time:0.4f} seconds")
+    logger.info(
+        f"Time taken to generate the profile: {profile_time:0.4f} seconds"
+    )
     logger.info(
         f"Time taken to upsert the profile: {upsert_time:0.4f} seconds"
     )