Fix all remaining logs in dpu, along with some other minor fixes

vibi-dpu/src/bitbucket/auth.rs

@@ -82,6 +82,7 @@ pub async fn update_access_token(auth_info: &BitbucketAuthInfo, review_opt: &Opt
         return Some(auth_info.to_owned());
     }
     // auth info has expired
+    log::info!("Updating expired authentication...");
     log::debug!("[update_access_token] auth info expired, expires_at = {}, now_secs = {}", expires_at, now_secs);
     let new_auth_info_opt = bitbucket_refresh_token(auth_info.refresh_token()).await;
     let mut new_auth_info = new_auth_info_opt.clone()

vibi-dpu/src/core/approval.rs

@@ -24,7 +24,7 @@ pub async fn process_approval(deserialised_msg_data: &Value, repo_config_val: &V
 	log::debug!("[process_approval] repo_config = {:?}", &repo_config);
 	save_repo_config_to_db(&repo_config, repo_name, repo_owner, repo_provider);
     if !repo_config.comment() {
-        log::info!("[process_approval] Comment setting is turned off");
+        log::info!("Comment setting is turned off, not adding comment...");
         return;
     }
     let pr_head_commit = deserialised_msg_data["review"]["commit_id"]

vibi-dpu/src/core/bitbucket/setup.rs

@@ -60,7 +60,6 @@ pub async fn handle_install_bitbucket(installation_code: &str) {
 			let repo_name = repo.name();
 			reponames.push(repo_name.clone());
 			log::debug!("[handle_install_bitbucket] Repo url git = {:?}", &repo.clone_ssh_url());
-			log::info!("[handle_install_bitbucket] Repo url git = {:?}", &repo.clone_ssh_url());
 			log::debug!("[handle_install_bitbucket] Repo name = {:?}", repo_name);
 			process_webhooks(workspace_slug.to_string(),
 			repo_name.to_string(),
@@ -71,7 +70,7 @@ pub async fn handle_install_bitbucket(installation_code: &str) {
 			task::spawn(async move {
 				let pr_list_opt = list_prs_bitbucket(&workspace_slug_async, &repo_name_async, &access_token_async, "OPEN").await;
 				if pr_list_opt.is_none() {
-					log::info!("[handle_install_bitbucket] No open pull requests found for processing.");
+					log::debug!("[handle_install_bitbucket] No open pull requests found for processing.");
 					return;
 				}
 				let pr_list = pr_list_opt.expect("Empty pr_list_opt");
@@ -121,11 +120,12 @@ async fn process_webhooks(workspace_slug: String, repo_name: String, access_toke
 	let webhook_callback_url = format!("{}/api/bitbucket/callbacks/webhook", 
 		env::var("SERVER_URL").expect("SERVER_URL must be set"));
 	if webhooks_data.is_empty() {
-		log::info!("[process_webhooks] Adding new webhook...");
 		let repo_name_async = repo_name.clone();
 		let workspace_slug_async = workspace_slug.clone();
 		let access_token_async = access_token.clone();
 		task::spawn(async move {
+			log::info!("Adding new webhook for {}/{}...",
+				&workspace_slug_async, access_token_async);
 			add_webhook(
 				&workspace_slug_async, 
 				&repo_name_async, 
@@ -136,11 +136,12 @@ async fn process_webhooks(workspace_slug: String, repo_name: String, access_toke
 	let matching_webhook = webhooks_data.into_iter()
 		.find(|w| w.url().to_string() == webhook_callback_url);
 	if matching_webhook.is_none() {
-		log::info!("[process_webhooks] Adding new webhook...");
 		let repo_name_async = repo_name.clone();
 		let workspace_slug_async = workspace_slug.clone();
 		let access_token_async = access_token.clone();
 		task::spawn(async move {
+			log::info!("Adding new webhook for {}/{}...",
+				&workspace_slug_async, access_token_async);
 			add_webhook(
 				&workspace_slug_async, 
 				&repo_name_async, 
@@ -149,6 +150,6 @@ async fn process_webhooks(workspace_slug: String, repo_name: String, access_toke
 		return;
 	}
 	let webhook = matching_webhook.expect("no matching webhook");
-	log::info!("[process_webhooks] Webhook already exists: {:?}", &webhook);
+	log::info!("Not adding webhook, already exists: {:?}...", webhook.url());
 	save_webhook_to_db(&webhook);
 }

vibi-dpu/src/core/github/comment.rs

@@ -20,7 +20,7 @@ pub async fn add_comment(comment_text: &str, review: &Review, access_token: &str
         return;
     }
     let response = response_res.expect("Error in getting response");
-    println!("[github/add_comment] response from comment post request = {:?}", &response);
+    log::debug!("[github/add_comment] response from comment post request = {:?}", &response);
 }
 
 fn prepare_add_comment_url(review: &Review) -> String {

vibi-dpu/src/core/relevance.rs

@@ -7,7 +7,8 @@ use crate::utils::repo_config::RepoConfig;
 pub async fn process_relevance(hunkmap: &HunkMap, review: &Review,
 	repo_config: &mut RepoConfig, access_token: &str, old_review_opt: &Option<Review>,
 ) {
-	log::info!("[process_relevance] Process relevence for PR: {}, repo config: {:?}", review.id(), repo_config);
+	log::info!("Processing relevance of code authors...");
+    log::debug!("Process relevence for PR: {}, repo config: {:?}", review.id(), repo_config);
 	for prhunk in hunkmap.prhunkvec() {
 		// calculate number of hunks for each userid
 		let mut review_mut = review.clone();
@@ -20,23 +21,24 @@ pub async fn process_relevance(hunkmap: &HunkMap, review: &Review,
 		}
 		let relevance_vec = relevance_vec_opt.expect("Empty coverage_obj_opt");
 		if repo_config.comment() {
-			log::info!("[process_relevance] Inserting comment...");
 			// create comment text
 			let comment = comment_text(&relevance_vec, repo_config.auto_assign());
 			// add comment
 			if review.provider().to_string() == ProviderEnum::Bitbucket.to_string() {
 				// TODO - add feature flag check
 				// TODO - add comment change check
 				if did_comment_change(&relevance_vec, &old_review_opt) {
+                    log::info!("Inserting comment on repo {}...", review.repo_name());
 					bitbucket::comment::add_comment(&comment, review, &access_token).await;
-				}
+				} else { log::info!("No changes in author relevance, not adding comment...");}
 			}
 			if review.provider().to_string() == ProviderEnum::Github.to_string() {
+                log::info!("Inserting comment on repo {}...", review.repo_name());
 				github::comment::add_comment(&comment, review, &access_token).await;
 			}
 		}
 		if repo_config.auto_assign() {
-			log::info!("[process_relevance] Auto assigning reviewers...");
+			log::info!("Auto assigning reviewers for repo {}...", review.repo_name());
 			log::debug!("[process_relevance] review.provider() = {:?}", review.provider());
 			if review.provider().to_string() == ProviderEnum::Bitbucket.to_string() {
 				add_bitbucket_reviewers(&prhunk, hunkmap, review, &access_token).await;
@@ -50,13 +52,13 @@ pub async fn process_relevance(hunkmap: &HunkMap, review: &Review,
 
 fn did_comment_change(relevance_vec: &Vec<Relevance>, old_review_opt: &Option<Review>) -> bool {
 	if old_review_opt.is_none() {
-		log::info!("[did_comment_change] No review record found in db, inserting comment...");
+		log::debug!("[did_comment_change] No review record found in db, inserting comment...");
 		return true;
 	}
 	let old_review = old_review_opt.to_owned().expect("Empty old_review_opt");
 	let old_relevance_vec_opt = old_review.relevance();
 	if old_relevance_vec_opt.is_none() {
-		log::info!("[did_comment_change] No relevance found in db, inserting comment...");
+		log::debug!("[did_comment_change] No relevance found in db, inserting comment...");
 		return true;
 	}
 	let old_relevance_vec = old_relevance_vec_opt.to_owned()
@@ -195,7 +197,7 @@ fn comment_text(relevance_vec: &Vec<Relevance>, auto_assign: bool) -> String {
         let provider_id_opt = provider_ids.iter().next();
         if provider_id_opt.is_some() {
             let provider_id = provider_id_opt.expect("Empty provider_id_opt");
-            log::info!("[comment-text] provider_id: {:?}", provider_id);
+            log::debug!("[comment-text] provider_id: {:?}", provider_id);
             let formatted_relevance_value = format!("{:.2}", *relevance);
             comment += &format!("| {} | {}% |\n", provider_id, formatted_relevance_value);
         }

vibi-dpu/src/core/review.rs

@@ -31,7 +31,7 @@ pub async fn process_review(message_data: &Vec<u8>) {
 	if hunk_already_exists(&review) {
 		return;
 	}
-	log::info!("[process_review] Processing PR : {}", &review.id());
+	log::info!("Parsed task for review no : {}...", &review.id());
 	let access_token_opt = get_access_token(&Some(review.clone()), review.provider()).await;
 
 	if access_token_opt.is_none() {
@@ -74,6 +74,7 @@ fn hunk_already_exists(review: &Review) -> bool {
 	return true;
 }
 pub async fn process_review_changes(review: &Review) -> Option<HunkMap>{
+	log::info!("Processing changes in code...");
 	let mut prvec = Vec::<PrHunkItem>::new();
 	let fileopt = get_excluded_files(&review);
 	log::debug!("[process_review_changes] fileopt = {:?}", &fileopt);
@@ -107,7 +108,7 @@ pub async fn process_review_changes(review: &Review) -> Option<HunkMap>{
 pub async fn commit_check(review: &Review, access_token: &str) {
 	if !commit_exists(&review.base_head_commit(), &review.clone_dir()) 
 		|| !commit_exists(&review.pr_head_commit(), &review.clone_dir()) {
-		log::info!("[commit_check] Pulling repository {} for commit history", &review.repo_name());
+		log::info!("Executing git pull on repo {}...", &review.repo_name());
 		git_pull(review, access_token).await;
 	}
 }
@@ -164,7 +165,7 @@ fn publish_hunkmap(hunkmap: &HunkMap) {
 		.send()
 		.await {
 			Ok(_) => {
-				log::info!("[publish_hunkmap] Hunkmap published successfully for: {} !", &key_clone);
+				log::info!("Published code changes successfully: {} !", &key_clone);
 			},
 			Err(e) => {
 				log::error!("[publish_hunkmap] Failed to publish hunkmap: {} for: {}", e, &key_clone);

vibi-dpu/src/core/trigger.rs

@@ -1,6 +1,6 @@
 use serde_json::Value;
 
-use crate::{core::{review::{commit_check, process_review_changes, send_hunkmap}, utils::get_access_token}, db::{repo::get_clone_url_clone_dir, repo_config::save_repo_config_to_db, review::get_review_from_db}, github::prs::get_and_store_pr_info, utils::{parsing::parse_string_field_pubsub, repo_config::RepoConfig, review::Review, user::ProviderEnum}};
+use crate::{core::{review::{commit_check, process_review_changes, send_hunkmap}, utils::get_access_token}, db::{repo::get_clone_url_clone_dir, repo_config::save_repo_config_to_db, review::get_review_from_db}, github::prs::get_and_store_pr_info, utils::{parsing::parse_string_field_pubsub, pr_info::PrInfo, repo_config::RepoConfig, review::Review, user::ProviderEnum}};
 
 #[derive(Debug)]
 struct TriggerReview {
@@ -19,7 +19,7 @@ pub async fn process_trigger(message_data: &Vec<u8>) {
 		return;
 	}
 	let (trigger_review, repo_config) = parse_res.expect("Empty parse_res");
-	log::info!("[process_trigger] Processing PR: {} in repo: {}", &trigger_review.pr_number, &trigger_review.repo_name);
+	log::info!("Processing PR: {} in repo: {}...", &trigger_review.pr_number, &trigger_review.repo_name);
 	// get access token
 	if trigger_review.repo_provider != ProviderEnum::Github.to_string().to_lowercase() {
 		log::error!("[process_trigger] Not implemented for non github providers");
@@ -39,7 +39,7 @@ pub async fn process_trigger(message_data: &Vec<u8>) {
 		log::error!("[process_trigger] Unable to get pr info from provider");
 		return;
 	}
-	let review_opt = get_review_obj(&trigger_review, &access_token).await;
+	let review_opt = get_review_obj(&trigger_review, &pr_info_opt).await;
 	if review_opt.is_none() {
 		log::error!("[process_trigger] Unable to get review details: {:?}", &trigger_review);
 		return;
@@ -96,13 +96,12 @@ fn parse_trigger_msg(message_data: &Vec<u8>) -> Option<(TriggerReview, RepoConfi
 	return Some((trigger_review, repo_config));
 }
 
-async fn get_review_obj(trigger_review: &TriggerReview, access_token: &str) -> Option<Review> {
-	let pr_info_opt = get_and_store_pr_info(&trigger_review.repo_owner, &trigger_review.repo_name, access_token, &trigger_review.pr_number).await;
+async fn get_review_obj(trigger_review: &TriggerReview, pr_info_opt: &Option<PrInfo>) -> Option<Review> {
 	if pr_info_opt.is_none() {
 		log::error!("[get_review_obj] Unable to get and store pr info: {:?}", &trigger_review);
 		return None;
 	}
-	let pr_info = pr_info_opt.expect("Empty pr_info_opt");
+	let pr_info = pr_info_opt.to_owned().expect("Empty pr_info_opt");
 	let clone_opt = get_clone_url_clone_dir(&trigger_review.repo_provider, &trigger_review.repo_owner, &trigger_review.repo_name);
 	if clone_opt.is_none() {
 		log::error!("[get_review_obj] Unable to get clone url and directory for bitbucket review");

vibi-dpu/src/db/hunk.rs

@@ -31,10 +31,10 @@ pub fn get_hunk_from_db(review: &Review) -> Option<HunkMap> {
 }
 
 pub fn store_hunkmap_to_db(hunkmap: &HunkMap, review: &Review) {
-	log::info!("[store_hunkmap_to_db]: hunkmap: {:?}, review: {:?}", hunkmap, review);
+	log::debug!("[store_hunkmap_to_db]: hunkmap: {:?}, review: {:?}", hunkmap, review);
     let db = get_db();
 	let hunk_key = format!("hunk/{}/{}/{}", review.db_key(), review.base_head_commit(), review.pr_head_commit());
-	log::info!("[store_hunkmap_to_db] hunk_key = {}", hunk_key);
+	log::debug!("[store_hunkmap_to_db] hunk_key = {}", hunk_key);
 	let json = serde_json::to_vec(hunkmap).expect("Failed to serialize hunkmap");
 
     // Insert JSON into sled DB

vibi-dpu/src/db/prs.rs

@@ -124,7 +124,8 @@ pub async fn github_process_and_update_pr_if_different(webhook_data: &Value, rep
 	if event_action == "opened" {
 		// new PR opened
 		log::debug!("[github_process_and_update_pr_if_different|new_pr_opened] {:?}", pr_info_parsed);
-		update_pr_info_in_db(&repo_owner, &repo_owner, &pr_info_parsed, &pr_number, repo_provider).await;
+		update_pr_info_in_db(&repo_owner,
+			&repo_owner, &pr_info_parsed, &pr_number, repo_provider).await;
 		return true;
 	}
 	if event_action == "synchronize" {
@@ -135,6 +136,7 @@ pub async fn github_process_and_update_pr_if_different(webhook_data: &Value, rep
 	if event_action == "submitted" {
 		let event_review_status = webhook_data["review"]["state"].to_string().trim_matches('"').to_string();
 		if event_review_status == "approved" {
+			log::info!("Processing Approved PR event...");
 			log::debug!("[github_process_and_update_pr_if_different| pr has been approved] webhook data for pr {:?}", &webhook_data);
 			update_pr_info_in_db(&repo_owner, &repo_name, &pr_info_parsed, &pr_number, repo_provider).await;
 			process_approval(webhook_data, repo_config, repo_owner, repo_name, pr_number, repo_provider).await;
@@ -144,6 +146,7 @@ pub async fn github_process_and_update_pr_if_different(webhook_data: &Value, rep
 			return false; // event is not open or synchronize
 		}
 	} else {
+		log::info!("PR event is not recognized, skipping processing");
 		log::debug!("[github_process_and_update_pr_if_different | no update needed] event is not opened or synchronise or approved");
 		return false;
 	}

vibi-dpu/src/github/auth.rs

@@ -195,7 +195,7 @@ fn pat_access_token() -> Option<String> {
     }
     let github_pat = github_pat_res.expect("Empty GITHUB_PAT env var");
     if github_pat.len() == 0 {
-        log::debug!("[pat_access_token] GITHUB PAT 0 length");
+        log::error!("[pat_access_token] GITHUB PAT 0 length");
         return None;
     }
     log::debug!("[pat_access_token] GITHUB PAT: [REDACTED], length = {}",
@@ -206,7 +206,7 @@ fn pat_access_token() -> Option<String> {
     }
     let provider = provider_res.expect("Empty PROVIDER env var");
     if provider.len() == 0 {
-        log::debug!("[pat_access_token] PROVIDER 0 length");
+        log::error!("[pat_access_token] PROVIDER 0 length");
         return None;
     }
     log::debug!("[pat_access_token] PROVIDER: {}", provider);

vibi-dpu/src/github/prs.rs

@@ -1,4 +1,5 @@
 use crate::db::prs::update_pr_info_in_db;
+use crate::utils::user::ProviderEnum;
 use crate::utils::{pr_info::PrInfo, reqwest_client::get_client};
 use reqwest::header::{HeaderMap, USER_AGENT};
 use reqwest::Response;
@@ -122,10 +123,10 @@ pub async fn get_pr_info_github(repo_owner: &str, repo_name: &str, access_token:
 }
 
 pub async fn get_and_store_pr_info(repo_owner: &str, repo_name: &str, access_token: &str, pr_number: &str) -> Option<PrInfo> {
-    let repo_provider = "github";
     if let Some(pr_info) = get_pr_info_github(repo_owner, repo_name, access_token, pr_number).await {
         // If PR information is available, store it in the database
-        update_pr_info_in_db(repo_owner, repo_name, &pr_info, pr_number, repo_provider).await;
+        update_pr_info_in_db(repo_owner, repo_name, &pr_info, pr_number,
+            &ProviderEnum::Github.to_string().to_lowercase()).await;
         return Some(pr_info);
     } else {
         log::error!("[get_and_store_pr_info] No PR info available for PR number: {:?} repository: {:?} repo_owner{:?}", pr_number, repo_name, repo_owner);

vibi-dpu/src/pubsub/listener.rs

@@ -51,7 +51,9 @@ async fn process_message(attributes: &HashMap<String, String>, data_bytes: &Vec<
 			} else { log::info!("No changes detected in PR, Webhook Callback Processed!");}
 		}
 		"manual_trigger" => {
+			log::info!("Processing trigger...");
 			process_trigger(&data_bytes).await;
+			log::info!("Trigger task processed!");
 		}
 		"PATSetup" => {
 			log::info!("Setting up repositories...");

vibi-dpu/src/utils/coverage.rs

@@ -138,7 +138,7 @@ impl CoverageMap {
             let provider_id_opt = provider_ids.iter().next();
             if provider_id_opt.is_some() {
                 let provider_id_alias = provider_id_opt.expect("Empty provider_id_opt");
-                log::info!("[comment-text] provider_id: {:?}", provider_id_alias);
+                log::debug!("[comment-text] provider_id: {:?}", provider_id_alias);
                 let formatted_relevance_value = format!("{:.2}", *relevance);
                 if reviewer_handles.contains(provider_id_alias) {
                     comment += &format!("| {} | {}% | :white_check_mark: |\n", provider_id_alias, formatted_relevance_value);

vibi-dpu/src/utils/pr_info.rs

@@ -1,6 +1,6 @@
 use serde::{Deserialize, Serialize};
 
-#[derive(Debug, Serialize, Deserialize)]
+#[derive(Debug, Serialize, Deserialize, Clone)]
 pub struct PrInfo {
     pub base_head_commit: String,
     pub pr_head_commit: String,