add: detail logging

src/api/image_prep_api.py

@@ -19,6 +19,7 @@ from fastapi.responses import JSONResponse
 from src.components.auto_crop import crop_transparent_image
 from src.components.color_extraction import ColorExtractionRMBG
 from src.components.title_des_gen import NecklaceProductListing
+from src.utils import logger
 
 preprocessing_router = APIRouter()
 
@@ -49,12 +50,16 @@ def replicate_enhancer(input):
 
 @preprocessing_router.post("/rem_bg")
 async def remove_background(image: UploadFile = File(...)):
+    logger.info("-" * 50)
+    logger.info(">>> REMOVE BACKGROUND STARTED <<<")
     start_time = time.time()
 
     try:
         image_bytes = await image.read()
         image = Image.open(BytesIO(image_bytes)).convert("RGB")
+        logger.info(">>> IMAGE LOADED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE LOADING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500, content={"error": f"Error reading image: {str(e)}", "code": 500})
 
     try:
@@ -62,13 +67,17 @@ async def remove_background(image: UploadFile = File(...)):
         image.save(act_img_base_64, format="WEBP")
         image_bytes_ = base64.b64encode(act_img_base_64.getvalue()).decode("utf-8")
         image_data_uri = f"data:image/WEBP;base64,{image_bytes_}"
+        logger.info(">>> IMAGE ENCODING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE ENCODING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error converting image to base64: {str(e)}", "code": 500})
 
     try:
         output = replicate_bg({"image": image_data_uri})
+        logger.info(">>> BACKGROUND REMOVAL COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> BACKGROUND REMOVAL ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error running background removal: {str(e)}", "code": 500})
 
@@ -84,21 +93,30 @@ async def remove_background(image: UploadFile = File(...)):
             "inference_time": total_inference_time,
             "code": 200
         }
+        logger.info(">>> RESPONSE PREPARATION COMPLETED <<<")
+        logger.info(f">>> TOTAL INFERENCE TIME: {total_inference_time}s <<<")
+        logger.info(">>> REQUEST COMPLETED SUCCESSFULLY <<<")
+        logger.info("-" * 50)
         return JSONResponse(content=response, status_code=200)
 
     except Exception as e:
+        logger.error(f">>> RESPONSE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error processing response: {str(e)}", "code": 500})
 
 
 @preprocessing_router.post("/upscale_image")
 async def upscale_image(image: UploadFile = File(...), scale: int = 1):
+    logger.info("-" * 50)
+    logger.info(">>> IMAGE UPSCALING STARTED <<<")
     start_time = time.time()
 
     try:
         image_bytes = await image.read()
         image = Image.open(BytesIO(image_bytes)).convert("RGBA")
+        logger.info(">>> IMAGE LOADED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE LOADING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500, content={"error": f"Error reading image: {str(e)}", "code": 500})
 
     try:
@@ -106,7 +124,9 @@ async def upscale_image(image: UploadFile = File(...), scale: int = 1):
         image.save(act_img_base_64, format="PNG")
         image_bytes_ = base64.b64encode(act_img_base_64.getvalue()).decode("utf-8")
         image_data_uri = f"data:image/png;base64,{image_bytes_}"
+        logger.info(">>> IMAGE ENCODING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE ENCODING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error converting image to base64: {str(e)}", "code": 500})
 
@@ -117,7 +137,9 @@ async def upscale_image(image: UploadFile = File(...), scale: int = 1):
             "face_enhance": False
         }
         output = replicate_enhancer(input)
+        logger.info(">>> IMAGE ENHANCEMENT COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE ENHANCEMENT ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error running image enhancement: {str(e)}", "code": 500})
 
@@ -133,29 +155,40 @@ async def upscale_image(image: UploadFile = File(...), scale: int = 1):
             "inference_time": total_inference_time,
             "code": 200
         }
+        logger.info(">>> RESPONSE PREPARATION COMPLETED <<<")
+        logger.info(f">>> TOTAL INFERENCE TIME: {total_inference_time}s <<<")
+        logger.info(">>> REQUEST COMPLETED SUCCESSFULLY <<<")
+        logger.info("-" * 50)
         return JSONResponse(content=response, status_code=200)
 
     except Exception as e:
+        logger.error(f">>> RESPONSE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error processing response: {str(e)}", "code": 500})
 
 
 @preprocessing_router.post("/crop_transparent")
 async def crop_transparent(image: UploadFile):
+    logger.info("-" * 50)
+    logger.info(">>> CROP TRANSPARENT STARTED <<<")
     start_time = time.time()
 
     try:
         if not image.content_type == "image/png":
+            logger.error(">>> INVALID FILE TYPE: NOT PNG <<<")
             return JSONResponse(status_code=400,
                                 content={"error": "Only PNG files are supported", "code": 400})
     except Exception as e:
+        logger.error(f">>> FILE TYPE CHECK ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error checking file type: {str(e)}", "code": 500})
 
     try:
         contents = await image.read()
         cropped_image_bytes, metadata = crop_transparent_image(contents)
+        logger.info(">>> IMAGE CROPPING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE CROPPING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error cropping image: {str(e)}", "code": 500})
 
@@ -165,6 +198,11 @@ async def crop_transparent(image: UploadFile):
 
         total_inference_time = round((time.time() - start_time), 2)
 
+        logger.info(">>> RESPONSE PREPARATION COMPLETED <<<")
+        logger.info(f">>> TOTAL INFERENCE TIME: {total_inference_time}s <<<")
+        logger.info(">>> REQUEST COMPLETED SUCCESSFULLY <<<")
+        logger.info("-" * 50)
+
         return JSONResponse(content={
             "status": "success",
             "code": 200,
@@ -175,12 +213,15 @@ async def crop_transparent(image: UploadFile):
             }
         }, status_code=200)
     except Exception as e:
+        logger.error(f">>> RESPONSE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error processing response: {str(e)}", "code": 500})
 
 
 @preprocessing_router.post("/background_replace")
 async def bg_replace(image: UploadFile = File(...), bg_image: UploadFile = File(...)):
+    logger.info("-" * 50)
+    logger.info(">>> BACKGROUND REPLACE STARTED <<<")
     start_time = time.time()
 
     try:
@@ -188,7 +229,9 @@ async def bg_replace(image: UploadFile = File(...), bg_image: UploadFile = File(
         bg_bytes = await bg_image.read()
         image = Image.open(BytesIO(image_bytes)).convert("RGBA")
         bg_image = Image.open(BytesIO(bg_bytes)).convert("RGB")
+        logger.info(">>> IMAGES LOADED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE LOADING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error reading images: {str(e)}", "code": 500})
 
@@ -197,7 +240,9 @@ async def bg_replace(image: UploadFile = File(...), bg_image: UploadFile = File(
         background = Image.fromarray(np.array(bg_image)).resize((width, height))
         orig_img = Image.fromarray(np.array(image)).resize((width, height))
         background.paste(orig_img, (0, 0), mask=orig_img)
+        logger.info(">>> IMAGE PROCESSING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error processing images: {str(e)}", "code": 500})
 
@@ -209,12 +254,18 @@ async def bg_replace(image: UploadFile = File(...), bg_image: UploadFile = File(
 
         total_inference_time = round((time.time() - start_time), 2)
 
+        logger.info(">>> RESPONSE PREPARATION COMPLETED <<<")
+        logger.info(f">>> TOTAL INFERENCE TIME: {total_inference_time}s <<<")
+        logger.info(">>> REQUEST COMPLETED SUCCESSFULLY <<<")
+        logger.info("-" * 50)
+
         return JSONResponse(content={
             "output": image_data_uri,
             "code": 200,
             "inference_time": total_inference_time
         }, status_code=200)
     except Exception as e:
+        logger.error(f">>> RESPONSE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error creating response: {str(e)}", "code": 500})
 
@@ -223,20 +274,26 @@ async def bg_replace(image: UploadFile = File(...), bg_image: UploadFile = File(
 async def remove_background_color_extraction(image: UploadFile = File(...),
                                              hex_color: str = "#FFFFFF",
                                              threshold: int = 30):
+    logger.info("-" * 50)
+    logger.info(">>> COLOR EXTRACTION STARTED <<<")
     start_time = time.time()
 
     try:
         image_bytes = await image.read()
         image = Image.open(BytesIO(image_bytes)).convert("RGBA")
         image = cv2.cvtColor(np.array(image), cv2.COLOR_RGB2BGR)
+        logger.info(">>> IMAGE LOADED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE LOADING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error reading image: {str(e)}", "code": 500})
 
     try:
         result = color_extraction_rmbg.extract_color(image, hex_color, threshold)
         result = Image.fromarray(cv2.cvtColor(result, cv2.COLOR_RGB2BGRA)).convert("RGBA")
+        logger.info(">>> COLOR EXTRACTION COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> COLOR EXTRACTION ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error extracting colors: {str(e)}", "code": 500})
 
@@ -248,24 +305,34 @@ async def remove_background_color_extraction(image: UploadFile = File(...),
 
         total_inference_time = round((time.time() - start_time), 2)
 
+        logger.info(">>> RESPONSE PREPARATION COMPLETED <<<")
+        logger.info(f">>> TOTAL INFERENCE TIME: {total_inference_time}s <<<")
+        logger.info(">>> REQUEST COMPLETED SUCCESSFULLY <<<")
+        logger.info("-" * 50)
+
         return JSONResponse(content={
             "output": image_data_uri,
             "code": 200,
             "inference_time": total_inference_time
         }, status_code=200)
     except Exception as e:
+        logger.error(f">>> RESPONSE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error creating response: {str(e)}", "code": 500})
 
 
 @preprocessing_router.post("/title_description_generator")
 async def product_title_description_generator(image: UploadFile = File(...)):
+    logger.info("-" * 50)
+    logger.info(">>> TITLE DESCRIPTION GENERATION STARTED <<<")
     start_time = time.time()
 
     try:
         image_bytes = await image.read()
         image = Image.open(BytesIO(image_bytes)).convert("RGB")
+        logger.info(">>> IMAGE LOADED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE LOADING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error reading image: {str(e)}", "code": 500})
 
@@ -273,7 +340,9 @@ async def product_title_description_generator(image: UploadFile = File(...)):
         result = product_listing_obj.gen_title_desc(image=image)
         title = result.split("Title:")[1].split("Description:")[0]
         description = result.split("Description:")[1]
+        logger.info(">>> TITLE AND DESCRIPTION GENERATION COMPLETED <<<")
     except Exception as e:
+        logger.error(">>> TITLE DESCRIPTION GENERATION ERROR <<<")
         return JSONResponse(status_code=500,
                             content={"error": "Please make sure the image is clear and necklaces are visible",
                                      "code": 500})
@@ -281,6 +350,11 @@ async def product_title_description_generator(image: UploadFile = File(...)):
     try:
         total_inference_time = round((time.time() - start_time), 2)
 
+        logger.info(">>> RESPONSE PREPARATION COMPLETED <<<")
+        logger.info(f">>> TOTAL INFERENCE TIME: {total_inference_time}s <<<")
+        logger.info(">>> REQUEST COMPLETED SUCCESSFULLY <<<")
+        logger.info("-" * 50)
+
         return JSONResponse(content={
             "code": 200,
             "title": title,
@@ -288,5 +362,6 @@ async def product_title_description_generator(image: UploadFile = File(...)):
             "inference_time": total_inference_time
         }, status_code=200)
     except Exception as e:
+        logger.error(f">>> RESPONSE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error creating response: {str(e)}", "code": 500})

src/api/image_regeneration_api.py

@@ -13,6 +13,7 @@ import requests
 from PIL import Image
 from fastapi import APIRouter, UploadFile, File, Form
 from fastapi.responses import JSONResponse
+from src.utils import logger
 
 image_regeneration_router = APIRouter()
 
@@ -48,6 +49,8 @@ async def image_re_gen(
         reference_image_c4_weight: Optional[float] = Form(default=0.0),
         reference_image_c4_stop: Optional[float] = Form(default=0.0),
 ):
+    logger.info("-" * 50)
+    logger.info(">>> IMAGE REDESIGN STARTED <<<")
     start_time = time.time()
 
     try:
@@ -60,8 +63,10 @@ async def image_re_gen(
                 reference_image_b64 = base64.b64encode(ref_img_base64.getvalue()).decode("utf-8")
                 return f"data:image/WEBP;base64,{reference_image_b64}"
             return None
+        logger.info(">>> REFERENCE IMAGE PROCESSING FUNCTION INITIALIZED <<<")
     except Exception as e:
-        return JSONResponse(status_code=500,
+        logger.error(f">>> REFERENCE IMAGE PROCESSING ERROR: {str(e)} <<<")
+        return JSONResponse(status_code=500, 
                           content={"error": f"Error processing reference image: {str(e)}", "code": 500})
 
     try:
@@ -70,7 +75,9 @@ async def image_re_gen(
         img_base64 = BytesIO()
         image.save(img_base64, format="WEBP")
         image_data_uri = f"data:image/WEBP;base64,{base64.b64encode(img_base64.getvalue()).decode('utf-8')}"
+        logger.info(">>> MAIN IMAGE PROCESSED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> MAIN IMAGE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                           content={"error": f"Error processing main image: {str(e)}", "code": 500})
 
@@ -81,7 +88,9 @@ async def image_re_gen(
             'c3': await process_reference_image(reference_image_c3),
             'c4': await process_reference_image(reference_image_c4)
         }
+        logger.info(">>> REFERENCE IMAGES PROCESSED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> REFERENCE IMAGES PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                           content={"error": f"Error processing reference images: {str(e)}", "code": 500})
 
@@ -106,7 +115,9 @@ async def image_re_gen(
             mask_image.save(mask_base64, format="WEBP")
             mask_image_data_uri = f"data:image/WEBP;base64,{base64.b64encode(mask_base64.getvalue()).decode('utf-8')}"
             input_data["inpaint_input_mask"] = mask_image_data_uri
+        logger.info(">>> INPUT DATA PREPARED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> INPUT DATA PREPARATION ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                           content={"error": f"Error preparing input data: {str(e)}", "code": 500})
 
@@ -127,7 +138,9 @@ async def image_re_gen(
                 stop_value = locals()[f'reference_image_{c}_stop']
                 if stop_value != 0.0 or stop_value != 0:
                     input_data[f"cn_stop{i}"] = stop_value
+        logger.info(">>> REFERENCE IMAGE PARAMETERS PROCESSED <<<")
     except Exception as e:
+        logger.error(f">>> REFERENCE IMAGE PARAMETERS ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                           content={"error": f"Error processing reference image parameters: {str(e)}", "code": 500})
 
@@ -136,18 +149,24 @@ async def image_re_gen(
         response = requests.get(output[0])
         output_base64 = base64.b64encode(response.content).decode('utf-8')
         base64_prefix = image_data_uri.split(",")[0] + ","
+        logger.info(">>> IMAGE REGENERATION COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE REGENERATION ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                           content={"error": f"Error generating image: {str(e)}", "code": 500})
 
     try:
-        inference_time = time.time() - start_time
+        inference_time = round(time.time() - start_time, 2)
         response = {
             "output": f"{base64_prefix}{output_base64}",
             "inference_time": inference_time,
             "code": 200,
         }
+        logger.info(f">>> TOTAL INFERENCE TIME: {inference_time}s <<<")
+        logger.info(">>> REQUEST COMPLETED SUCCESSFULLY <<<")
+        logger.info("-" * 50)
         return JSONResponse(content=response, status_code=200)
     except Exception as e:
+        logger.error(f">>> RESPONSE CREATION ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                           content={"error": f"Error creating response: {str(e)}", "code": 500})

src/api/nto_api.py

@@ -22,6 +22,7 @@ import os
 from pydantic import BaseModel
 import replicate
 import requests
+from src.utils.logger import logger
 
 pipeline = Pipeline()
 
@@ -55,18 +56,25 @@ class NecklaceTryOnIDEntity(BaseModel):
 
 @nto_cto_router.post("/clothingTryOnV2")
 async def clothing_try_on_v2(image: UploadFile = File(...), clothing_type: str = Form(...)):
+    logger.info("-" * 50)
+    logger.info(">>> CLOTHING TRY ON V2 STARTED <<<")
     start_time = time.time()
+
     try:
         image_bytes = await image.read()
         image = Image.open(BytesIO(image_bytes)).convert("RGB")
+        logger.info(">>> IMAGE LOADED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE LOADING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500, content={"error": f"Error reading image: {str(e)}", "code": 500})
 
     try:
         mask = await pipeline.shoulderPointMaskGeneration_(image=image)
+        logger.info(">>> MASK GENERATION COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> MASK GENERATION ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
-                            content={"error": f"Error generating mask: {str(e)}", "code": 500})
+                          content={"error": f"Error generating mask: {str(e)}", "code": 500})
 
     try:
         mask_img_base_64, act_img_base_64 = BytesIO(), BytesIO()
@@ -77,9 +85,11 @@ async def clothing_try_on_v2(image: UploadFile = File(...), clothing_type: str =
 
         mask_data_uri = f"data:image/webp;base64,{mask_bytes_}"
         image_data_uri = f"data:image/webp;base64,{image_bytes_}"
+        logger.info(">>> IMAGE ENCODING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE ENCODING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
-                            content={"error": f"Error converting images to base64: {str(e)}", "code": 500})
+                          content={"error": f"Error converting images to base64: {str(e)}", "code": 500})
 
     input = {
         "mask": mask_data_uri,
@@ -91,10 +101,15 @@ async def clothing_try_on_v2(image: UploadFile = File(...), clothing_type: str =
 
     try:
         output = replicate_run_cto(input)
+        logger.info(">>> REPLICATE PROCESSING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> REPLICATE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error running CTO Replicate: {str(e)}", "code": 500}, status_code=500)
 
     total_inference_time = round((time.time() - start_time), 2)
+    logger.info(f">>> TOTAL INFERENCE TIME: {total_inference_time}s <<<")
+    logger.info(">>> REQUEST COMPLETED SUCCESSFULLY <<<")
+    logger.info("-" * 50)
 
     response = {
         "code": 200,
@@ -108,12 +123,17 @@ async def clothing_try_on_v2(image: UploadFile = File(...), clothing_type: str =
 @nto_cto_router.post("/clothingTryOn")
 async def clothing_try_on(image: UploadFile = File(...),
                           mask: UploadFile = File(...), clothing_type: str = Form(...)):
+    logger.info("-" * 50)
+    logger.info(">>> CLOTHING TRY ON STARTED <<<")
     start_time = time.time()
+
     try:
         image_bytes = await image.read()
         mask_bytes = await mask.read()
         image, mask = Image.open(BytesIO(image_bytes)).convert("RGB"), Image.open(BytesIO(mask_bytes)).convert("RGB")
+        logger.info(">>> IMAGES LOADED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE LOADING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500, content={"error": f"Error reading image or mask: {str(e)}", "code": 500})
 
     try:
@@ -129,7 +149,9 @@ async def clothing_try_on(image: UploadFile = File(...),
         arr[mask_y:, :] = 255
 
         mask = Image.fromarray(arr).resize((512, 512))
+        logger.info(">>> IMAGE PROCESSING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error processing image or mask: {str(e)}", "code": 500})
 
@@ -142,7 +164,9 @@ async def clothing_try_on(image: UploadFile = File(...),
 
         mask_data_uri = f"data:image/webp;base64,{mask_bytes_}"
         image_data_uri = f"data:image/webp;base64,{image_bytes_}"
+        logger.info(">>> IMAGE ENCODING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE ENCODING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500,
                             content={"error": f"Error encoding images to base64: {str(e)}", "code": 500})
 
@@ -156,8 +180,11 @@ async def clothing_try_on(image: UploadFile = File(...),
 
     try:
         output = replicate_run_cto(input)
+        logger.info(">>> REPLICATE PROCESSING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> REPLICATE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error running CTO Replicate: {str(e)}", "code": 500}, status_code=500)
+
     try:
         response = requests.get(output[0])
         output_image = Image.open(BytesIO(response.content)).resize(actual_image.size)
@@ -169,6 +196,7 @@ async def clothing_try_on(image: UploadFile = File(...),
         result.save(in_mem_file, format="WEBP", quality=85)
         base_64_output = base64.b64encode(in_mem_file.getvalue()).decode('utf-8')
         total_inference_time = round((time.time() - start_time), 2)
+        logger.info(">>> OUTPUT IMAGE PROCESSING COMPLETED <<<")
 
         response = {
             "output": f"data:image/WEBP;base64,{base_64_output}",
@@ -176,10 +204,14 @@ async def clothing_try_on(image: UploadFile = File(...),
             "inference_time": total_inference_time
         }
     except Exception as e:
+        logger.error(f">>> OUTPUT IMAGE PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(status_code=500, content={"error": f"Error processing output image: {str(e)}", "code": 500})
 
-    return JSONResponse(content=response, status_code=200)
+    logger.info(f">>> TOTAL INFERENCE TIME: {total_inference_time}s <<<")
+    logger.info(">>> REQUEST COMPLETED SUCCESSFULLY <<<")
+    logger.info("-" * 50)
 
+    return JSONResponse(content=response, status_code=200)
 
 @nto_cto_router.post("/productData/{storeId}")
 async def product_data(
@@ -327,21 +359,29 @@ async def parse_necklace_try_on_id(necklaceImageId: str = Form(...),
 @nto_cto_router.post("/necklaceTryOnID")
 async def necklace_try_on_id(necklace_try_on_id: NecklaceTryOnIDEntity = Depends(parse_necklace_try_on_id),
                              image: UploadFile = File(...)):
+    logger.info("-" * 50)
+    logger.info(f">>> NECKLACE TRY ON ID STARTED :: {necklace_try_on_id.storename} <<<")
     start_time = time.time()
+
     try:
         data, _ = supabase.table("APIKeyList").select("*").filter("API_KEY", "eq",
                                                                   necklace_try_on_id.api_token).execute()
         api_key_actual = data[1][0]['API_KEY']
         if api_key_actual != necklace_try_on_id.api_token:
+            logger.error(">>> API KEY VALIDATION FAILED <<<")
             return JSONResponse(content={"error": "Invalid API Key"}, status_code=401)
+        logger.info(">>> API KEY VALIDATION SUCCESSFUL <<<")
     except Exception as e:
+        logger.error(f">>> API KEY VALIDATION ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error validating API key: {str(e)}", "code": 500}, status_code=500)
 
     try:
         imageBytes = await image.read()
         jewellery_url = f"https://lvuhhlrkcuexzqtsbqyu.supabase.co/storage/v1/object/public/Stores/{necklace_try_on_id.storename}/{necklace_try_on_id.necklaceCategory}/image/{necklace_try_on_id.necklaceImageId}.png"
         image, jewellery = Image.open(BytesIO(imageBytes)), Image.open(returnBytesData(url=jewellery_url))
+        logger.info(">>> IMAGES LOADED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE LOADING ERROR: {str(e)} <<<")
         return JSONResponse(content={
             "error": f"The requested resource (Image, necklace category, or store) is not available. Please verify the availability and try again. Error: {str(e)}",
             "code": 404}, status_code=404)
@@ -349,7 +389,9 @@ async def necklace_try_on_id(necklace_try_on_id: NecklaceTryOnIDEntity = Depends
     try:
         result, headetText, mask = await pipeline.necklaceTryOn_(image=image, jewellery=jewellery,
                                                                  storename=necklace_try_on_id.storename)
+        logger.info(">>> NECKLACE TRY ON PROCESSING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> NECKLACE TRY ON PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error during necklace try-on process: {str(e)}", "code": 500},
                             status_code=500)
 
@@ -360,7 +402,9 @@ async def necklace_try_on_id(necklace_try_on_id: NecklaceTryOnIDEntity = Depends
         mask.save(inMemFileMask, format="WEBP", quality=85)
         outputBytes = inMemFile.getvalue()
         maskBytes = inMemFileMask.getvalue()
+        logger.info(">>> RESULT IMAGES SAVED <<<")
     except Exception as e:
+        logger.error(f">>> RESULT SAVING ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error saving result images: {str(e)}", "code": 500}, status_code=500)
 
     try:
@@ -373,22 +417,34 @@ async def necklace_try_on_id(necklace_try_on_id: NecklaceTryOnIDEntity = Depends
             "inference_time": total_backend_time
         }
         if creditResponse == "No Credits Available":
+            logger.error(">>> NO CREDITS REMAINING <<<")
             response = {"error": "No Credits Remaining"}
             return JSONResponse(content=response, status_code=402)
+        logger.info(">>> CREDITS DEDUCTED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> CREDIT DEDUCTION ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error deducting credits: {str(e)}", "code": 500}, status_code=500)
 
-    return JSONResponse(content=response, status_code=200)
+    logger.info(f">>> TOTAL INFERENCE TIME: {total_backend_time}s <<<")
+    logger.info(f">>> NECKLACE TRY ON COMPLETED :: {necklace_try_on_id.storename} <<<")
+    logger.info("-" * 50)
 
+    return JSONResponse(content=response, status_code=200)
 
 @nto_cto_router.post("/canvasPoints")
 async def canvas_points(necklace_try_on_id: NecklaceTryOnIDEntity = Depends(parse_necklace_try_on_id),
                         image: UploadFile = File(...)):
+    logger.info("-" * 50)
+    logger.info(f">>> CANVAS POINTS STARTED :: {necklace_try_on_id.storename} <<<")
+    start_time = time.time()
+
     try:
         imageBytes = await image.read()
         jewellery_url = f"https://lvuhhlrkcuexzqtsbqyu.supabase.co/storage/v1/object/public/Stores/{necklace_try_on_id.storename}/{necklace_try_on_id.necklaceCategory}/image/{necklace_try_on_id.necklaceImageId}.png"
         image, jewellery = Image.open(BytesIO(imageBytes)), Image.open(returnBytesData(url=jewellery_url))
+        logger.info(">>> IMAGES LOADED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE LOADING ERROR: {str(e)} <<<")
         return JSONResponse(content={
             "error": f"The requested resource (Image, necklace category, or store) is not available. Please verify the availability and try again. Error: {str(e)}",
             "code": 404}, status_code=404)
@@ -396,18 +452,28 @@ async def canvas_points(necklace_try_on_id: NecklaceTryOnIDEntity = Depends(pars
     try:
         response = await pipeline.canvasPoint(image=image, jewellery=jewellery, storename=necklace_try_on_id.storename)
         response = {"code": 200, "output": response}
+        logger.info(">>> CANVAS POINTS PROCESSING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> CANVAS POINTS PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error during canvas point process: {str(e)}", "code": 500},
                             status_code=500)
 
     try:
         creditResponse = deductAndTrackCredit(storename=necklace_try_on_id.storename, endpoint="/necklaceTryOnID")
         if creditResponse == "No Credits Available":
+            logger.error(">>> NO CREDITS REMAINING <<<")
             return JSONResponse(content={"error": "No Credits Remaining", "code": 402}, status_code=402)
+        logger.info(">>> CREDITS DEDUCTED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> CREDIT DEDUCTION ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error deducting credits: {str(e)}", "code": 500}, status_code=500)
 
-    return JSONResponse(status_code=200, content={response})
+    total_inference_time = round((time.time() - start_time), 2)
+    logger.info(f">>> TOTAL INFERENCE TIME: {total_inference_time}s <<<")
+    logger.info(f">>> CANVAS POINTS COMPLETED :: {necklace_try_on_id.storename} <<<")
+    logger.info("-" * 50)
+
+    return JSONResponse(status_code=200, content=response)
 
 
 @nto_cto_router.post("/necklaceTryOnWithPoints")
@@ -417,12 +483,17 @@ async def necklace_try_on_with_points(necklace_try_on_id: NecklaceTryOnIDEntity
                                       left_y: int = Form(...),
                                       right_x: int = Form(...),
                                       right_y: int = Form(...)):
+    logger.info("-" * 50)
+    logger.info(f">>> NECKLACE TRY ON WITH POINTS STARTED :: {necklace_try_on_id.storename} <<<")
     start_time = time.time()
+
     try:
         imageBytes = await image.read()
         jewellery_url = f"https://lvuhhlrkcuexzqtsbqyu.supabase.co/storage/v1/object/public/Stores/{necklace_try_on_id.storename}/{necklace_try_on_id.necklaceCategory}/image/{necklace_try_on_id.necklaceImageId}.png"
         image, jewellery = Image.open(BytesIO(imageBytes)), Image.open(returnBytesData(url=jewellery_url))
+        logger.info(">>> IMAGES LOADED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> IMAGE LOADING ERROR: {str(e)} <<<")
         return JSONResponse(content={
             "error": f"The requested resource (Image, necklace category, or store) is not available. Please verify the availability and try again. Error: {str(e)}",
             "code": 404}, status_code=404)
@@ -432,7 +503,9 @@ async def necklace_try_on_with_points(necklace_try_on_id: NecklaceTryOnIDEntity
             image=image, jewellery=jewellery, left_shoulder=(left_x, left_y), right_shoulder=(right_x, right_y),
             storename=necklace_try_on_id.storename
         )
+        logger.info(">>> NECKLACE TRY ON PROCESSING COMPLETED <<<")
     except Exception as e:
+        logger.error(f">>> NECKLACE TRY ON PROCESSING ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error during necklace try-on process: {str(e)}", "code": 500},
                             status_code=500)
 
@@ -443,7 +516,9 @@ async def necklace_try_on_with_points(necklace_try_on_id: NecklaceTryOnIDEntity
         mask.save(inMemFileMask, format="WEBP", quality=85)
         outputBytes = inMemFile.getvalue()
         maskBytes = inMemFileMask.getvalue()
+        logger.info(">>> RESULT IMAGES SAVED <<<")
     except Exception as e:
+        logger.error(f">>> RESULT SAVING ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error saving result images: {str(e)}", "code": 500}, status_code=500)
 
     try:
@@ -456,9 +531,16 @@ async def necklace_try_on_with_points(necklace_try_on_id: NecklaceTryOnIDEntity
             "inference_time": total_inference_time
         }
         if creditResponse == "No Credits Available":
+            logger.error(">>> NO CREDITS REMAINING <<<")
             response = {"error": "No Credits Remaining"}
             return JSONResponse(content=response, status_code=402)
+        logger.info(">>> CREDITS DEDUCTED SUCCESSFULLY <<<")
     except Exception as e:
+        logger.error(f">>> CREDIT DEDUCTION ERROR: {str(e)} <<<")
         return JSONResponse(content={"error": f"Error deducting credits: {str(e)}", "code": 500}, status_code=500)
 
+    logger.info(f">>> TOTAL INFERENCE TIME: {total_inference_time}s <<<")
+    logger.info(f">>> NECKLACE TRY ON WITH POINTS COMPLETED :: {necklace_try_on_id.storename} <<<")
+    logger.info("-" * 50)
+
     return JSONResponse(content=response, status_code=200)