A lexicon-driven AppView for ATProto.
Something went wrong. Try again.
12345678910111213141516171819202122232425262728293031323334353637383940414243444546474849505152535455565758596061626364656667686970717273747576777879808182838485868788899091929394959697989910010110210310410510610710810911011111211311411511611711811912012112212312412512612712812913013113213313413513613713813914014114214314414514614714814915015115215315415515615715815916016116216316416516616716816917017117217317417517617717817918018118218318418518618718818919019119219319419519619719819920020120220320420520620720820921021121221321421521621721821922022122222322422522622722822923023123223323423523623723823924024124224324424524624724824925025125225325425525625725825926026126226326426526626726826927027127227327427527627727827928028128228328428528628728828929029129229329429529629729829930030130230330430530630730830931031131231331431531631731831932032132232332432532632732832933033133233333433533633733833934034134234334434534634734834935035135235335435535635735835936036136236336436536636736836937037137237337437537637737837938038138238338438538638738838939039139239339439539639739839940040140240340440540640740840941041141241341441541641741841942042142242342442542642742842943043143243343443543643743843944044144244344444544644744844945045145245345445545645745845946046146246346446546646746846947047147247347447547647747847948048148248348448548648748848949049149249349449549649749849950050150250350450550650750850951051151251351451551651751851952052152252352452552652752852953053153253353453553653753853954054154254354454554654754854955055155255355455555655755855956056156256356456556656756856957057157257357457557657757857958058158258358458558658758858959059159259359459559659759859960060160260360460560660760860961061161261361461561661761861962062162262362462562662762862963063163263363463563663763863964064164264364464564664764864965065165265365465565665765865966066166266366466566666766866967067167267367467567667767867968068168268368468568668768868969069169269369469569669769869970070170270370470570670770870971071171271371471571671771871972072172272372472572672772872973073173273373473573673773873974074174274374474574674774874975075175275375475575675775875976076176276376476576676776876977077177277377477577677777877978078178278378478578678778878979079179279379479579679779879980080180280380480580680780880981081181281381481581681781881982082182282382482582682782882983083183283383483583683783883984084184284384484584684784884985085185285385485585685785885986086186286386486586686786886987087187287387487587687787887988088188288388488588688788888989089189289389489589689789889990090190290390490590690790890991091191291391491591691791891992092192292392492592692792892993093193293393493593693793893994094194294394494594694794894995095195295395495595695795895996096196296396496596696796896997097197297397497597697797897998098198298398498598698798898999099199299399499599699799899910001001100210031004100510061007100810091010101110121013101410151016101710181019102010211022102310241025102610271028102910301031103210331034103510361037103810391040104110421043104410451046104710481049105010511052105310541055105610571058105910601061106210631064106510661067106810691070107110721073107410751076107710781079108010811082108310841085108610871088108910901091109210931094109510961097109810991100110111021103110411051106110711081109111011111112111311141115111611171118111911201121112211231124112511261127112811291130113111321133113411351136113711381139114011411142114311441145114611471148114911501151115211531154115511561157115811591160116111621163116411651166116711681169117011711172117311741175117611771178117911801181118211831184118511861187118811891190119111921193119411951196119711981199120012011202120312041205120612071208120912101211121212131214121512161217121812191220122112221223122412251226122712281229123012311232123312341235123612371238123912401241124212431244124512461247124812491250125112521253125412551256125712581259126012611262126312641265126612671268126912701271127212731274127512761277use axum::Json;use axum::response::{IntoResponse, Response};use mlua::LuaSerdeExt;use serde_json::Value;use std::collections::HashMap;use std::sync::Arc;use std::sync::atomic::Ordering;use std::time::Instant;
use crate::AppState;use crate::auth::Claims;use crate::db::{DatabaseBackend, adapt_sql};use crate::error::{AppError, LUA_AUTH_ERROR_PREFIX, ScriptErrorType, parse_lua_line};use crate::event_log::{EventLog, Severity, log_event};use crate::lexicon::ParsedLexicon;use crate::repo;use crate::telemetry::counters::Counters;
use super::atproto_api;use super::context;use super::db_api;use super::http_api;use super::record;use super::sandbox;
struct ScriptTimingGuard { counters: Arc<Counters>, start: Instant,}
impl Drop for ScriptTimingGuard { fn drop(&mut self) { let elapsed_us = u64::try_from(self.start.elapsed().as_micros()).unwrap_or(u64::MAX); crate::telemetry::counters::add_saturating(&self.counters.script_runtime_us, elapsed_us); self.counters .script_executions .fetch_add(1, Ordering::Relaxed); }}
/// Load all script variables from the database as a key-value map.async fn load_env_vars(db: &sqlx::AnyPool, backend: DatabaseBackend) -> HashMap<String, String> { let sql = adapt_sql("SELECT key, value FROM happyview_script_variables", backend); crate::db::query_as::<(String, String)>(&sql) .fetch_all(db) .await .unwrap_or_default() .into_iter() .collect()}
/// Execute a Lua script for a procedure endpoint.#[allow(clippy::too_many_arguments)]pub async fn execute_procedure_script( state: &AppState, method: &str, claims: &Claims, input: &Value, params: &std::collections::HashMap<String, Value>, lexicon: &ParsedLexicon, script: &str, space_ctx: Option<&context::SpaceContext>, delegate_did: Option<&str>,) -> Result<Response, AppError> { let start = Instant::now(); let _script_timing = ScriptTimingGuard { counters: state.telemetry_counters.clone(), start, }; let backend = state.db_backend; let span = tracing::info_span!( "script.execute", method = method, script_type = "procedure", caller_did = %claims.did(), ); span.in_scope(|| tracing::info!("script execution started")); let collection = lexicon.target_collection.as_deref().unwrap_or_default();
// Capture script source and input for error logging before anything is consumed. let script_source = script.to_string(); let input_json = input.clone();
let pds_auth: Option<repo::PdsAuth> = if let Some(client_key) = claims.client_key() { let encryption_key = state .config .token_encryption_key .as_ref() .ok_or_else(|| AppError::Internal("TOKEN_ENCRYPTION_KEY not configured".into()))?; let api_client_id = match repo::get_dpop_client_id(state, client_key).await { Ok(id) => id, Err(e) => { let error_message = format!("{e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(e); } }; let dpop_key_id = claims .dpop_key_id() .ok_or_else(|| AppError::Internal("DPoP key ID not available in claims".into()))? .to_string(); Some(repo::PdsAuth::Dpop { api_client_id, dpop_key_id, encryption_key: *encryption_key, }) } else { repo::get_oauth_session(state, claims.did()) .await .ok() .map(|s| repo::PdsAuth::OAuth(Arc::new(s))) };
let lua = match sandbox::create_sandbox() { Ok(l) => l, Err(e) => { let error_message = format!("failed to create Lua VM: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); } };
let state_arc = Arc::new(state.clone()); let claims_arc = Arc::new(claims.clone()); let pds_auth_arc = pds_auth.map(Arc::new);
if let Err(e) = db_api::register_db_api(&lua, state_arc.clone()) { let error_message = format!("failed to register db API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = http_api::register_http_api(&lua, state_arc.clone()) { let error_message = format!("failed to register http API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = super::xrpc_api::register_xrpc_api(&lua, state_arc.clone(), Some(claims.did().to_string())) { let error_message = format!("failed to register xrpc API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = atproto_api::register_atproto_api(&lua, state_arc.clone(), Some(claims.did())) { let error_message = format!("failed to register atproto API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = crate::lua::spaces_api::register_spaces_write_api( &lua, state_arc.clone(), Some(claims.did()), ) { let error_message = format!("failed to register spaces write API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = crate::lua::linked_repos_api::register_linked_repos_api(&lua, state_arc.clone()) { let error_message = format!("failed to register linked repos API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Some(ref pds_auth) = pds_auth_arc && let Err(e) = atproto_api::register_atproto_blob_api( &lua, state_arc.clone(), claims_arc.clone(), pds_auth.clone(), ) { let error_message = format!("failed to register atproto blob API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = super::jobs_api::register_jobs_api( &lua, state_arc.clone(), Some(super::jobs_api::JobsCaller { did: claims.did().to_string(), api_client_id: pds_auth_arc.as_ref().and_then(|a| match a.as_ref() { repo::PdsAuth::Dpop { api_client_id, .. } => Some(api_client_id.clone()), _ => None, }), dpop_key_id: pds_auth_arc.as_ref().and_then(|a| match a.as_ref() { repo::PdsAuth::Dpop { dpop_key_id, .. } => Some(dpop_key_id.clone()), _ => None, }), }), ) { let error_message = format!("failed to register jobs API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = record::register_record_api( &lua, state_arc.clone(), Some(claims_arc), pds_auth_arc, delegate_did.map(|s| s.to_string()), ) { let error_message = format!("failed to register Record API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
// Override the sandbox's tracing-only `log()` with a version that // also writes a `script.log` row to `event_logs` so operators can // see script output from the dashboard. The xrpc trigger id is // computed from the lexicon's id + procedure type. let trigger_id = format!("xrpc.procedure:{}", lexicon.id); if let Err(e) = super::scripts::register_log_event_api(&lua, &state_arc, &trigger_id, Some(claims.did())) { let error_message = format!("failed to register log API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = context::set_procedure_context( &lua, method, input, params, claims.did(), collection, space_ctx, delegate_did, ) { let error_message = format!("failed to set context: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = context::set_env_context(&lua, &load_env_vars(&state.db, backend).await) { let error_message = format!("failed to set env context: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = lua.load(script).exec() { let error_message = format!("{e}"); tracing::error!(method, error = %e, "lua script load failed"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; let (line, clean_msg) = parse_lua_line(&error_message); return Err(AppError::ScriptError { error_type: ScriptErrorType::Syntax, message: clean_msg, method: method.to_string(), line, }); }
let handle: mlua::Function = match lua.globals().get("handle") { Ok(f) => f, Err(e) => { let error_message = format!("{e}"); tracing::error!(method, error = %e, "lua script missing handle function"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::ScriptError { error_type: ScriptErrorType::MissingHandle, message: "script does not define a handle() function".to_string(), method: method.to_string(), line: None, }); } };
let result: mlua::Value = match handle.call_async(()).await { Ok(r) => r, Err(e) => { let msg = e.to_string(); tracing::error!(method, error = %msg, "lua script execution failed"); let (line, clean_msg) = parse_lua_line(&msg); let app_error = if msg.contains(LUA_AUTH_ERROR_PREFIX) || clean_msg.contains(LUA_AUTH_ERROR_PREFIX) { let auth_msg = clean_msg .strip_prefix(LUA_AUTH_ERROR_PREFIX) .unwrap_or(&clean_msg) .to_string(); AppError::Auth(auth_msg) } else if msg.contains("execution limit") { AppError::ScriptError { error_type: ScriptErrorType::Timeout, message: "script exceeded execution time limit".to_string(), method: method.to_string(), line, } } else { AppError::ScriptError { error_type: ScriptErrorType::Runtime, message: clean_msg, method: method.to_string(), line, } }; log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": msg, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(app_error); } };
let json_value: Value = match lua.from_value(result) { Ok(v) => v, Err(e) => { let error_message = format!("{e}"); tracing::error!(method, error = %e, "failed to convert lua result to JSON"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "input": input_json, "caller_did": claims.did(), "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::ScriptError { error_type: ScriptErrorType::Runtime, message: error_message, method: method.to_string(), line: None, }); } };
span.in_scope(|| { tracing::info!( duration_ms = start.elapsed().as_millis() as u64, "script execution completed" ); }); log_event( &state.db, EventLog { event_type: "script.executed".to_string(), severity: Severity::Info, actor_did: Some(claims.did().to_string()), subject: Some(method.to_string()), detail: serde_json::json!({ "method": method, "caller_did": claims.did(), "duration_ms": start.elapsed().as_millis() as u64, "response_size": json_value.to_string().len(), "input": input_json, "response": json_value, }), }, backend, ) .await;
Ok(Json(json_value).into_response())}
/// Execute a Lua script for a query endpoint.pub async fn execute_query_script( state: &AppState, method: &str, params: &HashMap<String, serde_json::Value>, lexicon: &ParsedLexicon, script: &str, claims: Option<&Claims>, space_ctx: Option<&context::SpaceContext>,) -> Result<Response, AppError> { let start = Instant::now(); let _script_timing = ScriptTimingGuard { counters: state.telemetry_counters.clone(), start, }; let backend = state.db_backend; let span = tracing::info_span!("script.execute", method = method, script_type = "query",); span.in_scope(|| tracing::info!("script execution started")); let collection = lexicon.target_collection.as_deref().unwrap_or_default();
// Capture script source for error logging. let script_source = script.to_string();
let lua = match sandbox::create_sandbox() { Ok(l) => l, Err(e) => { let error_message = format!("failed to create Lua VM: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); } };
let state_arc = Arc::new(state.clone());
if let Err(e) = db_api::register_db_api(&lua, state_arc.clone()) { let error_message = format!("failed to register db API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = http_api::register_http_api(&lua, state_arc.clone()) { let error_message = format!("failed to register http API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = super::xrpc_api::register_xrpc_api( &lua, state_arc.clone(), claims.map(|c| c.did().to_string()), ) { let error_message = format!("failed to register xrpc API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = atproto_api::register_atproto_api(&lua, state_arc.clone(), claims.map(|c| c.did())) { let error_message = format!("failed to register atproto API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = crate::lua::spaces_api::register_spaces_write_api( &lua, state_arc.clone(), claims.map(|c| c.did()), ) { let error_message = format!("failed to register spaces write API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = crate::lua::linked_repos_api::register_linked_repos_api(&lua, state_arc.clone()) { let error_message = format!("failed to register linked repos API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
// Register the Record API in no-auth mode. Queries don't have a PDS // auth context — the local-only methods (Record.load, :save_local, // :delete_local, Record.delete_local) work; PDS-touching variants // error with the no-PDS-auth message. if let Err(e) = record::register_record_api_no_auth(&lua, state_arc.clone()) { let error_message = format!("failed to register Record API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
// Override the sandbox's tracing-only `log()` with a version that // also writes a `script.log` row to `event_logs`. let trigger_id = format!("xrpc.query:{}", lexicon.id); if let Err(e) = super::scripts::register_log_event_api( &lua, &state_arc, &trigger_id, claims.map(|c| c.did()), ) { let error_message = format!("failed to register log API: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = context::set_query_context( &lua, method, params, collection, claims.map(|c| c.did()), space_ctx, ) { let error_message = format!("failed to set context: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = context::set_env_context(&lua, &load_env_vars(&state.db, backend).await) { let error_message = format!("failed to set env context: {e}"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::Internal(error_message)); }
if let Err(e) = lua.load(script).exec() { let error_message = format!("{e}"); tracing::error!(method, error = %e, "lua script load failed"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; let (line, clean_msg) = parse_lua_line(&error_message); return Err(AppError::ScriptError { error_type: ScriptErrorType::Syntax, message: clean_msg, method: method.to_string(), line, }); }
let handle: mlua::Function = match lua.globals().get("handle") { Ok(f) => f, Err(e) => { let error_message = format!("{e}"); tracing::error!(method, error = %e, "lua script missing handle function"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::ScriptError { error_type: ScriptErrorType::MissingHandle, message: "script does not define a handle() function".to_string(), method: method.to_string(), line: None, }); } };
let result: mlua::Value = match handle.call_async(()).await { Ok(r) => r, Err(e) => { let msg = e.to_string(); tracing::error!(method, error = %msg, "lua script execution failed"); let (line, clean_msg) = parse_lua_line(&msg); let app_error = if msg.contains(LUA_AUTH_ERROR_PREFIX) || clean_msg.contains(LUA_AUTH_ERROR_PREFIX) { let auth_msg = clean_msg .strip_prefix(LUA_AUTH_ERROR_PREFIX) .unwrap_or(&clean_msg) .to_string(); AppError::Auth(auth_msg) } else if msg.contains("execution limit") { AppError::ScriptError { error_type: ScriptErrorType::Timeout, message: "script exceeded execution time limit".to_string(), method: method.to_string(), line, } } else { AppError::ScriptError { error_type: ScriptErrorType::Runtime, message: clean_msg, method: method.to_string(), line, } }; log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": msg, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(app_error); } };
let json_value: Value = match lua.from_value(result) { Ok(v) => v, Err(e) => { let error_message = format!("{e}"); tracing::error!(method, error = %e, "failed to convert lua result to JSON"); log_event( &state.db, EventLog { event_type: "script.error".to_string(), severity: Severity::Error, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "error": error_message, "script_source": script_source, "method": method, "duration_ms": start.elapsed().as_millis() as u64, }), }, backend, ) .await; return Err(AppError::ScriptError { error_type: ScriptErrorType::Runtime, message: error_message, method: method.to_string(), line: None, }); } };
span.in_scope(|| { tracing::info!( duration_ms = start.elapsed().as_millis() as u64, "script execution completed" ); }); log_event( &state.db, EventLog { event_type: "script.executed".to_string(), severity: Severity::Info, actor_did: None, subject: Some(method.to_string()), detail: serde_json::json!({ "method": method, "duration_ms": start.elapsed().as_millis() as u64, "response_size": json_value.to_string().len(), "params": params, "response": json_value, }), }, backend, ) .await;
Ok(Json(json_value).into_response())}
#[cfg(test)]mod tests { use super::*; use crate::lexicon::{LexiconType, ProcedureAction}; use crate::test_support::{memory_pool, test_state_with_pool};
fn query_lexicon() -> ParsedLexicon { ParsedLexicon { id: "com.example.probe".to_string(), lexicon_type: LexiconType::Query, record_key: None, parameters: None, input: None, output: None, record_schema: None, raw: serde_json::json!({ "id": "com.example.probe" }), revision: 1, target_collection: Some("com.example.probe".to_string()), action: ProcedureAction::Upsert, token_cost: None, space_type: None, space_name: None, space_collections: None, } }
#[tokio::test] async fn successful_script_execution_moves_the_script_counters() { let state = test_state_with_pool(memory_pool().await); let lexicon = query_lexicon(); let params = HashMap::new(); let counters = state.telemetry_counters.clone();
let result = execute_query_script( &state, "com.example.probe", ¶ms, &lexicon, "function handle() return { ok = true } end", None, None, ) .await;
assert!( result.is_ok(), "script should have executed: {:?}", result.err() ); assert_eq!(counters.script_executions.load(Ordering::Relaxed), 1); }
#[tokio::test] async fn a_script_missing_handle_still_moves_the_script_counters() { let state = test_state_with_pool(memory_pool().await); let lexicon = query_lexicon(); let params = HashMap::new(); let counters = state.telemetry_counters.clone();
let result = execute_query_script( &state, "com.example.probe", ¶ms, &lexicon, "local unused = 1", None, None, ) .await;
assert!( result.is_err(), "script has no handle() function, so this must error" ); assert_eq!(counters.script_executions.load(Ordering::Relaxed), 1); }
#[tokio::test] async fn a_lua_runtime_error_still_moves_the_script_counters() { // `handle()` runs and raises — a different early return than the // "missing handle" case (this one comes from `handle.call_async` // failing, not from `lua.globals().get("handle")` failing). let state = test_state_with_pool(memory_pool().await); let lexicon = query_lexicon(); let params = HashMap::new(); let counters = state.telemetry_counters.clone();
let result = execute_query_script( &state, "com.example.probe", ¶ms, &lexicon, "function handle() error('boom') end", None, None, ) .await;
assert!(result.is_err()); assert_eq!(counters.script_executions.load(Ordering::Relaxed), 1); }
#[tokio::test] async fn script_counters_accumulate_across_calls_on_the_same_counters() { let state = test_state_with_pool(memory_pool().await); let lexicon = query_lexicon(); let params = HashMap::new(); let counters = state.telemetry_counters.clone();
for _ in 0..20 { let _ = execute_query_script( &state, "com.example.probe", ¶ms, &lexicon, "function handle() return {} end", None, None, ) .await; }
assert_eq!(counters.script_executions.load(Ordering::Relaxed), 20); assert!( counters.script_runtime_us.load(Ordering::Relaxed) > 0, "20 script executions should accumulate measurable wall-clock time" ); }}