Skip to main content

platform_runtime/
functions.rs

1use crate::retries::RetryPolicy;
2use async_trait::async_trait;
3use chrono::{DateTime, Utc};
4use platform_core::{
5    ActorContext, AppError, AppResult, CorrelationId, DbPool, ErrorCode, ExecutionContext,
6    ExecutionId, ExecutionLogCaptureReport, ExecutionLogCaptureStatus, ExecutionLogScope,
7    ExecutionLogWriter, PostgresExecutionLogWriter, RuntimeSpanAttributes, TenantId, TraceContext,
8    capture_execution_logs, db::DbTransaction, record_runtime_span_attributes,
9    trace_context_from_headers, trace_headers,
10};
11use serde::{Deserialize, Serialize};
12use serde_json::Value;
13use std::collections::BTreeMap;
14use std::fmt::Debug;
15use std::sync::Arc;
16use std::time::{Duration, Instant};
17use tracing::Instrument;
18use uuid::Uuid;
19
20const STALE_PROCESSING_LOCK_SECONDS: i64 = 300;
21
22#[async_trait]
23pub trait FunctionHandler: Debug + Send + Sync {
24    async fn call(&self, ctx: ExecutionContext, input: Value) -> AppResult<Value>;
25
26    fn observability(&self) -> Option<FunctionHandlerObservability> {
27        None
28    }
29}
30
31pub use FunctionHandler as RuntimeFunction;
32
33#[derive(Debug, Clone, PartialEq, Eq)]
34pub struct FunctionHandlerObservability {
35    pub source: String,
36    pub attributes: Value,
37}
38
39impl FunctionHandlerObservability {
40    pub fn new(source: impl Into<String>, attributes: Value) -> Self {
41        Self {
42            source: source.into(),
43            attributes: normalize_log_attributes(attributes),
44        }
45    }
46}
47
48#[derive(Debug, Clone, Copy, PartialEq, Eq)]
49enum ExecutionLogSeverity {
50    Info,
51    Error,
52}
53
54impl ExecutionLogSeverity {
55    fn as_str(self) -> &'static str {
56        match self {
57            Self::Info => "info",
58            Self::Error => "error",
59        }
60    }
61}
62
63#[derive(Debug, Clone)]
64pub struct FunctionDefinition {
65    pub name: String,
66    pub version: u16,
67    pub queue: String,
68    pub retry_policy: RetryPolicy,
69    pub handler: Arc<dyn FunctionHandler>,
70}
71
72#[derive(Debug, Default, Clone)]
73pub struct FunctionRegistry {
74    functions: BTreeMap<String, FunctionDefinition>,
75}
76
77impl FunctionRegistry {
78    pub fn register(&mut self, function: FunctionDefinition) {
79        self.functions.insert(function.name.clone(), function);
80    }
81
82    pub fn get(&self, name: &str) -> Option<&FunctionDefinition> {
83        self.functions.get(name)
84    }
85
86    pub fn all(&self) -> impl Iterator<Item = &FunctionDefinition> {
87        self.functions.values()
88    }
89}
90
91#[derive(Debug, Clone, Copy, PartialEq, Eq, Deserialize, Serialize)]
92#[serde(rename_all = "snake_case")]
93pub enum FunctionRunStatus {
94    Pending,
95    Processing,
96    Completed,
97    Failed,
98    Dead,
99}
100
101#[derive(Debug, Clone, Copy, PartialEq, Eq, Deserialize, Serialize)]
102#[serde(rename_all = "snake_case")]
103pub enum FunctionTenancyMode {
104    None,
105    Optional,
106    Required,
107}
108
109impl FunctionTenancyMode {
110    const fn as_str(self) -> &'static str {
111        match self {
112            Self::None => "none",
113            Self::Optional => "optional",
114            Self::Required => "required",
115        }
116    }
117
118    const fn accepts(self, tenant_id: Option<&TenantId>) -> bool {
119        match self {
120            Self::None => tenant_id.is_none(),
121            Self::Optional => true,
122            Self::Required => tenant_id.is_some(),
123        }
124    }
125}
126
127impl FunctionRunStatus {
128    fn as_str(self) -> &'static str {
129        match self {
130            Self::Pending => "pending",
131            Self::Processing => "processing",
132            Self::Completed => "completed",
133            Self::Failed => "failed",
134            Self::Dead => "dead",
135        }
136    }
137}
138
139#[derive(Debug, Clone)]
140pub struct EnqueueFunctionRequest {
141    pub function_name: String,
142    pub input_json: Value,
143    pub correlation_id: CorrelationId,
144    pub actor: ActorContext,
145    pub tenant_id: Option<TenantId>,
146    pub tenancy_mode: FunctionTenancyMode,
147    pub trace: TraceContext,
148    pub causation_id: Option<String>,
149    pub max_attempts: Option<i32>,
150}
151
152#[derive(Debug, Clone, Deserialize, Serialize)]
153pub struct ClaimedFunctionRun {
154    pub id: String,
155    pub function_name: String,
156    pub input_json: Value,
157    pub attempts: i32,
158    pub max_attempts: i32,
159    pub correlation_id: String,
160    pub actor: ActorContext,
161    pub tenant_id: Option<TenantId>,
162    pub tenancy_mode: FunctionTenancyMode,
163    pub trace: TraceContext,
164    pub causation_id: Option<String>,
165}
166
167#[derive(Debug, Clone)]
168pub struct RuntimeClient {
169    pool: DbPool,
170    service_name: String,
171}
172
173impl RuntimeClient {
174    pub fn new(pool: DbPool) -> Self {
175        Self {
176            pool,
177            service_name: "lenso".to_owned(),
178        }
179    }
180
181    #[must_use]
182    pub fn with_service_name(mut self, service_name: impl Into<String>) -> Self {
183        self.service_name = service_name.into();
184        self
185    }
186
187    pub async fn enqueue_function(&self, request: EnqueueFunctionRequest) -> AppResult<String> {
188        let mut tx = self.pool.begin().await.map_err(map_runtime_error)?;
189        let run = self.enqueue_function_in_tx(&mut tx, request).await?;
190        tx.commit().await.map_err(map_runtime_error)?;
191        self.record_function_enqueued(&run).await;
192        Ok(run.id)
193    }
194
195    /// Enqueues one function run with a caller-owned durable identity inside an
196    /// existing Host transaction. This is used by durable transport adapters
197    /// that must atomically commit their own receipt and Runtime work.
198    pub async fn enqueue_function_with_id_in_tx(
199        &self,
200        tx: &mut DbTransaction<'_>,
201        run_id: impl Into<String>,
202        request: EnqueueFunctionRequest,
203    ) -> AppResult<()> {
204        self.enqueue_function_in_tx_with_id(tx, run_id.into(), request)
205            .await
206            .map(|_| ())
207    }
208
209    pub(crate) async fn enqueue_function_in_tx(
210        &self,
211        tx: &mut DbTransaction<'_>,
212        request: EnqueueFunctionRequest,
213    ) -> AppResult<EnqueuedFunctionRun> {
214        self.enqueue_function_in_tx_with_id(tx, format!("fnrun_{}", Uuid::now_v7()), request)
215            .await
216    }
217
218    async fn enqueue_function_in_tx_with_id(
219        &self,
220        tx: &mut DbTransaction<'_>,
221        id: String,
222        request: EnqueueFunctionRequest,
223    ) -> AppResult<EnqueuedFunctionRun> {
224        if !request.tenancy_mode.accepts(request.tenant_id.as_ref()) {
225            return Err(AppError::new(
226                ErrorCode::Validation,
227                "function tenant context is incompatible with its tenancy mode",
228            ));
229        }
230        let max_attempts = request.max_attempts.unwrap_or(3);
231        let mut input_json = request.input_json;
232        attach_runtime_context_to_input(
233            &mut input_json,
234            &request.correlation_id,
235            &request.trace,
236            request.causation_id.as_deref(),
237        );
238        let span = tracing::info_span!(
239            "function_enqueue",
240            lenso.correlation_id = tracing::field::Empty,
241            lenso.story_id = tracing::field::Empty,
242            lenso.function_run_id = tracing::field::Empty,
243            lenso.execution.kind = tracing::field::Empty,
244            lenso.execution.name = tracing::field::Empty,
245        );
246        record_runtime_span_attributes(
247            &span,
248            &RuntimeSpanAttributes::function(
249                request.correlation_id.0.clone(),
250                id.clone(),
251                request.function_name.clone(),
252            ),
253        );
254
255        async {
256            sqlx::query(
257                r#"
258                insert into runtime.function_runs (
259                    id,
260                    function_name,
261                    input_json,
262                    max_attempts,
263                    correlation_id,
264                    actor,
265                    tenant_id,
266                    tenancy_mode
267                )
268                values ($1, $2, $3, $4, $5, $6, $7, $8)
269                "#,
270            )
271            .bind(&id)
272            .bind(&request.function_name)
273            .bind(&input_json)
274            .bind(max_attempts)
275            .bind(&request.correlation_id.0)
276            .bind(serde_json::to_value(&request.actor).map_err(map_serde_error)?)
277            .bind(request.tenant_id.as_ref().map(|tenant| &tenant.0))
278            .bind(request.tenancy_mode.as_str())
279            .execute(&mut **tx)
280            .await
281            .map_err(map_runtime_error)
282        }
283        .instrument(span)
284        .await?;
285
286        Ok(EnqueuedFunctionRun {
287            id,
288            function_name: request.function_name,
289            correlation_id: request.correlation_id.0,
290            trace: request.trace,
291            max_attempts,
292        })
293    }
294
295    pub(crate) async fn record_function_enqueued(&self, run: &EnqueuedFunctionRun) {
296        self.record_function_execution_log(
297            &FunctionLogContext {
298                id: run.id.clone(),
299                function_name: run.function_name.clone(),
300                correlation_id: run.correlation_id.clone(),
301                trace: run.trace.clone(),
302            },
303            ExecutionLogSeverity::Info,
304            "Function run enqueued",
305            serde_json::json!({
306                "attempt": 0,
307                "max_attempts": run.max_attempts,
308            }),
309        )
310        .await;
311    }
312
313    async fn record_function_execution_log(
314        &self,
315        run: &FunctionLogContext,
316        severity: ExecutionLogSeverity,
317        body: &'static str,
318        attributes: Value,
319    ) {
320        emit_function_lifecycle_event(run, severity, body, &attributes, None);
321        if let Err(error) = insert_execution_log_projection(
322            &self.pool,
323            function_log_record(run, severity, body, attributes, &self.service_name),
324        )
325        .await
326        {
327            tracing::warn!(
328                error = ?error,
329                function_run_id = %run.id,
330                "failed to write function execution log"
331            );
332        }
333    }
334}
335
336#[derive(Debug, Clone)]
337pub(crate) struct EnqueuedFunctionRun {
338    pub id: String,
339    function_name: String,
340    correlation_id: String,
341    trace: TraceContext,
342    max_attempts: i32,
343}
344
345#[derive(Debug, Clone)]
346pub struct RuntimeWorker {
347    pool: DbPool,
348    registry: Arc<FunctionRegistry>,
349    worker_id: String,
350    service_name: String,
351    execution_log_writer: Option<Arc<dyn ExecutionLogWriter>>,
352}
353
354impl RuntimeWorker {
355    pub fn new(
356        pool: DbPool,
357        registry: Arc<FunctionRegistry>,
358        worker_id: impl Into<String>,
359    ) -> Self {
360        let execution_log_writer = Arc::new(PostgresExecutionLogWriter::new(pool.clone()));
361        Self {
362            pool,
363            registry,
364            worker_id: worker_id.into(),
365            service_name: "lenso".to_owned(),
366            execution_log_writer: Some(execution_log_writer),
367        }
368    }
369
370    #[must_use]
371    pub fn with_service_name(mut self, service_name: impl Into<String>) -> Self {
372        self.service_name = service_name.into();
373        self
374    }
375
376    #[must_use]
377    #[doc(hidden)]
378    pub fn with_execution_log_writer(
379        mut self,
380        execution_log_writer: Arc<dyn ExecutionLogWriter>,
381    ) -> Self {
382        self.execution_log_writer = Some(execution_log_writer);
383        self
384    }
385
386    #[must_use]
387    #[doc(hidden)]
388    pub fn without_execution_log_capture(mut self) -> Self {
389        self.execution_log_writer = None;
390        self
391    }
392
393    pub async fn claim_batch(&self, batch_size: i64) -> AppResult<Vec<ClaimedFunctionRun>> {
394        let span = tracing::info_span!(
395            "function_claim_batch",
396            worker_id = %self.worker_id,
397            lenso.execution.kind = "function_claim",
398            lenso.execution.name = "function.claim_batch",
399        );
400
401        async {
402            let runs = sqlx::query_as::<_, FunctionRunRow>(
403                r#"
404            with claimed as (
405                select id
406                from runtime.function_runs
407                where (
408                    status in ('pending', 'failed')
409                    and available_at <= now()
410                )
411                or (
412                    status = 'processing'
413                    and locked_at <= now() - ($1::double precision * interval '1 second')
414                )
415                order by available_at asc, created_at asc
416                limit $2
417                for update skip locked
418            )
419            update runtime.function_runs function_run
420            set status = 'processing',
421                locked_at = now(),
422                locked_by = $3,
423                started_at = coalesce(started_at, now()),
424                last_error = null,
425                updated_at = now()
426            from claimed
427            where function_run.id = claimed.id
428            returning
429                function_run.id,
430                function_run.function_name,
431                function_run.input_json,
432                function_run.attempts,
433                function_run.max_attempts,
434                function_run.correlation_id,
435                function_run.actor,
436                function_run.tenant_id,
437                function_run.tenancy_mode
438            "#,
439            )
440            .bind(stale_processing_lock_seconds())
441            .bind(batch_size)
442            .bind(&self.worker_id)
443            .fetch_all(&self.pool)
444            .await
445            .map(|rows| {
446                rows.into_iter()
447                    .map(TryInto::try_into)
448                    .collect::<AppResult<Vec<_>>>()
449            })
450            .map_err(map_runtime_error)??;
451
452            for run in &runs {
453                self.record_function_execution_log(
454                    run,
455                    ExecutionLogSeverity::Info,
456                    "Function run claimed",
457                    serde_json::json!({
458                        "attempt": run.attempts + 1,
459                        "max_attempts": run.max_attempts,
460                        "worker_id": self.worker_id,
461                    }),
462                )
463                .await;
464            }
465
466            Ok(runs)
467        }
468        .instrument(span)
469        .await
470    }
471
472    pub async fn claim_and_run_batch(&self, batch_size: i64) -> AppResult<usize> {
473        let span = tracing::info_span!(
474            "function_worker_loop",
475            worker_id = %self.worker_id,
476            lenso.execution.kind = "worker_loop",
477            lenso.execution.name = "runtime_worker.claim_and_run_batch",
478        );
479
480        async {
481            let runs = self.claim_batch(batch_size).await?;
482            let count = runs.len();
483
484            for run in runs {
485                self.run_claimed(run).await?;
486            }
487
488            Ok(count)
489        }
490        .instrument(span)
491        .await
492    }
493
494    async fn run_claimed(&self, run: ClaimedFunctionRun) -> AppResult<()> {
495        let span = tracing::info_span!(
496            "function_run",
497            lenso.correlation_id = tracing::field::Empty,
498            lenso.story_id = tracing::field::Empty,
499            lenso.function_run_id = tracing::field::Empty,
500            lenso.execution.kind = tracing::field::Empty,
501            lenso.execution.name = tracing::field::Empty,
502        );
503        record_runtime_span_attributes(
504            &span,
505            &RuntimeSpanAttributes::function(
506                run.correlation_id.clone(),
507                run.id.clone(),
508                run.function_name.clone(),
509            ),
510        );
511
512        async {
513            self.record_function_execution_log(
514                &run,
515                ExecutionLogSeverity::Info,
516                "Function run started",
517                serde_json::json!({
518                    "attempt": run.attempts + 1,
519                    "max_attempts": run.max_attempts,
520                    "worker_id": self.worker_id,
521                }),
522            )
523            .await;
524
525            let Some(definition) = self.registry.get(&run.function_name) else {
526                let error = AppError::new(
527                    ErrorCode::Internal,
528                    format!("Runtime function {} is not registered", run.function_name),
529                )
530                .retryable();
531                self.mark_failed(&run, &error, RetryPolicy::default().initial_delay)
532                    .await?;
533                return Ok(());
534            };
535
536            let attempt = u32::try_from(run.attempts + 1).unwrap_or(u32::MAX);
537            let ctx = ExecutionContext {
538                execution_id: ExecutionId(run.id.clone()),
539                function_name: run.function_name.clone(),
540                attempt,
541                queue: definition.queue.clone(),
542                correlation_id: CorrelationId::new(run.correlation_id.clone()),
543                causation_id: run.causation_id.clone(),
544                actor: run.actor.clone(),
545                tenant_id: run.tenant_id.clone(),
546                trace: run.trace.clone(),
547                deadline: None::<DateTime<Utc>>,
548            };
549
550            let execution_log_scope = ExecutionLogScope::function(
551                &ctx,
552                self.service_name.clone(),
553                self.worker_id.clone(),
554            );
555            let observability = definition.handler.observability();
556            let ((result, started_at, duration_ms), execution_log_report) = capture_execution_logs(
557                execution_log_scope,
558                self.execution_log_writer.clone(),
559                async {
560                    let started_at = Utc::now();
561                    let started = Instant::now();
562                    let result = definition.handler.call(ctx, run.input_json.clone()).await;
563                    let duration_ms = started.elapsed().as_millis().try_into().unwrap_or(i64::MAX);
564                    (result, started_at, duration_ms)
565                },
566            )
567            .await;
568            if execution_log_capture_is_incomplete(execution_log_report) {
569                tracing::warn!(
570                    function_run_id = %run.id,
571                    status = ?execution_log_report.status,
572                    observed = execution_log_report.observed,
573                    persisted = execution_log_report.persisted,
574                    dropped = execution_log_report.dropped,
575                    write_failures = execution_log_report.write_failures,
576                    "structured execution log capture was incomplete"
577                );
578            }
579            if let Some(observability) = observability {
580                self.record_function_handler_operation_log(
581                    &run,
582                    observability,
583                    started_at,
584                    duration_ms,
585                    result.as_ref().err(),
586                )
587                .await;
588            }
589
590            match result {
591                Ok(_output) => self.mark_completed(&run).await,
592                Err(error) => {
593                    self.mark_failed(&run, &error, definition.retry_policy.initial_delay)
594                        .await
595                }
596            }
597        }
598        .instrument(span)
599        .await
600    }
601
602    pub async fn mark_completed(&self, run: &ClaimedFunctionRun) -> AppResult<()> {
603        sqlx::query(
604            r#"
605            update runtime.function_runs
606            set status = 'completed',
607                completed_at = now(),
608                locked_at = null,
609                locked_by = null,
610                last_error = null,
611                updated_at = now()
612            where id = $1
613            "#,
614        )
615        .bind(&run.id)
616        .execute(&self.pool)
617        .await
618        .map(|_| ())
619        .map_err(map_runtime_error)?;
620
621        self.record_function_execution_log(
622            run,
623            ExecutionLogSeverity::Info,
624            "Function run completed",
625            serde_json::json!({
626                "attempt": run.attempts + 1,
627                "max_attempts": run.max_attempts,
628                "worker_id": self.worker_id,
629            }),
630        )
631        .await;
632
633        Ok(())
634    }
635
636    pub async fn mark_failed(
637        &self,
638        run: &ClaimedFunctionRun,
639        error: &AppError,
640        retry_delay: Duration,
641    ) -> AppResult<()> {
642        let next_attempt = run.attempts + 1;
643        let status = if next_attempt >= run.max_attempts {
644            FunctionRunStatus::Dead
645        } else if error.retryable {
646            FunctionRunStatus::Failed
647        } else {
648            FunctionRunStatus::Dead
649        };
650
651        let span = tracing::info_span!(
652            "function_run_fail",
653            lenso.correlation_id = tracing::field::Empty,
654            lenso.story_id = tracing::field::Empty,
655            lenso.function_run_id = tracing::field::Empty,
656            lenso.execution.kind = tracing::field::Empty,
657            lenso.execution.name = tracing::field::Empty,
658        );
659        record_runtime_span_attributes(
660            &span,
661            &RuntimeSpanAttributes::function(
662                run.correlation_id.clone(),
663                run.id.clone(),
664                run.function_name.clone(),
665            ),
666        );
667
668        async {
669            sqlx::query(
670                r#"
671            update runtime.function_runs
672            set status = $2,
673                attempts = attempts + 1,
674                available_at = case
675                    when $2 = 'failed' then now() + ($4::double precision * interval '1 second')
676                    else available_at
677                end,
678                locked_at = null,
679                locked_by = null,
680                last_error = $3,
681                updated_at = now()
682            where id = $1
683            "#,
684            )
685            .bind(&run.id)
686            .bind(status.as_str())
687            .bind(error.public_message.as_str())
688            .bind(retry_delay_seconds(retry_delay))
689            .execute(&self.pool)
690            .await
691            .map(|_| ())
692            .map_err(map_runtime_error)?;
693
694            self.record_function_execution_log(
695                run,
696                ExecutionLogSeverity::Error,
697                if status == FunctionRunStatus::Dead {
698                    "Function run marked dead"
699                } else {
700                    "Function run failed"
701                },
702                serde_json::json!({
703                    "attempt": next_attempt,
704                    "max_attempts": run.max_attempts,
705                    "status": status.as_str(),
706                    "retryable": error.retryable,
707                    "error": error.public_message,
708                    "worker_id": self.worker_id,
709                }),
710            )
711            .await;
712
713            Ok(())
714        }
715        .instrument(span)
716        .await
717    }
718
719    async fn record_function_execution_log(
720        &self,
721        run: &ClaimedFunctionRun,
722        severity: ExecutionLogSeverity,
723        body: &'static str,
724        attributes: Value,
725    ) {
726        emit_function_lifecycle_event(run, severity, body, &attributes, Some(&self.worker_id));
727        if let Err(error) = insert_execution_log_projection(
728            &self.pool,
729            function_log_record(run, severity, body, attributes, &self.service_name),
730        )
731        .await
732        {
733            tracing::warn!(
734                error = ?error,
735                function_run_id = %run.id,
736                "failed to write function execution log"
737            );
738        }
739    }
740
741    async fn record_function_handler_operation_log(
742        &self,
743        run: &ClaimedFunctionRun,
744        observability: FunctionHandlerObservability,
745        started_at: DateTime<Utc>,
746        duration_ms: i64,
747        error: Option<&AppError>,
748    ) {
749        let body = if error.is_some() {
750            "Function handler operation failed"
751        } else {
752            "Function handler operation completed"
753        };
754        let severity = if error.is_some() {
755            ExecutionLogSeverity::Error
756        } else {
757            ExecutionLogSeverity::Info
758        };
759        let attributes = function_handler_operation_attributes(
760            run,
761            &self.worker_id,
762            observability,
763            duration_ms,
764            error,
765        );
766        emit_function_lifecycle_event(run, severity, body, &attributes, Some(&self.worker_id));
767        if let Err(error) = insert_execution_log_projection(
768            &self.pool,
769            function_log_record(run, severity, body, attributes, &self.service_name)
770                .with_occurred_at(started_at),
771        )
772        .await
773        {
774            tracing::warn!(
775                error = ?error,
776                function_run_id = %run.id,
777                "failed to write function handler operation log"
778            );
779        }
780    }
781}
782
783fn execution_log_capture_is_incomplete(report: ExecutionLogCaptureReport) -> bool {
784    report.status != ExecutionLogCaptureStatus::Complete
785}
786
787#[derive(Debug)]
788struct FunctionLogContext {
789    id: String,
790    function_name: String,
791    correlation_id: String,
792    trace: TraceContext,
793}
794
795trait FunctionLogSource {
796    fn id(&self) -> String;
797    fn function_name(&self) -> String;
798    fn correlation_id(&self) -> String;
799    fn trace(&self) -> TraceContext;
800}
801
802impl FunctionLogSource for FunctionLogContext {
803    fn id(&self) -> String {
804        self.id.clone()
805    }
806
807    fn function_name(&self) -> String {
808        self.function_name.clone()
809    }
810
811    fn correlation_id(&self) -> String {
812        self.correlation_id.clone()
813    }
814
815    fn trace(&self) -> TraceContext {
816        self.trace.clone()
817    }
818}
819
820impl FunctionLogSource for ClaimedFunctionRun {
821    fn id(&self) -> String {
822        self.id.clone()
823    }
824
825    fn function_name(&self) -> String {
826        self.function_name.clone()
827    }
828
829    fn correlation_id(&self) -> String {
830        self.correlation_id.clone()
831    }
832
833    fn trace(&self) -> TraceContext {
834        self.trace.clone()
835    }
836}
837
838fn emit_function_lifecycle_event(
839    run: &impl FunctionLogSource,
840    severity: ExecutionLogSeverity,
841    body: &'static str,
842    attributes: &Value,
843    worker_id: Option<&str>,
844) {
845    match severity {
846        ExecutionLogSeverity::Error => {
847            tracing::error!(
848                function_run_id = %run.id(),
849                function_name = %run.function_name(),
850                correlation_id = %run.correlation_id(),
851                worker_id = worker_id.unwrap_or(""),
852                attributes = %attributes,
853                "{body}"
854            );
855        }
856        _ => {
857            tracing::info!(
858                function_run_id = %run.id(),
859                function_name = %run.function_name(),
860                correlation_id = %run.correlation_id(),
861                worker_id = worker_id.unwrap_or(""),
862                attributes = %attributes,
863                "{body}"
864            );
865        }
866    }
867}
868
869fn function_log_record(
870    run: &impl FunctionLogSource,
871    severity: ExecutionLogSeverity,
872    body: impl Into<String>,
873    attributes: Value,
874    service_name: &str,
875) -> ExecutionLogProjectionRecord {
876    ExecutionLogProjectionRecord::from_runtime_attrs(
877        RuntimeSpanAttributes::function(run.correlation_id(), run.id(), run.function_name()),
878        severity,
879        body,
880    )
881    .with_attributes(attributes)
882    .with_trace(run.trace())
883    .with_service_name(service_name)
884}
885
886#[derive(Debug, Clone)]
887struct ExecutionLogProjectionRecord {
888    correlation_id: String,
889    execution_id: String,
890    execution_type: String,
891    execution_name: String,
892    severity: ExecutionLogSeverity,
893    body: String,
894    attributes: Value,
895    trace: TraceContext,
896    service_name: String,
897    occurred_at: Option<DateTime<Utc>>,
898}
899
900impl ExecutionLogProjectionRecord {
901    fn from_runtime_attrs(
902        attrs: RuntimeSpanAttributes,
903        severity: ExecutionLogSeverity,
904        body: impl Into<String>,
905    ) -> Self {
906        let execution_id = attrs
907            .function_run_id
908            .clone()
909            .or(attrs.outbox_event_id)
910            .unwrap_or_else(|| attrs.story_id.clone());
911
912        Self {
913            correlation_id: attrs.correlation_id,
914            execution_id,
915            execution_type: attrs.execution_kind,
916            execution_name: attrs.execution_name,
917            severity,
918            body: body.into(),
919            attributes: Value::Object(Default::default()),
920            trace: TraceContext::default(),
921            service_name: "lenso".to_owned(),
922            occurred_at: None,
923        }
924    }
925
926    fn with_attributes(mut self, attributes: Value) -> Self {
927        self.attributes = attributes;
928        self
929    }
930
931    fn with_trace(mut self, trace: TraceContext) -> Self {
932        self.trace = trace;
933        self
934    }
935
936    fn with_service_name(mut self, service_name: &str) -> Self {
937        self.service_name = service_name.to_owned();
938        self
939    }
940
941    fn with_occurred_at(mut self, occurred_at: DateTime<Utc>) -> Self {
942        self.occurred_at = Some(occurred_at);
943        self
944    }
945}
946
947async fn insert_execution_log_projection(
948    pool: &DbPool,
949    record: ExecutionLogProjectionRecord,
950) -> AppResult<String> {
951    let id = format!("elog_{}", Uuid::now_v7());
952    let occurred_at = record.occurred_at.unwrap_or_else(Utc::now);
953
954    sqlx::query(
955        r#"
956        insert into platform.execution_logs (
957            id,
958            correlation_id,
959            story_id,
960            execution_id,
961            execution_type,
962            execution_name,
963            occurred_at,
964            severity,
965            body,
966            attributes,
967            trace_id,
968            span_id,
969            service_name,
970            redacted_fields
971        )
972        values ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14)
973        "#,
974    )
975    .bind(&id)
976    .bind(&record.correlation_id)
977    .bind(&record.correlation_id)
978    .bind(&record.execution_id)
979    .bind(&record.execution_type)
980    .bind(&record.execution_name)
981    .bind(occurred_at)
982    .bind(record.severity.as_str())
983    .bind(&record.body)
984    .bind(normalize_log_attributes(record.attributes))
985    .bind(&record.trace.trace_id)
986    .bind(&record.trace.span_id)
987    .bind(&record.service_name)
988    .bind(Vec::<String>::new())
989    .execute(pool)
990    .await
991    .map_err(map_runtime_error)?;
992
993    Ok(id)
994}
995
996fn function_handler_operation_attributes(
997    run: &ClaimedFunctionRun,
998    worker_id: &str,
999    observability: FunctionHandlerObservability,
1000    duration_ms: i64,
1001    error: Option<&AppError>,
1002) -> Value {
1003    let mut attributes = match observability.attributes {
1004        Value::Object(attributes) => attributes,
1005        other => serde_json::Map::from_iter([("value".to_owned(), other)]),
1006    };
1007    attributes.insert("source".to_owned(), Value::String(observability.source));
1008    attributes.insert("attempt".to_owned(), serde_json::json!(run.attempts + 1));
1009    attributes.insert(
1010        "max_attempts".to_owned(),
1011        serde_json::json!(run.max_attempts),
1012    );
1013    attributes.insert("duration_ms".to_owned(), serde_json::json!(duration_ms));
1014    attributes.insert("success".to_owned(), serde_json::json!(error.is_none()));
1015    attributes.insert("worker_id".to_owned(), serde_json::json!(worker_id));
1016    attributes.insert(
1017        "function_name".to_owned(),
1018        serde_json::json!(run.function_name),
1019    );
1020    attributes.insert("request_id".to_owned(), serde_json::json!(run.id));
1021    attributes.insert("trace_id".to_owned(), serde_json::json!(run.trace.trace_id));
1022    attributes.insert("span_id".to_owned(), serde_json::json!(run.trace.span_id));
1023
1024    if let Some(error) = error {
1025        attributes.insert(
1026            "error_code".to_owned(),
1027            serde_json::json!(error.code.as_str()),
1028        );
1029        attributes.insert("error".to_owned(), serde_json::json!(error.public_message));
1030        attributes.insert("retryable".to_owned(), serde_json::json!(error.retryable));
1031        attributes.insert("error_details".to_owned(), serde_json::json!(error.details));
1032    }
1033
1034    Value::Object(attributes)
1035}
1036
1037fn normalize_log_attributes(attributes: Value) -> Value {
1038    match attributes {
1039        Value::Object(_) => attributes,
1040        other => serde_json::json!({ "value": other }),
1041    }
1042}
1043
1044fn stale_processing_lock_seconds() -> f64 {
1045    STALE_PROCESSING_LOCK_SECONDS as f64
1046}
1047
1048fn retry_delay_seconds(delay: Duration) -> f64 {
1049    delay.as_secs_f64()
1050}
1051
1052type FunctionRunRow = (
1053    String,
1054    String,
1055    Value,
1056    i32,
1057    i32,
1058    String,
1059    Value,
1060    Option<String>,
1061    String,
1062);
1063
1064impl TryFrom<FunctionRunRow> for ClaimedFunctionRun {
1065    type Error = AppError;
1066
1067    fn try_from(row: FunctionRunRow) -> Result<Self, Self::Error> {
1068        let (
1069            id,
1070            function_name,
1071            input_json,
1072            attempts,
1073            max_attempts,
1074            correlation_id,
1075            actor,
1076            tenant_id,
1077            tenancy_mode,
1078        ) = row;
1079        let runtime_context = input_json.get("_lenso_runtime");
1080        let trace = runtime_context
1081            .map(trace_context_from_headers)
1082            .unwrap_or_default();
1083        let causation_id = runtime_context
1084            .and_then(|context| context.get("causation_id"))
1085            .and_then(Value::as_str)
1086            .map(ToOwned::to_owned);
1087        Ok(Self {
1088            id,
1089            function_name,
1090            input_json,
1091            attempts,
1092            max_attempts,
1093            correlation_id,
1094            actor: serde_json::from_value(actor).map_err(map_serde_error)?,
1095            tenant_id: tenant_id.map(TenantId),
1096            tenancy_mode: serde_json::from_value(Value::String(tenancy_mode))
1097                .map_err(map_serde_error)?,
1098            trace,
1099            causation_id,
1100        })
1101    }
1102}
1103
1104fn attach_runtime_context_to_input(
1105    input_json: &mut Value,
1106    correlation_id: &CorrelationId,
1107    trace: &TraceContext,
1108    causation_id: Option<&str>,
1109) {
1110    let mut runtime_context = trace_headers(trace, correlation_id);
1111    if let Some(causation_id) = causation_id {
1112        runtime_context["causation_id"] = Value::String(causation_id.to_owned());
1113    }
1114
1115    match input_json {
1116        Value::Object(object) => {
1117            object.insert("_lenso_runtime".to_owned(), runtime_context);
1118        }
1119        other => {
1120            *other = serde_json::json!({
1121                "payload": other.clone(),
1122                "_lenso_runtime": runtime_context,
1123            });
1124        }
1125    }
1126}
1127
1128pub(crate) fn map_runtime_error(source: sqlx::Error) -> AppError {
1129    AppError::new(ErrorCode::Internal, "Runtime operation failed").with_source(source)
1130}
1131
1132fn map_serde_error(source: serde_json::Error) -> AppError {
1133    AppError::new(ErrorCode::Internal, "Runtime payload serialization failed").with_source(source)
1134}
1135
1136#[cfg(test)]
1137mod tests {
1138    use super::*;
1139
1140    #[test]
1141    fn disabled_execution_log_capture_is_reported_as_incomplete() {
1142        assert!(execution_log_capture_is_incomplete(
1143            ExecutionLogCaptureReport {
1144                status: ExecutionLogCaptureStatus::Disabled,
1145                observed: 0,
1146                persisted: 0,
1147                dropped: 0,
1148                write_failures: 0,
1149            }
1150        ));
1151    }
1152}