reconciler.py 9.2 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226
  1. from __future__ import annotations
  2. import logging
  3. import signal
  4. import threading
  5. from datetime import timedelta
  6. from zoneinfo import ZoneInfo
  7. from supply_infra.config import InfraSettings, get_infra_settings
  8. from supply_infra.db.repositories.pipeline_run_repo import PipelineRunRepository
  9. from supply_infra.db.repositories.pipeline_step_run_repo import PipelineStepRunRepository
  10. from supply_infra.db.session import dispose_engine, get_session
  11. from supply_infra.pipeline.dates import CHINA_TIMEZONE, china_now
  12. from supply_infra.pipeline.enums import RunStatus, StepStatus
  13. from supply_infra.pipeline.health import run_alert_level
  14. from supply_infra.pipeline.run_service import PIPELINE_KEY, submit_pipeline_run
  15. logger = logging.getLogger(__name__)
  16. def reconcile_once() -> dict[str, int]:
  17. settings = get_infra_settings()
  18. now = china_now()
  19. stats = {
  20. "retries_promoted": 0,
  21. "expired_steps": 0,
  22. "deadline_exceeded": 0,
  23. "previous_run_unblocked": 0,
  24. "alerts_emitted": 0,
  25. "missed_runs_submitted": 0,
  26. }
  27. with get_session() as session:
  28. run_repo = PipelineRunRepository(session)
  29. step_repo = PipelineStepRunRepository(session)
  30. stats["retries_promoted"] = step_repo.promote_due_retries(now)
  31. for step in step_repo.list_expired_running(now):
  32. run = run_repo.get(step.run_id, for_update=True)
  33. if run is not None and run.status in {
  34. RunStatus.CANCELLING.value,
  35. RunStatus.CANCELLED.value,
  36. }:
  37. step.status = StepStatus.CANCELLED.value
  38. step.finished_at = now
  39. step.lease_owner = None
  40. step.lease_until = None
  41. step.error_code = "cancelled"
  42. step.error_message = "Cancellation completed after worker lease expired"
  43. if run.status == RunStatus.CANCELLING.value:
  44. run_repo.finish(
  45. run,
  46. status=RunStatus.CANCELLED.value,
  47. now=now,
  48. )
  49. stats["expired_steps"] += 1
  50. continue
  51. if run is not None and run.status == RunStatus.DEADLINE_EXCEEDED.value:
  52. step.status = StepStatus.TIMED_OUT.value
  53. step.finished_at = now
  54. step.lease_owner = None
  55. step.lease_until = None
  56. step.error_code = "deadline_exceeded"
  57. step.error_message = "Worker lease expired after pipeline deadline"
  58. stats["expired_steps"] += 1
  59. continue
  60. step.status = StepStatus.TIMED_OUT.value
  61. step.finished_at = now
  62. step.lease_owner = None
  63. step.lease_until = None
  64. step.error_code = "lease_expired"
  65. step.error_message = "Worker heartbeat lease expired"
  66. if step.retryable and step.attempt < step.max_attempts:
  67. step_repo.create_retry_attempt(step, status=StepStatus.READY.value)
  68. if run is not None:
  69. run.status = RunStatus.QUEUED.value
  70. run.current_step = step.step_key
  71. run.lease_owner = None
  72. run.lease_until = None
  73. else:
  74. step_repo.block_unfinished_downstream(
  75. run_id=step.run_id,
  76. after_order=step.step_order,
  77. reason="Worker heartbeat lease expired",
  78. )
  79. if run is not None:
  80. run_repo.finish(
  81. run,
  82. status=RunStatus.FAILED.value,
  83. now=now,
  84. error_code="lease_expired",
  85. error_message=f"Lease expired at step {step.step_key}",
  86. )
  87. stats["expired_steps"] += 1
  88. for run in run_repo.list_past_deadline(now):
  89. for step in step_repo.list_for_run(run.run_id):
  90. if step.status == StepStatus.RUNNING.value:
  91. step.error_code = "deadline_exceeded"
  92. step.error_message = (
  93. "Pipeline exceeded next scheduled start; waiting for "
  94. "the worker or lease expiry"
  95. )
  96. continue
  97. if step.status in {
  98. StepStatus.PENDING.value,
  99. StepStatus.READY.value,
  100. StepStatus.RETRY_WAIT.value,
  101. StepStatus.BLOCKED.value,
  102. }:
  103. step.status = StepStatus.BLOCKED.value
  104. step.error_code = "deadline_exceeded"
  105. step.error_message = "Pipeline exceeded next scheduled start"
  106. run_repo.finish(
  107. run,
  108. status=RunStatus.DEADLINE_EXCEEDED.value,
  109. now=now,
  110. error_code="deadline_exceeded",
  111. error_message="Pipeline exceeded next scheduled start",
  112. )
  113. stats["deadline_exceeded"] += 1
  114. for run in run_repo.list_blocked_previous():
  115. blocked_by = (run.summary_json or {}).get("blocked_by_run_id")
  116. previous = run_repo.get(str(blocked_by)) if blocked_by else None
  117. if previous is not None and previous.status in {
  118. RunStatus.QUEUED.value,
  119. RunStatus.RUNNING.value,
  120. RunStatus.CANCELLING.value,
  121. RunStatus.BLOCKED_PREVIOUS_RUN.value,
  122. }:
  123. continue
  124. if previous is not None and step_repo.has_running_for_run(previous.run_id):
  125. continue
  126. latest = step_repo.latest_attempts(run.run_id)
  127. first = min(latest.values(), key=lambda item: item.step_order, default=None)
  128. if first is None:
  129. continue
  130. first.status = StepStatus.READY.value
  131. first.error_code = None
  132. first.error_message = None
  133. for step in latest.values():
  134. if step.step_run_id != first.step_run_id:
  135. step.status = StepStatus.PENDING.value
  136. step.error_code = None
  137. step.error_message = None
  138. run.status = RunStatus.QUEUED.value
  139. run.summary_json = None
  140. stats["previous_run_unblocked"] += 1
  141. for run in run_repo.list_nonterminal():
  142. alert_level = run_alert_level(
  143. status=run.status,
  144. started_at=run.started_at,
  145. created_at=run.created_at,
  146. deadline_at=run.deadline_at,
  147. now=now,
  148. settings=settings,
  149. )
  150. if alert_level is not None:
  151. logger.warning(
  152. "pipeline_alert level=%s run_id=%s biz_dt=%s status=%s deadline=%s",
  153. alert_level,
  154. run.run_id,
  155. run.biz_dt,
  156. run.status,
  157. run.deadline_at.isoformat() if run.deadline_at else None,
  158. )
  159. stats["alerts_emitted"] += 1
  160. local_now = now.replace(tzinfo=CHINA_TIMEZONE).astimezone(
  161. ZoneInfo(settings.scheduler_timezone)
  162. )
  163. missed_cutoff = local_now.replace(
  164. hour=settings.scheduler_cron_hour,
  165. minute=settings.scheduler_cron_minute,
  166. second=0,
  167. microsecond=0,
  168. ) + timedelta(seconds=settings.pipeline_missed_run_grace_seconds)
  169. if settings.scheduler_enabled and local_now >= missed_cutoff:
  170. biz_dt = local_now.strftime("%Y%m%d")
  171. with get_session() as session:
  172. existing = PipelineRunRepository(session).get_for_business_day(
  173. pipeline_key=PIPELINE_KEY,
  174. biz_dt=biz_dt,
  175. )
  176. if existing is None:
  177. submission = submit_pipeline_run(
  178. biz_dt=biz_dt,
  179. trigger_type="reconcile",
  180. trigger_source="missed_run_reconciler",
  181. trigger_reason="Scheduled batch was absent after the grace window",
  182. settings=settings,
  183. )
  184. if submission.created:
  185. logger.error(
  186. "pipeline_alert level=critical type=missed_run_recovered "
  187. "run_id=%s biz_dt=%s",
  188. submission.run_id,
  189. biz_dt,
  190. )
  191. stats["missed_runs_submitted"] = 1
  192. return stats
  193. class PipelineReconciler:
  194. def __init__(self, settings: InfraSettings | None = None) -> None:
  195. self.settings = settings or get_infra_settings()
  196. self._stop = threading.Event()
  197. def stop(self, *_args: object) -> None:
  198. self._stop.set()
  199. def run_forever(self) -> None:
  200. signal.signal(signal.SIGTERM, self.stop)
  201. signal.signal(signal.SIGINT, self.stop)
  202. logger.info("Pipeline reconciler started")
  203. try:
  204. while not self._stop.is_set():
  205. try:
  206. logger.info("Pipeline reconcile result: %s", reconcile_once())
  207. except Exception:
  208. logger.exception("Pipeline reconcile failed")
  209. self._stop.wait(self.settings.pipeline_reconcile_seconds)
  210. finally:
  211. dispose_engine()
  212. logger.info("Pipeline reconciler stopped")