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(®ex, &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;