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 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}