Compare commits

..
Author SHA1 Message Date
Brandon Thomas d2060f42a0 alert with traceid 2026-07-03 02:27:51 -04:00
Brandon Thomas b791ca42b5 traceid logging 2026-07-03 02:22:44 -04:00
Brandon Thomas 62b01bd9d8 trace-id 2026-07-03 01:45:20 -04:00
Brandon Thomas 4ce3f240c7 debug logs (#1724) 2026-07-02 22:09:38 -04:00
Brandon Thomas 3a2e3b30ec debug logs #2 (#1723) 2026-07-02 19:36:48 -04:00
Brandon Thomas 82c0a7a4d9 debug logs: new field, new queries, new APIs, new dashbord UX (#1722) 2026-07-02 16:43:00 -04:00
57 changed files with 1308 additions and 340 deletions
@@ -1,12 +1,12 @@
{
"db_name": "MySQL",
"query": "\nINSERT INTO debug_logs\nSET\n event_token = ?,\n debug_log_type = ?,\n maybe_log_level = ?,\n maybe_creator_user_token = ?,\n message = ?\n ",
"query": "\nINSERT INTO debug_logs\nSET\n event_token = ?,\n debug_log_type = ?,\n maybe_log_level = ?,\n maybe_creator_user_token = ?,\n maybe_ip_address = ?,\n maybe_url = ?,\n message = ?\n ",
"describe": {
"columns": [],
"parameters": {
"Right": 5
"Right": 7
},
"nullable": []
},
"hash": "62995374005dc0553d007fb69e642d89a95cd5aaeeababd110c92c565023cfcf"
"hash": "32a8d1cfec89ba2056463a33ddc501a8a99283c7c00982a7fa79f7ff382c9b22"
}
@@ -1,6 +1,6 @@
{
"db_name": "MySQL",
"query": "\nSELECT\n d.id as `id: u64`,\n d.event_token as `event_token: tokens::tokens::non_unique::debug_logs_event_token::DebugLogEventToken`,\n d.debug_log_type as `debug_log_type: enums::by_table::debug_logs::debug_log_type::DebugLogType`,\n d.maybe_log_level as `maybe_log_level: enums::by_table::debug_logs::debug_log_level::DebugLogLevel`,\n d.maybe_creator_user_token as `maybe_creator_user_token: tokens::tokens::users::UserToken`,\n d.message,\n d.created_at,\n u.display_name as `maybe_user_display_name?`,\n u.username as `maybe_user_username?`,\n u.email_gravatar_hash as `maybe_user_gravatar_hash?`\nFROM debug_logs d\nLEFT OUTER JOIN users u\n ON u.token = d.maybe_creator_user_token\nWHERE d.maybe_creator_user_token = ?\n AND d.id < ?\nORDER BY d.id DESC\nLIMIT ?\n ",
"query": "\nSELECT\n d.id as `id: u64`,\n d.event_token as `event_token: tokens::tokens::non_unique::debug_logs_event_token::DebugLogEventToken`,\n d.debug_log_type as `debug_log_type: enums::by_table::debug_logs::debug_log_type::DebugLogType`,\n d.maybe_log_level as `maybe_log_level: enums::by_table::debug_logs::debug_log_level::DebugLogLevel`,\n d.maybe_creator_user_token as `maybe_creator_user_token: tokens::tokens::users::UserToken`,\n d.maybe_ip_address,\n d.maybe_url,\n d.message,\n d.created_at,\n u.display_name as `maybe_user_display_name?`,\n u.username as `maybe_user_username?`,\n u.email_gravatar_hash as `maybe_user_gravatar_hash?`\nFROM debug_logs d\nLEFT OUTER JOIN users u\n ON u.token = d.maybe_creator_user_token\nWHERE d.maybe_creator_user_token = ?\n AND d.id < ?\nORDER BY d.id DESC\nLIMIT ?\n ",
"describe": {
"columns": [
{
@@ -55,6 +55,26 @@
},
{
"ordinal": 5,
"name": "maybe_ip_address",
"type_info": {
"type": "VarString",
"flags": "BINARY",
"char_set": 224,
"max_size": 160
}
},
{
"ordinal": 6,
"name": "maybe_url",
"type_info": {
"type": "VarString",
"flags": "BINARY",
"char_set": 224,
"max_size": 1020
}
},
{
"ordinal": 7,
"name": "message",
"type_info": {
"type": "Blob",
@@ -64,7 +84,7 @@
}
},
{
"ordinal": 6,
"ordinal": 8,
"name": "created_at",
"type_info": {
"type": "Datetime",
@@ -74,7 +94,7 @@
}
},
{
"ordinal": 7,
"ordinal": 9,
"name": "maybe_user_display_name?",
"type_info": {
"type": "VarString",
@@ -84,7 +104,7 @@
}
},
{
"ordinal": 8,
"ordinal": 10,
"name": "maybe_user_username?",
"type_info": {
"type": "VarString",
@@ -94,7 +114,7 @@
}
},
{
"ordinal": 9,
"ordinal": 11,
"name": "maybe_user_gravatar_hash?",
"type_info": {
"type": "String",
@@ -113,6 +133,8 @@
false,
true,
true,
true,
true,
false,
false,
true,
@@ -120,5 +142,5 @@
true
]
},
"hash": "1197c08c8b390fb8bffbe10ad9f7d073a58b6c9124ee11573c6723d6d5471881"
"hash": "d1ade7fcfd3efac1cd3163c392110327bb73edb74fa0d9693fee5feddb8a3223"
}
@@ -1,6 +1,6 @@
{
"db_name": "MySQL",
"query": "\nSELECT\n d.id as `id: u64`,\n d.event_token as `event_token: tokens::tokens::non_unique::debug_logs_event_token::DebugLogEventToken`,\n d.debug_log_type as `debug_log_type: enums::by_table::debug_logs::debug_log_type::DebugLogType`,\n d.maybe_log_level as `maybe_log_level: enums::by_table::debug_logs::debug_log_level::DebugLogLevel`,\n d.maybe_creator_user_token as `maybe_creator_user_token: tokens::tokens::users::UserToken`,\n d.message,\n d.created_at,\n u.display_name as `maybe_user_display_name?`,\n u.username as `maybe_user_username?`,\n u.email_gravatar_hash as `maybe_user_gravatar_hash?`\nFROM debug_logs d\nLEFT OUTER JOIN users u\n ON u.token = d.maybe_creator_user_token\nWHERE d.event_token = ?\nORDER BY d.id ASC\nLIMIT ?\n ",
"query": "\nSELECT\n d.id as `id: u64`,\n d.event_token as `event_token: tokens::tokens::non_unique::debug_logs_event_token::DebugLogEventToken`,\n d.debug_log_type as `debug_log_type: enums::by_table::debug_logs::debug_log_type::DebugLogType`,\n d.maybe_log_level as `maybe_log_level: enums::by_table::debug_logs::debug_log_level::DebugLogLevel`,\n d.maybe_creator_user_token as `maybe_creator_user_token: tokens::tokens::users::UserToken`,\n d.maybe_ip_address,\n d.maybe_url,\n d.message,\n d.created_at,\n u.display_name as `maybe_user_display_name?`,\n u.username as `maybe_user_username?`,\n u.email_gravatar_hash as `maybe_user_gravatar_hash?`\nFROM debug_logs d\nLEFT OUTER JOIN users u\n ON u.token = d.maybe_creator_user_token\nWHERE d.event_token = ?\nORDER BY d.id ASC\nLIMIT ?\n ",
"describe": {
"columns": [
{
@@ -55,6 +55,26 @@
},
{
"ordinal": 5,
"name": "maybe_ip_address",
"type_info": {
"type": "VarString",
"flags": "BINARY",
"char_set": 224,
"max_size": 160
}
},
{
"ordinal": 6,
"name": "maybe_url",
"type_info": {
"type": "VarString",
"flags": "BINARY",
"char_set": 224,
"max_size": 1020
}
},
{
"ordinal": 7,
"name": "message",
"type_info": {
"type": "Blob",
@@ -64,7 +84,7 @@
}
},
{
"ordinal": 6,
"ordinal": 8,
"name": "created_at",
"type_info": {
"type": "Datetime",
@@ -74,7 +94,7 @@
}
},
{
"ordinal": 7,
"ordinal": 9,
"name": "maybe_user_display_name?",
"type_info": {
"type": "VarString",
@@ -84,7 +104,7 @@
}
},
{
"ordinal": 8,
"ordinal": 10,
"name": "maybe_user_username?",
"type_info": {
"type": "VarString",
@@ -94,7 +114,7 @@
}
},
{
"ordinal": 9,
"ordinal": 11,
"name": "maybe_user_gravatar_hash?",
"type_info": {
"type": "String",
@@ -113,6 +133,8 @@
false,
true,
true,
true,
true,
false,
false,
true,
@@ -120,5 +142,5 @@
true
]
},
"hash": "ae311f7fde7c73f166cd8c0a5c9965850e314936a401b24a3900585ab53a7db6"
"hash": "e9a149ffc963a59019fdd69bd53128fad946856d432108bf9b923dfeaf2442c5"
}
Generated
+15
View File
@@ -3621,6 +3621,7 @@ dependencies = [
"env_logger 0.11.9",
"log",
"storyteller_root",
"trace_id",
"workspace-build-acceleration",
]
@@ -6766,6 +6767,7 @@ version = "0.0.1"
dependencies = [
"env_logger 0.11.9",
"log",
"trace_id",
"workspace-build-acceleration",
]
@@ -8286,6 +8288,7 @@ dependencies = [
"rootly_client",
"sha2 0.11.0-rc.5",
"tokio",
"trace_id",
"workspace-build-acceleration",
]
@@ -11678,6 +11681,7 @@ dependencies = [
"tokens",
"tokio",
"toml 1.0.7+spec-1.1.0",
"trace_id",
"tts_common",
"url",
"url_config",
@@ -13316,6 +13320,17 @@ version = "0.3.3"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "8df9b6e13f2d32c91b9bd719c00d1958837bc7dec474d94952798cc8e69eeec3"
[[package]]
name = "trace_id"
version = "0.0.1"
dependencies = [
"rand 0.8.5",
"serde",
"serde_derive",
"tokio",
"workspace-build-acceleration",
]
[[package]]
name = "tracing"
version = "0.1.41"
+2
View File
@@ -130,6 +130,7 @@ members = [
"crates/schema/public/enums",
"crates/schema/public/reusable_types", # TODO(bt, 2022-12-21): Deprecate
"crates/schema/public/tokens",
"crates/schema/trace_id",
# Services: API servers, jobs, workers, etc.
"crates/service/job/gmicloud_job",
@@ -293,6 +294,7 @@ subprocess_common = { path = "crates/lib/deprecated/subprocess_common" }
test_data = { path = "crates/testing/test_data" }
test_utils = { path = "crates/testing/test_utils" }
tokens = { path = "crates/schema/public/tokens" }
trace_id = { path = "crates/schema/trace_id" }
url_utils = { path = "crates/lib/url_utils" }
users = { path = "crates/lib/users" }
uuid_utils = { path = "crates/lib/uuid_utils" }
@@ -0,0 +1,6 @@
-- noinspection SqlDialectInspectionForFile
-- noinspection SqlNoDataSourceInspectionForFile
-- noinspection SqlResolveForFile
ALTER TABLE debug_logs
DROP COLUMN maybe_ip_address;
@@ -0,0 +1,6 @@
-- noinspection SqlDialectInspectionForFile
-- noinspection SqlNoDataSourceInspectionForFile
-- noinspection SqlResolveForFile
ALTER TABLE debug_logs
ADD COLUMN maybe_ip_address VARCHAR(40) DEFAULT NULL;
@@ -0,0 +1,6 @@
-- noinspection SqlDialectInspectionForFile
-- noinspection SqlNoDataSourceInspectionForFile
-- noinspection SqlResolveForFile
ALTER TABLE debug_logs
DROP COLUMN maybe_url;
@@ -0,0 +1,6 @@
-- noinspection SqlDialectInspectionForFile
-- noinspection SqlNoDataSourceInspectionForFile
-- noinspection SqlResolveForFile
ALTER TABLE debug_logs
ADD COLUMN maybe_url VARCHAR(255) DEFAULT NULL;
@@ -19,6 +19,12 @@ CREATE TABLE debug_logs (
-- The user who created the log entry (if any).
maybe_creator_user_token VARCHAR(32) DEFAULT NULL,
-- The client IP address of the request (if any). Wide enough for IPv6.
maybe_ip_address VARCHAR(40) DEFAULT NULL,
-- The request URL (if any). Truncated to 255 characters on insert.
maybe_url VARCHAR(255) DEFAULT NULL,
-- The log message body.
message MEDIUMTEXT NOT NULL,
@@ -16,6 +16,10 @@ pub struct ModerationDebugLogEntry {
pub debug_log_type: DebugLogType,
pub maybe_log_level: Option<DebugLogLevel>,
pub maybe_creator_user_token: Option<UserToken>,
/// The client IP address of the request (if recorded).
pub maybe_ip_address: Option<String>,
/// The request URL (if recorded; truncated to 255 chars).
pub maybe_url: Option<String>,
pub message: String,
pub created_at: DateTime<Utc>,
/// The creator user, joined in when the row has a user token.
@@ -66,6 +66,10 @@ pub struct ModerationListAllDebugLogsEntry {
pub debug_log_type: DebugLogType,
pub maybe_log_level: Option<DebugLogLevel>,
pub maybe_creator_user_token: Option<UserToken>,
/// The client IP address of the request (if recorded).
pub maybe_ip_address: Option<String>,
/// The request URL (if recorded; truncated to 255 chars).
pub maybe_url: Option<String>,
pub message: String,
pub created_at: DateTime<Utc>,
pub maybe_user: Option<ModerationDebugLogUser>,
+1
View File
@@ -25,6 +25,7 @@ workspace-build-acceleration = { version = "0.1", path = "../../workspace-build-
# External
dotenv.workspace = true
env_logger = "0.11.3"
trace_id.workspace = true
log = "0.4.14"
[dev-dependencies]
+32 -1
View File
@@ -29,6 +29,37 @@ pub fn init_env_logger(default_if_absent: Option<&str>) {
env::set_var(ENV_RUST_LOG, default_log_level);
}
env_logger::init();
// Custom format so that log lines emitted while serving an HTTP request
// automatically carry the request's trace id (see the `trace_id` crate and
// the `TraceIdMiddleware` in storyteller-web). Outside of a request scope
// the trace segment is simply omitted.
env_logger::Builder::from_env(env_logger::Env::default())
.format(|buf, record| {
use std::io::Write;
let timestamp = buf.timestamp();
let level_style = buf.default_level_style(record.level());
match trace_id::current_trace_id() {
Some(trace) => writeln!(
buf,
"[{} {level_style}{}{level_style:#} {} {}] {}",
timestamp,
record.level(),
record.target(),
trace,
record.args(),
),
None => writeln!(
buf,
"[{} {level_style}{}{level_style:#} {}] {}",
timestamp,
record.level(),
record.target(),
record.args(),
),
}
})
.init();
}
+1
View File
@@ -25,6 +25,7 @@ workspace-build-acceleration = { workspace = true }
# External
env_logger = "0.11.3"
trace_id.workspace = true
log = { workspace = true }
[dev-dependencies]
+32 -1
View File
@@ -68,6 +68,37 @@ pub fn init_env_logger(default_if_absent: Option<&str>) {
env::set_var(ENV_RUST_LOG, default_log_level);
}
env_logger::init();
// Custom format so that log lines emitted while serving an HTTP request
// automatically carry the request's trace id (see the `trace_id` crate and
// the `TraceIdMiddleware` in storyteller-web). Outside of a request scope
// the trace segment is simply omitted.
env_logger::Builder::from_env(env_logger::Env::default())
.format(|buf, record| {
use std::io::Write;
let timestamp = buf.timestamp();
let level_style = buf.default_level_style(record.level());
match trace_id::current_trace_id() {
Some(trace) => writeln!(
buf,
"[{} {level_style}{}{level_style:#} {} {}] {}",
timestamp,
record.level(),
record.target(),
trace,
record.args(),
),
None => writeln!(
buf,
"[{} {level_style}{}{level_style:#} {}] {}",
timestamp,
record.level(),
record.target(),
record.args(),
),
}
})
.init();
}
+1
View File
@@ -24,6 +24,7 @@ chrono.workspace = true
sha2.workspace = true
log.workspace = true
tokio.workspace = true
trace_id.workspace = true
[dev-dependencies]
tokio = { version = "1", features = ["full"] }
@@ -49,6 +49,9 @@ pub struct NotificationDetails {
/// Third-party identifier associated with the event, if any.
pub(crate) third_party_id: Option<String>,
/// The request-scoped trace id associated with the event, if any.
pub(crate) trace_id: Option<String>,
/// IP address of the request that triggered this notification, if any.
pub(crate) request_ip_address: Option<String>,
@@ -189,6 +192,10 @@ impl NotificationDetails {
parts.push(format!("Request IP: {}", ip));
}
if let Some(trace_id) = &self.trace_id {
parts.push(format!("Trace ID: {}", trace_id));
}
if parts.is_empty() { None } else { Some(parts.join("\n")) }
}
@@ -31,6 +31,10 @@ pub struct NotificationDetailsBuilder {
pub(crate) avt_cookie_token: Option<String>,
pub(crate) session_token: Option<String>,
pub(crate) session_user_token: Option<String>,
/// The request-scoped trace id, if any. Auto-filled from the tokio
/// task-local at `build()` time when not explicitly set.
pub(crate) trace_id: Option<String>,
}
impl NotificationDetailsBuilder {
@@ -57,6 +61,7 @@ impl NotificationDetailsBuilder {
avt_cookie_token: None,
session_token: None,
session_user_token: None,
trace_id: None,
}
}
@@ -87,6 +92,7 @@ impl NotificationDetailsBuilder {
avt_cookie_token: None,
session_token: None,
session_user_token: None,
trace_id: None,
}
}
@@ -167,6 +173,11 @@ impl NotificationDetailsBuilder {
self
}
pub fn set_trace_id(mut self, trace_id: Option<String>) -> Self {
self.trace_id = trace_id;
self
}
pub fn set_session_user_token(mut self, session_user_token: Option<String>) -> Self {
self.session_user_token = session_user_token;
self
@@ -199,6 +210,11 @@ impl NotificationDetailsBuilder {
avt_cookie_token: self.avt_cookie_token,
session_token: self.session_token,
session_user_token: self.session_user_token,
// Auto-fill from the request's task-local so any page fired while
// serving a request is correlated even if the caller never set it.
trace_id: self.trace_id.or_else(|| {
trace_id::current_trace_id().map(|t| t.to_string())
}),
}
}
@@ -19,6 +19,12 @@ where
/// The user associated with these debug log events (if any).
pub maybe_creator_user_token: Option<&'e UserToken>,
/// The client IP address of the request (if any). Truncated on insert.
pub maybe_ip_address: Option<&'e str>,
/// The request URL (if any). Truncated to 255 characters on insert.
pub maybe_url: Option<&'e str>,
/// The events to insert.
pub events: Vec<DebugLogEvent>,
@@ -56,9 +62,11 @@ where
}
let maybe_user_token_str = args.maybe_creator_user_token.map(|t| t.as_str().to_string());
let maybe_ip_address = args.maybe_ip_address.map(|ip| truncate_chars(ip, MAX_IP_ADDRESS_CHARS));
let maybe_url = args.maybe_url.map(|url| truncate_chars(url, MAX_URL_CHARS));
let mut query_builder = QueryBuilder::new(
"INSERT INTO debug_logs (event_token, debug_log_type, maybe_log_level, maybe_creator_user_token, message) VALUES "
"INSERT INTO debug_logs (event_token, debug_log_type, maybe_log_level, maybe_creator_user_token, maybe_ip_address, maybe_url, message) VALUES "
);
for (i, event) in args.events.iter().enumerate() {
@@ -71,6 +79,10 @@ where
query_builder.push(", ");
query_builder.push_bind(&maybe_user_token_str);
query_builder.push(", ");
query_builder.push_bind(maybe_ip_address);
query_builder.push(", ");
query_builder.push_bind(maybe_url);
query_builder.push(", ");
query_builder.push_bind(&event.message);
query_builder.push(")");
@@ -85,3 +97,17 @@ where
Ok(event_token)
}
/// Maximum stored length for `maybe_ip_address` (VARCHAR(40)).
const MAX_IP_ADDRESS_CHARS: usize = 40;
/// Maximum stored length for `maybe_url` (VARCHAR(255)).
const MAX_URL_CHARS: usize = 255;
/// Truncate to at most `max_chars` characters (UTF-8 safe).
fn truncate_chars(value: &str, max_chars: usize) -> &str {
match value.char_indices().nth(max_chars) {
Some((idx, _)) => &value[..idx],
None => value,
}
}
@@ -27,6 +27,12 @@ where
/// The log message body (pre-serialized JSON or any text).
pub message: &'e str,
/// The client IP address of the request (if any). Truncated on insert.
pub maybe_ip_address: Option<&'e str>,
/// The request URL (if any). Truncated to 255 characters on insert.
pub maybe_url: Option<&'e str>,
pub mysql_executor: E,
pub phantom: PhantomData<&'c E>,
}
@@ -53,12 +59,16 @@ SET
debug_log_type = ?,
maybe_log_level = ?,
maybe_creator_user_token = ?,
maybe_ip_address = ?,
maybe_url = ?,
message = ?
"#,
event_token.as_str(),
args.debug_log_type.to_str(),
args.maybe_log_level.map(|l| l.to_str()),
args.maybe_creator_user_token.map(|t| t.as_str()),
args.maybe_ip_address.map(|ip| truncate_chars(ip, MAX_IP_ADDRESS_CHARS)),
args.maybe_url.map(|url| truncate_chars(url, MAX_URL_CHARS)),
args.message,
)
.execute(args.mysql_executor)
@@ -66,3 +76,17 @@ SET
Ok(event_token)
}
/// Maximum stored length for `maybe_ip_address` (VARCHAR(40)).
const MAX_IP_ADDRESS_CHARS: usize = 40;
/// Maximum stored length for `maybe_url` (VARCHAR(255)).
const MAX_URL_CHARS: usize = 255;
/// Truncate to at most `max_chars` characters (UTF-8 safe).
fn truncate_chars(value: &str, max_chars: usize) -> &str {
match value.char_indices().nth(max_chars) {
Some((idx, _)) => &value[..idx],
None => value,
}
}
@@ -43,6 +43,8 @@ pub struct AllDebugLogRow {
pub debug_log_type: DebugLogType,
pub maybe_log_level: Option<DebugLogLevel>,
pub maybe_creator_user_token: Option<UserToken>,
pub maybe_ip_address: Option<String>,
pub maybe_url: Option<String>,
pub message: String,
pub created_at: DateTime<Utc>,
@@ -77,6 +79,8 @@ SELECT
d.debug_log_type,
d.maybe_log_level,
d.maybe_creator_user_token,
d.maybe_ip_address,
d.maybe_url,
d.message,
d.created_at,
u.display_name as maybe_user_display_name,
@@ -133,6 +137,8 @@ fn row_from_mysql_row(row: MySqlRow) -> Result<AllDebugLogRow, sqlx::Error> {
debug_log_type: row.try_get("debug_log_type")?,
maybe_log_level: row.try_get("maybe_log_level")?,
maybe_creator_user_token: row.try_get("maybe_creator_user_token")?,
maybe_ip_address: row.try_get("maybe_ip_address")?,
maybe_url: row.try_get("maybe_url")?,
message: row.try_get("message")?,
created_at,
maybe_user_display_name: row.try_get("maybe_user_display_name")?,
@@ -27,6 +27,8 @@ pub struct DebugLogRow {
pub debug_log_type: DebugLogType,
pub maybe_log_level: Option<DebugLogLevel>,
pub maybe_creator_user_token: Option<UserToken>,
pub maybe_ip_address: Option<String>,
pub maybe_url: Option<String>,
pub message: String,
pub created_at: DateTime<Utc>,
@@ -43,6 +45,8 @@ struct RawDebugLogRow {
debug_log_type: DebugLogType,
maybe_log_level: Option<DebugLogLevel>,
maybe_creator_user_token: Option<UserToken>,
maybe_ip_address: Option<String>,
maybe_url: Option<String>,
message: String,
created_at: NaiveDateTime,
maybe_user_display_name: Option<String>,
@@ -67,6 +71,8 @@ SELECT
d.debug_log_type as `debug_log_type: enums::by_table::debug_logs::debug_log_type::DebugLogType`,
d.maybe_log_level as `maybe_log_level: enums::by_table::debug_logs::debug_log_level::DebugLogLevel`,
d.maybe_creator_user_token as `maybe_creator_user_token: tokens::tokens::users::UserToken`,
d.maybe_ip_address,
d.maybe_url,
d.message,
d.created_at,
u.display_name as `maybe_user_display_name?`,
@@ -92,6 +98,8 @@ LIMIT ?
debug_log_type: row.debug_log_type,
maybe_log_level: row.maybe_log_level,
maybe_creator_user_token: row.maybe_creator_user_token,
maybe_ip_address: row.maybe_ip_address,
maybe_url: row.maybe_url,
message: row.message,
created_at: row.created_at.and_utc(),
maybe_user_display_name: row.maybe_user_display_name,
@@ -39,6 +39,8 @@ pub struct UserDebugLogRow {
pub debug_log_type: DebugLogType,
pub maybe_log_level: Option<DebugLogLevel>,
pub maybe_creator_user_token: Option<UserToken>,
pub maybe_ip_address: Option<String>,
pub maybe_url: Option<String>,
pub message: String,
pub created_at: DateTime<Utc>,
@@ -55,6 +57,8 @@ struct RawUserDebugLogRow {
debug_log_type: DebugLogType,
maybe_log_level: Option<DebugLogLevel>,
maybe_creator_user_token: Option<UserToken>,
maybe_ip_address: Option<String>,
maybe_url: Option<String>,
message: String,
created_at: NaiveDateTime,
maybe_user_display_name: Option<String>,
@@ -85,6 +89,8 @@ SELECT
d.debug_log_type as `debug_log_type: enums::by_table::debug_logs::debug_log_type::DebugLogType`,
d.maybe_log_level as `maybe_log_level: enums::by_table::debug_logs::debug_log_level::DebugLogLevel`,
d.maybe_creator_user_token as `maybe_creator_user_token: tokens::tokens::users::UserToken`,
d.maybe_ip_address,
d.maybe_url,
d.message,
d.created_at,
u.display_name as `maybe_user_display_name?`,
@@ -112,6 +118,8 @@ LIMIT ?
debug_log_type: row.debug_log_type,
maybe_log_level: row.maybe_log_level,
maybe_creator_user_token: row.maybe_creator_user_token,
maybe_ip_address: row.maybe_ip_address,
maybe_url: row.maybe_url,
message: row.message,
created_at: row.created_at.and_utc(),
maybe_user_display_name: row.maybe_user_display_name,
@@ -18,7 +18,16 @@ pub const MAX_LENGTH: usize = 24;
#[derive(Clone, Copy, Eq, PartialEq, Ord, PartialOrd, Hash, Serialize, Deserialize, ToSchema)]
#[serde(rename_all = "snake_case")]
pub enum DebugLogType {
// ========== First party ==========
/// A user request, typically the Json<T> actix_web handlers read.
HttpRequest,
/// A backend/pipeline failure while serving a request.
BackendFailure,
// ========== Third party ==========
FalRequest,
KinoviRequest,
GrokApiRequest,
@@ -34,6 +43,7 @@ impl DebugLogType {
pub fn to_str(&self) -> &'static str {
match self {
Self::HttpRequest => "http_request",
Self::BackendFailure => "backend_failure",
Self::FalRequest => "fal_request",
Self::KinoviRequest => "kinovi_request",
Self::GrokApiRequest => "grok_api_request",
@@ -45,6 +55,7 @@ impl DebugLogType {
pub fn from_str(value: &str) -> Result<Self, EnumError> {
match value {
"http_request" => Ok(Self::HttpRequest),
"backend_failure" => Ok(Self::BackendFailure),
"fal_request" => Ok(Self::FalRequest),
"kinovi_request" => Ok(Self::KinoviRequest),
"grok_api_request" => Ok(Self::GrokApiRequest),
@@ -57,6 +68,7 @@ impl DebugLogType {
pub fn all_variants() -> BTreeSet<Self> {
BTreeSet::from([
Self::HttpRequest,
Self::BackendFailure,
Self::FalRequest,
Self::KinoviRequest,
Self::GrokApiRequest,
@@ -79,6 +91,7 @@ mod tests {
#[test]
fn test_serialization() {
assert_serialization(DebugLogType::HttpRequest, "http_request");
assert_serialization(DebugLogType::BackendFailure, "backend_failure");
assert_serialization(DebugLogType::FalRequest, "fal_request");
assert_serialization(DebugLogType::KinoviRequest, "kinovi_request");
assert_serialization(DebugLogType::GrokApiRequest, "grok_api_request");
@@ -89,6 +102,7 @@ mod tests {
#[test]
fn to_str() {
assert_eq!(DebugLogType::HttpRequest.to_str(), "http_request");
assert_eq!(DebugLogType::BackendFailure.to_str(), "backend_failure");
assert_eq!(DebugLogType::FalRequest.to_str(), "fal_request");
assert_eq!(DebugLogType::KinoviRequest.to_str(), "kinovi_request");
assert_eq!(DebugLogType::GrokApiRequest.to_str(), "grok_api_request");
@@ -99,6 +113,7 @@ mod tests {
#[test]
fn from_str() {
assert_eq!(DebugLogType::from_str("http_request").unwrap(), DebugLogType::HttpRequest);
assert_eq!(DebugLogType::from_str("backend_failure").unwrap(), DebugLogType::BackendFailure);
assert_eq!(DebugLogType::from_str("fal_request").unwrap(), DebugLogType::FalRequest);
assert_eq!(DebugLogType::from_str("kinovi_request").unwrap(), DebugLogType::KinoviRequest);
assert_eq!(DebugLogType::from_str("grok_api_request").unwrap(), DebugLogType::GrokApiRequest);
@@ -120,8 +135,9 @@ mod tests {
#[test]
fn all_variants() {
let mut variants = DebugLogType::all_variants();
assert_eq!(variants.len(), 6);
assert_eq!(variants.len(), 7);
assert_eq!(variants.pop_first(), Some(DebugLogType::HttpRequest));
assert_eq!(variants.pop_first(), Some(DebugLogType::BackendFailure));
assert_eq!(variants.pop_first(), Some(DebugLogType::FalRequest));
assert_eq!(variants.pop_first(), Some(DebugLogType::KinoviRequest));
assert_eq!(variants.pop_first(), Some(DebugLogType::GrokApiRequest));
+25
View File
@@ -0,0 +1,25 @@
[package]
name = "trace_id"
edition = "2018"
version = "0.0.1"
authors = [
"Brandon Thomas <bt@brand.io>",
"Brandon Thomas <echelon@gmail.com>",
]
publish = false
[package.metadata.cargo-udeps.ignore]
normal = ["workspace-build-acceleration"]
[lib]
name = "trace_id"
path = "src/lib.rs"
[dependencies]
# Workspace hack (faster compile times)
workspace-build-acceleration.workspace = true
rand = { version = "0.8.5", features = ["std_rng"] }
serde.workspace = true
serde_derive.workspace = true
tokio.workspace = true
+156
View File
@@ -0,0 +1,156 @@
//! trace_id
//!
//! Request-scoped trace identifiers for observability.
//!
//! A `TraceId` is generated for every inbound HTTP request (see the
//! `trace_id_middleware` in `storyteller-web`), stored in a tokio task-local,
//! and emitted with every log line and pager notification produced while
//! serving that request.
use std::fmt;
use serde_derive::{Deserialize, Serialize};
/// The string prefix for trace ids.
pub const TRACE_ID_PREFIX: &str = "trace_";
/// Number of Crockford base32 characters after the prefix.
/// 26 characters × 5 bits = 130 bits of entropy (≥ the 128-bit industry
/// standard for trace ids). Total length: 6 + 26 = 32 characters.
pub const TRACE_ID_ENTROPY_CHARS: usize = 26;
/// Total serialized length of a trace id ("trace_" + entropy).
pub const TRACE_ID_TOTAL_LENGTH: usize = 32;
/// Crockford base32 alphabet, lowercase (no i, l, o, u).
const CROCKFORD_LOWERCASE_CHARSET: &[u8] = b"0123456789abcdefghjkmnpqrstvwxyz";
/// A unique-per-request trace identifier, eg. `trace_1h3x9k2m4p7q8r5t6v0w2y3z4a`.
#[derive(Clone, Eq, PartialEq, Ord, PartialOrd, Hash, Serialize, Deserialize)]
pub struct TraceId(String);
impl TraceId {
/// Generate a new random trace id. Infallible.
#[inline]
pub fn generate() -> Self {
use rand::Rng;
let mut rng = rand::thread_rng();
let entropy: String = (0..TRACE_ID_ENTROPY_CHARS)
.map(|_| {
let idx = rng.gen_range(0..CROCKFORD_LOWERCASE_CHARSET.len());
CROCKFORD_LOWERCASE_CHARSET[idx] as char
})
.collect();
TraceId(format!("{}{}", TRACE_ID_PREFIX, entropy))
}
#[inline]
pub fn as_str(&self) -> &str {
&self.0
}
}
impl fmt::Display for TraceId {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
write!(f, "{}", self.0)
}
}
impl fmt::Debug for TraceId {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
write!(f, "{}", self.0)
}
}
tokio::task_local! {
/// The trace id for the currently-executing request, if any.
///
/// Set by the HTTP middleware via [`TRACE_ID_TASK_LOCAL.scope(...)`], and
/// readable from anywhere within the request's task — including the
/// logger's format closure and the pager — via [`current_trace_id`].
pub static TRACE_ID_TASK_LOCAL: TraceId;
}
/// The trace id of the currently-executing request, if one is in scope.
///
/// Returns `None` outside of a request context (startup, background threads,
/// detached `tokio::spawn` tasks that weren't explicitly re-scoped).
#[inline]
pub fn current_trace_id() -> Option<TraceId> {
TRACE_ID_TASK_LOCAL.try_with(|trace_id| trace_id.clone()).ok()
}
#[cfg(test)]
mod tests {
use super::*;
mod generation {
use super::*;
#[test]
fn total_length_is_32() {
assert_eq!(TraceId::generate().as_str().len(), TRACE_ID_TOTAL_LENGTH);
}
#[test]
fn has_prefix() {
assert!(TraceId::generate().as_str().starts_with(TRACE_ID_PREFIX));
}
#[test]
fn entropy_uses_crockford_lowercase_only() {
let trace_id = TraceId::generate();
let entropy = &trace_id.as_str()[TRACE_ID_PREFIX.len()..];
assert_eq!(entropy.len(), TRACE_ID_ENTROPY_CHARS);
for c in entropy.chars() {
assert!(
CROCKFORD_LOWERCASE_CHARSET.contains(&(c as u8)),
"unexpected character: {}",
c
);
}
}
#[test]
fn ids_are_unique() {
let a = TraceId::generate();
let b = TraceId::generate();
assert_ne!(a, b);
}
}
mod task_local {
use super::*;
#[tokio::test]
async fn absent_outside_scope() {
assert!(current_trace_id().is_none());
}
#[tokio::test]
async fn present_inside_scope() {
let trace_id = TraceId::generate();
let expected = trace_id.clone();
TRACE_ID_TASK_LOCAL
.scope(trace_id, async move {
assert_eq!(current_trace_id(), Some(expected));
})
.await;
}
#[tokio::test]
async fn survives_await_points() {
let trace_id = TraceId::generate();
let expected = trace_id.clone();
TRACE_ID_TASK_LOCAL
.scope(trace_id, async move {
tokio::task::yield_now().await;
assert_eq!(current_trace_id(), Some(expected));
})
.await;
}
}
}
@@ -89,6 +89,7 @@ seedance2pro_client.workspace = true
server_environment = { path = "../../../lib/server_environment" }
thumbnail_generator = { path = "../../../api_clients/thumbnail_generator" }
tokens.workspace = true
trace_id.workspace = true
tts_common = { path = "../../../lib/deprecated/tts_common" }
url_config = { path = "../../../lib/url_config" }
url_utils = { path = "../../../lib/url_utils" }
@@ -0,0 +1,62 @@
use log::warn;
use sqlx::{Executor, MySql};
use enums::by_table::debug_logs::debug_log_level::DebugLogLevel;
use enums::by_table::debug_logs::debug_log_type::DebugLogType;
use mysql_queries::queries::debug_logs::insert_debug_log::{insert_debug_log, InsertDebugLogArgs};
use tokens::tokens::non_unique::debug_logs_event_token::DebugLogEventToken;
use tokens::tokens::users::UserToken;
/// Best-effort info-level debug log of an inbound generation HTTP request.
/// Never fails the request — insert errors are logged and swallowed.
pub async fn insert_generation_request_debug_log<'e, 'c: 'e, E>(
debug_log_event_token: &'e DebugLogEventToken,
user_token: &'e UserToken,
ip_address: &'e str,
request_url: &'e str,
request_json: &'e str,
mysql_executor: E,
) where
E: 'c + Executor<'c, Database = MySql>,
{
if let Err(err) = insert_debug_log(InsertDebugLogArgs {
apriori_debug_log_event_token: Some(debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::HttpRequest,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(ip_address),
maybe_url: Some(request_url),
message: request_json,
mysql_executor,
phantom: Default::default(),
}).await {
warn!("Failed to insert HTTP request debug log: {:?}", err);
}
}
/// Best-effort error-level debug log of a generation backend failure.
/// Never fails the request — insert errors are logged and swallowed.
pub async fn insert_generation_failure_debug_log<'e, 'c: 'e, E>(
debug_log_event_token: &'e DebugLogEventToken,
user_token: &'e UserToken,
ip_address: &'e str,
request_url: &'e str,
error_message: &'e str,
mysql_executor: E,
) where
E: 'c + Executor<'c, Database = MySql>,
{
if let Err(err) = insert_debug_log(InsertDebugLogArgs {
apriori_debug_log_event_token: Some(debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::BackendFailure,
maybe_log_level: Some(DebugLogLevel::Error),
maybe_ip_address: Some(ip_address),
maybe_url: Some(request_url),
message: error_message,
mysql_executor,
phantom: Default::default(),
}).await {
warn!("Failed to insert generation failure debug log: {:?}", err);
}
}
@@ -1,4 +1,5 @@
mod test_synthetic_failure_reason;
pub mod generation_debug_logs;
pub mod job_failure_test;
pub mod map_seedance2pro_web_errors;
pub mod payments_error_test;
mod test_synthetic_failure_reason;
@@ -3,6 +3,9 @@ use std::sync::Arc;
use crate::billing::wallets::attempt_wallet_deduction::attempt_wallet_deduction_else_common_web_error;
use crate::http_server::common_responses::common_web_error::CommonWebError;
use crate::http_server::common_responses::media::media_links_builder::MediaLinksBuilder;
use crate::http_server::endpoints::generate::common::generation_debug_logs::{
insert_generation_failure_debug_log, insert_generation_request_debug_log,
};
use crate::http_server::endpoints::generate::common::payments_error_test::payments_error_test;
use crate::http_server::endpoints::media_files::helpers::get_media_domain::get_media_domain;
use crate::http_server::validations::validate_idempotency_token_format::validate_idempotency_token_format;
@@ -38,6 +41,7 @@ use mysql_queries::queries::media_files::get::get_media_file::{get_media_file, g
use mysql_queries::queries::prompts::insert_prompt::{insert_prompt, InsertPromptArgs};
use sqlx::Acquire;
use tokens::tokens::generic_inference_jobs::InferenceJobToken;
use tokens::tokens::non_unique::debug_logs_event_token::DebugLogEventToken;
use utoipa::ToSchema;
/// Seedance 1.0 Lite Image to Video
@@ -84,6 +88,21 @@ pub async fn generate_seedance_1_0_lite_image_to_video_handler(
}
};
// ==================== DEBUG LOG: HTTP REQUEST ==================== //
let debug_log_event_token = DebugLogEventToken::generate();
let ip_address = get_request_ip(&http_request);
let request_url = http_request.uri().to_string();
insert_generation_request_debug_log(
&debug_log_event_token,
user_token,
&ip_address,
&request_url,
&serde_json::to_string(&*request).unwrap_or_default(),
&mut *mysql_connection,
).await;
let start_frame_media_file_token = match &request.media_file_token {
Some(token) => token,
None => {
@@ -208,12 +227,21 @@ pub async fn generate_seedance_1_0_lite_image_to_video_handler(
api_key: &server_state.inference_providers.fal.api_key,
};
let fal_result = enqueue_seedance_1_lite_image_to_video_webhook(args)
.await
.map_err(|err| {
warn!("Error calling enqueue_seedance_1_lite_image_to_video_webhook: {:?}", err);
CommonWebError::from_error(err)
})?;
let fal_result = match enqueue_seedance_1_lite_image_to_video_webhook(args).await {
Ok(result) => result,
Err(err) => {
warn!("Error calling enqueue_seedance_1_lite_image_to_video_webhook: {:?}", err);
insert_generation_failure_debug_log(
&debug_log_event_token,
user_token,
&ip_address,
&request_url,
&format!("Seedance 1.0 Lite generation failed: {:?}", err),
&mut *mysql_connection,
).await;
return Err(CommonWebError::from_error(err));
}
};
let external_job_id = fal_result.request_id
.ok_or_else(|| {
@@ -223,8 +251,6 @@ pub async fn generate_seedance_1_0_lite_image_to_video_handler(
info!("Fal request_id: {}", external_job_id);
let ip_address = get_request_ip(&http_request);
let mut transaction = mysql_connection
.begin()
.await
@@ -294,7 +320,7 @@ pub async fn generate_seedance_1_0_lite_image_to_video_handler(
starting_job_status_override: None,
maybe_frontend_failure_category: None,
maybe_failure_reason: None,
maybe_debug_log_event_token: None,
maybe_debug_log_event_token: Some(&debug_log_event_token),
phantom: Default::default(),
}).await;
@@ -3,6 +3,9 @@ use std::sync::Arc;
use crate::billing::wallets::attempt_wallet_deduction::attempt_wallet_deduction_else_common_web_error;
use crate::http_server::common_responses::common_web_error::CommonWebError;
use crate::http_server::common_responses::media::media_links_builder::MediaLinksBuilder;
use crate::http_server::endpoints::generate::common::generation_debug_logs::{
insert_generation_failure_debug_log, insert_generation_request_debug_log,
};
use crate::http_server::endpoints::generate::common::payments_error_test::payments_error_test;
use crate::http_server::endpoints::media_files::helpers::get_media_domain::get_media_domain;
use crate::http_server::validations::validate_idempotency_token_format::validate_idempotency_token_format;
@@ -35,6 +38,7 @@ use mysql_queries::queries::media_files::get::get_media_file::{get_media_file, g
use mysql_queries::queries::prompts::insert_prompt::{insert_prompt, InsertPromptArgs};
use sqlx::Acquire;
use tokens::tokens::generic_inference_jobs::InferenceJobToken;
use tokens::tokens::non_unique::debug_logs_event_token::DebugLogEventToken;
use utoipa::ToSchema;
/// Seedance 1.0 Pro Image to Video
@@ -81,6 +85,21 @@ pub async fn generate_seedance_1_0_pro_image_to_video_handler(
}
};
// ==================== DEBUG LOG: HTTP REQUEST ==================== //
let debug_log_event_token = DebugLogEventToken::generate();
let ip_address = get_request_ip(&http_request);
let request_url = http_request.uri().to_string();
insert_generation_request_debug_log(
&debug_log_event_token,
user_token,
&ip_address,
&request_url,
&serde_json::to_string(&*request).unwrap_or_default(),
&mut *mysql_connection,
).await;
let start_frame_media_file_token = match &request.media_file_token {
Some(token) => token,
None => {
@@ -182,12 +201,21 @@ pub async fn generate_seedance_1_0_pro_image_to_video_handler(
api_key: &server_state.inference_providers.fal.api_key,
};
let fal_result = enqueue_seedance_1_pro_image_to_video_webhook(args)
.await
.map_err(|err| {
warn!("Error calling enqueue_seedance_1_pro_image_to_video_webhook: {:?}", err);
CommonWebError::from_error(err)
})?;
let fal_result = match enqueue_seedance_1_pro_image_to_video_webhook(args).await {
Ok(result) => result,
Err(err) => {
warn!("Error calling enqueue_seedance_1_pro_image_to_video_webhook: {:?}", err);
insert_generation_failure_debug_log(
&debug_log_event_token,
user_token,
&ip_address,
&request_url,
&format!("Seedance 1.0 Pro generation failed: {:?}", err),
&mut *mysql_connection,
).await;
return Err(CommonWebError::from_error(err));
}
};
let external_job_id = fal_result.request_id
.ok_or_else(|| {
@@ -197,8 +225,6 @@ pub async fn generate_seedance_1_0_pro_image_to_video_handler(
info!("Fal request_id: {}", external_job_id);
let ip_address = get_request_ip(&http_request);
let mut transaction = mysql_connection
.begin()
.await
@@ -268,7 +294,7 @@ pub async fn generate_seedance_1_0_pro_image_to_video_handler(
starting_job_status_override: None,
maybe_frontend_failure_category: None,
maybe_failure_reason: None,
maybe_debug_log_event_token: None,
maybe_debug_log_event_token: Some(&debug_log_event_token),
phantom: Default::default(),
}).await;
@@ -3,6 +3,9 @@ use std::sync::Arc;
use crate::billing::wallets::attempt_wallet_deduction::attempt_wallet_deduction_else_common_web_error;
use crate::http_server::common_responses::common_web_error::CommonWebError;
use crate::http_server::endpoints::generate::common::generation_debug_logs::{
insert_generation_failure_debug_log, insert_generation_request_debug_log,
};
use crate::http_server::endpoints::generate::common::payments_error_test::payments_error_test;
use crate::http_server::validations::validate_idempotency_token_format::validate_idempotency_token_format;
use crate::http_server::web_utils::get_request_platform_type::get_request_platform_type;
@@ -30,6 +33,7 @@ use mysql_queries::queries::prompt_context_items::insert_batch_prompt_context_it
use mysql_queries::queries::prompts::insert_prompt::{insert_prompt, InsertPromptArgs};
use sqlx::Acquire;
use tokens::tokens::generic_inference_jobs::InferenceJobToken;
use tokens::tokens::non_unique::debug_logs_event_token::DebugLogEventToken;
/// Seedance 1.5 Pro Multi-Function (text and image to video)
@@ -78,6 +82,21 @@ pub async fn seedance_1p5_pro_multi_function_video_gen_handler(
}
};
// ==================== DEBUG LOG: HTTP REQUEST ==================== //
let debug_log_event_token = DebugLogEventToken::generate();
let ip_address = get_request_ip(&http_request);
let request_url = http_request.uri().to_string();
insert_generation_request_debug_log(
&debug_log_event_token,
user_token,
&ip_address,
&request_url,
&serde_json::to_string(&*request).unwrap_or_default(),
&mut *mysql_connection,
).await;
if let Err(reason) = validate_idempotency_token_format(&request.uuid_idempotency_token) {
return Err(CommonWebError::BadInputWithSimpleMessage(reason));
}
@@ -177,12 +196,21 @@ pub async fn seedance_1p5_pro_multi_function_video_gen_handler(
api_key: &server_state.inference_providers.fal.api_key,
};
fal_result = enqueue_seedance_1p5_pro_image_to_video_webhook(args)
.await
.map_err(|err| {
warn!("Error calling enqueue_seedance_1p5_pro_image_to_video_webhook: {:?}", err);
CommonWebError::from_error(err)
})?;
fal_result = match enqueue_seedance_1p5_pro_image_to_video_webhook(args).await {
Ok(result) => result,
Err(err) => {
warn!("Error calling enqueue_seedance_1p5_pro_image_to_video_webhook: {:?}", err);
insert_generation_failure_debug_log(
&debug_log_event_token,
user_token,
&ip_address,
&request_url,
&format!("Seedance 1.5 Pro generation failed: {:?}", err),
&mut *mysql_connection,
).await;
return Err(CommonWebError::from_error(err));
}
};
} else {
info!("text-to-video case");
@@ -217,12 +245,21 @@ pub async fn seedance_1p5_pro_multi_function_video_gen_handler(
&mut mysql_connection,
).await?;
fal_result = enqueue_seedance_1p5_pro_text_to_video_webhook(args)
.await
.map_err(|err| {
warn!("Error calling enqueue_seedance_1p5_pro_text_to_video_webhook: {:?}", err);
CommonWebError::from_error(err)
})?;
fal_result = match enqueue_seedance_1p5_pro_text_to_video_webhook(args).await {
Ok(result) => result,
Err(err) => {
warn!("Error calling enqueue_seedance_1p5_pro_text_to_video_webhook: {:?}", err);
insert_generation_failure_debug_log(
&debug_log_event_token,
user_token,
&ip_address,
&request_url,
&format!("Seedance 1.5 Pro generation failed: {:?}", err),
&mut *mysql_connection,
).await;
return Err(CommonWebError::from_error(err));
}
};
}
let external_job_id = fal_result.request_id
@@ -233,8 +270,6 @@ pub async fn seedance_1p5_pro_multi_function_video_gen_handler(
info!("Fal request_id: {}", external_job_id);
let ip_address = get_request_ip(&http_request);
let mut transaction = mysql_connection
.begin()
.await
@@ -342,7 +377,7 @@ pub async fn seedance_1p5_pro_multi_function_video_gen_handler(
starting_job_status_override: None,
maybe_frontend_failure_category: None,
maybe_failure_reason: None,
maybe_debug_log_event_token: None,
maybe_debug_log_event_token: Some(&debug_log_event_token),
phantom: Default::default(),
}).await;
@@ -5,6 +5,12 @@ use crate::billing::wallets::attempt_wallet_deduction::attempt_wallet_deduction_
use crate::http_server::common_responses::common_web_error::CommonWebError;
use crate::http_server::endpoint_helpers::refund_wallet_after_api_failure::refund_wallet_after_api_failure;
use crate::http_server::endpoints::generate::common::map_seedance2pro_web_errors::map_seedance2pro_error_to_web_error;
use crate::http_server::endpoints::generate::common::generation_debug_logs::{
insert_generation_failure_debug_log, insert_generation_request_debug_log,
};
use enums::by_table::debug_logs::debug_log_level::DebugLogLevel;
use enums::by_table::debug_logs::debug_log_type::DebugLogType;
use mysql_queries::queries::debug_logs::insert_debug_log::{insert_debug_log, InsertDebugLogArgs};
use crate::http_server::endpoints::generate::common::payments_error_test::payments_error_test;
use crate::http_server::user_lookup::user_session::session_utils::lookup::user_session_feature_flags::UserSessionFeatureFlags;
use crate::http_server::validations::validate_idempotency_token_format::validate_idempotency_token_format;
@@ -49,6 +55,9 @@ use sqlx::MySql;
use tokens::tokens::characters::CharacterToken;
use tokens::tokens::generic_inference_jobs::InferenceJobToken;
use tokens::tokens::media_files::MediaFileToken;
use tokens::tokens::non_unique::debug_logs_event_token::DebugLogEventToken;
use tokens::tokens::users::UserToken;
use url::Url;
use url_utils::extension::extract_extension_from_url::{extract_extension_from_url, ExtractExtensions};
@@ -60,6 +69,14 @@ struct SeedanceGenerationResult {
generation_mode: CommonGenerationMode,
}
/// Request-scoped context for writing `debug_logs` rows.
struct DebugLogContext<'a> {
event_token: &'a DebugLogEventToken,
user_token: &'a UserToken,
ip_address: &'a str,
request_url: &'a str,
}
// ======================== Handler ========================
/// Seedance 2.0 Multi-Function video generation (text-to-video, keyframe, and reference).
@@ -108,6 +125,28 @@ pub async fn seedance_2p0_multi_function_video_gen_handler(
let user_token = &user_session.user_token;
// ==================== DEBUG LOG: HTTP REQUEST ==================== //
let debug_log_event_token = DebugLogEventToken::generate();
let ip_address = get_request_ip(&http_request);
let request_url = http_request.uri().to_string();
insert_generation_request_debug_log(
&debug_log_event_token,
user_token,
&ip_address,
&request_url,
&serde_json::to_string(&*request).unwrap_or_default(),
&mut *mysql_connection,
).await;
let debug_log_context = DebugLogContext {
event_token: &debug_log_event_token,
user_token,
ip_address: &ip_address,
request_url: &request_url,
};
if let Err(reason) = validate_idempotency_token_format(&request.uuid_idempotency_token) {
return Err(CommonWebError::BadInputWithSimpleMessage(reason));
}
@@ -203,6 +242,8 @@ pub async fn seedance_2p0_multi_function_video_gen_handler(
batch_count,
duration_seconds,
kinovi_character_ids.clone(),
&debug_log_context,
&mut mysql_connection,
).await;
match result {
@@ -226,6 +267,8 @@ pub async fn seedance_2p0_multi_function_video_gen_handler(
batch_count,
duration_seconds,
kinovi_character_ids.clone(),
&debug_log_context,
&mut mysql_connection,
).await;
match result {
@@ -248,6 +291,14 @@ pub async fn seedance_2p0_multi_function_video_gen_handler(
}
}
insert_generation_failure_debug_log(
&debug_log_event_token,
user_token,
&ip_address,
&request_url,
&format!("Seedance 2.0 generation failed: {:?}", err),
&mut *mysql_connection,
).await;
refund_wallet_after_api_failure(&deduction_result.ledger_entry_token, &mut mysql_connection).await?;
return Err(err);
}
@@ -270,6 +321,8 @@ pub async fn seedance_2p0_multi_function_video_gen_handler(
batch_count,
duration_seconds,
kinovi_character_ids,
&debug_log_context,
&mut mysql_connection,
).await;
match result {
@@ -289,6 +342,14 @@ pub async fn seedance_2p0_multi_function_video_gen_handler(
}
}
insert_generation_failure_debug_log(
&debug_log_event_token,
user_token,
&ip_address,
&request_url,
&format!("Seedance 2.0 generation failed: {:?}", err),
&mut *mysql_connection,
).await;
refund_wallet_after_api_failure(&deduction_result.ledger_entry_token, &mut mysql_connection).await?;
return Err(err);
}
@@ -305,8 +366,6 @@ pub async fn seedance_2p0_multi_function_video_gen_handler(
// --- DB writes in a transaction ---
let ip_address = get_request_ip(&http_request);
let mut transaction = mysql_connection
.begin()
.await
@@ -438,7 +497,7 @@ pub async fn seedance_2p0_multi_function_video_gen_handler(
creator_set_visibility: Visibility::Public,
maybe_platform_type: get_request_platform_type(&http_request),
maybe_cost_estimates: None,
maybe_debug_log_event_token: None,
maybe_debug_log_event_token: Some(&debug_log_event_token),
mysql_executor: &mut *transaction,
phantom: Default::default(),
}
@@ -543,6 +602,8 @@ async fn upload_and_generate(
batch_count: KinoviBatchCount,
duration_seconds: u8,
kinovi_character_ids: Option<Vec<String>>,
debug_log_context: &DebugLogContext<'_>,
mysql_connection: &mut sqlx::pool::PoolConnection<MySql>,
) -> Result<SeedanceGenerationResult, CommonWebError> {
// --- Upload files to seedance2pro CDN ---
@@ -605,24 +666,44 @@ async fn upload_and_generate(
let prompt = request.prompt.clone().unwrap_or_else(|| "".to_string());
let kinovi_request = KinoviGenerateVideoRequest {
model_type: KinoviModelType::Seedance2Pro,
prompt,
aspect_ratio,
output_resolution,
duration_seconds,
batch_count,
start_frame_url,
end_frame_url,
reference_image_urls,
reference_video_urls,
reference_audio_urls,
character_ids: kinovi_character_ids,
use_face_blur_hack: None,
};
// ==================== DEBUG LOG: KINOVI REQUEST ==================== //
// Logged BEFORE the send so the outbound payload is captured even when
// the generation call fails.
if let Err(err) = insert_debug_log(InsertDebugLogArgs {
apriori_debug_log_event_token: Some(debug_log_context.event_token),
maybe_creator_user_token: Some(debug_log_context.user_token),
debug_log_type: DebugLogType::KinoviRequest,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(debug_log_context.ip_address),
maybe_url: Some(debug_log_context.request_url),
message: &format!("{:#?}", kinovi_request),
mysql_executor: &mut **mysql_connection,
phantom: Default::default(),
}).await {
warn!("Failed to insert Kinovi request debug log: {:?}", err);
}
let video_gen_args = GenerateVideoArgs {
session,
host_override: None,
request: KinoviGenerateVideoRequest {
model_type: KinoviModelType::Seedance2Pro,
prompt,
aspect_ratio,
output_resolution,
duration_seconds,
batch_count,
start_frame_url,
end_frame_url,
reference_image_urls,
reference_video_urls,
reference_audio_urls,
character_ids: kinovi_character_ids,
use_face_blur_hack: None,
},
request: kinovi_request,
};
let gen_response = generate_video(video_gen_args).await
@@ -75,6 +75,8 @@ pub async fn moderation_list_all_debug_logs_handler(
debug_log_type: row.debug_log_type,
maybe_log_level: row.maybe_log_level,
maybe_creator_user_token: row.maybe_creator_user_token,
maybe_ip_address: row.maybe_ip_address,
maybe_url: row.maybe_url,
message: row.message,
created_at: row.created_at,
maybe_user,
@@ -71,6 +71,8 @@ pub async fn moderation_list_debug_logs_for_token_handler(
debug_log_type: row.debug_log_type,
maybe_log_level: row.maybe_log_level,
maybe_creator_user_token: row.maybe_creator_user_token,
maybe_ip_address: row.maybe_ip_address,
maybe_url: row.maybe_url,
message: row.message,
created_at: row.created_at,
maybe_user,
@@ -72,6 +72,8 @@ pub async fn moderation_list_debug_logs_for_user_handler(
debug_log_type: row.debug_log_type,
maybe_log_level: row.maybe_log_level,
maybe_creator_user_token: row.maybe_creator_user_token,
maybe_ip_address: row.maybe_ip_address,
maybe_url: row.maybe_url,
message: row.message,
created_at: row.created_at,
maybe_user,
@@ -16,6 +16,7 @@ use enums::common::generation::common_model_type::CommonModelType;
use enums::common::generation_provider::GenerationProvider;
use enums::common::platform_type::PlatformType;
use http_server_common::request::get_request_ip::get_request_ip;
use enums::by_table::debug_logs::debug_log_level::DebugLogLevel;
use mysql_queries::queries::debug_logs::insert_debug_log::{insert_debug_log, InsertDebugLogArgs};
use mysql_queries::queries::generic_inference::api_providers::seedance2pro::insert_generic_inference_job_for_seedance2pro_queue_with_apriori_job_token::KinoviVersion;
use mysql_queries::queries::idepotency_tokens::insert_idempotency_token::insert_idempotency_token;
@@ -106,6 +107,7 @@ pub async fn omni_api_image_generate_handler(
})?;
let ip_address = get_request_ip(&http_request);
let request_url = http_request.uri().to_string();
// ==================== INGEST URL INPUTS ==================== //
@@ -138,7 +140,9 @@ pub async fn omni_api_image_generate_handler(
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::HttpRequest,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &serde_json::to_string(&*request).unwrap_or_default(),
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -158,7 +162,32 @@ pub async fn omni_api_image_generate_handler(
server_state: &server_state,
user_token,
resolved_media: &resolved_media,
}).await?;
}).await;
// ==================== DEBUG LOG: PIPELINE ERROR ==================== //
let pipeline_result = match pipeline_result {
Ok(result) => result,
Err(err) => {
// Best-effort error log; never mask the original error.
if let Ok(mut error_log_connection) = server_state.mysql_pool.acquire().await {
if let Err(log_err) = insert_debug_log(InsertDebugLogArgs {
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::BackendFailure,
maybe_log_level: Some(DebugLogLevel::Error),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &format!("Image generation pipeline failed: {:?}", err),
mysql_executor: &mut *error_log_connection,
phantom: Default::default(),
}).await {
warn!("Failed to insert pipeline error debug log: {:?}", log_err);
}
}
return Err(err);
}
};
let mut mysql_connection = server_state.mysql_pool.acquire().await?;
@@ -170,7 +199,9 @@ pub async fn omni_api_image_generate_handler(
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::FalRequest,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &format!("{:#?}", outbound_request),
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -18,6 +18,7 @@ use enums::common::generation::common_video_model::CommonVideoModel;
use enums::common::generation_provider::GenerationProvider;
use enums::common::platform_type::PlatformType;
use http_server_common::request::get_request_ip::get_request_ip;
use enums::by_table::debug_logs::debug_log_level::DebugLogLevel;
use mysql_queries::queries::debug_logs::insert_debug_log::{insert_debug_log, InsertDebugLogArgs};
use mysql_queries::queries::generic_inference::api_providers::seedance2pro::insert_generic_inference_job_for_seedance2pro_queue_with_apriori_job_token::KinoviVersion;
use mysql_queries::queries::idepotency_tokens::insert_idempotency_token::insert_idempotency_token;
@@ -119,6 +120,7 @@ pub async fn omni_api_video_generate_handler(
})?;
let ip_address = get_request_ip(&http_request);
let request_url = http_request.uri().to_string();
// ==================== INGEST URL INPUTS ==================== //
@@ -205,7 +207,9 @@ pub async fn omni_api_video_generate_handler(
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::HttpRequest,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &serde_json::to_string(&*request).unwrap_or_default(),
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -225,7 +229,32 @@ pub async fn omni_api_video_generate_handler(
media_file_to_url_map: &media_file_to_url_map,
kinovi_character_id_map: &kinovi_character_id_map,
kinovi_account,
}).await?;
}).await;
// ==================== DEBUG LOG: PIPELINE ERROR ==================== //
let pipeline_result = match pipeline_result {
Ok(result) => result,
Err(err) => {
// Best-effort error log; never mask the original error.
if let Ok(mut error_log_connection) = server_state.mysql_pool.acquire().await {
if let Err(log_err) = insert_debug_log(InsertDebugLogArgs {
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::BackendFailure,
maybe_log_level: Some(DebugLogLevel::Error),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &format!("Video generation pipeline failed: {:?}", err),
mysql_executor: &mut *error_log_connection,
phantom: Default::default(),
}).await {
warn!("Failed to insert pipeline error debug log: {:?}", log_err);
}
}
return Err(err);
}
};
let mut mysql_connection = server_state.mysql_pool.acquire().await?;
@@ -237,7 +266,9 @@ pub async fn omni_api_video_generate_handler(
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::FalRequest,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &format!("{:#?}", outbound_request),
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -255,7 +286,9 @@ pub async fn omni_api_video_generate_handler(
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::GrokApiRequest,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &format!("{:#?}", outbound_request),
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -15,6 +15,7 @@ use enums::common::generation::common_generation_mode::CommonGenerationMode;
use enums::common::generation::common_model_type::CommonModelType;
use enums::common::generation_provider::GenerationProvider;
use http_server_common::request::get_request_ip::get_request_ip;
use enums::by_table::debug_logs::debug_log_level::DebugLogLevel;
use mysql_queries::queries::debug_logs::insert_debug_log::{insert_debug_log, InsertDebugLogArgs};
use mysql_queries::queries::generic_inference::api_providers::seedance2pro::insert_generic_inference_job_for_seedance2pro_queue_with_apriori_job_token::KinoviVersion;
use mysql_queries::queries::idepotency_tokens::insert_idempotency_token::insert_idempotency_token;
@@ -130,11 +131,16 @@ pub async fn omni_gen_image_generate_handler(
// ==================== DEBUG LOG: HTTP REQUEST ==================== //
let ip_address = get_request_ip(&http_request);
let request_url = http_request.uri().to_string();
if let Err(err) = insert_debug_log(InsertDebugLogArgs {
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::HttpRequest,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &serde_json::to_string(&*request).unwrap_or_default(),
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -154,7 +160,32 @@ pub async fn omni_gen_image_generate_handler(
server_state: &server_state,
user_token,
resolved_media: &resolved_media,
}).await?;
}).await;
// ==================== DEBUG LOG: PIPELINE ERROR ==================== //
let pipeline_result = match pipeline_result {
Ok(result) => result,
Err(err) => {
// Best-effort error log; never mask the original error.
if let Ok(mut error_log_connection) = server_state.mysql_pool.acquire().await {
if let Err(log_err) = insert_debug_log(InsertDebugLogArgs {
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::BackendFailure,
maybe_log_level: Some(DebugLogLevel::Error),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &format!("Image generation pipeline failed: {:?}", err),
mysql_executor: &mut *error_log_connection,
phantom: Default::default(),
}).await {
warn!("Failed to insert pipeline error debug log: {:?}", log_err);
}
}
return Err(err);
}
};
let mut mysql_connection = server_state.mysql_pool.acquire().await?;
@@ -166,7 +197,9 @@ pub async fn omni_gen_image_generate_handler(
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::FalRequest,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &format!("{:#?}", outbound_request),
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -178,7 +211,6 @@ pub async fn omni_gen_image_generate_handler(
// ==================== WRITE RESULT ==================== //
let ip_address = get_request_ip(&http_request);
let maybe_platform_type = get_request_platform_type(&http_request);
let mut transaction = mysql_connection
@@ -17,6 +17,7 @@ use enums::common::generation::common_model_type::CommonModelType;
use enums::common::generation::common_video_model::CommonVideoModel;
use enums::common::generation_provider::GenerationProvider;
use http_server_common::request::get_request_ip::get_request_ip;
use enums::by_table::debug_logs::debug_log_level::DebugLogLevel;
use mysql_queries::queries::debug_logs::insert_debug_log::{insert_debug_log, InsertDebugLogArgs};
use mysql_queries::queries::generic_inference::api_providers::seedance2pro::insert_generic_inference_job_for_seedance2pro_queue_with_apriori_job_token::KinoviVersion;
use mysql_queries::queries::idepotency_tokens::insert_idempotency_token::insert_idempotency_token;
@@ -191,11 +192,16 @@ pub async fn omni_gen_video_generate_handler(
// ==================== DEBUG LOG: HTTP REQUEST ==================== //
let ip_address = get_request_ip(&http_request);
let request_url = http_request.uri().to_string();
if let Err(err) = insert_debug_log(InsertDebugLogArgs {
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::HttpRequest,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &serde_json::to_string(&*request).unwrap_or_default(),
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -215,7 +221,32 @@ pub async fn omni_gen_video_generate_handler(
media_file_to_url_map: &media_file_to_url_map,
kinovi_character_id_map: &kinovi_character_id_map,
kinovi_account,
}).await?;
}).await;
// ==================== DEBUG LOG: PIPELINE ERROR ==================== //
let pipeline_result = match pipeline_result {
Ok(result) => result,
Err(err) => {
// Best-effort error log; never mask the original error.
if let Ok(mut error_log_connection) = server_state.mysql_pool.acquire().await {
if let Err(log_err) = insert_debug_log(InsertDebugLogArgs {
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::BackendFailure,
maybe_log_level: Some(DebugLogLevel::Error),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &format!("Video generation pipeline failed: {:?}", err),
mysql_executor: &mut *error_log_connection,
phantom: Default::default(),
}).await {
warn!("Failed to insert pipeline error debug log: {:?}", log_err);
}
}
return Err(err);
}
};
let mut mysql_connection = server_state.mysql_pool.acquire().await?;
@@ -227,7 +258,9 @@ pub async fn omni_gen_video_generate_handler(
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::FalRequest,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &format!("{:#?}", outbound_request),
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -245,7 +278,9 @@ pub async fn omni_gen_video_generate_handler(
apriori_debug_log_event_token: Some(&debug_log_event_token),
maybe_creator_user_token: Some(user_token),
debug_log_type: DebugLogType::GrokApiRequest,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: Some(&ip_address),
maybe_url: Some(&request_url),
message: &format!("{:#?}", outbound_request),
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -257,7 +292,6 @@ pub async fn omni_gen_video_generate_handler(
// ==================== WRITE RESULT ==================== //
let ip_address = get_request_ip(&http_request);
let maybe_platform_type = get_request_platform_type(&http_request);
let mut transaction = mysql_connection.begin().await.map_err(|err| {
@@ -13,6 +13,7 @@ use beeble_client::webhook_api::beeble_webhook_payload::{
parse_beeble_webhook, BeebleWebhookPayload, BeebleWebhookStatus,
};
use bucket_paths::legacy::typified_paths::public::media_files::bucket_file_path::MediaFileBucketPath;
use enums::by_table::debug_logs::debug_log_level::DebugLogLevel;
use enums::by_table::debug_logs::debug_log_type::DebugLogType;
use enums::by_table::generic_inference_jobs::frontend_failure_category::FrontendFailureCategory;
use enums::by_table::media_files::media_file_class::MediaFileClass;
@@ -101,7 +102,9 @@ pub async fn beeble_webhook_handler(
apriori_debug_log_event_token: Some(debug_log_event_token),
maybe_creator_user_token: job.maybe_creator_user_token.as_ref(),
debug_log_type: DebugLogType::BeebleWebhook,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: None,
maybe_url: None,
message: &raw_body,
mysql_executor: &mut *mysql_connection,
phantom: Default::default(),
@@ -1,6 +1,7 @@
use crate::http_server::common_responses::common_web_error::CommonWebError;
use crate::state::server_state::ServerState;
use actix_web::web::Json;
use enums::by_table::debug_logs::debug_log_level::DebugLogLevel;
use enums::by_table::debug_logs::debug_log_type::DebugLogType;
use enums::by_table::generic_inference_jobs::frontend_failure_category::FrontendFailureCategory;
use fal_client::webhook_payload::raw::webhook_error_type::WebhookErrorType;
@@ -52,7 +53,9 @@ pub async fn handle_failed_fal_webhook(
apriori_debug_log_event_token: Some(debug_log_event_token),
maybe_creator_user_token: job.maybe_creator_user_token.as_ref(),
debug_log_type: DebugLogType::FalWebhook,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Error),
maybe_ip_address: None,
maybe_url: None,
message: raw_body,
mysql_executor: &mut **mysql_connection,
phantom: Default::default(),
@@ -1,4 +1,5 @@
use actix_web::web::Json;
use enums::by_table::debug_logs::debug_log_level::DebugLogLevel;
use enums::by_table::debug_logs::debug_log_type::DebugLogType;
use fal_client::webhook_payload::hydrated::hydrated_webhook_contents::WebhookSuccessData;
use http_server_common::response::response_success_helpers::SimpleGenericJsonSuccess;
@@ -52,7 +53,9 @@ pub async fn handle_successful_fal_webhook(
apriori_debug_log_event_token: Some(debug_log_event_token),
maybe_creator_user_token: job.maybe_creator_user_token.as_ref(),
debug_log_type: DebugLogType::FalWebhook,
maybe_log_level: None,
maybe_log_level: Some(DebugLogLevel::Info),
maybe_ip_address: None,
maybe_url: None,
message: raw_body,
mysql_executor: &mut **mysql_connection,
phantom: Default::default(),
@@ -44,6 +44,7 @@ pub(crate) fn check_common_web_error(
.set_urgency(Some(NotificationUrgency::Medium))
.set_http_method(Some(method.to_string()))
.set_http_path(Some(path.to_string()))
.set_trace_id(metadata.trace_id.clone())
.set_http_status_code(Some(500))
.set_request_ip_address(metadata.request_ip_address.clone())
.set_avt_cookie_token(metadata.avt_cookie_token.clone())
@@ -30,6 +30,7 @@ pub(crate) fn check_status_code_fallback(
.set_urgency(Some(NotificationUrgency::Medium))
.set_http_method(Some(method.to_string()))
.set_http_path(Some(path.to_string()))
.set_trace_id(metadata.trace_id.clone())
.set_http_status_code(Some(status_code))
.set_request_ip_address(metadata.request_ip_address.clone())
.set_avt_cookie_token(metadata.avt_cookie_token.clone())
@@ -2,9 +2,12 @@ use std::sync::Arc;
use actix_web::dev::ServiceRequest;
use actix_web::web;
use actix_web::HttpMessage;
use http_server_common::request::get_request_ip::get_request_ip;
use log::debug;
use trace_id::TraceId;
use crate::state::server_state::ServerState;
/// Optional per-request context extracted by the error alerting middleware
@@ -16,6 +19,8 @@ pub(crate) struct RequestDebuggingMetadata {
pub avt_cookie_token: Option<String>,
pub session_token: Option<String>,
pub session_user_token: Option<String>,
/// Set by `TraceIdMiddleware` (outermost middleware) on every request.
pub trace_id: Option<String>,
}
impl RequestDebuggingMetadata {
@@ -26,6 +31,10 @@ impl RequestDebuggingMetadata {
let request_ip_address = Some(get_request_ip(http_request));
let trace_id = http_request.extensions()
.get::<TraceId>()
.map(|t| t.to_string());
let server_state = req.app_data::<web::Data<Arc<ServerState>>>();
let avt_cookie_token = server_state
@@ -58,6 +67,7 @@ impl RequestDebuggingMetadata {
avt_cookie_token,
session_token,
session_user_token,
trace_id,
}
}
}
@@ -1,3 +1,4 @@
pub mod error_alerting_middleware;
pub mod metrics_middleware;
pub mod pushback_filter_middleware;
pub mod trace_id_middleware;
@@ -0,0 +1 @@
pub mod trace_id_middleware;
@@ -0,0 +1,95 @@
//! Per-request trace id middleware.
//!
//! Generates a unique [`TraceId`] for every inbound HTTP request and makes it
//! available three ways:
//!
//! 1. **Request extensions** — downstream middleware and handlers can read
//! it via `req.extensions().get::<TraceId>()`.
//! 2. **Tokio task-local** — the whole request runs inside
//! [`trace_id::TRACE_ID_TASK_LOCAL`], so `trace_id::current_trace_id()`
//! works from anywhere in the request's task. The env-logger format
//! hook uses this to stamp every log line, and the pager uses it to tag
//! notifications.
//! 3. **`x-trace-id` response header** — so clients and support tickets can
//! quote the id.
//!
//! Register this middleware LAST in the actix `.wrap(...)` chain so it runs
//! FIRST (actix middleware executes in reverse registration order) and every
//! other middleware sees the trace id.
//!
//! NB: Detached `tokio::spawn` tasks do NOT inherit the task-local. Wrap
//! spawned futures in `TRACE_ID_TASK_LOCAL.scope(trace_id, fut)` if they
//! should stay correlated.
use std::future::{Future, Ready, ready};
use std::pin::Pin;
use actix_web::Error;
use actix_web::HttpMessage;
use actix_web::dev::{Service, ServiceRequest, ServiceResponse, Transform};
use actix_web::http::header::{HeaderName, HeaderValue};
use trace_id::{TraceId, TRACE_ID_TASK_LOCAL};
/// Response header carrying the request's trace id.
pub const TRACE_ID_HEADER: &str = "x-trace-id";
#[derive(Clone, Default)]
pub struct TraceIdMiddleware;
impl<S, B> Transform<S, ServiceRequest> for TraceIdMiddleware
where
S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error> + 'static,
S::Future: 'static,
B: 'static,
{
type Response = ServiceResponse<B>;
type Error = Error;
type InitError = ();
type Transform = TraceIdService<S>;
type Future = Ready<Result<Self::Transform, Self::InitError>>;
fn new_transform(&self, service: S) -> Self::Future {
ready(Ok(TraceIdService { service }))
}
}
pub struct TraceIdService<S> {
service: S,
}
impl<S, B> Service<ServiceRequest> for TraceIdService<S>
where
S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error> + 'static,
S::Future: 'static,
B: 'static,
{
type Response = ServiceResponse<B>;
type Error = Error;
type Future = Pin<Box<dyn Future<Output = Result<Self::Response, Self::Error>>>>;
actix_service::forward_ready!(service);
fn call(&self, req: ServiceRequest) -> Self::Future {
let trace_id = TraceId::generate();
// Make the trace id readable from the request itself.
req.extensions_mut().insert(trace_id.clone());
let response_trace_id = trace_id.clone();
let fut = self.service.call(req);
Box::pin(TRACE_ID_TASK_LOCAL.scope(trace_id, async move {
let mut response = fut.await?;
if let Ok(header_value) = HeaderValue::from_str(response_trace_id.as_str()) {
response.headers_mut().insert(
HeaderName::from_static(TRACE_ID_HEADER),
header_value,
);
}
Ok(response)
}))
}
}
+18 -3
View File
@@ -26,6 +26,7 @@ use actix_helpers::middleware::banned_cidr_filter::banned_cidr_filter::BannedCid
use actix_helpers::middleware::banned_ip_filter::banned_ip_filter::BannedIpFilter;
use actix_helpers::middleware::disabled_endpoint_filter::disabled_endpoint_filter::DisabledEndpointFilter;
use actix_multipart::form::MultipartFormConfig;
use actix_web::HttpMessage;
use actix_web::middleware::{DefaultHeaders, Logger};
use actix_web::{middleware, web, App, HttpServer};
use billing_component::stripe::traits::internal_product_to_stripe_lookup::InternalProductToStripeLookup;
@@ -46,6 +47,7 @@ use crate::billing::stripe_internal_user_lookup_impl::StripeInternalUserLookupIm
use crate::http_server::middleware::error_alerting_middleware::error_alerting_middleware::ErrorAlertingMiddleware;
use crate::http_server::middleware::metrics_middleware::metrics_middleware::MetricsMiddleware;
use crate::http_server::middleware::pushback_filter_middleware::PushbackFilter;
use crate::http_server::middleware::trace_id_middleware::trace_id_middleware::TraceIdMiddleware;
use crate::http_server::routes::add_routes::add_routes;
use crate::http_server::web_utils::handle_multipart_error::handle_multipart_error;
use crate::startup::build_dependencies::setup_dependencies;
@@ -65,9 +67,10 @@ pub mod state;
pub mod threads;
pub mod util;
// Report cloudflare trace ID header (CF-Ray) in logs
// Report cloudflare trace ID header (CF-Ray) and our request trace id in logs.
// %{trace_id}xi is resolved by `custom_request_replace` below.
const LOG_FORMAT: &str =
"[%{HOSTNAME}e] IP=[%{X-Forwarded-For}i] %{CF-Ray}i \"%r\" %s %b \"%{Referer}i\" \"%{User-Agent}i\" %T";
"[%{HOSTNAME}e] IP=[%{X-Forwarded-For}i] %{CF-Ray}i %{trace_id}xi \"%r\" %s %b \"%{Referer}i\" \"%{User-Agent}i\" %T";
#[actix_web::main]
async fn main() -> AnyhowResult<()> {
@@ -269,9 +272,21 @@ pub async fn serve(
.wrap(BannedIpFilter::new(ip_ban_list))
.wrap(BannedCidrFilter::new(cidr_ban_set))
.wrap(Logger::new(LOG_FORMAT)
// NB: The access-log line is written after the response body completes,
// which is OUTSIDE the trace-id task-local scope — so we resolve the
// trace id from request extensions at request time instead.
.custom_request_replace("trace_id", |req| {
req.extensions()
.get::<trace_id::TraceId>()
.map(|t| t.to_string())
.unwrap_or_else(|| "-".to_string())
})
.exclude("/liveness")
.exclude("/readiness"))
.wrap(middleware::Compress::default());
.wrap(middleware::Compress::default())
// NB: Registered last => runs FIRST. Every request gets a trace id
// before any other middleware or handler executes.
.wrap(TraceIdMiddleware);
add_routes(app, server_environment)
})
@@ -13,6 +13,18 @@ import {
IconUser,
} from "@tabler/icons-react";
/** Compact form for the header row, eg. "Jul 2, 18:02:47". */
export function formatDebugLogDateTimeCompact(iso: string): string {
return new Date(iso).toLocaleString("en-US", {
month: "short",
day: "numeric",
hour: "2-digit",
minute: "2-digit",
second: "2-digit",
hour12: false,
});
}
export function formatDebugLogDateTime(iso: string): string {
return new Date(iso).toLocaleString("en-US", {
month: "short",
@@ -49,6 +61,11 @@ function getLogTypeBadgeProps(logType: string): {
variant: "secondary",
className: "bg-amber-500/10 text-amber-400 border-transparent",
};
case "backend_failure":
return {
variant: "secondary",
className: "bg-red-500/10 text-red-400 border-transparent",
};
case "kinovi_request":
return {
variant: "secondary",
@@ -86,8 +103,6 @@ export interface DebugLogCardProps {
log: DebugLog;
copiedId: string | null;
onCopy: (value: string, id: string) => void;
/** Show a direct link to the event's debug-logs page in the header row. */
showEventLink?: boolean;
/** Start expanded (defaults to true). */
defaultExpanded?: boolean;
/** Expand/collapse-all broadcast from the page. */
@@ -98,7 +113,6 @@ export function DebugLogCard({
log,
copiedId,
onCopy,
showEventLink = false,
defaultExpanded = true,
expandAll,
}: DebugLogCardProps) {
@@ -135,48 +149,54 @@ export function DebugLogCard({
{log.maybe_log_level.toUpperCase()}
</Badge>
)}
{showEventLink && (
<span className="text-xs text-muted-foreground tabular-nums whitespace-nowrap">
{formatDebugLogDateTimeCompact(log.created_at)}
</span>
{log.maybe_url && (
<span
className="font-mono text-xs text-muted-foreground truncate max-w-[18rem]"
title={log.maybe_url}
>
{log.maybe_url}
</span>
)}
{maybeUser && (
<span
className="inline-flex items-center min-w-0"
onClick={(e) => e.stopPropagation()}
>
<Link
to={`/debug_logs/${encodeURIComponent(log.event_token)}`}
className="font-mono text-xs text-muted-foreground hover:text-foreground hover:underline truncate"
title={`View event ${log.event_token}`}
>
{log.event_token}
</Link>
</span>
)}
{maybeUser && (
<span
className="inline-flex items-center gap-1 text-xs text-muted-foreground min-w-0"
onClick={(e) => e.stopPropagation()}
>
<Link
to={`/user/profile/${encodeURIComponent(maybeUser.username)}`}
className="inline-flex items-center gap-1 hover:underline text-foreground/80 min-w-0"
className="inline-flex items-center gap-1 hover:underline text-foreground/80 text-xs min-w-0"
title={maybeUser.username}
>
<IconUser className="size-3.5 shrink-0" />
<span className="truncate">{maybeUser.display_name}</span>
</Link>
<Link
to={`/debug_logs/user/${encodeURIComponent(maybeUser.user_token)}`}
className="inline-flex items-center gap-1 text-muted-foreground hover:text-foreground shrink-0 hover:underline"
title="View this user's debug logs"
>
<IconListSearch className="size-3.5" />
logs
</Link>
</span>
)}
<span className="text-xs text-muted-foreground tabular-nums whitespace-nowrap">
{formatDebugLogDateTime(log.created_at)}
</span>
<span className="text-xs text-muted-foreground/60 font-mono ml-auto">
#{log.id}
{log.maybe_ip_address && (
<span
className="font-mono text-xs text-muted-foreground truncate min-w-0 max-w-[10rem]"
title={log.maybe_ip_address}
>
{log.maybe_ip_address}
</span>
)}
<span
className="ml-auto inline-flex items-center gap-1.5 min-w-0"
onClick={(e) => e.stopPropagation()}
>
<Link
to={`/debug_logs/${encodeURIComponent(log.event_token)}`}
className="font-mono text-xs text-muted-foreground hover:text-foreground hover:underline truncate"
title={`View event ${log.event_token}`}
>
{log.event_token}
</Link>
<span className="text-xs text-muted-foreground/60 font-mono whitespace-nowrap">
(#{log.id})
</span>
</span>
<span
className="ml-2 inline-flex items-center"
@@ -202,40 +222,53 @@ export function DebugLogCard({
{expanded && (
<div className="border-t border-border/50 p-4 flex flex-col gap-3">
<div className="flex flex-wrap gap-x-6 gap-y-1 text-xs text-muted-foreground">
<div>
<span className="uppercase tracking-wider font-medium">
Event:
</span>{" "}
<Link
to={`/debug_logs/${encodeURIComponent(log.event_token)}`}
className="font-mono text-foreground/80 hover:underline"
>
{log.event_token}
</Link>
</div>
{log.maybe_creator_user_token && (
<span className="inline-flex items-center gap-3 min-w-0">
<button
type="button"
onClick={() =>
onCopy(log.maybe_creator_user_token!, `user_token_${log.id}`)
}
className="inline-flex items-center gap-1 text-muted-foreground hover:text-foreground cursor-pointer min-w-0"
title="Copy user token"
>
<span className="whitespace-nowrap">user token:</span>
<span className="font-mono truncate">
{log.maybe_creator_user_token}
</span>
{copiedId === `user_token_${log.id}` ? (
<IconCheck className="size-3 shrink-0 text-emerald-400" />
) : (
<IconCopy className="size-3 shrink-0 opacity-60" />
)}
</button>
<span className="text-muted-foreground/40">|</span>
{maybeUser && (
{/* Line 1: timestamp, path, ip, event token — all click-to-copy. */}
<div className="flex flex-wrap items-center gap-x-6 gap-y-1 text-xs text-muted-foreground">
<span className="tabular-nums whitespace-nowrap">
{formatDebugLogDateTime(log.created_at)}
</span>
{log.maybe_url && (
<CopyText
label="Path:"
value={log.maybe_url}
display={log.maybe_url}
copyKey={`url_${log.id}`}
copiedId={copiedId}
onCopy={onCopy}
title="Copy URL"
className="font-mono truncate max-w-[32rem]"
/>
)}
{log.maybe_ip_address && (
<CopyText
label="IP:"
value={log.maybe_ip_address}
display={log.maybe_ip_address}
copyKey={`ip_${log.id}`}
copiedId={copiedId}
onCopy={onCopy}
title="Copy IP address"
className="font-mono truncate max-w-[16rem]"
/>
)}
<CopyText
label="Event Token:"
value={log.event_token}
display={log.event_token}
copyKey={`event_${log.id}`}
copiedId={copiedId}
onCopy={onCopy}
title="Copy event token"
className="font-mono truncate"
/>
</div>
{/* Line 2: the user and their event logs. */}
{log.maybe_creator_user_token && (
<div className="flex flex-wrap items-center gap-x-6 gap-y-1 text-xs text-muted-foreground">
<span className="inline-flex items-center gap-1.5 min-w-0">
<span className="whitespace-nowrap">User:</span>
{maybeUser ? (
<Link
to={`/user/profile/${encodeURIComponent(maybeUser.username)}`}
className="inline-flex items-center gap-1.5 text-foreground/80 hover:text-foreground hover:underline min-w-0"
@@ -244,18 +277,29 @@ export function DebugLogCard({
<IconUser className="size-3.5 shrink-0" />
<span className="truncate">{maybeUser.display_name}</span>
</Link>
) : (
<CopyText
value={log.maybe_creator_user_token}
display={log.maybe_creator_user_token}
copyKey={`user_token_${log.id}`}
copiedId={copiedId}
onCopy={onCopy}
title="Copy user token"
className="font-mono truncate"
icon={<IconUser className="size-3.5 shrink-0" />}
/>
)}
<Link
to={`/debug_logs/user/${encodeURIComponent(log.maybe_creator_user_token)}`}
className="inline-flex items-center gap-1 text-muted-foreground hover:text-foreground hover:underline shrink-0"
title="View this user's debug logs"
>
<IconListSearch className="size-3.5" />
logs
</Link>
</span>
)}
</div>
<Link
to={`/debug_logs/user/${encodeURIComponent(log.maybe_creator_user_token)}`}
className="inline-flex items-center gap-1 hover:text-foreground hover:underline shrink-0"
title="View this user's debug logs"
>
<IconListSearch className="size-3.5" />
user event logs
</Link>
</div>
)}
<PrettyPayload raw={log.message} />
</div>
)}
@@ -263,6 +307,52 @@ export function DebugLogCard({
);
}
interface CopyTextProps {
/** Optional label rendered before the value, eg. "Path:". */
label?: string;
/** The raw value copied to the clipboard. */
value: string;
/** The rendered text (may differ from the copied value). */
display: string;
copyKey: string;
copiedId: string | null;
onCopy: (value: string, id: string) => void;
title: string;
className?: string;
icon?: React.ReactNode;
}
function CopyText({
label,
value,
display,
copyKey,
copiedId,
onCopy,
title,
className,
icon,
}: CopyTextProps) {
return (
<button
type="button"
onClick={() => onCopy(value, copyKey)}
className="inline-flex items-center gap-1 hover:text-foreground cursor-pointer min-w-0"
title={title}
>
{label && <span className="whitespace-nowrap">{label}</span>}
{icon}
<span className={className}>{display}</span>
{copiedId === copyKey ? (
<IconCheck className="size-3 shrink-0 text-emerald-400" />
) : (
<IconCopy className="size-3 shrink-0 opacity-60" />
)}
</button>
);
}
function tryParseJson(raw: string): unknown | undefined {
const trimmed = raw.trim();
if (
@@ -269,7 +269,6 @@ export function DebugLogsAll() {
log={log}
copiedId={copiedId}
onCopy={copy}
showEventLink
defaultExpanded={false}
expandAll={expandAll}
/>
@@ -254,7 +254,6 @@ export function UserDebugLogs() {
log={log}
copiedId={copiedId}
onCopy={copy}
showEventLink
defaultExpanded={false}
expandAll={expandAll}
/>
@@ -109,6 +109,7 @@ export type DebugLogType =
| "fal_queue"
| "fal_webhook"
| "kinovi_request"
| "backend_failure"
| (string & {});
export type DebugLogLevel =
@@ -126,6 +127,8 @@ export interface DebugLog {
id: number;
maybe_log_level: DebugLogLevel | null;
maybe_creator_user_token: string | null;
maybe_ip_address: string | null;
maybe_url: string | null;
message: string;
maybe_user: DebugLogUser | null;
}
+1 -1
View File
@@ -24,7 +24,7 @@ if (import.meta.env.DEV) {
// (disabled — it overrides the origin above and points at localhost:12345,
// which breaks dev unless a local backend is running. Re-enable only when
// testing against a local storyteller-web.)
//StorytellerApiHostStore.getInstance().setDevelopment();
StorytellerApiHostStore.getInstance().setDevelopment();
} catch (e) {
console.warn("Failed to set dev API host override", e);
}
+88 -168
View File
File diff suppressed because it is too large Load Diff