worker.rs (23334B)
1 /* 2 This file is part of TALER 3 Copyright (C) 2025, 2026 Taler Systems SA 4 5 TALER is free software; you can redistribute it and/or modify it under the 6 terms of the GNU Affero General Public License as published by the Free Software 7 Foundation; either version 3, or (at your option) any later version. 8 9 TALER is distributed in the hope that it will be useful, but WITHOUT ANY 10 WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR 11 A PARTICULAR PURPOSE. See the GNU Affero General Public License for more details. 12 13 You should have received a copy of the GNU Affero General Public License along with 14 TALER; see the file COPYING. If not, see <http://www.gnu.org/licenses/> 15 */ 16 17 use std::time::Duration; 18 19 use failure_injection::{InjectedErr, fail_point}; 20 use http_client::ApiErr; 21 use jiff::Timestamp; 22 use sqlx::{Acquire as _, PgConnection, PgPool, postgres::PgListener}; 23 use taler_api::subject::{self, IncomingSubject, parse_incoming_unstructured}; 24 use taler_common::{ 25 ExpoBackoffDecorr, 26 config::Config, 27 types::amount::{self, Currency}, 28 }; 29 use tokio::sync::Notify; 30 use tracing::{debug, error, info, trace, warn}; 31 32 use crate::{ 33 config::{AccountType, WorkerCfg}, 34 constants::SYNC_CURSOR_KEY, 35 cyclos_api::{ 36 api::{CyclosAuth, CyclosErr}, 37 client::Client, 38 types::{AccountKind, HistoryItem, InputError, NotFoundError, OrderBy}, 39 }, 40 db::{ 41 self, AddIncomingResult, ChargebackFailureResult, RegisterResult, TxIn, TxOut, TxOutKind, 42 kv_get, kv_set, 43 }, 44 notification::watch_notification, 45 }; 46 47 #[derive(Debug, thiserror::Error)] 48 pub enum WorkerError { 49 #[error(transparent)] 50 Db(#[from] sqlx::Error), 51 #[error(transparent)] 52 Api(#[from] ApiErr<CyclosErr>), 53 #[error("Another worker is running concurrently")] 54 Concurrency, 55 #[error(transparent)] 56 Injected(#[from] InjectedErr), 57 } 58 59 pub type WorkerResult = Result<(), WorkerError>; 60 61 /// Retry an operation, not a terminated task. A closed pool cannot recover, 62 /// and injected interruptions must remain visible to the caller/supervisor. 63 fn retry_delay( 64 err: &WorkerError, 65 jitter: &mut ExpoBackoffDecorr, 66 frequency: Duration, 67 ) -> Option<Duration> { 68 match err { 69 WorkerError::Db(sqlx::Error::PoolClosed) | WorkerError::Injected(_) => None, 70 WorkerError::Concurrency => Some(jitter.backoff().max(Duration::from_secs(15))), 71 WorkerError::Api(e) 72 if matches!(*e.err, CyclosErr::Input(InputError::Validation { .. })) => 73 { 74 // Invalid input must not be resubmitted at notification speed. 75 Some(jitter.backoff().max(frequency)) 76 } 77 _ => Some(jitter.backoff()), 78 } 79 } 80 81 pub async fn run_worker( 82 cfg: &Config, 83 pool: &PgPool, 84 client: &http_client::Client, 85 transient: bool, 86 ) -> anyhow::Result<()> { 87 let cfg = WorkerCfg::parse(cfg)?; 88 let client = Client { 89 client, 90 api_url: &cfg.host.api_url, 91 auth: &CyclosAuth::Basic { 92 username: cfg.host.username, 93 password: cfg.host.password, 94 }, 95 }; 96 if transient { 97 let mut conn = pool.acquire().await?; 98 Worker { 99 client: &client, 100 db: &mut conn, 101 account_type_id: *cfg.account_type_id, 102 payment_type_id: *cfg.payment_type_id, 103 account_type: cfg.account_type, 104 currency: cfg.currency, 105 } 106 .run() 107 .await?; 108 return Ok(()); 109 } 110 111 let notification = Notify::new(); 112 113 let watcher = async { 114 watch_notification(&client, ¬ification).await; 115 }; 116 let worker = async { 117 let mut jitter = ExpoBackoffDecorr::default(); 118 loop { 119 let res: WorkerResult = async { 120 let db = &mut PgListener::connect_with(pool).await?; 121 db.listen_all(["transfer"]).await?; 122 info!(target: "worker", "database listener connected"); 123 loop { 124 let result = Worker { 125 client: &client, 126 db: db.acquire().await?, 127 account_type_id: *cfg.account_type_id, 128 payment_type_id: *cfg.payment_type_id, 129 account_type: cfg.account_type, 130 currency: cfg.currency, 131 } 132 .run() 133 .await; 134 match result { 135 Ok(()) => jitter.reset(), 136 Err(err @ WorkerError::Db(_)) => return Err(err), 137 Err(err) => { 138 let Some(delay) = retry_delay(&err, &mut jitter, cfg.frequency) else { 139 return Err(err); 140 }; 141 error!(target: "worker", ?delay, "synchronization pass failed: {err}"); 142 tokio::time::sleep(delay).await; 143 continue; 144 } 145 } 146 tokio::select! { 147 _ = tokio::time::sleep(cfg.frequency) => { 148 info!(target: "worker", "running at frequency"); 149 } 150 res = db.try_recv() => { 151 let mut ntf = res?; 152 while let Some(n) = ntf { 153 debug!(target: "worker", "notification from {}", n.channel()); 154 ntf = db.next_buffered(); 155 } 156 } 157 _ = notification.notified() => { 158 info!(target: "worker", "running at notification trigger"); 159 } 160 } 161 } 162 } 163 .await; 164 let err = res.unwrap_err(); 165 let Some(delay) = retry_delay(&err, &mut jitter, cfg.frequency) else { 166 break Err(err); 167 }; 168 error!(target: "worker", ?delay, "database session failed: {err}"); 169 tokio::time::sleep(delay).await; 170 } 171 }; 172 // The optional notification listener reconnects independently. Polling 173 // continues during its outages; a terminal worker result is not swallowed. 174 tokio::select! { 175 result = worker => result?, 176 _ = watcher => unreachable!("notification listener does not return"), 177 } 178 Ok(()) 179 } 180 181 pub struct Worker<'a> { 182 pub client: &'a Client<'a>, 183 pub db: &'a mut PgConnection, 184 pub currency: Currency, 185 pub account_type_id: i64, 186 pub payment_type_id: i64, 187 pub account_type: AccountType, 188 } 189 190 impl Worker<'_> { 191 /// Run a single worker pass 192 pub async fn run(&mut self) -> WorkerResult { 193 // Some worker operations are not idempotent, therefore it's not safe to have multiple worker 194 // running concurrently. We use a global Postgres advisory lock to prevent it. 195 if !db::worker_lock(self.db).await? { 196 return Err(WorkerError::Concurrency); 197 } 198 199 // Sync transactions 200 let mut cursor: Timestamp = kv_get(&mut *self.db, SYNC_CURSOR_KEY) 201 .await? 202 .unwrap_or_default(); 203 204 loop { 205 let page = self 206 .client 207 .history(self.account_type_id, OrderBy::DateAsc, 0, Some(cursor)) 208 .await?; 209 for transfer in page.page { 210 if transfer.date > cursor { 211 cursor = transfer.date; 212 } 213 let tx = extract_tx_info(transfer); 214 match tx { 215 Tx::In(tx_in) => self.ingest_in(tx_in).await?, 216 Tx::Out(tx_out) => self.ingest_out(tx_out).await?, 217 } 218 } 219 220 kv_set(&mut *self.db, SYNC_CURSOR_KEY, &cursor).await?; 221 222 if !page.has_next_page { 223 break; 224 } 225 } 226 227 // Send transactions 228 let start = Timestamp::now(); 229 loop { 230 let batch = db::pending_batch(&mut *self.db, &start).await?; 231 if batch.is_empty() { 232 break; 233 } 234 for initiated in batch { 235 debug!(target: "worker", "send tx {initiated}"); 236 let res = self 237 .client 238 .direct_payment( 239 initiated.creditor_id, 240 self.payment_type_id, 241 initiated.amount, 242 &initiated.subject, 243 ) 244 .await; 245 fail_point("direct-payment")?; 246 match res { 247 Ok(tx) => { 248 // Update transaction status, on failure the initiated transaction will be orphan 249 db::initiated_submit_success( 250 &mut *self.db, 251 initiated.id, 252 &tx.date, 253 tx.id.0, 254 ) 255 .await?; 256 trace!(target: "worker", "init tx {}", tx.id); 257 } 258 Err(e) => { 259 let msg = match &*e.err { 260 CyclosErr::Unknown(NotFoundError { entity_type, key }) => { 261 format!("unknown {entity_type} {key}") 262 } 263 CyclosErr::Forbidden(err) => err.to_string(), 264 _ => return Err(e.into()), 265 }; 266 // TODO is permission should be considered are hard or soft failure ? 267 db::initiated_submit_permanent_failure(&mut *self.db, initiated.id, &msg) 268 .await?; 269 error!(target: "worker", "initiated failure {initiated}: {msg}"); 270 } 271 } 272 } 273 } 274 Ok(()) 275 } 276 277 /// Ingest an incoming transaction 278 async fn ingest_in(&mut self, tx: TxIn) -> WorkerResult { 279 match self.account_type { 280 AccountType::Exchange => { 281 let transfer = self.client.transfer(tx.transfer_id).await?; 282 let bounce = async |db: &mut PgConnection, 283 reason: &str| 284 -> Result<(), WorkerError> { 285 // Fetch existing transaction 286 if let Some(chargeback) = transfer.charged_back_by { 287 let res = db::register_bounced_tx_in( 288 db, 289 &tx, 290 *chargeback.id, 291 reason, 292 &Timestamp::now(), 293 ) 294 .await?; 295 if res.tx_new { 296 info!(target: "worker", 297 "in {tx} bounced (recovered) in {}: {reason}", chargeback.id 298 ); 299 } else { 300 trace!(target: "worker", 301 "in {tx} already seen and bounced in {}: {reason}",chargeback.id 302 ); 303 } 304 } else if !transfer.can_chargeback { 305 match db::register_tx_in(db, &tx, &None, &Timestamp::now()).await? { 306 AddIncomingResult::Success { new, .. } => { 307 if new { 308 warn!(target: "worker", "in {tx} cannot bounce: {reason}"); 309 } else { 310 trace!(target: "worker", "in {tx} already seen and cannot bounce "); 311 } 312 } 313 AddIncomingResult::ReservePubReuse 314 | AddIncomingResult::UnknownMapping 315 | AddIncomingResult::MappingReuse => unreachable!(), 316 } 317 } else { 318 let chargeback_id = self.client.chargeback(*transfer.id).await?; 319 fail_point("chargeback")?; 320 let res = db::register_bounced_tx_in( 321 db, 322 &tx, 323 chargeback_id, 324 reason, 325 &Timestamp::now(), 326 ) 327 .await?; 328 if res.tx_new { 329 info!(target: "worker", "in {tx} bounced in {chargeback_id}: {reason}"); 330 } else { 331 trace!(target: "worker", "in {tx} already seen and bounced in {chargeback_id}: {reason}"); 332 } 333 } 334 Ok(()) 335 }; 336 if let Some(chargeback) = transfer.chargeback_of { 337 // This a chargeback of one of our transaction, if we bounce we might enter a loop 338 match db::initiated_chargeback_failure(&mut *self.db, *chargeback.id).await? { 339 ChargebackFailureResult::Unknown => { 340 trace!(target: "worker", "initiated failure unknown: charged back") 341 } 342 ChargebackFailureResult::Known(initiated) => { 343 error!(target: "worker", "initiated failure {initiated}: charged back") 344 } 345 ChargebackFailureResult::Idempotent(initiated) => { 346 trace!(target: "worker", "initiated failure {initiated} already seen: charged back") 347 } 348 } 349 // Sill register the incoming transaction as an incoming one 350 match db::register_tx_in(self.db, &tx, &None, &Timestamp::now()).await? { 351 AddIncomingResult::Success { new, .. } => { 352 if new { 353 info!(target: "worker", "in {tx} chargeback"); 354 } else { 355 trace!(target: "worker", "in {tx} chargeback already seen"); 356 } 357 } 358 AddIncomingResult::ReservePubReuse 359 | AddIncomingResult::UnknownMapping 360 | AddIncomingResult::MappingReuse => unreachable!(), 361 } 362 363 return Ok(()); 364 } 365 match parse_incoming_unstructured(&tx.subject) { 366 Ok(subject) => { 367 match subject { 368 IncomingSubject::Key(subject) => { 369 match db::register_tx_in( 370 self.db, 371 &tx, 372 &Some(subject), 373 &Timestamp::now(), 374 ) 375 .await? 376 { 377 AddIncomingResult::Success { new, .. } => { 378 if new { 379 info!(target: "worker", "in {tx}"); 380 } else { 381 trace!(target: "worker", "in {tx} already seen"); 382 } 383 } 384 AddIncomingResult::ReservePubReuse => { 385 bounce(self.db, "reserve pub reuse").await? 386 } 387 AddIncomingResult::UnknownMapping => { 388 bounce(self.db, "unknown mapping").await? 389 } 390 AddIncomingResult::MappingReuse => { 391 bounce(self.db, "mapping reuse").await? 392 } 393 } 394 } 395 IncomingSubject::AdminBalanceAdjust => { 396 // TODO bounce or skip ? 397 } 398 } 399 } 400 Err(e) => bounce(self.db, &e.to_string()).await?, 401 } 402 } 403 AccountType::Normal => { 404 match db::register_tx_in(self.db, &tx, &None, &Timestamp::now()).await? { 405 AddIncomingResult::Success { new, .. } => { 406 if new { 407 info!(target: "worker", "in {tx}"); 408 } else { 409 trace!(target: "worker", "in {tx} already seen"); 410 } 411 } 412 AddIncomingResult::ReservePubReuse 413 | AddIncomingResult::UnknownMapping 414 | AddIncomingResult::MappingReuse => unreachable!(), 415 } 416 } 417 } 418 Ok(()) 419 } 420 421 async fn ingest_out(&mut self, tx: TxOut) -> WorkerResult { 422 match self.account_type { 423 AccountType::Exchange => { 424 let transfer = self.client.transfer(tx.transfer_id).await?; 425 426 if transfer.charged_back_by.is_some() { 427 match db::initiated_chargeback_failure(&mut *self.db, *transfer.id).await? { 428 ChargebackFailureResult::Unknown => { 429 trace!(target: "worker", "initiated failure unknown: charged back") 430 } 431 ChargebackFailureResult::Known(initiated) => { 432 error!(target: "worker", "initiated failure {initiated}: charged back") 433 } 434 ChargebackFailureResult::Idempotent(initiated) => { 435 trace!(target: "worker", "initiated failure {initiated} already seen: charged back") 436 } 437 } 438 } 439 440 let kind = if let Ok(subject) = subject::parse_outgoing(&tx.subject) { 441 TxOutKind::Talerable(subject) 442 } else if let Some(chargeback) = &transfer.chargeback_of { 443 TxOutKind::Bounce(*chargeback.id) 444 } else { 445 TxOutKind::Simple 446 }; 447 448 let res = db::register_tx_out(self.db, &tx, &kind, &Timestamp::now()).await?; 449 match res.result { 450 RegisterResult::idempotent => match kind { 451 TxOutKind::Simple => { 452 trace!(target: "worker", "out malformed {tx} already seen") 453 } 454 TxOutKind::Bounce(_) => { 455 trace!(target: "worker", "out bounce {tx} already seen") 456 } 457 TxOutKind::Talerable(_) => { 458 trace!(target: "worker", "out {tx} already seen") 459 } 460 }, 461 RegisterResult::known => match kind { 462 TxOutKind::Simple => { 463 warn!(target: "worker", "out malformed {tx}") 464 } 465 TxOutKind::Bounce(_) => { 466 info!(target: "worker", "out bounce {tx}") 467 } 468 TxOutKind::Talerable(_) => { 469 info!(target: "worker", "out {tx}") 470 } 471 }, 472 RegisterResult::recovered => match kind { 473 TxOutKind::Simple => { 474 warn!(target: "worker", "out malformed (recovered) {tx}") 475 } 476 TxOutKind::Bounce(_) => { 477 warn!(target: "worker", "out bounce (recovered) {tx}") 478 } 479 TxOutKind::Talerable(_) => { 480 warn!(target: "worker", "out (recovered) {tx}") 481 } 482 }, 483 } 484 } 485 AccountType::Normal => { 486 let res = db::register_tx_out(self.db, &tx, &TxOutKind::Simple, &Timestamp::now()) 487 .await?; 488 match res.result { 489 RegisterResult::idempotent => { 490 trace!(target: "worker", "out {tx} already seen"); 491 } 492 RegisterResult::known => { 493 info!(target: "worker", "out {tx}"); 494 } 495 RegisterResult::recovered => { 496 warn!(target: "worker", "out (recovered) {tx}"); 497 } 498 } 499 } 500 } 501 Ok(()) 502 } 503 } 504 505 pub enum Tx { 506 In(TxIn), 507 Out(TxOut), 508 } 509 510 pub fn extract_tx_info(tx: HistoryItem) -> Tx { 511 let amount = amount::decimal(tx.amount.trim_start_matches('-')); 512 let (id, name) = match tx.related_account.kind { 513 AccountKind::System => (tx.related_account.ty.id, tx.related_account.ty.name), 514 AccountKind::User { user } => (user.id, user.display), 515 }; 516 if tx.amount.starts_with('-') { 517 Tx::Out(TxOut { 518 transfer_id: *tx.id, 519 tx_id: tx.transaction.map(|it| *it.id), 520 amount, 521 subject: tx.description.unwrap_or_default(), 522 creditor_id: *id, 523 creditor_name: name, 524 valued_at: tx.date, 525 }) 526 } else { 527 Tx::In(TxIn { 528 transfer_id: *tx.id, 529 tx_id: tx.transaction.map(|it| *it.id), 530 amount, 531 subject: tx.description.unwrap_or_default(), 532 debtor_id: *id, 533 debtor_name: name, 534 valued_at: tx.date, 535 }) 536 } 537 } 538 539 #[cfg(test)] 540 mod retry_tests { 541 use super::*; 542 543 #[test] 544 fn database_outages_retry_but_terminal_interruptions_propagate() { 545 let mut jitter = ExpoBackoffDecorr::default(); 546 let err = WorkerError::Db(sqlx::Error::Io( 547 std::io::ErrorKind::ConnectionRefused.into(), 548 )); 549 let delay = retry_delay(&err, &mut jitter, Duration::from_secs(60)).unwrap(); 550 assert!(delay >= Duration::from_millis(400)); 551 assert!(delay <= Duration::from_secs(30)); 552 assert!( 553 retry_delay( 554 &WorkerError::Db(sqlx::Error::PoolClosed), 555 &mut jitter, 556 Duration::ZERO 557 ) 558 .is_none() 559 ); 560 assert!( 561 retry_delay( 562 &WorkerError::Injected(InjectedErr("worker interrupted")), 563 &mut jitter, 564 Duration::ZERO 565 ) 566 .is_none() 567 ); 568 assert!( 569 retry_delay(&WorkerError::Concurrency, &mut jitter, Duration::ZERO).unwrap() 570 >= Duration::from_secs(15) 571 ); 572 } 573 }