Skip to main content

pipedash_core/application/services/
log_service.rs

1use std::collections::{
2    HashMap,
3    HashSet,
4};
5use std::future::Future;
6use std::io;
7use std::sync::atomic::{
8    AtomicBool,
9    AtomicU64,
10    Ordering,
11};
12use std::sync::{
13    Arc,
14    Mutex,
15    PoisonError,
16};
17use std::time::Duration;
18
19use bytes::Bytes;
20use chrono::Utc;
21use dashmap::{
22    DashMap,
23    Entry,
24};
25use futures::Stream;
26use tokio::sync::{
27    mpsc,
28    oneshot,
29    Semaphore,
30};
31use tokio::time::Instant;
32use tokio_util::sync::CancellationToken;
33use tokio_util::task::TaskTracker;
34
35use super::provider_service::{
36    ProviderLease,
37    ProviderService,
38};
39use crate::application::Generation;
40use crate::domain::{
41    DomainError,
42    DomainResult,
43    LogAvailability,
44    LogCacheStats,
45    LogDocumentMeta,
46    LogLinesPage,
47    LogNode,
48    LogNodeKind,
49    LogSearchQuery,
50    LogSearchResult,
51    LogSink,
52    PipelineRun,
53    PipelineStatus,
54    RunLogDocument,
55    RunLogNode,
56    RunLogTree,
57};
58use crate::event::{
59    CoreEvent,
60    EventBus,
61};
62use crate::infrastructure::database::Repository;
63use crate::infrastructure::deduplication::{
64    hash_request,
65    RequestDeduplicator,
66};
67use crate::infrastructure::run_logs::{
68    search_regex,
69    BlockLimits,
70    CacheEpoch,
71    DocError,
72    DocKey,
73    Document,
74    Ingester,
75    LogStore,
76    PublishOutcome,
77    ReadLease,
78    StepBound,
79    StoredTree,
80};
81
82const INGEST_PERMITS: usize = 2;
83const SEARCH_PERMITS: usize = 2;
84const INGEST_QUEUE: usize = 16;
85const EXPORT_QUEUE: usize = 4;
86const PROGRESS_TICK: Duration = Duration::from_millis(500);
87const COMPLETE_TREE_TTL: Duration = Duration::from_secs(60);
88const OPEN_TREE_TTL: Duration = Duration::from_secs(10);
89const FAILURE_COOLDOWN: Duration = Duration::from_secs(5 * 60);
90const PARTIAL_COOLDOWN: Duration = Duration::from_secs(10);
91const SHUTDOWN_PATIENCE: Duration = Duration::from_secs(5);
92const REVISION_GONE: &str = "This log revision is no longer available";
93const EXPORT_INTERRUPTED: &str = "Pipedash stopped before the log finished downloading";
94const PROVIDER_CHANGED: &str = "The provider changed while the log was downloading. Open it again.";
95
96type TreeKey = (i64, Generation, CacheEpoch, String, i64);
97type Built = (Arc<RunLogTree>, Arc<PipelineRun>);
98
99struct Attempt {
100    id: u64,
101    generation: Generation,
102    epoch: CacheEpoch,
103    received: Arc<AtomicU64>,
104    cancel: CancellationToken,
105}
106
107struct AttemptRecord {
108    generation: Generation,
109    epoch: CacheEpoch,
110    at: Instant,
111    failure: Option<String>,
112}
113
114enum Recent {
115    Failure(String),
116    Fresh,
117}
118
119enum Stop {
120    Silent,
121    ProviderChanged,
122}
123
124enum Finished {
125    Stopped(Stop),
126    Published { revision: i64 },
127    Failed(String),
128}
129
130struct AttemptGuard {
131    service: Arc<LogService>,
132    key: DocKey,
133    id: u64,
134}
135
136impl Drop for AttemptGuard {
137    fn drop(&mut self) {
138        self.service
139            .inflight
140            .remove_if(&self.key, |_, attempt| attempt.id == self.id);
141    }
142}
143
144struct SearchSession<'a> {
145    searches: &'a DashMap<(DocKey, String), (u64, CancellationToken)>,
146    key: (DocKey, String),
147    id: u64,
148    cancel: CancellationToken,
149}
150
151impl Drop for SearchSession<'_> {
152    fn drop(&mut self) {
153        self.cancel.cancel();
154        self.searches
155            .remove_if(&self.key, |_, (id, _)| *id == self.id);
156    }
157}
158
159pub struct LogService {
160    store: Arc<LogStore>,
161    provider_service: Arc<ProviderService>,
162    repository: Arc<Repository>,
163    event_bus: Arc<dyn EventBus>,
164    trees: RequestDeduplicator<Built, DomainError>,
165    tree_memo: DashMap<TreeKey, (Instant, Arc<RunLogTree>, Arc<PipelineRun>)>,
166    pipeline_providers: DashMap<String, i64>,
167    inflight: DashMap<DocKey, Attempt>,
168    attempts: DashMap<DocKey, AttemptRecord>,
169    searches: DashMap<(DocKey, String), (u64, CancellationToken)>,
170    ingest_permits: Arc<Semaphore>,
171    search_permits: Arc<Semaphore>,
172    admission: Mutex<bool>,
173    root: CancellationToken,
174    tracker: TaskTracker,
175    next_id: AtomicU64,
176}
177
178pub struct LogExport {
179    doc: Arc<Document>,
180    lease: ReadLease,
181    provider_id: i64,
182    epoch: CacheEpoch,
183    service: Arc<LogService>,
184}
185
186struct IngestWork {
187    service: Arc<LogService>,
188    lease: ProviderLease,
189    epoch: CacheEpoch,
190    key: DocKey,
191    node: RunLogNode,
192    run: Arc<PipelineRun>,
193    steps: Vec<StepBound>,
194    revision: i64,
195    cancel: CancellationToken,
196    received: Arc<AtomicU64>,
197}
198
199impl LogService {
200    pub fn new(
201        store: Arc<LogStore>, provider_service: Arc<ProviderService>, repository: Arc<Repository>,
202        event_bus: Arc<dyn EventBus>,
203    ) -> Self {
204        Self {
205            store,
206            provider_service,
207            repository,
208            event_bus,
209            trees: RequestDeduplicator::new(),
210            tree_memo: DashMap::new(),
211            pipeline_providers: DashMap::new(),
212            inflight: DashMap::new(),
213            attempts: DashMap::new(),
214            searches: DashMap::new(),
215            ingest_permits: Arc::new(Semaphore::new(INGEST_PERMITS)),
216            search_permits: Arc::new(Semaphore::new(SEARCH_PERMITS)),
217            admission: Mutex::new(true),
218            root: CancellationToken::new(),
219            tracker: TaskTracker::new(),
220            next_id: AtomicU64::new(1),
221        }
222    }
223
224    fn admit(&self, spawn: impl FnOnce(&TaskTracker)) -> DomainResult<()> {
225        let open = self
226            .admission
227            .lock()
228            .unwrap_or_else(PoisonError::into_inner);
229        if !*open {
230            return Err(DomainError::InternalError(
231                "Pipedash is shutting down".to_string(),
232            ));
233        }
234        spawn(&self.tracker);
235
236        Ok(())
237    }
238
239    async fn provider_of(&self, pipeline_id: &str) -> DomainResult<i64> {
240        if let Some(provider_id) = self.pipeline_providers.get(pipeline_id).map(|id| *id) {
241            return Ok(provider_id);
242        }
243        let provider_id = self
244            .repository
245            .get_cached_pipelines(None)
246            .await?
247            .into_iter()
248            .find(|pipeline| pipeline.id == pipeline_id)
249            .map(|pipeline| pipeline.provider_id)
250            .ok_or_else(|| DomainError::PipelineNotFound(pipeline_id.to_string()))?;
251        self.pipeline_providers
252            .insert(pipeline_id.to_string(), provider_id);
253
254        Ok(provider_id)
255    }
256
257    async fn lease_of(&self, pipeline_id: &str) -> DomainResult<(ProviderLease, CacheEpoch)> {
258        let provider_id = self.provider_of(pipeline_id).await?;
259        let lease = match self.provider_service.acquire(provider_id).await {
260            Err(DomainError::ProviderNotFound(_)) => {
261                self.pipeline_providers.remove(pipeline_id);
262                return Err(DomainError::PipelineNotFound(pipeline_id.to_string()));
263            }
264            other => other?,
265        };
266        let epoch = self.store.epoch(provider_id);
267        if !lease.provider.capabilities().logs {
268            return Err(DomainError::NotSupported(
269                "Run logs are not available for this provider".to_string(),
270            ));
271        }
272
273        Ok((lease, epoch))
274    }
275
276    async fn doc_key(
277        &self, pipeline_id: &str, run_number: i64, node_id: &str,
278    ) -> DomainResult<DocKey> {
279        Ok(DocKey {
280            provider_id: self.provider_of(pipeline_id).await?,
281            pipeline_id: pipeline_id.to_string(),
282            run_number,
283            node_id: node_id.to_string(),
284        })
285    }
286
287    pub async fn run_log_tree(
288        &self, pipeline_id: &str, run_number: i64,
289    ) -> DomainResult<RunLogTree> {
290        let (lease, epoch) = self.lease_of(pipeline_id).await?;
291        let (tree, _) = self.tree_of(&lease, epoch, pipeline_id, run_number).await?;
292
293        Ok(RunLogTree::clone(&tree))
294    }
295
296    async fn tree_of(
297        &self, lease: &ProviderLease, epoch: CacheEpoch, pipeline_id: &str, run_number: i64,
298    ) -> DomainResult<Built> {
299        let request = hash_request(
300            lease.id,
301            lease.generation,
302            &format!(
303                "run-log-tree:{}:{}:{pipeline_id}:{run_number}",
304                epoch.global, epoch.provider
305            ),
306        );
307        let built = self
308            .trees
309            .deduplicate(request, || {
310                self.build_tree(lease, epoch, pipeline_id, run_number)
311            })
312            .await?;
313        if self.store.epoch(lease.id) == epoch {
314            self.memoize(
315                (
316                    lease.id,
317                    lease.generation,
318                    epoch,
319                    pipeline_id.to_string(),
320                    run_number,
321                ),
322                built.clone(),
323            );
324        }
325
326        Ok(built)
327    }
328
329    async fn build_tree(
330        &self, lease: &ProviderLease, epoch: CacheEpoch, pipeline_id: &str, run_number: i64,
331    ) -> DomainResult<Built> {
332        let run = self
333            .provider_call(
334                lease,
335                lease.provider.fetch_run_details(pipeline_id, run_number),
336            )
337            .await?;
338        if run.status.is_terminal() {
339            if let Some(stored) = self
340                .store
341                .read_tree(lease.id, pipeline_id, run_number)
342                .await
343            {
344                if stored.run_status == run.status && stored.run_concluded_at == run.concluded_at {
345                    return Ok((Arc::new(stored.tree), Arc::new(run)));
346                }
347            }
348        }
349
350        let nodes = self
351            .provider_call(lease, lease.provider.fetch_log_nodes(&run))
352            .await?;
353        let tree = tree_from_nodes(&run, nodes);
354        if tree.complete {
355            let stored = StoredTree {
356                run_status: run.status.clone(),
357                run_concluded_at: run.concluded_at,
358                tree: tree.clone(),
359            };
360            let saved = self
361                .provider_service
362                .commit(lease, || {
363                    self.store
364                        .write_tree(lease.id, pipeline_id, run_number, &stored, epoch)
365                })
366                .await;
367            if let Some(Err(e)) = saved {
368                tracing::warn!(provider_id = lease.id, error = %e, "Failed to save the run log tree");
369            }
370        }
371
372        Ok((Arc::new(tree), Arc::new(run)))
373    }
374
375    fn memoize(&self, key: TreeKey, built: Built) {
376        let now = Instant::now();
377        self.tree_memo
378            .retain(|_, (at, _, _)| now.saturating_duration_since(*at) < COMPLETE_TREE_TTL);
379        self.tree_memo.insert(key, (now, built.0, built.1));
380    }
381
382    fn memoized(
383        &self, lease: &ProviderLease, epoch: CacheEpoch, pipeline_id: &str, run_number: i64,
384    ) -> Option<Built> {
385        let entry = self.tree_memo.get(&(
386            lease.id,
387            lease.generation,
388            epoch,
389            pipeline_id.to_string(),
390            run_number,
391        ))?;
392        let (at, tree, run) = entry.value();
393        let ttl = if tree.complete {
394            COMPLETE_TREE_TTL
395        } else {
396            OPEN_TREE_TTL
397        };
398
399        (Instant::now().saturating_duration_since(*at) < ttl)
400            .then(|| (Arc::clone(tree), Arc::clone(run)))
401    }
402
403    fn ensure_active(&self, provider_id: i64) -> DomainResult<()> {
404        let now = Utc::now();
405        match self
406            .provider_service
407            .scheduler()
408            .paused_until(provider_id, now)
409        {
410            Some(until) => Err(DomainError::RateLimited {
411                message: "Provider API quota or rate-limit cooldown is active".to_string(),
412                retry_after: (until - now).to_std().ok(),
413            }),
414            None => Ok(()),
415        }
416    }
417
418    async fn note_limit(&self, lease: &ProviderLease, error: &DomainError) {
419        if matches!(
420            error,
421            DomainError::RateLimited { .. } | DomainError::ServiceUnavailable { .. }
422        ) {
423            self.provider_service.check_quota(lease).await;
424        }
425    }
426
427    async fn provider_call<T>(
428        &self, lease: &ProviderLease, call: impl Future<Output = DomainResult<T>>,
429    ) -> DomainResult<T> {
430        self.ensure_active(lease.id)?;
431        let result = call.await;
432        if let Err(e) = &result {
433            self.note_limit(lease, e).await;
434        }
435
436        result
437    }
438
439    pub async fn open_document(
440        self: &Arc<Self>, pipeline_id: &str, run_number: i64, node_id: &str, retry: bool,
441    ) -> DomainResult<RunLogDocument> {
442        let (lease, epoch) = self.lease_of(pipeline_id).await?;
443        let (tree, run) = match self.memoized(&lease, epoch, pipeline_id, run_number) {
444            Some(built) => built,
445            None => self.tree_of(&lease, epoch, pipeline_id, run_number).await?,
446        };
447        let node = tree
448            .nodes
449            .iter()
450            .find(|node| node.id == node_id)
451            .ok_or_else(|| {
452                DomainError::NotFound(format!("Job {node_id} isn't part of run #{run_number}"))
453            })?;
454        let Some(availability) = node.log else {
455            return Err(DomainError::NotFound(format!(
456                "{} has no log of its own",
457                node.name
458            )));
459        };
460        if availability == LogAvailability::Pending {
461            return Ok(RunLogDocument::Pending);
462        }
463
464        let key = DocKey {
465            provider_id: lease.id,
466            pipeline_id: pipeline_id.to_string(),
467            run_number,
468            node_id: node_id.to_string(),
469        };
470        let recent = self.recent_attempt(&key, &lease, epoch, retry);
471
472        if let Some(meta) = self.readable_meta(&key).await? {
473            if availability == LogAvailability::Ready && meta.complete {
474                return Ok(RunLogDocument::Ready(meta));
475            }
476            if recent.is_none() {
477                self.claim(&key, lease, epoch, node, &tree, run)?;
478            }
479
480            return Ok(RunLogDocument::Ready(meta));
481        }
482
483        if let Some(received_bytes) = self.running(&key, &lease, epoch) {
484            return Ok(RunLogDocument::Loading { received_bytes });
485        }
486        if let Some(Recent::Failure(message)) = recent {
487            return Ok(RunLogDocument::Unavailable { message });
488        }
489
490        Ok(RunLogDocument::Loading {
491            received_bytes: self.claim(&key, lease, epoch, node, &tree, run)?,
492        })
493    }
494
495    async fn readable_meta(&self, key: &DocKey) -> DomainResult<Option<LogDocumentMeta>> {
496        let Some(revision) = self.store.current(key) else {
497            return Ok(None);
498        };
499
500        Ok(self
501            .store
502            .lease(key, revision)
503            .await?
504            .map(|(doc, _lease)| doc.meta().to_meta()))
505    }
506
507    fn recent_attempt(
508        &self, key: &DocKey, lease: &ProviderLease, epoch: CacheEpoch, retry: bool,
509    ) -> Option<Recent> {
510        let record = self.attempts.get(key)?;
511        if record.generation != lease.generation || record.epoch != epoch {
512            return None;
513        }
514        let age = Instant::now().saturating_duration_since(record.at);
515
516        match &record.failure {
517            Some(message) => {
518                (!retry && age < FAILURE_COOLDOWN).then(|| Recent::Failure(message.clone()))
519            }
520            None => (age < PARTIAL_COOLDOWN).then_some(Recent::Fresh),
521        }
522    }
523
524    fn running(&self, key: &DocKey, lease: &ProviderLease, epoch: CacheEpoch) -> Option<u64> {
525        let attempt = self.inflight.get(key)?;
526
527        (attempt.generation == lease.generation && attempt.epoch == epoch)
528            .then(|| attempt.received.load(Ordering::Relaxed))
529    }
530
531    fn claim(
532        self: &Arc<Self>, key: &DocKey, lease: ProviderLease, epoch: CacheEpoch, node: &RunLogNode,
533        tree: &RunLogTree, run: Arc<PipelineRun>,
534    ) -> DomainResult<u64> {
535        let id = self.next_id.fetch_add(1, Ordering::Relaxed);
536        let cancel = self.root.child_token();
537        let received = Arc::new(AtomicU64::new(0));
538        let attempt = Attempt {
539            id,
540            generation: lease.generation,
541            epoch,
542            received: Arc::clone(&received),
543            cancel: cancel.clone(),
544        };
545
546        {
547            match self.inflight.entry(key.clone()) {
548                Entry::Occupied(mut entry) => {
549                    let current = entry.get();
550                    if current.generation == lease.generation && current.epoch == epoch {
551                        return Ok(current.received.load(Ordering::Relaxed));
552                    }
553                    current.cancel.cancel();
554                    entry.insert(attempt);
555                }
556                Entry::Vacant(entry) => {
557                    entry.insert(attempt);
558                }
559            }
560        }
561
562        let guard = AttemptGuard {
563            service: Arc::clone(self),
564            key: key.clone(),
565            id,
566        };
567        let work = IngestWork {
568            service: Arc::clone(self),
569            lease,
570            epoch,
571            key: key.clone(),
572            node: node.clone(),
573            run,
574            steps: step_bounds(node, tree),
575            revision: self.store.allocate_revision(),
576            cancel,
577            received,
578        };
579        self.admit(move |tracker| {
580            tracker.spawn(ingest(guard, work));
581        })?;
582
583        Ok(0)
584    }
585
586    fn interrupted(
587        &self, provider_id: i64, epoch: CacheEpoch, cancel: &CancellationToken,
588    ) -> Option<Stop> {
589        let now = self.store.epoch(provider_id);
590        if self.root.is_cancelled() || now.global != epoch.global {
591            Some(Stop::Silent)
592        } else if now.provider != epoch.provider {
593            Some(Stop::ProviderChanged)
594        } else if cancel.is_cancelled() {
595            Some(Stop::Silent)
596        } else {
597            None
598        }
599    }
600
601    fn busy_runs(&self) -> HashSet<(i64, String)> {
602        self.inflight
603            .iter()
604            .map(|entry| entry.key().run_id())
605            .collect()
606    }
607
608    async fn conclude(
609        &self, guard: AttemptGuard, finished: Finished, generation: Generation, epoch: CacheEpoch,
610        partial: bool,
611    ) {
612        let key = guard.key.clone();
613        let record = |failure: Option<String>| AttemptRecord {
614            generation,
615            epoch,
616            at: Instant::now(),
617            failure,
618        };
619        let failed = |message: String| CoreEvent::RunLogFailed {
620            pipeline_id: key.pipeline_id.clone(),
621            run_number: key.run_number,
622            node_id: key.node_id.clone(),
623            message,
624        };
625        let event = match finished {
626            Finished::Stopped(Stop::Silent) => None,
627            Finished::Stopped(Stop::ProviderChanged) => Some(failed(PROVIDER_CHANGED.to_string())),
628            Finished::Published { revision } => {
629                if partial {
630                    self.attempts.insert(key.clone(), record(None));
631                } else {
632                    self.attempts.remove(&key);
633                }
634                Some(CoreEvent::RunLogReady {
635                    pipeline_id: key.pipeline_id.clone(),
636                    run_number: key.run_number,
637                    node_id: key.node_id.clone(),
638                    revision,
639                })
640            }
641            Finished::Failed(message) => {
642                self.attempts
643                    .insert(key.clone(), record(Some(message.clone())));
644                Some(failed(message))
645            }
646        };
647        drop(guard);
648        if let Some(event) = event {
649            self.event_bus.emit(event).await;
650        }
651    }
652
653    async fn leased(
654        &self, pipeline_id: &str, run_number: i64, node_id: &str, revision: i64,
655    ) -> DomainResult<(DocKey, Arc<Document>, ReadLease)> {
656        let key = self.doc_key(pipeline_id, run_number, node_id).await?;
657        match self.store.lease(&key, revision).await? {
658            Some((doc, lease)) => Ok((key, doc, lease)),
659            None => Err(DomainError::NotFound(REVISION_GONE.to_string())),
660        }
661    }
662
663    fn doc_failure(&self, key: &DocKey, revision: i64, error: DocError) -> DomainError {
664        match error {
665            DocError::Corrupt => {
666                self.store.mark_corrupt(key, revision);
667                DomainError::InternalError("Log cache is corrupted".to_string())
668            }
669            DocError::Io(e) => DomainError::InternalError(format!("Couldn't read the log: {e}")),
670            DocError::Cancelled => DomainError::InternalError("Log read cancelled".to_string()),
671        }
672    }
673
674    async fn sweep(&self, reading: &DocKey) {
675        if let Err(e) = self.store.sweep_with(self.busy_runs(), Some(reading)).await {
676            tracing::warn!(error = %e, "Failed to remove stale run logs");
677        }
678    }
679
680    #[allow(clippy::too_many_arguments)]
681    pub async fn read_lines(
682        &self, pipeline_id: &str, run_number: i64, node_id: &str, revision: i64, start: u32,
683        count: u32, max_line_units: u32,
684    ) -> DomainResult<LogLinesPage> {
685        let (key, doc, lease) = self
686            .leased(pipeline_id, run_number, node_id, revision)
687            .await?;
688        let store = Arc::clone(&self.store);
689        let page = tokio::task::spawn_blocking(move || {
690            let page = doc.read_lines(store.block_cache(), start, count, max_line_units);
691            drop(lease);
692            page
693        })
694        .await
695        .map_err(|e| DomainError::InternalError(format!("Log reader stopped: {e}")))?;
696        self.sweep(&key).await;
697
698        page.map_err(|e| self.doc_failure(&key, revision, e))
699    }
700
701    pub async fn search(
702        &self, pipeline_id: &str, run_number: i64, node_id: &str, revision: i64, session_id: &str,
703        query: &LogSearchQuery,
704    ) -> DomainResult<LogSearchResult> {
705        let Some(regex) = search_regex(query)? else {
706            return Ok(LogSearchResult::default());
707        };
708
709        let (key, doc, lease) = self
710            .leased(pipeline_id, run_number, node_id, revision)
711            .await?;
712
713        let id = self.next_id.fetch_add(1, Ordering::Relaxed);
714        let cancel = self.root.child_token();
715        let session_key = (key.clone(), session_id.to_string());
716        if let Some((_, previous)) = self
717            .searches
718            .insert(session_key.clone(), (id, cancel.clone()))
719        {
720            previous.cancel();
721        }
722        let _session = SearchSession {
723            searches: &self.searches,
724            key: session_key,
725            id,
726            cancel: cancel.clone(),
727        };
728
729        let permit = tokio::select! {
730            permit = Arc::clone(&self.search_permits).acquire_owned() => permit,
731            _ = cancel.cancelled() => return Err(search_cancelled()),
732        }
733        .map_err(|_| search_cancelled())?;
734
735        let (tx, rx) = oneshot::channel();
736        self.admit(|tracker| {
737            tracker.spawn_blocking(move || {
738                let result = doc.search(&regex, &cancel);
739                drop(lease);
740                drop(permit);
741                let _ = tx.send(result);
742            });
743        })?;
744        let result = rx.await.map_err(|_| search_cancelled())?;
745        self.sweep(&key).await;
746
747        result.map_err(|e| match e {
748            DocError::Cancelled => search_cancelled(),
749            other => self.doc_failure(&key, revision, other),
750        })
751    }
752
753    pub async fn prepare_export(
754        self: &Arc<Self>, pipeline_id: &str, run_number: i64, node_id: &str, revision: i64,
755    ) -> DomainResult<LogExport> {
756        let provider_id = self.provider_of(pipeline_id).await?;
757        let epoch = self.store.epoch(provider_id);
758        let (_, doc, lease) = self
759            .leased(pipeline_id, run_number, node_id, revision)
760            .await?;
761
762        Ok(LogExport {
763            doc,
764            lease,
765            provider_id,
766            epoch,
767            service: Arc::clone(self),
768        })
769    }
770
771    pub async fn stats(&self) -> LogCacheStats {
772        self.store.stats().await
773    }
774
775    pub async fn clear(&self) -> DomainResult<()> {
776        let cleared = self.store.clear().await;
777        for attempt in self.inflight.iter() {
778            attempt.cancel.cancel();
779        }
780        for search in self.searches.iter() {
781            search.value().1.cancel();
782        }
783        self.tree_memo.clear();
784        self.attempts.clear();
785        self.searches.clear();
786
787        cleared
788    }
789
790    pub async fn shutdown(&self) {
791        {
792            let mut open = self
793                .admission
794                .lock()
795                .unwrap_or_else(PoisonError::into_inner);
796            *open = false;
797            self.root.cancel();
798        }
799        self.tracker.close();
800        if tokio::time::timeout(SHUTDOWN_PATIENCE, self.tracker.wait())
801            .await
802            .is_err()
803        {
804            tracing::warn!("Waiting for run log tasks to stop");
805            self.tracker.wait().await;
806        }
807    }
808}
809
810impl LogExport {
811    pub fn into_stream(
812        self,
813    ) -> DomainResult<impl Stream<Item = io::Result<Bytes>> + Send + 'static> {
814        let Self {
815            doc,
816            lease,
817            provider_id,
818            epoch,
819            service,
820        } = self;
821        if service.store.epoch(provider_id) != epoch {
822            return Err(DomainError::NotFound(REVISION_GONE.to_string()));
823        }
824
825        let (tx, rx) = mpsc::channel::<io::Result<Bytes>>(EXPORT_QUEUE);
826        let finished = Arc::new(AtomicBool::new(false));
827        let root = service.root.clone();
828        let done = Arc::clone(&finished);
829        service.admit(|tracker| {
830            tracker.spawn(export(doc, lease, tx, root, done));
831        })?;
832
833        Ok(futures::stream::unfold(Some(rx), move |rx| {
834            let finished = Arc::clone(&finished);
835            async move {
836                let mut rx = rx?;
837                match rx.recv().await {
838                    Some(item) => Some((item, Some(rx))),
839                    None if finished.load(Ordering::SeqCst) => None,
840                    None => Some((Err(io::Error::other(EXPORT_INTERRUPTED)), None)),
841                }
842            }
843        }))
844    }
845}
846
847async fn export(
848    doc: Arc<Document>, lease: ReadLease, tx: mpsc::Sender<io::Result<Bytes>>,
849    root: CancellationToken, finished: Arc<AtomicBool>,
850) {
851    let _lease = lease;
852    for index in 0..doc.block_count() {
853        if root.is_cancelled() {
854            return;
855        }
856        let block = Arc::clone(&doc);
857        let item = match tokio::task::spawn_blocking(move || block.text_block(index)).await {
858            Ok(Ok(bytes)) => Ok(bytes),
859            Ok(Err(e)) => Err(io::Error::other(e.to_string())),
860            Err(e) => Err(io::Error::other(e)),
861        };
862        let failed = item.is_err();
863        tokio::select! {
864            sent = tx.send(item) => {
865                if sent.is_err() {
866                    return;
867                }
868            }
869            _ = root.cancelled() => return,
870        }
871        if failed {
872            finished.store(true, Ordering::SeqCst);
873            return;
874        }
875    }
876    finished.store(true, Ordering::SeqCst);
877}
878
879async fn ingest(guard: AttemptGuard, work: IngestWork) {
880    let service = Arc::clone(&work.service);
881    let generation = work.lease.generation;
882    let epoch = work.epoch;
883    let partial = work.node.log == Some(LogAvailability::Partial);
884    let finished = work.run().await;
885    service
886        .conclude(guard, finished, generation, epoch, partial)
887        .await;
888}
889
890impl IngestWork {
891    async fn run(self) -> Finished {
892        let Self {
893            service,
894            lease,
895            epoch,
896            key,
897            node,
898            run,
899            steps,
900            revision,
901            cancel,
902            received,
903        } = self;
904        let provider_id = key.provider_id;
905        let interrupted = || service.interrupted(provider_id, epoch, &cancel);
906        let stopped = |stop: Option<Stop>| stop.map(Finished::Stopped);
907
908        let _permit = tokio::select! {
909            permit = Arc::clone(&service.ingest_permits).acquire_owned() => permit,
910            _ = cancel.cancelled() => {
911                return Finished::Stopped(interrupted().unwrap_or(Stop::Silent));
912            }
913        };
914        if let Some(finished) = stopped(interrupted()) {
915            return finished;
916        }
917
918        if let Err(e) = service.ensure_active(provider_id) {
919            return Finished::Failed(failure_message(&e));
920        }
921
922        let tmp = match service.store.tmp_dir().await {
923            Ok(tmp) => tmp,
924            Err(e) => return Finished::Failed(e.to_string()),
925        };
926        let (tx, mut rx) = mpsc::channel::<Bytes>(INGEST_QUEUE);
927        let ingester = Ingester {
928            key: key.clone(),
929            revision,
930            complete: node.log == Some(LogAvailability::Ready),
931            dir: tmp.clone(),
932            dialect: lease.provider.log_dialect(),
933            steps,
934            received: Arc::clone(&received),
935            limits: BlockLimits::default(),
936        };
937        let writer = tokio::task::spawn_blocking(move || ingester.run(&mut rx));
938
939        let read_result = {
940            let provider = Arc::clone(&lease.provider);
941            let node_id = key.node_id.clone();
942            let read = async move {
943                let mut sink = LogSink::new(tx);
944                let result = provider.read_log(&run, &node_id, &mut sink).await;
945                drop(sink);
946                result
947            };
948            tokio::pin!(read);
949
950            let mut ticker = tokio::time::interval(PROGRESS_TICK);
951            ticker.set_missed_tick_behavior(tokio::time::MissedTickBehavior::Skip);
952            let mut reported = 0;
953            loop {
954                tokio::select! {
955                    result = &mut read => break Some(result),
956                    _ = cancel.cancelled() => break None,
957                    _ = ticker.tick() => {
958                        let total = received.load(Ordering::Relaxed);
959                        if total != reported {
960                            reported = total;
961                            service
962                                .event_bus
963                                .emit(CoreEvent::RunLogProgress {
964                                    pipeline_id: key.pipeline_id.clone(),
965                                    run_number: key.run_number,
966                                    node_id: key.node_id.clone(),
967                                    received_bytes: total,
968                                })
969                                .await;
970                        }
971                        if service.store.epoch(provider_id) != epoch {
972                            cancel.cancel();
973                        }
974                    }
975                }
976            }
977        };
978
979        let written = writer.await;
980        if let Some(stop) = interrupted() {
981            service.store.discard(tmp).await;
982            return Finished::Stopped(stop);
983        }
984        let outcome = match written {
985            Ok(Ok(outcome)) => outcome,
986            Ok(Err(e)) => {
987                service.store.discard(tmp).await;
988                return Finished::Failed(format!("Couldn't save the log: {e}"));
989            }
990            Err(e) => {
991                service.store.discard(tmp).await;
992                return Finished::Failed(format!("Couldn't save the log: {e}"));
993            }
994        };
995        if let Some(Err(e)) = read_result {
996            if !outcome.truncated {
997                service.store.discard(tmp).await;
998                service.note_limit(&lease, &e).await;
999                return Finished::Failed(failure_message(&e));
1000            }
1001        }
1002
1003        let busy = service.busy_runs();
1004        let committed = service
1005            .provider_service
1006            .commit(&lease, || {
1007                service.store.publish(&key, &tmp, revision, epoch, busy)
1008            })
1009            .await;
1010        match committed {
1011            Some(Ok(PublishOutcome::Published)) => Finished::Published { revision },
1012            Some(Ok(PublishOutcome::StaleEpoch)) => {
1013                service.store.discard(tmp).await;
1014                Finished::Stopped(interrupted().unwrap_or(Stop::ProviderChanged))
1015            }
1016            Some(Err(e)) => {
1017                service.store.discard(tmp).await;
1018                Finished::Failed(e.to_string())
1019            }
1020            None => {
1021                service.store.discard(tmp).await;
1022                Finished::Stopped(Stop::ProviderChanged)
1023            }
1024        }
1025    }
1026}
1027
1028fn search_cancelled() -> DomainError {
1029    DomainError::InternalError("Search cancelled".to_string())
1030}
1031
1032fn failure_message(error: &DomainError) -> String {
1033    match error {
1034        DomainError::PipelineNotFound(_) | DomainError::NotFound(_) => {
1035            "The provider no longer has this log. It may have expired.".to_string()
1036        }
1037        DomainError::RateLimited {
1038            retry_after: Some(wait),
1039            ..
1040        } => format!(
1041            "Rate limit reached. Try again in {} min.",
1042            wait.as_millis().div_ceil(60_000).max(1)
1043        ),
1044        DomainError::RateLimited {
1045            retry_after: None, ..
1046        } => "Rate limit reached. Try again later.".to_string(),
1047        other => other.to_string(),
1048    }
1049}
1050
1051fn step_bounds(node: &RunLogNode, tree: &RunLogTree) -> Vec<StepBound> {
1052    tree.nodes
1053        .iter()
1054        .filter(|child| {
1055            child.kind == LogNodeKind::Step
1056                && child.log.is_none()
1057                && child.parent_id.as_deref() == Some(node.id.as_str())
1058        })
1059        .map(|step| StepBound {
1060            node_id: step.id.clone(),
1061            title: step.name.clone(),
1062            status: step.status.clone(),
1063            started_ms: step.started_at.map(|at| at.timestamp_millis()),
1064            finished_ms: step.finished_at.map(|at| at.timestamp_millis()),
1065        })
1066        .collect()
1067}
1068
1069fn tree_from_nodes(run: &PipelineRun, nodes: Vec<LogNode>) -> RunLogTree {
1070    let mut tree: Vec<RunLogNode> = Vec::with_capacity(nodes.len());
1071    let mut index = HashMap::with_capacity(nodes.len());
1072    for node in nodes {
1073        if index.contains_key(&node.id) {
1074            tracing::warn!(
1075                run_number = run.run_number,
1076                "Duplicate run log node ID ignored"
1077            );
1078            continue;
1079        }
1080        let parent = node
1081            .parent_id
1082            .as_ref()
1083            .and_then(|parent| index.get(parent).copied());
1084        let depth = parent.map_or(0, |parent: usize| tree[parent].depth.saturating_add(1));
1085        let duration_seconds = match (node.started_at, node.finished_at) {
1086            (Some(started), Some(finished)) => Some((finished - started).num_seconds()),
1087            _ => None,
1088        };
1089        index.insert(node.id.clone(), tree.len());
1090        tree.push(RunLogNode {
1091            navigable: node.log.is_some(),
1092            parent_id: parent.map(|_| node.parent_id.clone()).unwrap_or_default(),
1093            id: node.id,
1094            kind: node.kind,
1095            name: node.name,
1096            status: node.status,
1097            started_at: node.started_at,
1098            finished_at: node.finished_at,
1099            duration_seconds,
1100            log: node.log,
1101            web_url: node.web_url,
1102            depth,
1103        });
1104    }
1105
1106    for position in (0..tree.len()).rev() {
1107        if !tree[position].navigable {
1108            continue;
1109        }
1110        let parent = tree[position]
1111            .parent_id
1112            .as_ref()
1113            .and_then(|parent| index.get(parent).copied());
1114        if let Some(parent) = parent {
1115            tree[parent].navigable = true;
1116        }
1117    }
1118
1119    let complete = run.status.is_terminal()
1120        && tree.iter().all(|node| {
1121            node.status.is_terminal()
1122                && !matches!(
1123                    node.log,
1124                    Some(LogAvailability::Partial | LogAvailability::Pending)
1125                )
1126        });
1127    let with_log = || tree.iter().filter(|node| node.log.is_some());
1128    let default_node_id = with_log()
1129        .find(|node| node.status == PipelineStatus::Failed)
1130        .or_else(|| {
1131            with_log().find(|node| {
1132                matches!(
1133                    node.log,
1134                    Some(LogAvailability::Ready | LogAvailability::Partial)
1135                )
1136            })
1137        })
1138        .or_else(|| with_log().next())
1139        .map(|node| node.id.clone());
1140
1141    RunLogTree {
1142        nodes: tree,
1143        default_node_id,
1144        complete,
1145    }
1146}
1147
1148#[cfg(test)]
1149mod tests;