diff --git a/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/handle_storyteller_failed_job.rs b/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/handle_storyteller_failed_job.rs --- a/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/handle_storyteller_failed_job.rs +++ b/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/handle_storyteller_failed_job.rs @@ -1,10 +1,13 @@ use crate::core::events::generation_events::common::GenerationModel; use crate::core::events::basic_sendable_event_trait::BasicSendableEvent; use crate::core::events::generation_events::generation_failed_event::GenerationFailedEvent; +use crate::core::state::app_env_configs::app_env_configs::AppEnvConfigs; use crate::core::state::task_database::TaskDatabase; use crate::core::utils::enum_conversion::generation_provider::to_generation_service_provider; use crate::core::utils::enum_conversion::task_type::to_generation_action; +use super::sora_latency_client_log::maybe_log_sora_client_completion; use artcraft_api_defs::jobs::list_session_jobs::ListSessionJobsItem; +use artcraft_client::credentials::storyteller_credential_set::StorytellerCredentialSet; use enums::tauri::tasks::task_status::TaskStatus; use errors::AnyhowResult; use log::info; @@ -16,6 +19,8 @@ use sqlite_tasks::queries::update_task_status_with_rich_failure::{update_task_st pub async fn handle_failed_job( app_handle: &AppHandle, + app_env_configs: &AppEnvConfigs, + maybe_creds: Option<&StorytellerCredentialSet>, job: &ListSessionJobsItem, task: &Task, task_database: &TaskDatabase, @@ -37,6 +42,8 @@ pub async fn handle_failed_job( maybe_failure_message, }).await?; + maybe_log_sora_client_completion(app_env_configs, maybe_creds, job, task, "failure").await; + let service = to_generation_service_provider(task.provider); let action = to_generation_action(task.task_type); diff --git a/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/handle_storyteller_successful_job.rs b/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/handle_storyteller_successful_job.rs --- a/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/handle_storyteller_successful_job.rs +++ b/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/handle_storyteller_successful_job.rs @@ -8,6 +8,7 @@ use crate::core::utils::enum_conversion::generation_provider::to_generation_serv use crate::core::utils::enum_conversion::task_type::to_generation_action; use crate::core::utils::auto_download::{auto_download_task, clear_auto_download_checkpoint}; use super::events::maybe_handle_frontend_caller_notification::maybe_handle_frontend_caller_notification; +use super::sora_latency_client_log::maybe_log_sora_client_completion; use artcraft_api_defs::jobs::list_session_jobs::ListSessionJobsItem; use artcraft_api_defs::utils::media_links_to_thumbnail_template::media_links_to_thumbnail_template; use artcraft_client::credentials::storyteller_credential_set::StorytellerCredentialSet; @@ -62,6 +63,8 @@ pub async fn handle_successful_job( clear_auto_download_checkpoint(app_handle, task); send_additional_success_events(app_handle, app_env_configs, creds, job, task).await; + maybe_log_sora_client_completion(app_env_configs, creds, job, task, "success").await; + let service = to_generation_service_provider(task.provider); let action = to_generation_action(task.task_type); diff --git a/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/mod.rs b/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/mod.rs --- a/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/mod.rs +++ b/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/mod.rs @@ -1,4 +1,5 @@ mod events; mod handle_storyteller_failed_job; mod handle_storyteller_successful_job; +mod sora_latency_client_log; pub mod storyteller_task_polling_thread; diff --git a/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/sora_latency_client_log.rs b/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/sora_latency_client_log.rs new file mode 100644 --- /dev/null +++ b/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/sora_latency_client_log.rs @@ -0,0 +1,72 @@ +//! Client-side wall-clock log for Sora ArtCraft jobs (#1069 investigation). +//! No behavior change — structured `info!` only. + +use crate::core::state::app_env_configs::app_env_configs::AppEnvConfigs; +use artcraft_api_defs::jobs::list_session_jobs::ListSessionJobsItem; +use artcraft_api_defs::subscriptions::get_session_subscription::GetSessionSubscriptionResponse; +use artcraft_client::credentials::storyteller_credential_set::StorytellerCredentialSet; +use artcraft_client::endpoints::subscriptions::get_session_subscription::get_session_subscription; +use chrono::Utc; +use enums::common::payments_namespace::PaymentsNamespace; +use enums::tauri::tasks::task_model_type::TaskModelType; +use log::{info, warn}; +use sqlite_tasks::queries::task::Task; + +fn is_sora_model(model: Option<&TaskModelType>) -> Option<&'static str> { + match model { + Some(TaskModelType::Sora2) => Some("sora_2"), + Some(TaskModelType::Sora2Pro) => Some("sora_2_pro"), + _ => None, + } +} + +fn plan_tag_from_subscription_response(response: &GetSessionSubscriptionResponse) -> &'static str { + match response.active_subscription.as_ref().map(|s| s.product_slug.as_str()) { + None => "free", + Some("artcraft_basic") => "artcraft_basic", + Some("artcraft_pro") => "artcraft_pro", + Some("artcraft_max") => "artcraft_max", + Some(_) => "unknown", + } +} + +/// Best-effort structured log when a Sora ArtCraft task completes locally. +pub async fn maybe_log_sora_client_completion( + app_env_configs: &AppEnvConfigs, + maybe_creds: Option<&StorytellerCredentialSet>, + job: &ListSessionJobsItem, + task: &Task, + outcome: &str, +) { + let Some(model) = is_sora_model(task.model_type.as_ref()) else { + return; + }; + + let plan = match get_session_subscription( + &app_env_configs.storyteller_host, + maybe_creds, + PaymentsNamespace::Artcraft, + ) + .await + { + Ok(response) => plan_tag_from_subscription_response(&response), + Err(err) => { + warn!( + "Sora latency client log: subscription lookup failed (using unknown): {:?}", + err + ); + "unknown" + } + }; + + let elapsed_ms = (Utc::now() - job.created_at).num_milliseconds().max(0); + let job_token = task + .provider_job_id + .as_deref() + .unwrap_or(job.job_token.as_str()); + + info!( + "sora_latency_client model={} plan={} outcome={} client_elapsed_ms={} inference_job_token={}", + model, plan, outcome, elapsed_ms, job_token + ); +} diff --git a/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/storyteller_task_polling_thread.rs b/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/storyteller_task_polling_thread.rs --- a/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/storyteller_task_polling_thread.rs +++ b/crates/desktop/artcraft/src/services/storyteller/threads/storyteller_task_polling_thread/storyteller_task_polling_thread.rs @@ -119,7 +119,7 @@ async fn polling_loop( TaskStatus::CompleteFailure => continue, // NB: We're done with this task. _ => {} } - handle_failed_job(app_handle, job, task, task_database).await?; + handle_failed_job(app_handle, app_env_configs, creds.as_ref(), job, task, task_database).await?; } _ => continue, }