add logging

crates/service/web/storyteller_web/src/configs/connect_to_database.rs

@@ -1,15 +1,36 @@
+use std::time::Duration;
+
+use log::info;
+
 use errors::AnyhowResult;
 use shared_env_var_config::mysql::env_get_mysql_connection_string_or_default;
 use sqlx::mysql::MySqlPoolOptions;
 use sqlx::MySqlPool;
 
-pub async fn connect_to_database() -> AnyhowResult<MySqlPool>{
+pub async fn connect_to_database() -> AnyhowResult<MySqlPool> {
   let db_connection_string = env_get_mysql_connection_string_or_default();
 
-  let pool_options = MySqlPoolOptions::new()
-      .max_connections(easyenv::get_env_num("MYSQL_MAX_CONNECTIONS", 5)?);
+  // NB: The managed DB's connection ceiling is far above what we use, so the binding
+  // constraint is this per-pod pool. Keep `replicas * MYSQL_MAX_CONNECTIONS` (plus the
+  // background jobs' small pools) comfortably under the server's `max_connections`.
+  let max_connections = easyenv::get_env_num("MYSQL_MAX_CONNECTIONS", 20)?;
+  let min_connections = easyenv::get_env_num("MYSQL_MIN_CONNECTIONS", 0)?;
 
-  // TODO(bt,2024-09-17): Configure logging, etc. after we've upgraded sqlx
+  // NB: Fail fast under pool saturation rather than stacking up on sqlx's 30s default — a
+  // shorter timeout sheds load and surfaces the problem instead of hiding it behind long waits.
+  let acquire_timeout_seconds = easyenv::get_env_num::<u64>("MYSQL_ACQUIRE_TIMEOUT_SECONDS", 10)?;
+
+  // NB: Log the settings before building/connecting so a connect failure has context. We do NOT
+  // log the connection string (it contains credentials).
+  info!(
+    "Building MySQL pool: max_connections={}, min_connections={}, acquire_timeout_seconds={}",
+    max_connections, min_connections, acquire_timeout_seconds,
+  );
+
+  let pool_options = MySqlPoolOptions::new()
+      .max_connections(max_connections)
+      .min_connections(min_connections)
+      .acquire_timeout(Duration::from_secs(acquire_timeout_seconds));
 
   let pool = pool_options
       .connect(&db_connection_string)

crates/service/web/storyteller_web/src/http_server/endpoints/model_download/enqueue_gptsovits_model_download_handler.rs

@@ -86,6 +86,10 @@ pub async fn enqueue_gptsovits_model_download_handler(
     &server_state.session_checker,
     &mut *mysql_connection).await?;
 
+  // NB: The connection isn't needed past this point (the enqueue below uses the pool directly),
+  // so release it now rather than holding a pool slot for the rest of the handler.
+  drop(mysql_connection);
+
   // ==================== PAID PLAN + PRIORITY ==================== //
 
   let plan = get_correct_plan_for_session(server_state.server_environment, Some(&user_session));

crates/service/web/storyteller_web/src/http_server/endpoints/omni_gen/generate/image/omni_gen_image_generate_handler.rs

@@ -143,14 +143,20 @@ pub async fn omni_gen_image_generate_handler(
 
   // ==================== PIPELINE ==================== //
 
+  // NB: Release the pooled DB connection before the (slow, external) generation call so we don't
+  // hold a pool slot idle while waiting on the provider — that's what starves the pool and causes
+  // PoolTimedOut on unrelated endpoints. We re-acquire below to write the result.
+  drop(mysql_connection);
+
   let pipeline_result = run_pipeline_v2(RunPipelineV2Args {
     router_builder: &router_builder,
     server_state: &server_state,
-    mysql_connection: &mut mysql_connection,
     user_token,
     resolved_media: &resolved_media,
   }).await?;
 
+  let mut mysql_connection = server_state.mysql_pool.acquire().await?;
+
   // ==================== DEBUG LOG: FAL REQUEST ==================== //
 
   if let GenerateImageResponse::Fal(ref fal_payload) = pipeline_result.response {

crates/service/web/storyteller_web/src/http_server/endpoints/omni_gen/generate/image/pipeline_v2/run_pipeline_v2.rs

@@ -25,18 +25,20 @@ use crate::util::lookup::lookup_media_files_as_cdn_url_list_and_map::MediaFilesA
 pub struct RunPipelineV2Args<'a> {
   pub router_builder: &'a GenerateImageRequestBuilder,
   pub server_state: &'a ServerState,
-  pub mysql_connection: &'a mut sqlx::pool::PoolConnection<sqlx::MySql>,
   pub user_token: &'a UserToken,
   pub resolved_media: &'a MediaFilesAsCdnUrlListAndMap,
 }
 
+// NB: This pipeline does an external generation call (`finalize_and_generate`) that can take many
+// seconds. It deliberately does NOT hold a pooled DB connection across that call — it acquires a
+// short-lived connection only for the wallet deduction. Holding a pooled connection across the
+// external call is what starves the pool and causes `PoolTimedOut`.
 pub async fn run_pipeline_v2(
   args: RunPipelineV2Args<'_>,
 ) -> Result<ImagePipelineResult, CommonWebError> {
   let RunPipelineV2Args {
     router_builder,
     server_state,
-    mysql_connection,
     user_token,
     resolved_media,
   } = args;
@@ -55,17 +57,24 @@ pub async fn run_pipeline_v2(
   let apriori_job_token = InferenceJobToken::generate();
 
   let maybe_wallet_ledger_entry_token = if cost > 0 {
+    // NB: Short-lived connection — released before the external call below.
+    let mut billing_connection = server_state.mysql_pool.acquire().await
+      .map_err(|err| {
+        warn!("Failed to acquire MySQL connection for image billing: {:?}", err);
+        CommonWebError::from_error(err)
+      })?;
     let deduction = attempt_wallet_deduction_else_common_web_error(
       user_token,
       Some(apriori_job_token.as_str()),
       cost,
-      mysql_connection,
+      &mut billing_connection,
     ).await?;
     Some(deduction.ledger_entry_token)
   } else {
     None
   };
 
+  // NB: No pooled DB connection is held across this external generation call.
   let response = finalize_and_generate(draft_or_request, server_state, resolved_media).await?;
 
   Ok(ImagePipelineResult {

crates/service/web/storyteller_web/src/http_server/endpoints/omni_gen/generate/video/omni_gen_video_generate_handler.rs

@@ -200,16 +200,22 @@ pub async fn omni_gen_video_generate_handler(
     warn!("Failed to insert HTTP request debug log: {:?}", err);
   }
 
+  // NB: Release the pooled DB connection before the (slow, external) generation call so we don't
+  // hold a pool slot idle while waiting on the provider — that's what starves the pool and causes
+  // PoolTimedOut on unrelated endpoints. We re-acquire below to write the result.
+  drop(mysql_connection);
+
   let pipeline_result = run_pipeline_v2(RunPipelineV2Args {
     router_builder: &router_builder,
     server_state: &server_state,
-    mysql_connection: &mut mysql_connection,
     user_token,
     media_file_to_url_map: &media_file_to_url_map,
     kinovi_character_id_map: &kinovi_character_id_map,
     kinovi_account,
   }).await?;
 
+  let mut mysql_connection = server_state.mysql_pool.acquire().await?;
+
   // ==================== DEBUG LOG: FAL REQUEST ==================== //
 
   if let GenerateVideoResponse::Fal(ref fal_payload) = pipeline_result.response {

crates/service/web/storyteller_web/src/http_server/endpoints/omni_gen/generate/video/pipeline_v2/run_pipeline_v2.rs

@@ -3,7 +3,6 @@ use std::convert::TryFrom;
 use std::collections::HashMap;
 
 use log::{error, info, warn};
-use sqlx::pool::PoolConnection;
 use artcraft_router::api::router_video_model::RouterVideoModel;
 use artcraft_router::api::router_provider::RouterProvider;
 use artcraft_router::generate::generate_video::generate_video_request_builder::GenerateVideoRequestBuilder;
@@ -28,18 +27,20 @@ use crate::state::server_state::ServerState;
 pub struct RunPipelineV2Args<'a> {
   pub router_builder: &'a GenerateVideoRequestBuilder,
   pub server_state: &'a ServerState,
-  pub mysql_connection: &'a mut PoolConnection<sqlx::MySql>,
   pub user_token: &'a UserToken,
   pub media_file_to_url_map: &'a Option<HashMap<MediaFileToken, String>>,
   pub kinovi_character_id_map: &'a Option<HashMap<CharacterToken, String>>,
   pub kinovi_account: KinoviAccount,
 }
 
+// NB: This pipeline does an external generation call (`upload_and_generate`) that can take many
+// seconds. It deliberately does NOT hold a pooled DB connection across that call — it acquires
+// short-lived connections only for the billing and (on failure) refund writes. Holding a pooled
+// connection across the external call is what starves the pool and causes `PoolTimedOut`.
 pub async fn run_pipeline_v2(args: RunPipelineV2Args<'_>) -> Result<PipelineResult, CommonWebError> {
   let RunPipelineV2Args {
     router_builder,
     server_state,
-    mysql_connection,
     user_token,
     media_file_to_url_map,
     kinovi_character_id_map,
@@ -137,11 +138,19 @@ pub async fn run_pipeline_v2(args: RunPipelineV2Args<'_>) -> Result<PipelineResu
 
   info!("v2 estimated cost: {} credits (estimates: {:?})", cost, cost_estimates);
 
-  // 3. Bill wallet
-  let billing = bill_wallet(user_token, cost, mysql_connection).await?;
+  // 3. Bill wallet (short-lived connection — released before the external call below).
+  let billing = {
+    let mut billing_connection = server_state.mysql_pool.acquire().await
+      .map_err(|err| {
+        error!("Failed to acquire MySQL connection for billing: {:?}", err);
+        CommonWebError::from_error(err)
+      })?;
+    bill_wallet(user_token, cost, &mut billing_connection).await?
+  };
 
   // 4. Upload media (if draft) and generate video.
   //    The entire block is wrapped so Kinovi failures trigger a refund.
+  //    NB: No pooled DB connection is held across this call.
   let result = upload_and_generate(
     draft_or_request,
     server_state,
@@ -156,10 +165,15 @@ pub async fn run_pipeline_v2(args: RunPipelineV2Args<'_>) -> Result<PipelineResu
       if let Some(ledger_entry_token) = billing.maybe_wallet_ledger_entry_token.as_ref() {
         warn!("Kinovi v2 generation failed, issuing refund for {}: {:?}", ledger_entry_token.as_str(), err);
 
-        let result = refund_wallet_after_api_failure(ledger_entry_token, mysql_connection).await;
-
-        if let Err(refund_err) = result {
-          error!("Failed to refund wallet after Kinovi v2 failure: {:?}", refund_err);
+        match server_state.mysql_pool.acquire().await {
+          Ok(mut refund_connection) => {
+            if let Err(refund_err) = refund_wallet_after_api_failure(ledger_entry_token, &mut refund_connection).await {
+              error!("Failed to refund wallet after Kinovi v2 failure: {:?}", refund_err);
+            }
+          }
+          Err(acquire_err) => {
+            error!("Failed to acquire MySQL connection to refund wallet after Kinovi v2 failure: {:?}", acquire_err);
+          }
         }
       }
     }

crates/service/web/storyteller_web/src/http_server/endpoints/studio_gen2/enqueue_studio_gen2_handler.rs

@@ -192,6 +192,10 @@ pub async fn enqueue_studio_gen2_handler(
         CommonWebError::BadInputWithSimpleMessage("invalid idempotency token".to_string())
       })?;
 
+  // NB: The connection isn't needed past this point (the enqueue below uses the pool directly),
+  // so release it now rather than holding a pool slot for the rest of the handler.
+  drop(mysql_connection);
+
   // ==================== LOOK UP MODEL INFO ==================== //
 
   // TODO(bt): CHECK DATABASE FOR TOKENS!