finance_billing.py 17 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370
  1. import logging
  2. import uuid
  3. from sqlalchemy import func, select
  4. from sqlalchemy.exc import IntegrityError, SQLAlchemyError
  5. from sqlalchemy.ext.asyncio import AsyncSession
  6. from backend.app.models.archive import PrintArchive
  7. from backend.app.models.finance import TransactionType, UserWallet, WalletTransaction
  8. from backend.app.models.print_log import INCLUDE_OPEN_RUNS, PrintLogEntry
  9. from backend.app.services.finance_balance import sync_personal_wallet_balance
  10. from backend.app.services.finance_budget import is_billing_enabled, release_budget_reservation
  11. logger = logging.getLogger(__name__)
  12. class BillingRunIdCollisionError(RuntimeError):
  13. """A billing idempotency key points at a different physical print run."""
  14. async def _get_balance_after_for_transaction(
  15. db: AsyncSession,
  16. user_id: int | None,
  17. cost_center_id: int | None,
  18. amount: float,
  19. ) -> float:
  20. """Calculate balance_after for a transaction.
  21. For cost-center transactions: sum of ALL transactions for that cost center (global).
  22. For personal transactions (cost_center_id=None): user's wallet balance (personal).
  23. Args:
  24. user_id: The user making the transaction
  25. cost_center_id: The cost center (None for personal)
  26. amount: The transaction amount (positive/negative)
  27. Returns:
  28. The balance after this transaction would be applied
  29. """
  30. try:
  31. if cost_center_id is None:
  32. # Personal transaction: use user wallet balance
  33. wallet = (await db.execute(select(UserWallet).where(UserWallet.user_id == user_id))).scalar_one_or_none()
  34. if wallet is None:
  35. return float(amount)
  36. return float(wallet.balance) + amount
  37. else:
  38. # Cost-center transaction: sum of ALL transactions for this cost center (global, not per-user)
  39. result = await db.execute(
  40. select(func.coalesce(func.sum(WalletTransaction.amount), 0.0)).where(
  41. WalletTransaction.cost_center_id == cost_center_id,
  42. WalletTransaction.is_voided.is_(False),
  43. )
  44. )
  45. current_balance = float(result.scalar() or 0.0)
  46. return current_balance + amount
  47. except SQLAlchemyError as e:
  48. logger.error(f"Database error in _get_balance_after_for_transaction: {e}", exc_info=True)
  49. raise
  50. def _calculate_partial_charge(
  51. archive: PrintArchive,
  52. base_cost: float,
  53. *,
  54. filament_usage: tuple[float | None, float | None] | None = None,
  55. status: str | None = None,
  56. ) -> tuple[float, str]:
  57. """Calculate proportional charge for partial prints based on filament usage.
  58. ``status`` is how the charged run ended; without it, the archive's.
  59. Returns (charge_amount, description_suffix) where:
  60. - charge_amount: absolute cost to charge (0 if insufficient data)
  61. - description_suffix: reason/details for transaction description
  62. """
  63. try:
  64. status = status or archive.status
  65. # Only apply proportional calculation for non-completed prints
  66. if status == "completed":
  67. return round(float(base_cost), 2), ""
  68. if filament_usage is not None:
  69. actual_grams, planned_grams = filament_usage
  70. filament_used = float(actual_grams or 0.0)
  71. filament_planned = float(planned_grams) if planned_grams is not None else None
  72. else:
  73. # Backwards-compatible fallback for recalculation and callers that
  74. # do not have per-run telemetry. At print completion main.py passes
  75. # the measured/progress-scaled run usage explicitly: the archive
  76. # field is the slicer's planned amount and must not be mistaken for
  77. # the amount consumed by an aborted run.
  78. filament_used = float(archive.filament_used_grams or 0.0)
  79. filament_planned = None
  80. if archive.extra_data and isinstance(archive.extra_data, dict):
  81. filament_planned = archive.extra_data.get("filament_grams_total")
  82. if filament_planned is not None:
  83. filament_planned = float(filament_planned)
  84. # If we don't have reliable planned filament data, do not guess a partial charge.
  85. # Charging a failed/aborted print without an estimated baseline can overcharge users.
  86. if filament_planned is None or filament_planned <= 0:
  87. return 0.0, f"[{status}: insufficient filament data]"
  88. # Calculate proportional cost
  89. filament_ratio = min(1.0, max(0.0, filament_used / filament_planned)) # Clamp to [0, 1]
  90. charge = float(base_cost) * filament_ratio
  91. # Round charges to 2 decimals for consistent persistence
  92. charge = round(charge, 2)
  93. suffix = f"[{status}: {filament_ratio:.1%} filament ({filament_used:.1f}g/{filament_planned:.1f}g)]"
  94. return charge, suffix
  95. except ValueError as e:
  96. logger.error(f"Value error in _calculate_partial_charge: {e}", exc_info=True)
  97. raise
  98. async def _settle_reservation(db: AsyncSession, status: str, *, archive_id: int, print_queue_id: int | None) -> None:
  99. """Release or consume what the charged print reserved. Reservations are
  100. made per queue item. Without the print's own (no queue item, or its item
  101. closed already, e.g. cancelled by a stop before the printer reported the
  102. start) the archive's whose items are over, never those of another plate
  103. of it still pending or printing."""
  104. if print_queue_id is not None:
  105. await release_budget_reservation(db, source_type="print_queue", source_id=print_queue_id, status=status)
  106. else:
  107. await release_budget_reservation(db, print_archive_id=archive_id, status=status)
  108. async def apply_print_charge_for_archive(
  109. db: AsyncSession,
  110. archive_id: int,
  111. *,
  112. charged_user_id: int | None = None,
  113. cost_center_id: int | None = None,
  114. print_queue_id: int | None = None,
  115. print_run_id: str | None = None,
  116. base_cost_override: float | None = None,
  117. filament_usage: tuple[float | None, float | None] | None = None,
  118. run_entry_id: int | None = None,
  119. run_status: str | None = None,
  120. ) -> bool:
  121. """Apply an idempotent wallet charge for a print archive.
  122. Charges completed prints at full cost, and partial/failed prints proportionally
  123. based on actual filament used vs. planned filament.
  124. ``run_entry_id`` is the run being charged (its print log entry) and
  125. ``run_status`` how it ended. The charge is then the run's: its billing run
  126. id and cost centre, under a lock on the run row, so plates of
  127. one archive printing on two printers are each charged once. Without a run
  128. (a print started before runs were written at the start) the archive's.
  129. Returns True when a new wallet transaction was created.
  130. """
  131. try:
  132. if not await is_billing_enabled(db):
  133. await _settle_reservation(db, "released", archive_id=archive_id, print_queue_id=print_queue_id)
  134. logger.info("Billing is disabled; skipping print charge for archive ID %s.", archive_id)
  135. return False
  136. run = None
  137. if run_entry_id is not None:
  138. # Locked, and read again under the lock (the caller loaded it):
  139. # two ends of the same run (a repeated completion) mint and charge
  140. # its billing run id once.
  141. run = (
  142. await db.execute(
  143. select(PrintLogEntry)
  144. .where(PrintLogEntry.id == run_entry_id)
  145. .with_for_update()
  146. .execution_options(populate_existing=True, **{INCLUDE_OPEN_RUNS: True})
  147. )
  148. ).scalar_one_or_none()
  149. archive_query = select(PrintArchive).where(PrintArchive.id == archive_id)
  150. if run is None:
  151. archive_query = archive_query.with_for_update()
  152. archive = (await db.execute(archive_query)).scalar_one_or_none()
  153. if archive is None:
  154. logger.warning(f"Archive with ID {archive_id} not found.")
  155. return False
  156. if run is not None:
  157. # A run opened at its start has its own id. One written only at
  158. # its end (no start seen) has none, and is charged as before by the
  159. # archive's, which a repeated end then finds charged.
  160. effective_run_id = print_run_id or run.billing_run_id or archive.billing_run_id
  161. skipped = bool(run.wallet_charge_skipped)
  162. else:
  163. effective_run_id = print_run_id or archive.billing_run_id
  164. # The archive-level flag is retained only for legacy deleted charges.
  165. # A new scheduler dispatch clears it while persisting its new run UUID;
  166. # current deletions are represented by a voided transaction instead.
  167. skipped = archive.wallet_charge_skipped
  168. if skipped:
  169. logger.info(f"Wallet charge skipped for archive ID {archive_id}.")
  170. return False
  171. # Accept completed, aborted, cancelled, and failed prints. A run's own
  172. # end: with another plate of the archive ending at the same time, the
  173. # archive's status may be that one's.
  174. charged_status = run_status or archive.status
  175. if charged_status not in ("completed", "aborted", "cancelled", "failed"):
  176. logger.info(f"Archive ID {archive_id} has status {charged_status}, which is not chargeable.")
  177. return False
  178. # A queue print's user is the one who queued it, also when deleted
  179. # since: a reprint reuses the source archive, whose creator did not
  180. # print it. The archive's creator only for a print without a queue row.
  181. if charged_user_id is not None:
  182. # Read by the caller seconds before (the completion does usage and
  183. # archive work first): a user deleted since is no user. Charged by
  184. # id, PostgreSQL refused the wallet (FK) and the reservation stayed
  185. # active; SQLite wrote a wallet and a charge for a missing user.
  186. from backend.app.models.user import User
  187. actual_user_id = await db.scalar(select(User.id).where(User.id == charged_user_id))
  188. elif print_queue_id is not None:
  189. actual_user_id = None
  190. else:
  191. actual_user_id = archive.created_by_id
  192. if cost_center_id is not None:
  193. actual_cost_center_id = cost_center_id
  194. elif run is not None and run.cost_center_id is not None:
  195. actual_cost_center_id = run.cost_center_id
  196. else:
  197. actual_cost_center_id = archive.cost_center_id
  198. # No user: deleted while the print ran, or never had one (login turned
  199. # off). A cost centre's print is still its cost: charged to the cost
  200. # centre without a user (shown as "No user"), which also consumes its
  201. # reservation. That includes
  202. # the user's own private cost centre, which their personal prints go
  203. # through with billing on and which outlives them. Only a print with no
  204. # cost centre at all (started while billing was off) has nobody left to
  205. # charge, and holds no reservation (budgets exist per cost centre).
  206. if actual_user_id is None and actual_cost_center_id is None:
  207. logger.info("Archive ID %s has no user to charge (deleted) and no cost centre.", archive_id)
  208. return False
  209. base_cost = float(base_cost_override if base_cost_override is not None else (archive.cost or 0.0))
  210. if base_cost <= 0:
  211. # Nothing to charge, but the print is over: settle what it held
  212. # (reserved from an estimate, e.g. an older archive with grams but
  213. # no stored cost), as the zero-charge case below does.
  214. await _settle_reservation(db, "released", archive_id=archive.id, print_queue_id=print_queue_id)
  215. logger.info(f"Base cost for archive ID {archive_id} is zero or negative.")
  216. return False
  217. # New dispatches persist a UUID before sending the printer command,
  218. # and a run gets its own when it opens. Generate one here only for
  219. # legacy/in-flight rows created before that; the locked row makes this
  220. # fallback durable.
  221. if not effective_run_id:
  222. effective_run_id = str(uuid.uuid4())
  223. if run is None:
  224. archive.billing_run_id = effective_run_id
  225. if run is not None and run.billing_run_id != effective_run_id:
  226. run.billing_run_id = effective_run_id
  227. tx_conditions = [
  228. WalletTransaction.transaction_type == TransactionType.PRINT_CHARGE.value,
  229. WalletTransaction.print_run_id == effective_run_id,
  230. ]
  231. existing_tx = (await db.execute(select(WalletTransaction).where(*tx_conditions))).scalar_one_or_none()
  232. if existing_tx is not None:
  233. if existing_tx.print_archive_id != archive.id:
  234. logger.critical(
  235. "BILLING RUN ID COLLISION: run %s belongs to archive %s, not archive %s; charge aborted",
  236. effective_run_id,
  237. existing_tx.print_archive_id,
  238. archive.id,
  239. )
  240. raise BillingRunIdCollisionError(
  241. f"Billing run ID {effective_run_id} is already assigned to another archive"
  242. )
  243. logger.info(f"Transaction already exists for archive ID {archive_id}.")
  244. if existing_tx.is_voided:
  245. logger.info("Print charge for run %s was voided by an administrator.", effective_run_id)
  246. return False
  247. # Calculate charge (full for completed, partial for others)
  248. charge, reason_suffix = _calculate_partial_charge(
  249. archive,
  250. base_cost,
  251. filament_usage=filament_usage,
  252. status=charged_status,
  253. )
  254. if charge <= 0:
  255. await _settle_reservation(db, "released", archive_id=archive.id, print_queue_id=print_queue_id)
  256. logger.info(f"Calculated charge for archive ID {archive_id} is zero or negative.")
  257. return False
  258. wallet = None
  259. if actual_user_id is not None:
  260. wallet = (
  261. await db.execute(select(UserWallet).where(UserWallet.user_id == actual_user_id))
  262. ).scalar_one_or_none()
  263. if wallet is None:
  264. wallet = UserWallet(user_id=actual_user_id, balance=0.0)
  265. db.add(wallet)
  266. await db.flush()
  267. logger.info("Created new wallet for user ID %s.", actual_user_id)
  268. label = archive.print_name or archive.filename or f"Archive {archive.id}"
  269. description = f"Print charge: {label}{' ' + reason_suffix if reason_suffix else ''}"
  270. balance_after = await _get_balance_after_for_transaction(db, actual_user_id, actual_cost_center_id, -charge)
  271. if balance_after is not None:
  272. balance_after = round(float(balance_after), 2)
  273. tx = WalletTransaction(
  274. user_id=actual_user_id,
  275. cost_center_id=actual_cost_center_id,
  276. transaction_type=TransactionType.PRINT_CHARGE.value,
  277. amount=-charge,
  278. balance_after=balance_after,
  279. description=description,
  280. created_by_user_id=None,
  281. print_run_id=effective_run_id,
  282. print_archive_id=archive.id,
  283. print_queue_id=print_queue_id,
  284. )
  285. # Limit a concurrent deduplication conflict to a savepoint. The caller
  286. # owns the outer transaction, which may already contain archive-owner
  287. # backfills and other completion updates that must survive this race.
  288. try:
  289. async with db.begin_nested():
  290. db.add(tx)
  291. # Flush inside the savepoint to detect unique/index conflicts.
  292. await db.flush()
  293. except IntegrityError as e:
  294. # Distinguish a legitimate concurrent retry of this exact run from
  295. # a collision or an unrelated constraint failure. Only the former
  296. # is an idempotent no-op; everything else must remain loud so the
  297. # caller rolls back and the budget reservation stays active.
  298. concurrent_tx = (await db.execute(select(WalletTransaction).where(*tx_conditions))).scalar_one_or_none()
  299. if concurrent_tx is not None and concurrent_tx.print_archive_id == archive.id:
  300. logger.info("Transaction already exists for archive ID %s (concurrent), skipping", archive_id)
  301. return False
  302. logger.critical(
  303. "Failed to persist billing charge for archive %s and run %s: %s",
  304. archive_id,
  305. effective_run_id,
  306. e,
  307. exc_info=True,
  308. )
  309. if concurrent_tx is not None:
  310. raise BillingRunIdCollisionError(
  311. f"Billing run ID {effective_run_id} is already assigned to another archive"
  312. ) from e
  313. raise
  314. # Rebuild from the canonical personal-ledger definition. A shared cost
  315. # center charge must not debit the user's personal wallet.
  316. new_wallet_balance = await sync_personal_wallet_balance(db, wallet) if wallet is not None else None
  317. # Consume matching budget reservations after the transaction is persisted
  318. await _settle_reservation(db, "consumed", archive_id=archive.id, print_queue_id=print_queue_id)
  319. logger.info(f"Applied print charge for archive ID {archive_id}. New balance: {new_wallet_balance}.")
  320. return True
  321. except SQLAlchemyError as e:
  322. logger.error(f"Database error in apply_print_charge_for_archive: {e}", exc_info=True)
  323. raise
  324. except ValueError as e:
  325. logger.error(f"Value error in apply_print_charge_for_archive: {e}", exc_info=True)
  326. return False