diff --git a/AI-MAP.md b/AI-MAP.md index aebf19c6e..c0b0fee7a 100644 --- a/AI-MAP.md +++ b/AI-MAP.md @@ -143,6 +143,7 @@ - `docs/observability.rst` — **אובזרווביליות (Observability)**: המטרות וקהלי היעד, התצורה, בחירת Backend ל-Traces, הגדרת OTLP לסביבות, ואינסטרומנטציה ידנית. - `docs/observability/background-jobs-monitor.rst` — **Background Jobs Monitor**: פיצ'ר ה-Background Jobs Monitor מספק נראות (Observability) מלאה לכל ה-Jobs הרצים ברקע במערכת, כולל פעולות משתמש דינמיות (Drive, Reminders, Batch Operations). +- `docs/observability/daily-morning-report.rst` — **דוח בוקר יומי**: ה-job שמצליב בין מקורות הניטור הקיימים ושולח סיכום יומי לטלגרם — מה נכנס להודעה, איך נשמר הבסיס להשוואה, ולמה השליחה נבדקת מראש. - `docs/observability/observability_dashboard.md` — **📡 Observability Dashboard & API**: מסך ה-Admin ב-/admin/observability מרכז נתוני ניטור בזמן אמת ל-SRE ולמפתחים: כרטיסי מצב וגרפים, טבלת התראות עם סינון, ו-API מתועד למסלולי alerts, timeseries, aggregations, export, replay, runbook, quickfix ו-ai_explain. - `docs/observability/query-performance-profiler.rst` — **Query Performance Profiler**: כלי ניטור לשאילתות MongoDB איטיות: דשבורד ב-WebApp שמציג את השאילתות הכבדות, ה-API שמאחוריו, ומה הכלי במפורש אינו עושה. - `docs/observability/quick_fix_rules.md` — **🧠 Quick Fix חכם (Queue Delay + עומס/DB) – הנחיות למפתחים ולסוכני AI**: המטרה של Quick Fix היא לתת המלצה קצרה, בטוחה ושימושית על “מה לעשות עכשיו”, לפי אותות שאנחנו כבר מודדים. @@ -193,4 +194,4 @@ --- -עמודי פיגום autodoc שסוננו: 92. עמודים שנסרקו: 229. +עמודי פיגום autodoc שסוננו: 92. עמודים שנסרקו: 230. diff --git a/alert_forwarder.py b/alert_forwarder.py index 524917726..c2565caa3 100644 --- a/alert_forwarder.py +++ b/alert_forwarder.py @@ -1001,7 +1001,23 @@ def forward_alerts(alerts: List[Dict[str, Any]]) -> None: continue _post_to_slack(text_slack) # Send to Telegram only if severity >= configured minimum - if _severity_rank(severity) >= min_tg_rank: + if _severity_rank(severity) < min_tg_rank: + # שער החומרה היה עד כה המקום היחיד בצינור שבו הודעה נעלמת + # בלי שום עקבה — בזמן שהחסימה מרשימת ה-suppress שמתחתיו כן + # פולטת אירוע. הפער הזה הופך תקלת קונפיגורציה (למשל + # ALERT_TELEGRAM_MIN_SEVERITY שהועלה ושכחו ממנו) לשקט שנראה + # בדיוק כמו מערכת בריאה. + try: + emit_event( + "alert_telegram_below_min_severity", + severity="info", + alertname=alert_name, + severity_label=str(severity), + min_severity=str(os.getenv("ALERT_TELEGRAM_MIN_SEVERITY", "info")), + ) + except Exception: + pass + else: if _is_telegram_suppressed(alert_name): try: emit_event( diff --git a/config/alerts.yml b/config/alerts.yml index 9364c89a6..633d6bd79 100644 --- a/config/alerts.yml +++ b/config/alerts.yml @@ -19,3 +19,11 @@ alerts: severity: critical cooldown_seconds: 600 message: "⚠️ Job {job_id} תקוע כבר {minutes} דקות" + + # job מתוזמן שלא התחיל בכלל. job_failed ו-job_stuck מכסים רק ריצות שכבר + # התחילו, ולכן "לא רץ" היה עד היום שקט מוחלט — בדיוק הכשל שאי אפשר לראות. + - name: job_missed_alert + event_pattern: "job_missed" + severity: error + cooldown_seconds: 3600 + message: "🔕 Job {job_id} — לא נרשמה לו ריצה כבר {hours} שעות" diff --git a/database/manager.py b/database/manager.py index 34ad739dc..355d254ff 100644 --- a/database/manager.py +++ b/database/manager.py @@ -1972,6 +1972,39 @@ def _create_profiler_indexes(self, safe_create_index) -> None: name="slow_queries_coll_dur", ) + def _create_daily_report_indexes(self, safe_create_index) -> None: + """אינדקס TTL לאוסף שדוח הבוקר היומי שומר בו סנאפשוט אחד ליום. + + שם האוסף ומשך השמירה נקראים מהשירות עצמו ולא נכתבים כאן, בדיוק כמו + ב-``_create_profiler_indexes`` — שני מקורות לאותו קבוע היו נסחפים. + + **למה 45 יום ולא 7 כמו המקורות:** הסנאפשוט הוא מספרים בלבד והוא + זעיר, אבל הוא צריך לשרוד מעבר לחלון של 30 הימים שבו נשמרים הדפוסים + וסוגי השגיאות המוכרים. TTL זהה למקורות היה מוחק את הבסיס להשוואה + לפני שהוא מספיק לשמש. + + ``enforce=True`` מאותה סיבה שהוא קיים אצל הפרופיילר: מונגו אינו + מעדכן ``expireAfterSeconds`` של אינדקס קיים בקריאה חוזרת ל- + ``create_index`` — הוא מחזיר ``IndexOptionsConflict`` וה-retention + הישן שורד בשקט. + + ⚠️ זהו אינדקס TTL: הוא מוחק נתונים בפועל, במכוון. + """ + try: + from services.daily_report_service import COLLECTION_NAME, TTL_SECONDS # type: ignore + except Exception: + # השירות אינו זמין (סביבה מינימלית) — אין טעם ליצור אינדקס לאוסף + # שאיש לא כותב אליו. + return + + safe_create_index( + COLLECTION_NAME, + [("created_at", ASCENDING)], + name="ttl_cleanup", + expire_after_seconds=int(TTL_SECONDS), + enforce=True, + ) + def _create_indexes(self): """צור *רק* את האינדקסים הקריטיים (ברקע) למניעת COLLSCAN. @@ -2046,12 +2079,25 @@ def safe_create_index(*args: Any, **kwargs: Any) -> None: name="idx_job_runs_id", unique=True, ) + # job_runs — שאילתות לפי job_id עם מיון לפי זמן. + # משרת את get_job_history, את "/jobs failed" ב-ChatOps, ואת בדיקת + # "job מתוזמן שלא רץ" ב-_jobs_stuck_monitor. האינדקס הזה כבר מוצהר + # ב-database/job_runs_collection.py, אבל אותו קובץ אינו מיובא בשום + # מקום ולכן אף אינדקס שבו לא נוצר בפועל. + safe_create_index( + "job_runs", + [("job_id", ASCENDING), ("started_at", DESCENDING)], + name="idx_job_runs_job_started", + ) # slow_queries_log - האוסף שהפרופיילר כותב אליו. # קריאה לא-קשורה (unbound) כמו שאר הקובץ, כדי לתמוך גם ב-self דמה מטסטים # שאין עליו את המתודה (ראה שים התאימות למעלה). DatabaseManager._create_profiler_indexes(self, safe_create_index) + # daily_report_snapshots - סנאפשוט יומי של דוח הבוקר (קריאה לא-קשורה, כמו למעלה) + DatabaseManager._create_daily_report_indexes(self, safe_create_index) + # scheduler_jobs - אינדקס לשאילתות polling לפי next_run_time (רץ בתדירות גבוהה) safe_create_index( "scheduler_jobs", diff --git a/docs/environment-variables.rst b/docs/environment-variables.rst index 865a4ba95..adf7749ea 100644 --- a/docs/environment-variables.rst +++ b/docs/environment-variables.rst @@ -2228,6 +2228,24 @@ - ``scheduler_jobs`` - ``scheduler_jobs_eu`` - Bot + * - ``DISABLE_DAILY_REPORT`` + - מכבה את דוח הבוקר היומי. ריק = פעיל. + - לא + - (ריק) + - ``true`` + - Bot + * - ``DAILY_REPORT_HOUR_LOCAL`` + - שעת שליחת דוח הבוקר בפורמט ``HH:MM``, בשעון ישראל. ערך פגום חוזר ל-08:00 ונרשם כאזהרה. + - לא + - ``08:00`` + - ``07:30`` + - Bot + * - ``DAILY_REPORT_CORRELATION_WINDOW_MINUTES`` + - רוחב חלון ההצלבה בין התראה לשאילתה איטית, בדקות. נחסם לטווח 1–120. + - לא + - ``5`` + - ``10`` + - Bot * - ``WEEKLY_REPORT_DELAY_SECS`` - כמה זמן להמתין אחרי עלייה לפני הפעלת job הדו"חות השבועיים. - לא diff --git a/docs/index.rst b/docs/index.rst index 92696f4b0..1246645a5 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -152,6 +152,7 @@ Code Keeper Bot - תיעוד API observability observability/background-jobs-monitor + observability/daily-morning-report observability/observability_dashboard observability/query-performance-profiler observability/quick_fix_rules diff --git a/docs/observability/background-jobs-monitor.rst b/docs/observability/background-jobs-monitor.rst index 42c12717d..781a94fb7 100644 --- a/docs/observability/background-jobs-monitor.rst +++ b/docs/observability/background-jobs-monitor.rst @@ -37,6 +37,8 @@ Background Jobs Monitor - תבנית הדשבורד * - ``chatops/jobs_commands.py`` - פקודת ``/jobs`` בטלגרם + * - ``services/daily_report_service.py`` + - דוח הבוקר היומי: קריאת המקורות, השוואה מול אתמול ורינדור * - ``config/alerts.yml`` - הגדרות Alerts ל-Jobs @@ -79,6 +81,22 @@ Background Jobs Monitor {"keys": [("user_id", 1), ("job_id", 1)], "sparse": True}, ] +קולקציה: ``daily_report_snapshots`` +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +דוח הבוקר היומי שומר שורה אחת ליום — מספרים בלבד, בלי טקסט ההודעה — כדי +שיהיה לו מול מה להשוות מחר. ``_id`` הוא התאריך המקומי שהיום מתאר +(``YYYY-MM-DD``), ולכן ההשוואה יכולה לדרוש את D-1 במפורש במקום ליפול על +"השורה האחרונה שיש". + +הכתיבה היא ``$setOnInsert``: הכתיבה הראשונה ליום מנצחת, ולכן טריגר ידני +שרץ במקביל לריצה המתוזמנת אינו דורס סנאפשוט תקין. + +ה-TTL כאן **ארוך מזה של המקורות** (``slow_queries_log`` — שבעה ימים), כי +הסנאפשוט מחזיק גם זיכרון של דפוסי שאילתה וסוגי שגיאות מוכרים לחלון של 30 +יום. שמו של האוסף ומשך השמירה נקראים מ-``services/daily_report_service.py`` +ואינם כתובים שוב ב-``database/manager.py``. + UI / WebApp ----------- @@ -309,6 +327,12 @@ Alerts cooldown_seconds: 600 message: "⚠️ Job {job_id} תקוע כבר {minutes} דקות" + - name: job_missed_alert + event_pattern: "job_missed" + severity: error + cooldown_seconds: 3600 + message: "🔕 Job {job_id} — לא נרשמה לו ריצה כבר {hours} שעות" + Flow של Alerts ~~~~~~~~~~~~~~ @@ -317,13 +341,29 @@ Flow של Alerts 3. בדיקה מול ``alerts.yml`` ו-cooldown 4. שליחת התראה לערוץ המוגדר (Telegram/Slack) +**זיהוי Job שלא רץ בכלל:** + +``job_failed`` ו-``job_stuck`` מכסים רק הרצות ש**התחילו**. Job שהתזמון שלו +נעלם — משתנה סביבה שנמחק, חריגה בעלייה, restart שבלע את התזמון — היה שקט +מוחלט, וזה נראה בדיוק כמו מערכת בריאה. + +Job שמצהיר ב-``metadata`` על ``missed_after_hours`` נבדק באותו background loop +של ה-stuck monitor: שאילתה מצרפית אחת על ``job_runs`` מחזירה מי כן רץ בחלון +(``completed`` או ``failed`` — כשל כבר מכוסה, השאלה כאן היא אי-התחלה), והחסרים +מפיקים ``job_missed``. ההתראה נשלחת פעם אחת ליום לכל Job — השער הוא upsert מותנה על ``admin_reports``, ו"היום כבר נתפס" מגיע ממנו כהתנגשות מפתח ייחודי (``DuplicateKeyError``) ולא כ-``modified_count=0``, כי אופרטור ה-``$ne`` שבשאילתה אינו נכנס למסמך שנוצר ב-upsert. + +מה שנבדק הוא היעדר **רשומה** ב-``job_runs``, לא היעדר ריצה: ``JobTracker._persist_run`` רושם כשל כתיבה ללוג ואינו מפיל את ההרצה, ולכן ריצה שקרתה ורשומתה לא נשמרה תיראה כאן כהיעדר. שתי הבדיקות — ה-stuck וה-missed — רצות באותו loop אבל ב-``try`` נפרד: כשל של אחת אינו משתיק את השנייה. + **זיהוי Jobs תקועים:** מתבצע ב-background loop (כל ``JOBS_STUCK_MONITOR_INTERVAL_SECS`` שניות): 1. סריקת ``job_runs`` עם ``status=running`` 2. אם ``started_at`` לפני יותר מ-``JOBS_STUCK_THRESHOLD_MINUTES`` דקות -3. פליטת ``emit_event("job_stuck", ...)`` +3. סימון ``stuck_reported_at`` בכתיבה מותנה (``{"run_id": ..., "stuck_reported_at": {"$exists": false}}``) +4. פליטת ``emit_event("job_stuck", ...)`` — **רק אם הסימון באמת שינה מסמך** + +הצעד הרביעי אינו קוסמטי. הסריקה והסימון הם check-then-act: שני תהליכים שראו את אותה הרצה בסריקה יגיעו שניהם לכתיבה, ורק אצל אחד ``stuck_reported_at`` ייכתב בפועל. ``modified_count=0`` פירושו "מישהו אחר כבר דיווח", ובלי בדיקת ה-rowcount הסימון היה שדה לוואי במקום שער — ההתראה נפלטה פעמיים. כשל **כתיבה** (חריגה) נשאר fail-open ופולט בכל זאת, כי לא ידוע אם סימנו, והרצה תקועה שאיש אינו יודע עליה גרועה מהתראה כפולה. Troubleshooting --------------- diff --git a/docs/observability/daily-morning-report.rst b/docs/observability/daily-morning-report.rst new file mode 100644 index 000000000..6ec5e11af --- /dev/null +++ b/docs/observability/daily-morning-report.rst @@ -0,0 +1,270 @@ +דוח בוקר יומי +============== +:summary: ה-job שמצליב בין מקורות הניטור הקיימים ושולח סיכום יומי לטלגרם — מה נכנס להודעה, איך נשמר הבסיס להשוואה, ולמה השליחה נבדקת מראש. + +.. contents:: תוכן עניינים + :local: + :depth: 2 + +למה זה קיים +----------- + +לכל דשבורד יש חלק אחד של הסיפור, ולאף אחד מהם אין את השאר. התראה בזמן אמת +יודעת רק על עצמה: היא לא יכולה לומר שבאותו חלון זמן גם השאילתות האיטיות +התרכזו, גם ה-Hit Rate ירד, וגם נכנס דיפלוי. + +הדוח הזה **אינו מודד דבר חדש ואינו קובע שום סף חדש**. הוא קורא ממה שכבר +נכתב, מצליב בין המקורות, ומשווה מול אתמול. + +שני עקרונות שמכתיבים את כל ההתנהגות: + +- **מדווח שינוי, לא מצב.** מה שכבר חצה סף צעק בזמן אמת, ולכן כאן הוא ספירה + בלבד ולא חזרה על תוכן ההתראה. מה שזז בלי לחצות סף — זו הסיבה שהדוח קיים. +- **יום שקט אינו מייצר הודעה.** שורה שנראית זהה כל יום נהיית רקע, ומפסיקים + לקרוא אותה. החיות של ה-job נמדדת מרישום ההרצה ב-``job_runs`` ומהתראת + ``job_missed`` — לא מהודעה שמעידה על עצמה. + +מה נכנס להודעה +--------------- + +.. list-table:: + :header-rows: 1 + :widths: 22 33 45 + + * - מקור + - ספירה (כבר התריע) + - שינוי (אין עליו התראה) + * - Observability + - כמה CRITICAL, כמה ERROR, האם היה דיפלוי + - האם ה-endpoint האיטי ביותר הוא אותו אחד מאתמול + * - Query Profiler + - — + - דפוס שאילתה שלא נראה קודם, וקפיצה במספר החזרות של הדפוס הגדול ביותר + * - Cache + - — + - Hit Rate של היממה מול המצטבר של אתמול + * - Jobs + - כשלים והרצות תקועות + - Job שרץ בהצלחה על ``total_items: 0`` יומיים ברצף + * - DB + - — + - קצב גדילת האוספים הגדולים + * - MCP + - — + - סוג שגיאה שלא נראה קודם, ובקשות לכלי חסר + +הצלבת חלונות הזמן +~~~~~~~~~~~~~~~~~~ + +זו הסיבה שהדוח הוא דוח אחד ולא חמש הודעות. השאלה שנשאלת: האם אירועים +ממקורות שונים נופלים באותו חלון זמן. + +שאילתה איטית **בתוך** חלון של התראה מצביעה על שרשרת שלמה — endpoint, +שאילתה, אוסף. שאילתה איטית **מחוץ** לחלון אומרת שה-latency הגיע ממקום אחר, +ואין טעם לחפש אותו במסד. + +רוחב החלון הוא ‏5 דקות כברירת מחדל, וזה לא מספר שרירותי: זהו חלון הדגימה +שהתראות ה-latency נבנות עליו (``window_minutes`` ב-``config/alerts.yml``), +והדלי של ``service_metrics`` הוא 60 שניות. חלון רחב מדי מייצר קישור סיבתי +שגוי — וזה גרוע מכלום, כי הוא שולח לחפש במקום הלא נכון. הערך ניתן לכוונון +ב-``DAILY_REPORT_CORRELATION_WINDOW_MINUTES``. + +.. warning:: + + ההצלבה מפרשת חותמת זמן **נאיבית** כ-UTC. זה נכון כי + ``PersistentQueryProfilerService`` כותב ``datetime.utcnow()``. אם מישהו + יחליף שם לשעון מקומי, חלון של חמש דקות יהפוך לחלון של שעתיים־שלוש — + וההצלבה תשתוק בלי להתלונן. יש בדיקה ייעודית שמזייפת את השעון ומפילה את + הבנייה במקרה כזה. + +מקור שנכשל לקרוא אינו מקור שהחזיר אפס +-------------------------------------- + +זו ההבחנה המרכזית בקוד, והיא הסיבה שהדוח אינו משתמש בקוראים הקיימים כמו +שהם. ``aggregate_alert_summary``, ``aggregate_top_endpoints`` ו- +``get_pattern_statistics`` מחזירים ``0`` או ``[]`` גם כשהמסד לא זמין — כלומר +תקלה נראית בדיוק כמו "לא קרה כלום". + +אילו הדוח היה נשען עליהם, כשל בקריאה היה נשמר בסנאפשוט כאפס, ולמחרת הדוח היה +מכריז על **שיפור**. לכן כל מקור נקרא ישירות ונעטף ב-``SourceRead``: כשל הוא +``ok=False`` עם ערך ``None``, לעולם לא אפס. בהודעה הוא מופיע כ-"אין נתון", +ולעולם לא כ-"ירד" או "השתפר". + +כשל של מקור אחד אינו מפיל את הדוח ואינו משתיק את שאר השורות. + +הבסיס להשוואה +-------------- + +כל שורת שינוי דורשת ערך להשוות אליו. הוא נשמר באוסף +``daily_report_snapshots`` — שורה אחת ליום, מספרים בלבד, בלי טקסט ההודעה. +המבנה והמדיניות מתועדים ב-:doc:`background-jobs-monitor`. + +שלוש החלטות שכדאי להכיר: + +- **ההשוואה דורשת את D-1 במפורש.** לא "השורה האחרונה שיש": יום שבו ה-job לא + רץ היה גורם להשוואה מול שלשום, ואז שינוי של יומיים מדווח כשינוי של יום. + אין D-1 ← ההודעה אומרת שאין בסיס להשוואה, ומדלגת על השורות שדורשות אחד. +- **הסנאפשוט נשמר תמיד, ולפני ההחלטה אם לשלוח.** יום שקט שלא משאיר סנאפשוט + הופך את הדוח של מחר לשקר שקט. +- **‏Hit Rate מחושב מההפרש.** ``keyspace_hits`` ו-``keyspace_misses`` הם + מונים מצטברים מאז עליית Redis, ולכן הערך שהדשבורד מציג הוא ממוצע כל + החיים והשוואה יומית שלו היא רעש. הסנאפשוט שומר את המונים הגולמיים, + והדוח גוזר מהם את ה-Hit Rate של היממה. ``uptime_seconds`` שקטן מאתמול + פירושו ש-Redis הופעל מחדש — ואז ההודעה אומרת שאין בסיס, במקום להציג שינוי + מזויף. + +שער המסירה +----------- + +.. important:: + + הדוח **בודק שהוא יכול להימסר לפני שהוא מדווח הצלחה.** + +``emit_internal_alert`` מחזיר ``None`` ואינו מדווח כשל בשום מסלול. בלי בדיקה +מוקדמת, הרצה שבה ההודעה נחסמה הייתה מסתיימת ב-``completed`` — ✅ על משהו +שלא קרה. + +לפני השליחה נבדקים ארבעה תנאים, באמצעות **הפונקציות של ה-forwarder עצמו** +ולא בקריאה עצמאית של משתני הסביבה (רשימת ההשתקה מחושבת שם בזמן ה-import, +ולכן קריאה עצמאית עלולה לסתור את מה שקורה בפועל): + +.. list-table:: + :header-rows: 1 + :widths: 32 68 + + * - סיבת חסימה + - מתי + * - ``below_min_severity`` + - חומרת הדוח נמוכה מ-``ALERT_TELEGRAM_MIN_SEVERITY`` + * - ``suppressed`` + - ``daily_morning_report`` מופיע ב-``ALERT_TELEGRAM_SUPPRESS_ALERTS`` + * - ``no_token`` / ``no_chat`` + - ``ALERT_TELEGRAM_BOT_TOKEN`` או ``ALERT_TELEGRAM_CHAT_ID`` אינם מוגדרים + +תנאי שנכשל מסיים את ההרצה כ-``failed`` עם ``telegram_gate:<סיבה>``, וההודעה +אינה נשלחת. + +הדוח נשלח בחומרה ``warn`` ולא ``info``, כי ``info`` נמוך מהסף שמוגדר +בפרודקשן ולא היה מגיע כלל. + +.. note:: + + באותה הזדמנות נסגר חור כללי יותר: שער החומרה ב-``alert_forwarder`` היה + המקום היחיד בצינור ההתראות שבו הודעה נעלמת בלי עקבה, בזמן שהחסימה מרשימת + ההשתקה שורה מתחתיו כן פולטת אירוע. עכשיו הוא פולט + ``alert_telegram_below_min_severity`` — כך שגם דוחות אחרים שנחסמים על הסף + מפסיקים להיעלם בשקט. + +דוח אחד ביום, גם כשהבוט עולה מחדש +---------------------------------- + +ה-job יכול לרוץ יותר מפעם אחת ביום בלי שאף אחד עשה טעות: עלייה מחדש של הבוט עם ``misfire_grace_time`` פתוח, נפילה חזרה ל-``run_repeating``, או טריגר ידני מהדשבורד. ``JobTracker.track`` מונע רק ריצות **חופפות באותו תהליך**, ולכן הוא לא נותן שום הגנה כאן. + +לכן ממש לפני השליחה — ואחרי שער המסירה — הדוח "תופס את היום": upsert מותנה על ``admin_reports`` עם ``{"_id": "daily_morning_report", "day_key": {"$ne": <היום>}}``. תפיסה מוצלחת ← שולחים; היום כבר תפוס ← ההרצה מסתיימת כ-``skipped`` עם ``already_sent_today``. + +.. important:: + + ``DuplicateKeyError`` פירושו **"כבר נשלח היום"**, לא "הבדיקה נכשלה". כשאין התאמה לשאילתה, MongoDB בונה את המסמך החדש מסעיפי השוויון בלבד ואינו מכניס אליו אופרטורי השוואה כמו ``$ne`` — כלומר הוא מנסה ליצור מסמך עם ``_id`` שכבר קיים, ונכשל בהתנגשות מפתח ייחודי. ``except Exception`` שבולע אותה הופך את השער לחסר תועלת בדיוק במקרה שהוא נבנה בשבילו. + +**המדיניות בכשל שונה בכוונה בין שני המקומות שמשתמשים בתבנית הזו:** בדוח היומי כשל בתפיסה נסגר (``day_claim_failed``, ולא שולחים), כי דוח כפול גרוע מדוח חסר. ב-``job_missed`` כשל בתפיסה נפתח וההתראה נשלחת בכל זאת, כי התראה שנעלמת גרועה מהתראה כפולה. + +מיקום השער אחרי הרינדור, ולא לפניו, גם הוא מכוון: יום שקט אינו מייצר הודעה, ואסור לו "לשרוף" את היום — טריגר ידני מאוחר יותר עדיין צריך להיות מסוגל לשלוח אם בינתיים קרה משהו. + +תזמון +------ + +``run_daily`` בשעה שמוגדרת ב-``DAILY_REPORT_HOUR_LOCAL`` (ברירת מחדל +``08:00``), **בשעון ישראל**. + +ה-``time`` נושא ``tzinfo`` מפורש, כי ה-``Defaults`` של הבוט מוגדר רק עם +``parse_mode`` וברירת המחדל של ה-JobQueue היא UTC — בלי אזור זמן מפורש הדוח +היה נשלח בשעה הלא נכונה. + +``misfire_grace_time`` הוא שעה, כדי ש-restart סמוך לשעת השליחה לא יבלע את +היום. בסביבה שבה ה-JobQueue אינו תומך בחתימה הזו יש נפילה מבוקרת ל- +``run_repeating`` שמתחיל במופע הבא של אותה שעה. + +.. warning:: + + ``utils._get_israel_tz`` נופל ל-UTC כשמסד אזורי הזמן חסר בסביבה. הנפילה + הזו מזיזה את הדוח בשעתיים, ולכן ה-job רושם את אזור הזמן שנבחר בפועל + בהיסטוריית ההרצה — כדי שההיסט יהיה נראה בדשבורד ולא רק בלוג האפליקציה. + +הפעלה ידנית +~~~~~~~~~~~~ + +``daily_morning_report`` רשום ב-``services/register_jobs.py`` ולכן מופיע +בדשבורד תחת קטגוריית ``monitoring``, עם היסטוריית הרצות וכפתור הפעלה. + +.. note:: + + כשה-API של הבוט אינו זמין (``BOT_JOBS_API_BASE_URL`` אינו מוגדר), הלחיצה + אינה סינכרונית: היא נכתבת ל-``job_trigger_requests`` והבוט מושך אותה + ב-polling. יש להמתין עד דקה ולא ללחוץ שוב — לחיצות חוזרות רק יוצרות + בקשות כפולות. ראו :doc:`background-jobs-monitor`. + +.. note:: + + שתי ריצות באותו יום אינן דורסות זו את זו: כתיבת הסנאפשוט היא + ``$setOnInsert``, כלומר הכתיבה הראשונה מנצחת, והריצה השנייה משווה מול מה + שנשמר בפועל. ``JobTracker`` מונע חפיפה רק בתוך אותו תהליך, ולכן הוא לבדו + אינו הגנה מספקת. + +מה הדוח אינו עושה +------------------ + +- **אינו מדווח על מצב ה-Connection Pool.** אין בקוד היסטוריה של ה-Pool ואין + עליו התראה — הוא נמדד חי בלבד. שורת ה-DB בדוח היא קצב גדילת האוספים בלבד. + לתמונת ה-Pool נכנסים ל-``/db-health``. +- **אינו מדווח על מפתחות שהגיעו למכסת חסימה.** אין בקוד מקור שמחשב את זה. +- **אינו מבטיח שדפוס שאילתה חדש ניתן לניתוח.** הסימון נגזר מהרשומה עצמה: + שאילתה שנשמרה בלי הערכים האמיתיים אינה מסומנת כניתנת לניתוח. +- **אינו מציג נתוני MCP כאילו הם של אתמול.** האנדפוינטים השמורים ב-PostHog + אינם מקבלים טווח תאריכים, ולכן הסינון ליממה נעשה אצלנו, וחותמת הרענון של + PostHog מוצגת בשורה עצמה. + +משתני סביבה +------------ + +הרשימה המלאה: :doc:`../environment-variables`. + +.. list-table:: + :header-rows: 1 + :widths: 42 40 18 + + * - משתנה + - תיאור + - ברירת מחדל + * - ``DISABLE_DAILY_REPORT`` + - מכבה את הדוח + - (ריק) + * - ``DAILY_REPORT_HOUR_LOCAL`` + - שעת שליחה, ``HH:MM`` בשעון ישראל + - ``08:00`` + * - ``DAILY_REPORT_CORRELATION_WINDOW_MINUTES`` + - רוחב חלון ההצלבה בדקות + - ``5`` + +הדוח נשען גם על ``ALERT_TELEGRAM_MIN_SEVERITY`` ועל +``ALERT_TELEGRAM_BOT_TOKEN``/``ALERT_TELEGRAM_CHAT_ID`` — ראו `שער המסירה`_. + +טסטים +------ + +- ``tests/test_daily_report_service.py`` — הקריאה מכל מקור, ההשוואה, הרינדור, + וההבחנה בין כשל לאפס. +- ``tests/test_daily_report_job.py`` — שער המסירה, התזמון, וזיהוי Job שלא רץ. +- ``tests/test_daily_report_indexes.py`` — ה-TTL של הסנאפשוט והאינדקס על + ``job_runs``. + +לכל בדיקה מהותיות יש צד שני שמוודא שהיא יודעת גם לומר "כן": ביום שקט טענה כמו +"אין דפוס חדש" מתקיימת גם על קוד שאינו מסוגל לזהות דפוס חדש בכלל. + +ראו גם +------- + +- :doc:`background-jobs-monitor` — תשתית ה-Jobs, אוסף הסנאפשוט וההתראות +- :doc:`query-performance-profiler` — מקור השאילתות האיטיות +- :doc:`observability_dashboard` — מקור ההתראות והדיפלויים +- :doc:`/webapp/cache-inspector` — מקור מוני ה-Redis +- :doc:`/webapp/mcp-analytics` — מקור נתוני ה-MCP diff --git a/docs/observability/events_catalog.rst b/docs/observability/events_catalog.rst index 8d237f629..076131301 100644 --- a/docs/observability/events_catalog.rst +++ b/docs/observability/events_catalog.rst @@ -48,6 +48,25 @@ Alerts - ``alert_received`` — התקבלה התראה מה-Alertmanager. - ``alerts_parse_error`` — כשל בפענוח ההתראה. +- ``alert_telegram_below_min_severity`` — התראה לא נשלחה לטלגרם כי חומרתה נמוכה מ-``ALERT_TELEGRAM_MIN_SEVERITY``. +- ``alert_telegram_suppressed`` — התראה לא נשלחה לטלגרם כי שמה מופיע ב-``ALERT_TELEGRAM_SUPPRESS_ALERTS``. + +Jobs +---- + +- ``job_started`` / ``job_completed`` / ``job_failed`` / ``job_skipped`` — מחזור החיים של הרצת Job. +- ``job_stuck`` — הרצה נשארה ב-``running`` מעבר לסף. +- ``job_missed`` — ל-Job מתוזמן לא נרשמה אף ריצה בחלון שהוגדר לו. משלים את + השניים שמעליו, שמכסים רק הרצות שכבר התחילו. שני דיוקים חשובים: ריצה + ש**נכשלה** נחשבת כריצה (כשל כבר מכוסה ב-``job_failed``, וכאן נבדקת + אי-התחלה בלבד), ומה שנבדק הוא היעדר **רשומה** ב-``job_runs`` — כתיבה + שנכשלה נרשמת ללוג ואינה מפילה את ההרצה, ולכן ריצה שקרתה ורשומתה לא + נשמרה תיראה כאן כהיעדר. +- ``daily_report_sent`` — דוח הבוקר היומי נשלח. + +.. code-block:: json + + {"event":"job_missed","severity":"error","job_id":"daily_morning_report","hours":26} Repo Analyzer ------------- diff --git a/main.py b/main.py index 24aebcbb3..08d9d7518 100644 --- a/main.py +++ b/main.py @@ -800,6 +800,618 @@ async def _send_direct_admins(context: ContextTypes.DEFAULT_TYPE, text: str) -> return False +def _claim_outcome(res) -> str: + """מתרגם תוצאת כתיבה מותנה ל-``claimed`` או ל-``already``. + + התבנית המשותפת לכל אתרי הקריאה היא "תפוס את X, אבל רק אם עוד לא + נתפס" — ``update_one`` שהתנאי לתפיסה יושב בתוך השאילתה עצמה, ולכן + התפיסה אטומית. **התוצאה היא התשובה, לא תופעת לוואי:** מי שמתעלם ממנה + קיבל שער שקיים ואינו פועל, כי שני תהליכים שעברו את הקריאה יגיעו שניהם + לכתיבה ורק אחד באמת ישנה מסמך. + + שתי צורות מעידות על תפיסה מוצלחת: ``upserted_id`` כשלא היה מסמך קודם, + ו-``modified_count`` כשהיה מסמך במצב אחר. אפס בשניהם = מישהו כבר תפס. + (ב-``upsert=False`` רק השנייה אפשרית.) + + **חשוב:** זו רק אחת משתי הדרכים שבהן "כבר נתפס" מגיע. הדרך השנייה היא + חריגה, ואותה כל אתר קריאה תופס בעצמו — ראו ההערה ב- + ``_claim_daily_report_day``. + """ + if int(getattr(res, "modified_count", 0) or 0) or getattr(res, "upserted_id", None): + return "claimed" + return "already" + + +def _claim_daily_report_day(db_obj, day_key: str, now) -> str: + """תובע את היום עבור דוח הבוקר. ``claimed`` / ``already`` / ``error``. + + **למה זה קיים.** ה-job יכול לרוץ יותר מפעם אחת ביום: עלייה מחדש של + הבוט עם ``misfire_grace_time`` פתוח, נפילה חזרה ל-``run_repeating``, + או טריגר ידני מהדשבורד. ``tracker.track`` מונע רק ריצות **חופפות** + באותו תהליך, ולכן הוא לא עוזר כאן. המצב הזה כבר קרה בפרודקשן בדוח + השבועי, שנשלח כמה פעמים ביום. + + **למה ``DuplicateKeyError`` הוא "כבר נשלח" ולא "כשל".** תיעוד MongoDB, + בסעיף Upsert Behavior, אומר שכאשר אין התאמה המסמך החדש נבנה *מסעיפי + השוויון שבשאילתה בלבד*, ושאופרטורי השוואה (``$ne``) אינם נכנסים אליו. + כלומר כשכבר קיים מסמך עם אותו ``_id`` וה-``day_key`` של היום, השאילתה + לא מוצאת התאמה, מונגו מנסה ליצור מסמך עם ``_id`` שכבר תפוס, ונכשל + בהתנגשות מפתח ייחודי. זה בדיוק המקרה שהשער נבנה בשבילו. + + **fail-closed בכוונה.** כשל אחר מחזיר ``error``, והדוח לא נשלח. זו + מדיניות הפוכה מזו של ``job_missed``: התראה שנעלמת גרועה מהתראה כפולה, + אבל דוח כפול גרוע מדוח חסר — עדיף להפסיד יום מאשר להציף. + """ + try: + coll = db_obj["admin_reports"] + except Exception: + return "error" + try: + res = coll.update_one( + {"_id": "daily_morning_report", "day_key": {"$ne": day_key}}, + {"$set": {"day_key": day_key, "last_sent_at": now}}, + upsert=True, + ) + except DuplicateKeyError: + return "already" + except Exception: + return "error" + return _claim_outcome(res) + + +async def _check_missed_scheduled_jobs(db_obj, now=None) -> list: + """מזהה job מתוזמן שלא רץ בכלל, ומחזיר את רשימת מי שדווח עליו. + + ``job_failed`` ו-``job_stuck`` מכסים רק ריצות ש**התחילו**. job שהתזמון שלו + נעלם — משתנה סביבה שנמחק, restart שבלע את התזמון, חריגה בעלייה — פשוט + שותק, וזה נראה בדיוק כמו מערכת בריאה. זו הסיבה שהבדיקה הזו קיימת, והיא + היישום של הכלל שחיות נמדדת ב-heartbeat שהרכיב מעדכן ולא בכך שמישהו שם לב + שהוא שקט; ה-heartbeat כאן הוא רשומת ההרצה ב-``job_runs``. + + **שאילתה מצרפית אחת ולא לולאה.** המנגנון רץ כל 60 שניות, ואסור לו לייצר + בעצמו את בעיית הביצועים שהוא נועד לתפוס. + + ``failed`` נחשב "רץ" בכוונה: כשל כבר מכוסה ב-``job_failed``, והשאלה כאן + היא אי-התחלה בלבד. + """ + from datetime import datetime as _dt, timedelta as _td, timezone as _tz + + now = now or _dt.now(_tz.utc) + try: + from services.job_registry import JobRegistry # type: ignore + + registry = JobRegistry() + expected = {} + for job in registry.list_all(): + meta = getattr(job, "metadata", None) or {} + hours = meta.get("missed_after_hours") + if not hours: + continue + if not registry.is_enabled(job.job_id): + continue + expected[str(job.job_id)] = int(hours) + except Exception: + return [] + + if not expected: + return [] + + coll = getattr(db_obj, "job_runs", None) + if coll is None or not hasattr(coll, "aggregate"): + return [] + + # החלון הרחב ביותר מכסה את כולם בשאילתה אחת; ההשוואה הפרטנית נעשית אחריה. + cutoff = now - _td(hours=max(expected.values())) + pipeline = [ + { + "$match": { + "job_id": {"$in": sorted(expected)}, + "status": {"$in": ["completed", "failed"]}, + "started_at": {"$gte": cutoff}, + } + }, + {"$group": {"_id": "$job_id", "last_started_at": {"$max": "$started_at"}}}, + ] + try: + rows = await coll.aggregate(pipeline).to_list(length=100) + except Exception: + return [] + + last_seen = {} + for row in list(rows or []): + job_id = str((row or {}).get("_id") or "") + ts = (row or {}).get("last_started_at") + if job_id and ts is not None: + last_seen[job_id] = ts + + # האוסף נלקח פעם אחת ולא לכל job: הוא אינו משתנה בין איטרציות, וכשל + # בהשגתו משאיר ``None`` — כלומר fail-open, כמו כל כשל אחר בשער הזה. + try: + reports = getattr(db_obj, "admin_reports", None) + except Exception: + reports = None + + reported = [] + for job_id, hours in sorted(expected.items()): + ts = last_seen.get(job_id) + if ts is not None: + if ts.tzinfo is None: + ts = ts.replace(tzinfo=_tz.utc) + # אף פעם לא שלילי: הפרש שלילי מ-clock skew היה מסתיר ריצה אמיתית. + if max(_td(0), now - ts) < _td(hours=hours): + continue + + # התראה אחת ליום לכל job — upsert מותנה, "תפוס את היום אם עוד לא נתפס". + day_key = now.date().isoformat() + if reports is not None: + try: + res = await reports.update_one( + {"_id": f"job_missed:{job_id}", "day_key": {"$ne": day_key}}, + {"$set": {"day_key": day_key, "last_reported_at": now}}, + upsert=True, + ) + if _claim_outcome(res) == "already": + continue + except DuplicateKeyError: + # ה-``$ne`` אינו נכנס למסמך שנוצר ב-upsert (ראו ההסבר + # ב-``_claim_daily_report_day``), ולכן "כבר דיווחנו היום" + # מגיע לכאן כהתנגשות מפתח ולא כ-``modified_count=0``. + # ה-``except`` הרחב שהיה כאן בלע אותה, והתוצאה הייתה התראה + # חוזרת כל 60 שניות במקום אחת ליום. + continue + except Exception: + # כשל אחר: fail-open. התראה שנעלמת גרועה מהתראה כפולה — זו + # המדיניות ההפוכה מזו של הדוח היומי, ובכוונה. + pass + + reported.append(job_id) + return reported + + +async def _emit_stuck_job_events(db_obj, now) -> None: + """פולט ``job_stuck`` על הרצות שהתחילו ולא הסתיימו. + + הופרד מהמוניטור כדי שלא יחלוק גורל עם בדיקת ``job_missed``: הן נשענות + על שאילתות שונות (``find`` מול ``aggregate``), ואין סיבה שכשל של אחת + ישתיק את השנייה. + """ + from datetime import timedelta as _td + + from observability import emit_event as _emit # type: ignore + + try: + threshold_min = int(os.getenv("JOBS_STUCK_THRESHOLD_MINUTES", "20") or 20) + except Exception: + threshold_min = 20 + threshold_min = max(1, threshold_min) + cutoff = now - _td(minutes=threshold_min) + + coll = getattr(db_obj, "job_runs", None) + if coll is None or not callable(getattr(coll, "find", None)): + return + + # ‏stuck_reported_at הוא השער שמונע פליטה חוזרת על אותה הרצה. + cursor = coll.find( + { + "status": "running", + "started_at": {"$lt": cutoff}, + "stuck_reported_at": {"$exists": False}, + }, + {"run_id": 1, "job_id": 1, "started_at": 1}, + ).sort("started_at", 1).limit(50) + + try: + docs = await cursor.to_list(length=50) + except Exception: + docs = [] + + for doc in list(docs or []): + run_id = str(doc.get("run_id") or "").strip() + job_id = str(doc.get("job_id") or "").strip() + started_at = doc.get("started_at") + minutes = None + try: + if started_at: + minutes = int(max(1, (now - started_at).total_seconds() // 60)) + except Exception: + minutes = None + + if not run_id or not job_id: + continue + + # סימון + שורת לוג (שומרים 50 אחרונות). ה-``update_one`` המותנה הוא + # שער ולא סתם סימון: ה-``find`` למעלה וה-``update_one`` כאן הם + # check-then-act, ולכן שני תהליכים שראו את אותה הרצה יגיעו שניהם + # לכאן — ורק אצל אחד ``stuck_reported_at`` ייכתב בפועל. בדיקת + # ה-rowcount היא מה שהופך את זה לשער; בלעדיה השער היה קיים ולא + # פועל, וההתראה נפלטה פעמיים. + try: + res = await coll.update_one( + {"run_id": run_id, "stuck_reported_at": {"$exists": False}}, + { + "$set": {"stuck_reported_at": now}, + "$push": { + "logs": { + "$each": [ + { + "timestamp": now, + "level": "error", + "message": "Job stuck detected", + "details": {"minutes": minutes} if minutes is not None else None, + } + ], + "$slice": -50, + } + }, + }, + upsert=False, + ) + except Exception: + # כשל כתיבה אינו "מישהו אחר דיווח": לא ידוע אם סימנו, ולכן + # פולטים בכל זאת. אותה מדיניות fail-open כמו ב-``job_missed`` — + # הרצה תקועה שאיש אינו יודע עליה היא הכשל שהמנגנון נבנה לתפוס. + logger.debug("job_stuck_mark_failed run_id=%s", run_id, exc_info=True) + else: + if _claim_outcome(res) == "already": + continue + + _emit( + "job_stuck", + severity="error", + job_id=job_id, + run_id=run_id, + minutes=int(minutes or threshold_min), + ) + + +async def _emit_missed_job_events(db_obj, now) -> None: + """פולט ``job_missed`` על job מתוזמן שלא נרשמה לו ריצה בחלון שלו.""" + from observability import emit_event as _emit # type: ignore + from services.job_registry import JobRegistry as _JobRegistry # type: ignore + + for missed_id in await _check_missed_scheduled_jobs(db_obj, now): + meta = getattr(_JobRegistry().get(missed_id), "metadata", None) or {} + _emit( + "job_missed", + severity="error", + job_id=missed_id, + hours=int(meta.get("missed_after_hours") or 26), + ) + + +async def _jobs_monitor_tick(db_obj, now=None) -> None: + """סבב אחד של מוניטור ה-jobs: שתי בדיקות **עצמאיות**. + + הפרדת ה-``try`` היא כל העניין. בגרסה הקודמת שתי הבדיקות ישבו בבלוק + אחד, ולכן שלושה מסלולי יציאה של בדיקת ה-stuck — אוסף בלי ``find``, + חריגה, ו-``return`` מוקדם — דילגו על בדיקת ה-missed לגמרי. דווקא + ה-missed היא זו שתופסת את המקרה החמור יותר: job שלא רץ בכלל. + """ + if db_obj is None: + return + now = now or datetime.now(timezone.utc) + for check in (_emit_stuck_job_events, _emit_missed_job_events): + try: + await check(db_obj, now) + except Exception: + logger.debug("jobs_monitor_check_failed: %s", getattr(check, "__name__", "?"), exc_info=True) + + +# ===== עזרי דוח הבוקר היומי ===== +def _daily_report_tz(): + """אזור הזמן שבו נקבעת שעת השליחה ותאריך היום שהדוח מתאר. + + ``utils._get_israel_tz`` נופל ל-UTC (עם אזהרה בלוג) כשמסד אזורי הזמן חסר + בסביבה. הנפילה הזו מזיזה את הדוח בשעתיים, ולכן ה-job רושם את ה-tz שנבחר + בפועל בהיסטוריית ההרצה. + """ + try: + from utils import _get_israel_tz # type: ignore + + return _get_israel_tz() + except Exception: + from datetime import timezone as _tz + + return _tz.utc + + +def _daily_report_hour_minute() -> tuple[int, int]: + """שעת השליחה מתוך ``DAILY_REPORT_HOUR_LOCAL`` בפורמט ``HH:MM``. + + ערך פגום אינו מפיל את התזמון ואינו נבלע בשקט — הוא חוזר ל-08:00 ונרשם + כאזהרה, כי job שלא נקבע לו זמן פשוט לא ירוץ. + """ + raw = str(os.getenv("DAILY_REPORT_HOUR_LOCAL", "08:00") or "08:00").strip() + try: + hour_s, _, minute_s = raw.partition(":") + hour = int(hour_s) + minute = int(minute_s or 0) + if not (0 <= hour <= 23 and 0 <= minute <= 59): + raise ValueError(raw) + return hour, minute + except Exception: + logger.warning("daily_report_bad_hour_env", extra={"value": raw}) + return 8, 0 + + +def _daily_report_window_minutes() -> int: + """רוחב חלון ההצלבה בדקות. + + ‏5 דקות כברירת מחדל, ולא מספר שנשמע סביר: זהו חלון הדגימה שהתראות + ה-latency נבנות עליו (``window_minutes`` ב-``config/alerts.yml``), והדלי + של ``service_metrics`` הוא 60 שניות. רחב מדי מייצר קישור סיבתי שגוי, + שגרוע מכלום כי הוא שולח לחפש במקום הלא נכון. + """ + try: + value = int(os.getenv("DAILY_REPORT_CORRELATION_WINDOW_MINUTES", "5") or 5) + return max(1, min(120, value)) + except Exception: + return 5 + + +def _daily_report_db(): + """ה-Database של האפליקציה, או ``None`` כשאין מסד אמיתי. + + **דרך לקוח אחד בכוונה.** ``alerts_storage`` ו-``metrics_storage`` פותחים + ``MongoClient`` משלהם בלי ``tz_aware``, ולכן אותה חותמת חוזרת מהם נאיבית + ומהלקוח של האפליקציה מודעת-אזור. קריאה של כל המקורות דרך לקוח אחד מונעת + השוואה בין שני טיפוסים. + """ + try: + from database import db as _dbm # type: ignore + + db_obj = getattr(_dbm, "db", None) + if db_obj is None: + return None + if str(getattr(db_obj, "name", "") or "") == "noop_db": + return None + return db_obj + except Exception: + return None + + +def _build_daily_report_deps(db_obj): + """מרכיב את התלויות שהאיסוף צורך. + + שמות האוספים של ההתראות והמדדים נלקחים מהמודולים שכותבים אליהם ולא + משוכפלים כאן — אחרת שינוי של ``ALERTS_COLLECTION`` היה משאיר את הדוח + קורא אוסף ריק ומדווח "אפס התראות" בביטחון מלא. + """ + import services.daily_report_service as drs + + try: + from monitoring.alerts_storage import collection_name as _alerts_name # type: ignore + + alerts_coll = db_obj[_alerts_name()] + except Exception: + alerts_coll = None + try: + from monitoring.metrics_storage import collection_name as _metrics_name # type: ignore + + metrics_coll = db_obj[_metrics_name()] + except Exception: + metrics_coll = None + try: + from services.query_profiler_service import PersistentQueryProfilerService # type: ignore + + slow_coll = db_obj[PersistentQueryProfilerService.COLLECTION_NAME] + except Exception: + slow_coll = None + + def _cache_stats(): + from services.cache_inspector_service import get_cache_inspector_service # type: ignore + + return get_cache_inspector_service().get_cache_stats() + + def _mcp_endpoint(name, limit=None): + from services.mcp_analytics_service import get_mcp_analytics_service # type: ignore + + return get_mcp_analytics_service().run_endpoint(name, limit) + + return drs.ReportDeps( + alerts_coll=alerts_coll, + metrics_coll=metrics_coll, + slow_coll=slow_coll, + job_runs_coll=db_obj["job_runs"], + snapshots_coll=db_obj[drs.COLLECTION_NAME], + db_for_collstats=db_obj, + cache_stats_fn=_cache_stats, + mcp_run_endpoint_fn=_mcp_endpoint, + ) + + +def _daily_report_gate_reason() -> str: + """בודק מראש אם ההודעה בכלל יכולה להגיע לטלגרם. ריק = יכולה. + + ``emit_internal_alert`` מחזיר ``None`` ולעולם אינו מדווח כשל, ולכן בלי + הבדיקה הזו הדוח היה מסתיים ב-``completed`` גם כשההודעה נחסמה — הצלחה + מדומה על משהו שלא קרה. + + הבדיקה קוראת ל**פונקציות של ה-forwarder עצמו** ולא ל-``os.getenv``: את + רשימת ההשתקה הוא מחשב בזמן ה-import, ולכן קריאה עצמאית של המשתנה הייתה + יכולה לסתור את מה שקורה בפועל. + """ + try: + import alert_forwarder as _af # type: ignore + import services.daily_report_service as drs # type: ignore + except Exception: + return "" + + try: + if _af._severity_rank(drs.REPORT_SEVERITY) < _af._min_telegram_severity_rank(): + return "below_min_severity" + if _af._is_telegram_suppressed(drs.REPORT_ALERT_NAME): + return "suppressed" + except Exception: + return "" + if not os.getenv("ALERT_TELEGRAM_BOT_TOKEN"): + return "no_token" + if not os.getenv("ALERT_TELEGRAM_CHAT_ID"): + return "no_chat" + return "" + + +def _daily_report_gate_ok(run, tracker) -> bool: + """מפיל את ההרצה כשהדוח לא יכול להימסר, במקום לדווח הצלחה.""" + reason = _daily_report_gate_reason() + if not reason: + return True + tracker.fail_run(run.run_id, f"telegram_gate:{reason}") + return False + + +async def _daily_morning_report_body(tracker, run) -> None: + """גוף דוח הבוקר: אוסף סנאפשוט, משווה מול אתמול, ושולח רק אם יש מה לדווח. + + סדר הפעולות כאן אינו שרירותי: + + 1. **הסנאפשוט נשמר תמיד, ולפני ההחלטה אם לשלוח.** יום שקט שלא משאיר + סנאפשוט הופך את הדוח של מחר לשקר — אין לו מול מה להשוות. השמירה היא + ``$setOnInsert``, ולכן הריצה הראשונה מנצחת ואין דריסה. + 2. **שער המסירה נבדק לפני השליחה.** ``emit_internal_alert`` מחזיר + ``None`` תמיד ואינו מדווח כשל, ולכן בלי בדיקה מוקדמת הדוח היה מסתיים + ב-``completed`` גם כשההודעה נחסמה על סף החומרה — "✅" על משהו שלא קרה. + 3. **שער האידמפוטנטיות בא אחרון, ממש לפני השליחה.** אילו ישב מוקדם + יותר, יום שקט היה "שורף" את היום וטריגר ידני מאוחר יותר לא היה יכול + לשלוח דבר גם אם בינתיים קרה משהו. + """ + import asyncio as _asyncio + from datetime import datetime as _dt, timedelta as _td, timezone as _tz + + import services.daily_report_service as drs + + if str(os.getenv("DISABLE_DAILY_REPORT", "")).lower() in {"1", "true", "yes"}: + tracker.skip_run(run.run_id, "disabled_by_env") + return + + tz = _daily_report_tz() + now_utc = _dt.now(_tz.utc) + day_key = drs.day_key_for(now_utc.astimezone(tz)) + day_start, day_end = drs.window_for(now_utc) + window = _td(minutes=_daily_report_window_minutes()) + # ‏tz שנבחר בפועל נרשם בהיסטוריית ההרצה: אם מסד אזורי הזמן חסר, utils + # נופל ל-UTC והשעה זזה בשעתיים — וזה חייב להיות נראה כאן ולא רק בלוג. + tracker.add_log(run.run_id, "info", f"day={day_key} tz={tz} window_min={window.seconds // 60}") + + db_obj = _daily_report_db() + if db_obj is None: + tracker.skip_run(run.run_id, "no_database") + return + + deps = _build_daily_report_deps(db_obj) + snapshots = db_obj[drs.COLLECTION_NAME] + previous = drs.load_snapshot(snapshots, drs.previous_day_key(day_key)) + + snapshot = await _asyncio.to_thread( + drs.collect_snapshot, + day_key=day_key, + day_start_utc=day_start, + day_end_utc=day_end, + deps=deps, + previous=previous, + correlation_window=window, + now=now_utc, + ) + # כשל שמירה מפיל את ההרצה בכוונה: ראה נימוק (1) למעלה. + stored = await _asyncio.to_thread(drs.save_snapshot, snapshots, snapshot) + + diff = drs.compare(stored, previous, correlation_window=window) + text = drs.render_report(diff) + if text is None: + # ריצה מוצלחת בלי הודעה. **לא** skip: זו בדיוק הרשומה שממנה נמדדת + # החיות של ה-job. + tracker.add_log(run.run_id, "info", "nothing_to_report") + return + + if not _daily_report_gate_ok(run, tracker): + return + + claim = await _asyncio.to_thread(_claim_daily_report_day, db_obj, day_key, now_utc) + if claim == "already": + tracker.skip_run(run.run_id, "already_sent_today") + return + if claim != "claimed": + # fail-closed: לא ידוע אם נשלח, ולכן לא שולחים. + tracker.fail_run(run.run_id, "day_claim_failed") + return + + from internal_alerts import emit_internal_alert # type: ignore + + emit_internal_alert( + drs.REPORT_ALERT_NAME, + severity=drs.REPORT_SEVERITY, + summary=text, + source="main.daily_morning_report", + admin_ids=get_admin_ids(), + ) + tracker.add_log(run.run_id, "info", f"sections={','.join(diff.sections) or 'none'}") + try: + try: + from observability import emit_event as _emit + except Exception: # pragma: no cover + _emit = lambda *a, **k: None # noqa: E731 + _emit( + "daily_report_sent", + severity="info", + day=day_key, + sections=",".join(diff.sections), + has_baseline=bool(diff.has_baseline), + ) + except Exception: + pass + + +def _schedule_daily_morning_report(application, callback) -> None: + """מתזמן את הדוח לשעה קבועה בשעון ישראל. + + ``run_daily`` ולא ``run_repeating(86400)``: אינטרוול נסחף עם כל restart, + ו"בוקר" הוא דרישה מפורשת. ה-``time`` נושא ``tzinfo`` מפורש כי ה- + ``Defaults`` של הבוט מוגדר רק עם ``parse_mode`` — בלי אזור זמן, וברירת + המחדל של JobQueue היא UTC. + + ``misfire_grace_time`` של שעה: restart ב-07:59 לא אמור לבלוע את היום. + הנפילה ל-``run_repeating`` היא לסביבות שבהן ה-JobQueue אינו תומך + בחתימה הזו, באותה תבנית של ``_safe_run_once``/``_safe_run_repeating``. + """ + from datetime import datetime as _dt, time as _time, timedelta as _td, timezone as _tz + + hour, minute = _daily_report_hour_minute() + tz = _daily_report_tz() + when = _time(hour=hour, minute=minute, tzinfo=tz) + try: + application.job_queue.run_daily( + callback, + time=when, + name="daily_morning_report", + job_kwargs={"misfire_grace_time": 3600}, + ) + return + except TypeError: + try: + application.job_queue.run_daily(callback, time=when, name="daily_morning_report") + return + except Exception: + pass + except Exception as exc: + logger.warning("daily_report_run_daily_failed: %s", exc) + + # Fallback: אינטרוול יומי שמתחיל במופע הבא של השעה שנקבעה. + try: + now_local = _dt.now(_tz.utc).astimezone(tz) + target = now_local.replace(hour=hour, minute=minute, second=0, microsecond=0) + if target <= now_local: + target = target + _td(days=1) + first = max(60, int((target - now_local).total_seconds())) + application.job_queue.run_repeating( + callback, + interval=24 * 3600, + first=first, + name="daily_morning_report", + ) + except Exception as exc: + logger.warning("daily_report_schedule_failed: %s", exc) + + async def connect_claude_command(update: Update, context: ContextTypes.DEFAULT_TYPE): """מנפיק טוקן אישי (PAT) לחיבור הקבצים של המשתמש ל‑Claude דרך MCP (קריאה בלבד).""" try: @@ -5753,93 +6365,18 @@ def _get_scheduler_pymongo_client(app: Application): except Exception: return None - # Jobs Monitor: זיהוי הרצות "תקועות" (job_stuck) + # Jobs Monitor: הרצות "תקועות" (job_stuck) ו-job מתוזמן שלא רץ (job_missed) try: - from datetime import timedelta as _td - from observability import emit_event as _emit # type: ignore - async def _jobs_stuck_monitor(_context: ContextTypes.DEFAULT_TYPE): # noqa: ARG001 - try: - db_obj = await _get_scheduler_motor_db(_context.application) - if db_obj is None: - return - - try: - threshold_min = int(os.getenv("JOBS_STUCK_THRESHOLD_MINUTES", "20") or 20) - except Exception: - threshold_min = 20 - threshold_min = max(1, threshold_min) - - now = datetime.now(timezone.utc) - cutoff = now - _td(minutes=threshold_min) - - coll = getattr(db_obj, "job_runs", None) - if coll is None or not hasattr(coll, "find"): - return - - # emit only once per run (stuck_reported_at gate) - cursor = coll.find( - { - "status": "running", - "started_at": {"$lt": cutoff}, - "stuck_reported_at": {"$exists": False}, - }, - {"run_id": 1, "job_id": 1, "started_at": 1}, - ).sort("started_at", 1).limit(50) - - try: - docs = await cursor.to_list(length=50) - except Exception: - docs = [] - - for doc in list(docs or []): - run_id = str(doc.get("run_id") or "").strip() - job_id = str(doc.get("job_id") or "").strip() - started_at = doc.get("started_at") - minutes = None - try: - if started_at: - minutes = int(max(1, (now - started_at).total_seconds() // 60)) - except Exception: - minutes = None - - if not run_id or not job_id: - continue - - # mark + append log (keep last 50) - try: - await coll.update_one( - {"run_id": run_id, "stuck_reported_at": {"$exists": False}}, - { - "$set": {"stuck_reported_at": now}, - "$push": { - "logs": { - "$each": [ - { - "timestamp": now, - "level": "error", - "message": "Job stuck detected", - "details": {"minutes": minutes} if minutes is not None else None, - } - ], - "$slice": -50, - } - }, - }, - upsert=False, - ) - except Exception: - pass + """קליפה דקה: משיג את המסד ומעביר ל-``_jobs_monitor_tick``. - _emit( - "job_stuck", - severity="error", - job_id=job_id, - run_id=run_id, - minutes=int(minutes or threshold_min), - ) + כל הלוגיקה יושבת ברמת המודול כדי שתהיה ניתנת לבדיקה בלי להרים + את הבוט — וכדי ששתי הבדיקות יהיו באמת נפרדות זו מזו. + """ + try: + await _jobs_monitor_tick(await _get_scheduler_motor_db(_context.application)) except Exception: - return + logger.debug("jobs_monitor_tick_failed", exc_info=True) try: interval = int(os.getenv("JOBS_STUCK_MONITOR_INTERVAL_SECS", "60") or 60) @@ -6462,6 +6999,42 @@ class _Ctx: except Exception: pass + # Daily morning report — מצליב בין הדשבורדים ושולח סיכום פעם ביום + try: + async def _daily_morning_report(context: ContextTypes.DEFAULT_TYPE): + """קליפה דקה: פותחת רשומת הרצה ומעבירה ל-``_daily_morning_report_body``. + + כל הלוגיקה יושבת ברמת המודול כדי שסדר הפעולות — ובעיקר **ששני + השערים באמת נקראים לפני השליחה** — יהיה ניתן לבדיקה. שער שקיים + בקוד ואיש אינו מוודא שקוראים לו הוא בדיוק אותו כשל של אינדקס + שמוצהר ולא נוצר. + """ + from services.job_tracker import get_job_tracker, JobAlreadyRunningError + + tracker = get_job_tracker() + try: + trigger = ( + str(((getattr(getattr(context, "job", None), "data", None) or {}) or {}).get("trigger") or "scheduled") + .strip() + .lower() + ) + except Exception: + trigger = "scheduled" + + try: + with tracker.track("daily_morning_report", trigger=trigger) as run: + await _daily_morning_report_body(tracker, run) + except JobAlreadyRunningError: + try: + tracker.record_skipped(job_id="daily_morning_report", trigger=trigger, reason="already_running") + except Exception: + pass + return + + _schedule_daily_morning_report(application, _daily_morning_report) + except Exception: + logger.warning("Failed to set up daily morning report job", exc_info=True) + # Background cleanup jobs (Phase 2): cache maintenance and backups retention try: async def _cache_maintenance_job(context: ContextTypes.DEFAULT_TYPE): diff --git a/monitoring/alerts_storage.py b/monitoring/alerts_storage.py index 0831411b9..c0652322d 100644 --- a/monitoring/alerts_storage.py +++ b/monitoring/alerts_storage.py @@ -70,6 +70,16 @@ def _enabled() -> bool: return _write_enabled() +def collection_name() -> str: + """שם האוסף שהמודול הזה קורא וכותב אליו בפועל. + + קיים כדי שקוראים חיצוניים (למשל דוח הבוקר היומי) לא ישכפלו את ברירת + המחדל ``alerts_log`` ואת שם משתנה הסביבה. הביטוי כאן חייב להישאר זהה + לזה שב-``_get_collection``. + """ + return os.getenv("ALERTS_COLLECTION") or "alerts_log" + + _client = None # type: ignore _collection = None # type: ignore _catalog_collection = None # type: ignore diff --git a/monitoring/metrics_storage.py b/monitoring/metrics_storage.py index 691a739e1..6b31c8777 100644 --- a/monitoring/metrics_storage.py +++ b/monitoring/metrics_storage.py @@ -92,6 +92,16 @@ def _enabled() -> bool: _start_lock = Lock() +def collection_name() -> str: + """שם האוסף שהמודול הזה קורא וכותב אליו בפועל. + + קיים כדי שקוראים חיצוניים (למשל דוח הבוקר היומי) לא ישכפלו את ברירת + המחדל ``service_metrics`` ואת שם משתנה הסביבה. הביטוי כאן חייב להישאר + זהה לזה שב-``_get_collection``. + """ + return os.getenv("METRICS_COLLECTION") or "service_metrics" + + def _is_pytest() -> bool: return bool(os.getenv("PYTEST_CURRENT_TEST")) or ("pytest" in sys.modules) diff --git a/services/config_inspector_service.py b/services/config_inspector_service.py index cb695e825..f664e7967 100644 --- a/services/config_inspector_service.py +++ b/services/config_inspector_service.py @@ -1251,6 +1251,30 @@ class ConfigService: description="1/true מחייב את מנוע הרה-פקטור לרוץ במצב IA Layered (בדיקות ו-POC)", category="features", ), + "DISABLE_DAILY_REPORT": ConfigDefinition( + key="DISABLE_DAILY_REPORT", + services=("bot",), + default="", + description="1/true מכבה את דוח הבוקר היומי (ריק = פעיל)", + category="monitoring", + ), + "DAILY_REPORT_HOUR_LOCAL": ConfigDefinition( + key="DAILY_REPORT_HOUR_LOCAL", + services=("bot",), + default="08:00", + description="שעת שליחת דוח הבוקר, בפורמט HH:MM ובשעון ישראל (Asia/Jerusalem)", + category="monitoring", + ), + "DAILY_REPORT_CORRELATION_WINDOW_MINUTES": ConfigDefinition( + key="DAILY_REPORT_CORRELATION_WINDOW_MINUTES", + services=("bot",), + default="5", + description=( + "רוחב חלון ההצלבה בדקות בין התראה לשאילתה איטית. " + "צר מדי מפספס בגלל עיכוב אגרגציה, רחב מדי מייצר קישור סיבתי שגוי" + ), + category="monitoring", + ), "WEEKLY_REPORT_DELAY_SECS": ConfigDefinition( key="WEEKLY_REPORT_DELAY_SECS", services=("bot",), diff --git a/services/daily_report_service.py b/services/daily_report_service.py new file mode 100644 index 000000000..1aec7152c --- /dev/null +++ b/services/daily_report_service.py @@ -0,0 +1,1000 @@ +"""דוח בוקר יומי — קורא ומצליב בין מקורות הניטור הקיימים. + +המודול הזה **אינו מודד דבר חדש ואינו קובע שום סף חדש**. כל מספר בו נקרא +ממקור שכבר נכתב היום: ``alerts_log``, ``service_metrics``, ``slow_queries_log``, +``job_runs``, ``collStats``, Redis ‏``INFO``, ואנדפוינטים שמורים ב-PostHog. +מה שהוא כן מוסיף הוא **הצלבה** — האם אירועים ממקורות שונים נופלים באותו חלון +זמן — ו**השוואה מול אתמול**, שנשמרת באוסף קטן משלו. + +שלושה עקרונות שמכתיבים את כל המבנה כאן: + +1. **מקור שנכשל לקרוא אינו מקור שהחזיר אפס.** הקוראים הקיימים בריפו + (``aggregate_alert_summary``, ``aggregate_top_endpoints``, + ``get_pattern_statistics``) מחזירים ``0``/``[]`` גם כשה-DB לא זמין, ולכן + אי אפשר להישען עליהם: סנאפשוט שנשמר עם אפס בגלל תקלה יגרום לדוח של מחר + להכריז על **שיפור**. לכן כל מקור נקרא כאן ישירות ונעטף ב-:class:`SourceRead`, + שבו כשל הוא ``ok=False`` ו-``value=None`` — ולעולם לא אפס. +2. **הדוח מדווח שינוי, לא מצב.** שורה נכנסת להודעה רק כשקרה משהו. אין שורות + "תקין", כי שורה שנראית זהה כל יום מפסיקים לקרוא. +3. **בלי בסיס להשוואה לא ממציאים אחד.** ההשוואה דורשת את הסנאפשוט של D-1 + במפורש; "השורה האחרונה שיש" אינה תחליף, כי יום שבו ה-job לא רץ היה גורם + להשוואה מול שלשום ולדיווח שינוי כפול. +""" + +from __future__ import annotations + +import logging +import math +from collections import Counter +from dataclasses import dataclass, field +from datetime import date, datetime, timedelta, timezone +from typing import Any, Callable, Dict, Iterable, List, Optional, Sequence + +logger = logging.getLogger(__name__) + +#: האוסף שבו נשמר סנאפשוט יומי אחד. נקרא מכאן גם על ידי +#: ``DatabaseManager._create_daily_report_indexes`` כדי שלא יהיו שני מקורות לשם. +COLLECTION_NAME = "daily_report_snapshots" + +#: ‏45 יום. **ארוך בכוונה מה-TTL של המקורות** (``slow_queries_log`` — 7 ימים): +#: הסנאפשוט הוא מספרים בלבד, הוא זעיר, והוא צריך לשרוד מעבר לחלון של 30 הימים +#: שבו נשמרים הדפוסים והשגיאות המוכרים. TTL זהה למקורות היה מוחק את הבסיס +#: להשוואה לפני שהוא מספיק לשמש. +TTL_SECONDS = 45 * 24 * 60 * 60 + +#: כמה זמן אחורה נשמר זיכרון של "כבר ראינו את זה" — דפוסי שאילתה וסוגי שגיאות +#: ב-MCP. מול אתמול בלבד לא מספיק: דפוס שהופיע, נעלם וחזר היה מדווח כחדש פעמיים. +KNOWN_ITEMS_WINDOW_DAYS = 30 + +#: תקרת אורך להודעה. ‏Telegram חוסם ב-4096, וה-forwarder מוסיף כותרת משלו; +#: אותו מרווח ביטחון שנבחר ב-``services/rules_evaluator.py``. +MAX_MESSAGE_CHARS = 3800 + +#: חומרת ההתראה שדרכה הדוח נשלח. ``info`` לא היה מגיע: בפרודקשן +#: ``ALERT_TELEGRAM_MIN_SEVERITY=warn``, ו-``info`` נמוך ממנו. +REPORT_SEVERITY = "warn" + +#: שם ההתראה. ייעודי ולא ``admin_notification``, כדי שאפשר יהיה לכוון עליו +#: כלל או ``ALERT_TELEGRAM_SUPPRESS_ALERTS`` בלי לגעת בכל הודעות האדמין. +REPORT_ALERT_NAME = "daily_morning_report" + +#: התראות שאינן "אירוע" ולכן אינן פותחות חלון הצלבה: הדיפלוי נשמר בנפרד +#: (הוא החלון להצלבת קאש), והדוח עצמו נרשם ל-``alerts_log`` ואסור לו להצליב +#: מול עצמו. +_NON_EVENT_ALERT_NAMES = frozenset({"deployment_event", "admin_notification", REPORT_ALERT_NAME}) + +#: החומרות שנחשבות אירוע לצורך חלון ההצלבה. +_EVENT_SEVERITIES = frozenset({"critical", "error", "anomaly"}) + +#: האוספים שגודלם מדווח. אלה שני אוספי הלוג שתפחו בפועל, ושני אוספי +#: הניטור שנקראים כאן ממילא. +GROWTH_COLLECTIONS = ("service_metrics", "job_runs", "slow_queries_log", "alerts_log") + + +@dataclass(frozen=True) +class SourceRead: + """תוצאת קריאה ממקור אחד — ערוץ כשל אחד בלבד. + + שני מצבים שנראים דומים וחייבים להיבדל, בדיוק כמו ב- + ``services/mcp_analytics_service.EndpointResult``: + + * ``ok=True`` עם ערך ריק — נקרא בהצלחה, פשוט לא היה מה לספור. + * ``ok=False`` — הקריאה נכשלה. ``value`` הוא ``None``, **לא** אפס. + + בלי ההבחנה הזו כשל בקריאה נשמר בסנאפשוט כאפס, ומחר הדוח מכריז על שיפור. + """ + + value: Any = None + ok: bool = True + error: str = "" + + @classmethod + def failed(cls, error: str) -> "SourceRead": + return cls(value=None, ok=False, error=str(error or "unknown")) + + def to_doc(self) -> Dict[str, Any]: + """ייצוג לשמירה בסנאפשוט. כשל נשמר כ-``ok: False`` בלי ערכים.""" + doc: Dict[str, Any] = {"ok": bool(self.ok), "error": str(self.error or "")} + if self.ok and isinstance(self.value, dict): + doc.update(self.value) + return doc + + +def _exc_code(exc: BaseException) -> str: + """קוד כשל קצר לשמירה — שם המחלקה בלבד. + + ההודעה עצמה **אינה** נשמרת: היא עלולה לשאת כתובת חיבור או שם מסד, והמסמך + הזה נקרא בדשבורד ומודבק להודעת טלגרם. + """ + return f"exception:{type(exc).__name__}" + + +def ensure_utc_aware(value: Any) -> Optional[datetime]: + """מנרמל חותמת זמן ל-UTC מודע לאזור. + + ``datetime`` נאיבי מפורש כ-**UTC**, וזו הנחה שנשענת על הכותבים בפועל: + ``PersistentQueryProfilerService.record_slow_query_sync`` כותב + ``datetime.utcnow()`` (``services/query_profiler_service.py``), ושאר + האוספים כותבים ``datetime.now(timezone.utc)``. ביום שבו מישהו יחליף שם + ל-``datetime.now()`` המקומי, חלון ההצלבה של חמש דקות יהפוך לחלון של + שעתיים־שלוש — וזה ישתוק בלי שאף בדיקה תיפול, כי ב-CI שרץ ב-UTC שתי + הפונקציות מחזירות אותו דבר. לכן קיימת בדיקה ייעודית שמזייפת את השעון + ומוודאת שהכותב באמת UTC (``tests/test_daily_report_service.py``). + """ + if not isinstance(value, datetime): + return None + if value.tzinfo is None: + return value.replace(tzinfo=timezone.utc) + return value.astimezone(timezone.utc) + + +def _non_negative_delta(later: datetime, earlier: datetime) -> timedelta: + """הפרש זמן שלעולם אינו שלילי. + + שעונים בין מכונות אינם מסונכרנים לחלוטין, וחותמת שנכתבה "בעתיד" הייתה + מייצרת ``timedelta`` שלילי — ואז זוג אירועים אמיתי נזרק אל מחוץ לחלון. + """ + return max(timedelta(0), later - earlier) + + +def _fmt_bytes(num: Any) -> str: + try: + value = float(num) + except (TypeError, ValueError): + return "?" + if not math.isfinite(value): + return "?" + for unit in ("B", "KB", "MB", "GB"): + if abs(value) < 1024.0 or unit == "GB": + if unit == "B": + return f"{int(value)}{unit}" + return f"{value:.1f}{unit}" + value /= 1024.0 + return "?" + + +def _fmt_signed(num: int) -> str: + return f"+{num:,}" if num > 0 else f"{num:,}" + + +# -------------------------------------------------------------------------- +# קוראים — אחד לכל מקור. כל אחד מחזיר SourceRead ולעולם אינו זורק החוצה. +# -------------------------------------------------------------------------- + + +def read_alerts(coll, *, start: datetime, end: datetime) -> SourceRead: + """ספירת התראות, דיפלויים, וחלונות ההצלבה — בקריאה אחת. + + שדה הזמן הוא ``ts_dt`` ושדה החומרה ``severity`` (נשמר lowercase) — + שניהם נכתבים ב-``monitoring/alerts_storage.record_alert``. דרילים + (``details.is_drill``) מוחרגים, כמו בכל אגרגציה קיימת על האוסף הזה. + """ + try: + cursor = coll.find( + {"ts_dt": {"$gte": start, "$lt": end}, "details.is_drill": {"$ne": True}}, + {"ts_dt": 1, "name": 1, "severity": 1, "alert_type": 1, "endpoint": 1, "_id": 0}, + ) + critical = 0 + errors = 0 + deploy_ts: List[datetime] = [] + windows: List[Dict[str, Any]] = [] + for doc in cursor: + ts = ensure_utc_aware(doc.get("ts_dt")) + if ts is None: + continue + name = str(doc.get("name") or "") + severity = str(doc.get("severity") or "").lower() + alert_type = str(doc.get("alert_type") or "") + if name == "deployment_event" or alert_type == "deployment_event": + deploy_ts.append(ts) + continue + if severity == "critical": + critical += 1 + elif severity == "error": + errors += 1 + if severity in _EVENT_SEVERITIES and name not in _NON_EVENT_ALERT_NAMES: + windows.append( + {"ts": ts, "name": name, "endpoint": str(doc.get("endpoint") or "")} + ) + windows.sort(key=lambda item: item["ts"]) + return SourceRead( + value={ + "critical": critical, + "error": errors, + "deploy_count": len(deploy_ts), + "deploy_ts": sorted(deploy_ts), + "alert_windows": windows, + } + ) + except Exception as exc: # noqa: BLE001 — כל כשל הופך ל-ok=False, לא לאפס + logger.warning("daily_report_read_alerts_failed", extra={"error": type(exc).__name__}) + return SourceRead.failed(_exc_code(exc)) + + +def read_top_endpoint(coll, *, start: datetime, end: datetime) -> SourceRead: + """ה-endpoint האיטי ביותר בחלון. + + הפייפליין נגזר מ-``monitoring/metrics_storage.aggregate_top_endpoints``: + אותו שדה זמן (``ts``), אותה הבחנה בין ``request_agg`` מגובב לבין רשומת + בקשה בודדת. הוא משוכפל כאן ולא נקרא משם **בכוונה**, כי המקור מחזיר + ``[]`` גם כשה-DB נופל, ואנחנו חייבים להבדיל. + """ + pipeline = [ + {"$match": {"ts": {"$gte": start, "$lt": end}, "type": {"$in": ["request", "request_agg"]}}}, + { + "$project": { + "path": {"$ifNull": ["$path", {"$ifNull": ["$handler", "unknown"]}]}, + "method": {"$ifNull": ["$method", "UNKNOWN"]}, + "count": { + "$cond": [{"$eq": ["$type", "request_agg"]}, {"$ifNull": ["$count", 0]}, 1] + }, + "max_duration": { + "$cond": [ + {"$eq": ["$type", "request_agg"]}, + {"$ifNull": ["$max_duration", 0.0]}, + {"$ifNull": ["$duration_seconds", 0.0]}, + ] + }, + } + }, + { + "$group": { + "_id": {"path": "$path", "method": "$method"}, + "count": {"$sum": "$count"}, + "max_duration": {"$max": "$max_duration"}, + } + }, + {"$sort": {"max_duration": -1}}, + {"$limit": 1}, + ] + try: + rows = list(coll.aggregate(pipeline)) + if not rows: + return SourceRead(value={"top_slow_endpoint": None}) + row = rows[0] + ident = row.get("_id") or {} + return SourceRead( + value={ + "top_slow_endpoint": { + "endpoint": str(ident.get("path") or "unknown"), + "method": str(ident.get("method") or "UNKNOWN"), + "max_duration": float(row.get("max_duration") or 0.0), + "count": int(row.get("count") or 0), + } + } + ) + except Exception as exc: # noqa: BLE001 + logger.warning("daily_report_read_metrics_failed", extra={"error": type(exc).__name__}) + return SourceRead.failed(_exc_code(exc)) + + +def read_slow_queries( + coll, + *, + start: datetime, + end: datetime, + alert_windows: Sequence[Dict[str, Any]], + correlation_window: timedelta, + known_query_ids: Optional[Dict[str, str]] = None, +) -> SourceRead: + """שאילתות איטיות, דפוסים והצלבה — הכול מקריאה אחת. + + ``timestamp`` נכתב על ידי ``_persist_record``, ו-``query_id`` הוא גיבוב של + **צורת** השאילתה בלבד — הערכים מוחלפים ב-```` לפני החישוב, ולכן + אותו דפוס עם ערכים שונים הוא אותו ``query_id``. + + האוכלוסייה אחת לשני המספרים בכוונה: גם ספירת הדפוסים וגם ההצלבה נגזרות + מאותן רשומות, אחרת "6 מתוך 8" היה מתייחס לשתי קבוצות שונות. הנפח חסום + ממילא בסף השנייה שהפרופיילר אוכף. + """ + try: + rows = list( + coll.find( + {"timestamp": {"$gte": start, "$lt": end}}, + { + "query_id": 1, + "collection": 1, + "operation": 1, + "timestamp": 1, + "execution_time_ms": 1, + "raw_withheld_reason": 1, + "_id": 0, + }, + ) + ) + except Exception as exc: # noqa: BLE001 + logger.warning("daily_report_read_profiler_failed", extra={"error": type(exc).__name__}) + return SourceRead.failed(_exc_code(exc)) + + window_ts = [ts for ts in (ensure_utc_aware(w.get("ts")) for w in alert_windows) if ts] + counts: Counter = Counter() + meta: Dict[str, Dict[str, Any]] = {} + in_windows = 0 + outside_windows = 0 + seen_ids: Dict[str, str] = {} + + for row in rows: + query_id = str(row.get("query_id") or "") + if not query_id: + continue + counts[query_id] += 1 + ts = ensure_utc_aware(row.get("timestamp")) + if query_id not in meta: + meta[query_id] = { + "query_id": query_id, + "collection": str(row.get("collection") or "unknown"), + "operation": str(row.get("operation") or "unknown"), + # ניתן לניתוח רק אם הרשומה נשמרה עם הערכים האמיתיים. הדשבורד + # מציג את ``raw_withheld_reason`` בדיוק כשאין. + "analyzable": not bool(row.get("raw_withheld_reason")), + } + if ts is not None: + seen_ids[query_id] = ts.isoformat() + if any(_non_negative_delta(max(ts, w), min(ts, w)) <= correlation_window for w in window_ts): + in_windows += 1 + else: + outside_windows += 1 + + top_pattern = None + if counts: + top_id, top_count = counts.most_common(1)[0] + top_pattern = dict(meta.get(top_id, {"query_id": top_id})) + top_pattern["count"] = int(top_count) + + known = dict(known_query_ids or {}) + new_patterns = [ + dict(meta[qid], count=int(counts[qid])) for qid in counts if qid not in known + ] + new_patterns.sort(key=lambda item: item.get("count", 0), reverse=True) + + return SourceRead( + value={ + "total_slow": len(rows), + "unique_patterns": len(counts), + "top_pattern": top_pattern, + "new_patterns": new_patterns, + "seen_query_ids": seen_ids, + "slow_in_alert_windows": in_windows, + "slow_outside_alert_windows": outside_windows, + } + ) + + +def read_jobs(coll, *, start: datetime, end: datetime) -> SourceRead: + """כשלים, תקיעות, וג'ובים שרצים בהצלחה על אפס פריטים. + + ``total_items: 0`` בריצה שהסתיימה ב-``completed`` הוא בדיוק המקרה שאין + עליו התראה: שום דבר לא נכשל, ובכל זאת שום דבר לא נעשה. + """ + try: + rows = list( + coll.find( + {"started_at": {"$gte": start, "$lt": end}}, + {"job_id": 1, "status": 1, "total_items": 1, "stuck_reported_at": 1, "_id": 0}, + ) + ) + except Exception as exc: # noqa: BLE001 + logger.warning("daily_report_read_jobs_failed", extra={"error": type(exc).__name__}) + return SourceRead.failed(_exc_code(exc)) + + failed = 0 + stuck = 0 + zero_items: set = set() + for row in rows: + status = str(row.get("status") or "") + job_id = str(row.get("job_id") or "") + if status == "failed": + failed += 1 + if row.get("stuck_reported_at"): + stuck += 1 + if status == "completed" and int(row.get("total_items") or 0) == 0 and job_id: + zero_items.add(job_id) + return SourceRead( + value={"failed": failed, "stuck": stuck, "zero_items_jobs": sorted(zero_items)} + ) + + +def read_collection_sizes(db, *, names: Iterable[str] = GROWTH_COLLECTIONS) -> SourceRead: + """גודל האוספים דרך ``collStats`` — אותה פקודה שמסך DB Health מריץ. + + אוסף שאינו קיים מדלג בשקט: זה מצב תקין (למשל לפני הכתיבה הראשונה), + ולא כשל של המקור כולו. + """ + per_collection: Dict[str, Dict[str, int]] = {} + try: + for name in names: + try: + stats = db.command("collStats", name) + except Exception: # noqa: BLE001 — אוסף חסר אינו כשל של המקור + continue + per_collection[name] = { + "count": int(stats.get("count", 0) or 0), + "size_bytes": int(stats.get("size", 0) or 0), + } + return SourceRead(value={"per_collection": per_collection}) + except Exception as exc: # noqa: BLE001 + logger.warning("daily_report_read_collstats_failed", extra={"error": type(exc).__name__}) + return SourceRead.failed(_exc_code(exc)) + + +def read_cache(cache_stats_fn: Callable[[], Any]) -> SourceRead: + """המונים הגולמיים של Redis — לא ה-Hit Rate המחושב. + + ``keyspace_hits``/``keyspace_misses`` הם מונים **מצטברים מאז עליית + Redis**, ולכן ה-Hit Rate שהדשבורד מציג הוא ממוצע כל החיים. השוואה יומית + שלו כמעט תמיד רעש. לכן נשמרים כאן המונים עצמם, ו-``compare`` גוזר מהם + את ה-Hit Rate של היממה. ``uptime_seconds`` נשמר כדי לזהות אתחול של + Redis — שם ההפרש חסר משמעות. + """ + try: + stats = cache_stats_fn() + except Exception as exc: # noqa: BLE001 + logger.warning("daily_report_read_cache_failed", extra={"error": type(exc).__name__}) + return SourceRead.failed(_exc_code(exc)) + + if stats is None: + return SourceRead.failed("cache_unavailable") + if not bool(getattr(stats, "enabled", False)): + return SourceRead.failed("cache_disabled") + error = str(getattr(stats, "error", "") or "") + if error: + # ``get_cache_stats`` לעולם אינו זורק; הוא מדווח כשל בשדה ``error`` + # ומחזיר ``hit_rate=0.0``. בלי הבדיקה הזו האפס הזה היה נשמר כנתון. + return SourceRead.failed("cache_error") + return SourceRead( + value={ + "keyspace_hits": int(getattr(stats, "keyspace_hits", 0) or 0), + "keyspace_misses": int(getattr(stats, "keyspace_misses", 0) or 0), + "uptime_seconds": int(getattr(stats, "uptime_seconds", 0) or 0), + } + ) + + +def read_mcp( + run_endpoint_fn: Callable[..., Any], + *, + start: datetime, + end: datetime, + known_error_types: Optional[Dict[str, str]] = None, + failures_limit: int = 200, +) -> SourceRead: + """שגיאות MCP מסוג חדש ובקשות לכלי חסר. + + האנדפוינטים השמורים ב-PostHog **אינם מקבלים טווח תאריכים** — רק + ``limit`` — ולכן הסינון ליממה נעשה כאן, לפי ``failed_at``/``reported_at`` + שכל שורה נושאת. מסיבה זו גם נשמר ``last_refresh``: הנתון מגיע ממטמון של + PostHog, ואסור להציג נתון בן שעה תחת הכותרת "אתמול" בלי לומר זאת. + """ + known = dict(known_error_types or {}) + seen: Dict[str, str] = {} + new_types: List[str] = [] + failures_today = 0 + truncated = False + last_refresh = "" + + try: + failures = run_endpoint_fn("ck_mcp_tool_failures", failures_limit) + except Exception as exc: # noqa: BLE001 — החוזה אומר שלא זורק, אבל לא נסמוך + return SourceRead.failed(_exc_code(exc)) + if failures is None: + return SourceRead.failed("mcp_unavailable") + error_code = str(getattr(failures, "error_code", "") or "") + if error_code: + return SourceRead.failed(f"mcp:{error_code}") + + truncated = bool(getattr(failures, "has_more", False)) + last_refresh = str(getattr(failures, "last_refresh", "") or "") + for row in list(getattr(failures, "rows", []) or []): + if not isinstance(row, dict): + continue + ts = _parse_iso(row.get("failed_at")) + error_type = str(row.get("error_type") or "").strip() + if not error_type: + continue + if ts is not None: + seen[error_type] = ts.isoformat() + if start <= ts < end: + failures_today += 1 + if error_type not in known and error_type not in new_types: + new_types.append(error_type) + + missing_today = 0 + try: + missing = run_endpoint_fn("ck_mcp_missing_capabilities", None) + except Exception as exc: # noqa: BLE001 + return SourceRead.failed(_exc_code(exc)) + if missing is not None and not str(getattr(missing, "error_code", "") or ""): + for row in list(getattr(missing, "rows", []) or []): + if not isinstance(row, dict): + continue + ts = _parse_iso(row.get("reported_at")) + if ts is not None and start <= ts < end: + missing_today += 1 + + return SourceRead( + value={ + "new_error_types": new_types, + "seen_error_types": seen, + "failures_today": failures_today, + "failures_truncated": truncated, + "missing_capabilities_today": missing_today, + "last_refresh": last_refresh, + } + ) + + +def _parse_iso(value: Any) -> Optional[datetime]: + """פענוח חותמת זמן שהגיעה כמחרוזת מ-PostHog.""" + if isinstance(value, datetime): + return ensure_utc_aware(value) + if not isinstance(value, str) or not value.strip(): + return None + text = value.strip().replace("Z", "+00:00") + try: + return ensure_utc_aware(datetime.fromisoformat(text)) + except ValueError: + return None + + +# -------------------------------------------------------------------------- +# איסוף, שמירה, טעינה +# -------------------------------------------------------------------------- + + +@dataclass +class ReportDeps: + """התלויות שהאיסוף צורך. מוזרקות מ-``main.py``. + + הזרקה ולא ייבוא: כך הבדיקות מעבירות דמויות בלי לגעת ב-``sys.modules``, + וכל הקריאות עוברות דרך אותו ``MongoClient`` של האפליקציה — זה שמוגדר + ``tz_aware=True`` — במקום דרך הלקוחות הנפרדים ש-``alerts_storage`` ו- + ``metrics_storage`` פותחים לעצמם. + """ + + alerts_coll: Any = None + metrics_coll: Any = None + slow_coll: Any = None + job_runs_coll: Any = None + snapshots_coll: Any = None + db_for_collstats: Any = None + cache_stats_fn: Optional[Callable[[], Any]] = None + mcp_run_endpoint_fn: Optional[Callable[..., Any]] = None + + +def _roll_known(previous: Optional[Dict[str, str]], seen: Dict[str, str], *, now: datetime) -> Dict[str, str]: + """מגלגל את סט ה"כבר ראינו" קדימה, וגוזם מה שיצא מהחלון. + + נשמר כמילון ``{מזהה: חותמת אחרונה}`` ולא כרשימה, כי בלי החותמת אי אפשר + לגזום — והרשימה הייתה תופחת בלי גבול. + """ + cutoff = now - timedelta(days=KNOWN_ITEMS_WINDOW_DAYS) + merged: Dict[str, str] = {} + for source in (previous or {}, seen): + for key, raw_ts in (source or {}).items(): + ts = _parse_iso(raw_ts) + if ts is None or ts < cutoff: + continue + existing = merged.get(key) + if existing is None or raw_ts > existing: + merged[key] = str(raw_ts) + return merged + + +def collect_snapshot( + *, + day_key: str, + day_start_utc: datetime, + day_end_utc: datetime, + deps: ReportDeps, + previous: Optional[Dict[str, Any]] = None, + correlation_window: timedelta = timedelta(minutes=5), + now: Optional[datetime] = None, +) -> Dict[str, Any]: + """קורא את כל המקורות ומרכיב את מסמך הסנאפשוט. + + כשל של מקור אחד אינו מפיל את השאר ואינו משתיק אותם — הוא נרשם כ- + ``ok: False`` באותו מקור בלבד. הפונקציה סינכרונית בכוונה; היא נקראת + מתוך ``asyncio.to_thread`` כי היא נוגעת ב-Mongo, ב-Redis וב-HTTP. + """ + now = now or datetime.now(timezone.utc) + prev_sources = (previous or {}).get("sources") or {} + + alerts = ( + read_alerts(deps.alerts_coll, start=day_start_utc, end=day_end_utc) + if deps.alerts_coll is not None + else SourceRead.failed("no_collection") + ) + alert_windows = (alerts.value or {}).get("alert_windows", []) if alerts.ok else [] + + metrics = ( + read_top_endpoint(deps.metrics_coll, start=day_start_utc, end=day_end_utc) + if deps.metrics_coll is not None + else SourceRead.failed("no_collection") + ) + + prev_profiler = prev_sources.get("profiler") or {} + profiler = ( + read_slow_queries( + deps.slow_coll, + start=day_start_utc, + end=day_end_utc, + alert_windows=alert_windows, + correlation_window=correlation_window, + known_query_ids=prev_profiler.get("known_query_ids") if prev_profiler.get("ok") else None, + ) + if deps.slow_coll is not None + else SourceRead.failed("no_collection") + ) + + jobs = ( + read_jobs(deps.job_runs_coll, start=day_start_utc, end=day_end_utc) + if deps.job_runs_coll is not None + else SourceRead.failed("no_collection") + ) + + collstats = ( + read_collection_sizes(deps.db_for_collstats) + if deps.db_for_collstats is not None + else SourceRead.failed("no_db") + ) + + cache = ( + read_cache(deps.cache_stats_fn) + if deps.cache_stats_fn is not None + else SourceRead.failed("no_cache_reader") + ) + + prev_mcp = prev_sources.get("mcp") or {} + mcp = ( + read_mcp( + deps.mcp_run_endpoint_fn, + start=day_start_utc, + end=day_end_utc, + known_error_types=prev_mcp.get("known_error_types") if prev_mcp.get("ok") else None, + ) + if deps.mcp_run_endpoint_fn is not None + else SourceRead.failed("no_mcp_reader") + ) + + profiler_doc = profiler.to_doc() + if profiler.ok: + seen_ids = profiler_doc.pop("seen_query_ids", {}) + profiler_doc["known_query_ids"] = _roll_known( + prev_profiler.get("known_query_ids") if prev_profiler.get("ok") else None, + seen_ids, + now=now, + ) + mcp_doc = mcp.to_doc() + if mcp.ok: + seen_types = mcp_doc.pop("seen_error_types", {}) + mcp_doc["known_error_types"] = _roll_known( + prev_mcp.get("known_error_types") if prev_mcp.get("ok") else None, + seen_types, + now=now, + ) + + return { + "_id": day_key, + "day_start_utc": day_start_utc, + "day_end_utc": day_end_utc, + "created_at": now, + "sources": { + "alerts": alerts.to_doc(), + "metrics": metrics.to_doc(), + "profiler": profiler_doc, + "jobs": jobs.to_doc(), + "collstats": collstats.to_doc(), + "cache": cache.to_doc(), + "mcp": mcp_doc, + }, + } + + +def save_snapshot(coll, snapshot: Dict[str, Any]) -> Dict[str, Any]: + """שומר את הסנאפשוט של היום ומחזיר את מה שנשמר **בפועל**. + + הכתיבה היא ``$setOnInsert`` ולא ``$set``, כלומר הכתיבה הראשונה מנצחת — + אותו דפוס שבו ``record_alert`` מונע כפילויות. זה מה שמגן מפני שתי ריצות + מקבילות (המתוזמנת וטריגר ידני) שהיו דורסות זו את זו: ``JobTracker`` + מונע חפיפה רק בתוך אותו תהליך, ולכן הוא אינו הגנה מספקת. + + הפונקציה קוראת את המסמך חזרה ומחזירה אותו — כך שריצה שהפסידה בכתיבה + משווה מול הסנאפשוט שנשמר ולא מול מה שהיא עצמה חישבה. **כשל נזרק ואינו + נבלע**: דוח שנשלח בלי סנאפשוט הופך את הדוח של מחר לשקר שקט. + """ + day_key = snapshot["_id"] + payload = {k: v for k, v in snapshot.items() if k != "_id"} + coll.update_one({"_id": day_key}, {"$setOnInsert": payload}, upsert=True) + stored = coll.find_one({"_id": day_key}) + if not stored: + raise RuntimeError(f"snapshot_not_persisted:{day_key}") + return stored + + +def load_snapshot(coll, day_key: str) -> Optional[Dict[str, Any]]: + """טוען את הסנאפשוט של יום מסוים — לפי מפתח מפורש. + + **לא** "השורה האחרונה": יום שבו ה-job לא רץ היה גורם להשוואה מול שלשום, + ואז שינוי של יומיים מדווח כשינוי של יום. אין מסמך ← ``None``, והדוח + יאמר שאין בסיס להשוואה. + """ + try: + return coll.find_one({"_id": day_key}) + except Exception as exc: # noqa: BLE001 + logger.warning("daily_report_load_snapshot_failed", extra={"error": type(exc).__name__}) + return None + + +# -------------------------------------------------------------------------- +# השוואה ורינדור +# -------------------------------------------------------------------------- + + +@dataclass +class ReportDiff: + """מה ייכנס להודעה. שורה שאינה כאן פשוט לא תופיע.""" + + day_label: str = "" + has_baseline: bool = False + lines: List[str] = field(default_factory=list) + warnings: List[str] = field(default_factory=list) + sections: List[str] = field(default_factory=list) + + @property + def has_content(self) -> bool: + return bool(self.lines or self.warnings) + + +def _source(snapshot: Optional[Dict[str, Any]], name: str) -> Dict[str, Any]: + return ((snapshot or {}).get("sources") or {}).get(name) or {} + + +def _hit_rate(hits: int, misses: int) -> Optional[float]: + total = hits + misses + if total <= 0: + return None + return round(hits / total * 100.0, 1) + + +def compare( + today: Dict[str, Any], + yesterday: Optional[Dict[str, Any]], + *, + correlation_window: timedelta = timedelta(minutes=5), +) -> ReportDiff: + """מרכיב את שורות הדוח מהסנאפשוט של היום מול זה של אתמול. + + כל שורה כאן היא **שינוי או אירוע**. מקור שנכשל מדווח "אין נתון" ולעולם + לא "ירד" או "השתפר", ומקור בלי בסיס להשוואה מדלג על השורות שדורשות אחד. + """ + diff = ReportDiff(day_label=str(today.get("_id") or ""), has_baseline=yesterday is not None) + + for label, key in ( + ("התראות", "alerts"), + ("מדדים", "metrics"), + ("שאילתות", "profiler"), + ("jobs", "jobs"), + ("גודל אוספים", "collstats"), + ("קאש", "cache"), + ("MCP", "mcp"), + ): + src = _source(today, key) + if src and not src.get("ok", True): + diff.warnings.append(f"⚠️ {label}: אין נתון ({src.get('error') or 'unknown'})") + + # --- Observability --- + alerts = _source(today, "alerts") + if alerts.get("ok"): + critical = int(alerts.get("critical") or 0) + errors = int(alerts.get("error") or 0) + deploys = int(alerts.get("deploy_count") or 0) + if critical or errors or deploys: + parts = [] + if critical: + parts.append(f"{critical} CRITICAL") + if errors: + parts.append(f"{errors} ERROR") + if deploys: + parts.append(f"{deploys} דיפלוי") + diff.lines.append("🔭 התראות: " + " · ".join(parts)) + diff.sections.append("alerts") + + metrics = _source(today, "metrics") + prev_metrics = _source(yesterday, "metrics") + top = metrics.get("top_slow_endpoint") if metrics.get("ok") else None + prev_top = prev_metrics.get("top_slow_endpoint") if prev_metrics.get("ok") else None + if top and prev_metrics.get("ok"): + prev_name = (prev_top or {}).get("endpoint") + if prev_name and prev_name != top.get("endpoint"): + diff.lines.append( + f" ה-endpoint האיטי ביותר השתנה: {top.get('endpoint')} " + f"({float(top.get('max_duration') or 0.0):.1f}s) ← אתמול {prev_name}" + ) + diff.sections.append("top_endpoint_changed") + + # --- Query Profiler --- + profiler = _source(today, "profiler") + prev_profiler = _source(yesterday, "profiler") + if profiler.get("ok"): + for pattern in list(profiler.get("new_patterns") or [])[:3]: + suffix = " — ניתן לניתוח" if pattern.get("analyzable") else "" + diff.lines.append( + f"🔍 דפוס שאילתה חדש ב-{pattern.get('collection')} " + f"({pattern.get('operation')}, {pattern.get('count')} פעמים){suffix}" + ) + diff.sections.append("new_pattern") + + top_pattern = profiler.get("top_pattern") or {} + prev_top_pattern = (prev_profiler.get("top_pattern") or {}) if prev_profiler.get("ok") else {} + if top_pattern and prev_profiler.get("ok"): + now_count = int(top_pattern.get("count") or 0) + was_count = int(prev_top_pattern.get("count") or 0) + # תופעת זנב: דפוס אחד שרץ מאות פעמים. יחס כולל של שאילתות חלקי + # דפוסים היה ממסך אותה בדיוק ביום שבו היא מופיעה. + if now_count >= 10 and now_count >= was_count * 2: + diff.lines.append( + f" הדפוס הגדול ביותר קפץ {was_count} ← {now_count} חזרות (N+1?)" + ) + diff.sections.append("pattern_spike") + + inside = int(profiler.get("slow_in_alert_windows") or 0) + outside = int(profiler.get("slow_outside_alert_windows") or 0) + if inside or outside: + minutes = int(correlation_window.total_seconds() // 60) + diff.lines.append( + f" הצלבה (±{minutes} דק'): {inside} שאילתות איטיות בתוך חלונות התראה, " + f"{outside} מחוץ" + ) + diff.sections.append("correlation") + + # --- Cache --- + cache = _source(today, "cache") + prev_cache = _source(yesterday, "cache") + if cache.get("ok") and prev_cache.get("ok"): + uptime_now = int(cache.get("uptime_seconds") or 0) + uptime_prev = int(prev_cache.get("uptime_seconds") or 0) + if uptime_now < uptime_prev: + # ‏Redis הופעל מחדש: המונים אופסו, וההפרש היה יוצא שלילי או מנופח. + diff.lines.append("🧊 קאש: Redis הופעל מחדש — אין בסיס להשוואה יומית") + diff.sections.append("cache_restart") + else: + hits = int(cache.get("keyspace_hits") or 0) - int(prev_cache.get("keyspace_hits") or 0) + misses = int(cache.get("keyspace_misses") or 0) - int( + prev_cache.get("keyspace_misses") or 0 + ) + rate = _hit_rate(max(0, hits), max(0, misses)) + prev_rate = _hit_rate( + int(prev_cache.get("keyspace_hits") or 0), + int(prev_cache.get("keyspace_misses") or 0), + ) + if rate is not None and prev_rate is not None and abs(rate - prev_rate) >= 5.0: + note = "" + if rate < prev_rate and int(_source(today, "alerts").get("deploy_count") or 0): + note = " — היה דיפלוי באותה יממה" + diff.lines.append( + f"🧊 קאש: Hit Rate יומי {rate}% (מצטבר אתמול {prev_rate}%){note}" + ) + diff.sections.append("cache_hit_rate") + + # --- Jobs --- + jobs = _source(today, "jobs") + if jobs.get("ok"): + failed = int(jobs.get("failed") or 0) + stuck = int(jobs.get("stuck") or 0) + if failed or stuck: + parts = [] + if failed: + parts.append(f"{failed} כשלים") + if stuck: + parts.append(f"{stuck} תקועים") + diff.lines.append("⏱️ jobs: " + " · ".join(parts)) + diff.sections.append("jobs") + zero_now = set(jobs.get("zero_items_jobs") or []) + prev_jobs = _source(yesterday, "jobs") + zero_prev = set(prev_jobs.get("zero_items_jobs") or []) if prev_jobs.get("ok") else set() + repeated = sorted(zero_now & zero_prev) + if repeated: + diff.lines.append( + " רצו בהצלחה על אפס פריטים גם אתמול וגם היום: " + ", ".join(repeated) + ) + diff.sections.append("zero_items") + + # --- DB growth --- + collstats = _source(today, "collstats") + prev_collstats = _source(yesterday, "collstats") + if collstats.get("ok") and prev_collstats.get("ok"): + now_map = collstats.get("per_collection") or {} + prev_map = prev_collstats.get("per_collection") or {} + growth_parts = [] + for name in GROWTH_COLLECTIONS: + cur = now_map.get(name) + was = prev_map.get(name) + if not cur or not was: + continue + d_count = int(cur.get("count", 0)) - int(was.get("count", 0)) + d_size = int(cur.get("size_bytes", 0)) - int(was.get("size_bytes", 0)) + if d_count: + growth_parts.append(f"{name} {_fmt_signed(d_count)} מסמכים ({_fmt_bytes(d_size)})") + if growth_parts: + diff.lines.append("🩺 DB: " + " · ".join(growth_parts)) + diff.sections.append("db_growth") + + # --- MCP --- + mcp = _source(today, "mcp") + if mcp.get("ok"): + parts = [] + new_types = list(mcp.get("new_error_types") or []) + if new_types: + parts.append("שגיאה מסוג חדש: " + ", ".join(new_types[:3])) + missing = int(mcp.get("missing_capabilities_today") or 0) + if missing: + parts.append(f"בקשת כלי חסר ×{missing}") + if parts: + line = "🤖 MCP: " + " · ".join(parts) + refresh = str(mcp.get("last_refresh") or "") + if refresh: + # הנתון מגיע ממטמון של PostHog. בלי החותמת הזו נתון בן שעה + # מוצג תחת הכותרת "אתמול", וזה מה שמפרק אמון בדוח. + line += f" (נכון ל-{refresh})" + diff.lines.append(line) + diff.sections.append("mcp") + + return diff + + +def render_report(diff: ReportDiff, *, max_chars: int = MAX_MESSAGE_CHARS) -> Optional[str]: + """מרכיב את גוף ההודעה, או ``None`` כשאין מה לדווח. + + ``None`` הוא תשובה לגיטימית ואף הנפוצה: יום שקט אינו מייצר הודעה. החיות + של ה-job נמדדת מרשומת ההרצה ב-``job_runs`` ולא מהודעה שמעידה על עצמה. + """ + if not diff.has_content: + return None + + header = f"📋 דוח בוקר · {diff.day_label}" + body: List[str] = [header] + if not diff.has_baseline: + body.append("ℹ️ אין בסיס להשוואה (יום ראשון של הדוח) — מוצגים אירועים בלבד") + # אזהרות לפני שורות התוכן, ובכוונה. החיתוך למטה מוריד מהסוף, ולכן סדר + # הפוך היה מפיל קודם כול את "⚠️ מקור X: אין נתון" — כלומר הודעה חתוכה + # הייתה נראית כמו יום שבו כל המקורות נקראו בהצלחה. לאבד שורת תוכן זה + # חיסרון; לאבד את הידיעה שהדוח חלקי זה להטעות. + body.extend(diff.warnings) + body.extend(diff.lines) + + text = "\n".join(body) + if len(text) <= max_chars: + return text + + # חיתוך בגבול שורה, לא באמצע מילה: הודעה חתוכה עדיפה על שליחה שנכשלת + # בשקט מעל מגבלת Telegram. + trimmed: List[str] = [] + used = 0 + ellipsis = "\n…" + for line in body: + if used + len(line) + 1 + len(ellipsis) > max_chars: + break + trimmed.append(line) + used += len(line) + 1 + return "\n".join(trimmed) + ellipsis + + +# -------------------------------------------------------------------------- +# חלונות זמן +# -------------------------------------------------------------------------- + + +def day_key_for(now_local: datetime) -> str: + """מפתח היום שהדוח מתאר — התאריך המקומי של היממה שהסתיימה עכשיו.""" + return (now_local.date() - timedelta(days=1)).isoformat() + + +def previous_day_key(day_key: str) -> str: + """מפתח D-1. מפורש, כדי שההשוואה לא תיפול בשקט על 'האחרון שיש'.""" + return (date.fromisoformat(day_key) - timedelta(days=1)).isoformat() + + +def window_for(now_utc: datetime) -> tuple: + """‏24 השעות שהסתיימו עכשיו, מעוגלות לדקה.""" + end = now_utc.replace(second=0, microsecond=0) + return end - timedelta(days=1), end diff --git a/services/register_jobs.py b/services/register_jobs.py index f547ff15e..ca21cf21d 100644 --- a/services/register_jobs.py +++ b/services/register_jobs.py @@ -135,6 +135,27 @@ def register_all_jobs(): source_file="main.py", ) + register_job( + job_id="daily_morning_report", + name="דוח בוקר יומי", + description=( + "מצליב בין הדשבורדים ושולח סיכום יומי — רק כשיש מה לדווח. " + "החיות נמדדת מרישום ההרצה כאן, לא מהודעה" + ), + category=JobCategory.MONITORING, + job_type=JobType.REPEATING, + interval_seconds=24 * 3600, + # אין env_toggle: המוסכמה כאן היא "מופעל כשהמשתנה truthy", ו- + # DISABLE_DAILY_REPORT הפוך בדיוק. לכן הכיבוי נבדק בתוך ה-job + # ומדווח כ-skip_run, בדיוק כמו DISABLE_WEEKLY_REPORTS. + enabled=True, + callback_name="_daily_morning_report", + source_file="main.py", + # נקרא על ידי בדיקת "job מתוזמן שלא רץ" ב-_jobs_stuck_monitor. + # 26 שעות ולא 24: מרווח למניעת התראת שווא סביב שעון קיץ ודיפלוי. + metadata={"expect_run_every_seconds": 24 * 3600, "missed_after_hours": 26}, + ) + register_job( job_id="weekly_admin_report", name="דו\"ח שבועי", diff --git a/tests/test_daily_report_indexes.py b/tests/test_daily_report_indexes.py new file mode 100644 index 000000000..6d8188d41 --- /dev/null +++ b/tests/test_daily_report_indexes.py @@ -0,0 +1,125 @@ +"""אינדקסים שדוח הבוקר היומי נשען עליהם. + +שני דברים נבדקים כאן, ושניהם נבדקים כי הם כבר נכשלו בריפו הזה בדיוק באותה +צורה: אינדקס שמוצהר במסמך ולא נוצר בקוד. + +1. **ה-TTL של ``daily_report_snapshots``** — בלעדיו האוסף גדל בלי גבול, בדיוק + כמו ``job_runs`` ו-``service_metrics``. +2. **האינדקס ``(job_id, started_at)`` על ``job_runs``** — הוא כבר מוצהר + ב-``database/job_runs_collection.py``, אבל אותו קובץ אינו מיובא בשום מקום, + ולכן אף אינדקס שבו לא נוצר בפועל. הבדיקה מקבעת שהוא באמת נוצר עכשיו. +""" + +from __future__ import annotations + + +def _import_manager(monkeypatch): + monkeypatch.setenv("BOT_TOKEN", "x") + monkeypatch.setenv("MONGODB_URL", "mongodb://localhost:27017/db") + monkeypatch.setenv("DISABLE_DB", "1") + import database.manager as dm + + return dm + + +class TestDailyReportSnapshotIndex: + def test_creates_a_ttl_index_on_the_field_the_writer_actually_writes(self, monkeypatch): + dm = _import_manager(monkeypatch) + import services.daily_report_service as drs + + requested: list[tuple] = [] + dm.DatabaseManager._create_daily_report_indexes( + object(), lambda collection, keys, **kwargs: requested.append((collection, keys, kwargs)) + ) + + assert len(requested) == 1 + collection, keys, kwargs = requested[0] + assert collection == drs.COLLECTION_NAME + # ``created_at`` הוא השדה ש-``collect_snapshot`` כותב. אינדקס TTL על + # שדה שאיש אינו כותב פשוט לא מוחק כלום — וזה בדיוק המצב של + # ``ttl_cleanup`` על ``service_metrics.timestamp`` היום. + assert keys == [("created_at", 1)] + assert kwargs["name"] == "ttl_cleanup" + assert kwargs["expire_after_seconds"] == drs.TTL_SECONDS + # בלי enforce, שינוי עתידי של TTL_SECONDS לא יוחל על אינדקס קיים. + assert kwargs["enforce"] is True + + def test_snapshot_ttl_outlives_the_sources_it_compares_against(self, monkeypatch): + """הסנאפשוט חייב לשרוד יותר מהמקורות, אחרת אין מול מה להשוות. + + ``slow_queries_log`` נשמר שבעה ימים, והזיכרון של דפוסים מוכרים הוא 30 + יום — TTL קצר מהם היה מוחק את הבסיס להשוואה לפני שהוא מספיק לשמש. + """ + _import_manager(monkeypatch) + import services.daily_report_service as drs + from services.query_profiler_service import PersistentQueryProfilerService + + assert drs.TTL_SECONDS > PersistentQueryProfilerService.TTL_SECONDS + assert drs.TTL_SECONDS > drs.KNOWN_ITEMS_WINDOW_DAYS * 24 * 3600 + + def test_writer_and_index_agree_on_the_field_name(self, monkeypatch): + """מקבע את החוזה בין הכותב לאינדקס, במקום להסתמך על כך שמישהו יזכור.""" + from datetime import datetime, timezone + + import services.daily_report_service as drs + + snapshot = drs.collect_snapshot( + day_key="2026-09-06", + day_start_utc=datetime(2026, 9, 6, 8, 0, tzinfo=timezone.utc), + day_end_utc=datetime(2026, 9, 7, 8, 0, tzinfo=timezone.utc), + deps=drs.ReportDeps(), + now=datetime(2026, 9, 7, 8, 0, tzinfo=timezone.utc), + ) + assert isinstance(snapshot["created_at"], datetime) + + +class TestJobRunsQueryIndex: + def test_job_runs_gets_the_compound_index_its_queries_need(self, monkeypatch): + """האינדקס שהוצהר ולא נוצר — עד עכשיו. + + משרת את ``JobTracker.get_job_history``, את ``/jobs failed`` ב-ChatOps, + ואת בדיקת "job מתוזמן שלא רץ" שרצה כל 60 שניות. + + ‏``_create_indexes`` קוראת ל-``safe_create_index`` מתוך ``self`` + (ראו ההערה בגוף הפונקציה על תאימות לטסטים), ויוצאת מוקדם כש-``db`` + הוא ``None`` — ולכן הדמה כאן מספקת את שניהם. + """ + dm = _import_manager(monkeypatch) + requested: list[tuple] = [] + + class _Recorder: + db = object() + + @staticmethod + def safe_create_index(collection, keys, **kwargs): + requested.append((collection, keys, kwargs)) + + dm.DatabaseManager._create_indexes(_Recorder()) + + job_runs_indexes = { + kwargs.get("name"): keys for collection, keys, kwargs in requested if collection == "job_runs" + } + assert "idx_job_runs_job_started" in job_runs_indexes, ( + "האינדקס מוצהר ב-database/job_runs_collection.py אך אותו קובץ אינו מיובא; " + "הוא חייב להיווצר כאן" + ) + assert job_runs_indexes["idx_job_runs_job_started"] == [("job_id", 1), ("started_at", -1)] + # האינדקס הייחודי הקיים לא זז. + assert "idx_job_runs_id" in job_runs_indexes + + def test_create_indexes_also_wires_the_snapshot_ttl(self, monkeypatch): + """האינדקס לא שווה כלום אם ``_create_indexes`` לא קוראת לו בעלייה.""" + dm = _import_manager(monkeypatch) + import services.daily_report_service as drs + + requested: list[tuple] = [] + + class _Recorder: + db = object() + + @staticmethod + def safe_create_index(collection, keys, **kwargs): + requested.append((collection, keys, kwargs)) + + dm.DatabaseManager._create_indexes(_Recorder()) + assert any(collection == drs.COLLECTION_NAME for collection, _, _ in requested) diff --git a/tests/test_daily_report_job.py b/tests/test_daily_report_job.py new file mode 100644 index 000000000..35b7dcd33 --- /dev/null +++ b/tests/test_daily_report_job.py @@ -0,0 +1,809 @@ +"""בדיקות ל-job של דוח הבוקר: שער המסירה, התזמון, וזיהוי job שלא רץ. + +הבדיקות כאן נוגעות בקוד שב-``main.py``, ולכן הן עובדות מול הפונקציות +ברמת המודול — אלה שנכתבו במפורש כדי להיות ניתנות לבדיקה בלי להרים את הבוט. + +הדגש המרכזי: **שער המסירה**. ``emit_internal_alert`` מחזיר ``None`` תמיד +ואינו מדווח כשל, ולכן בלי בדיקה מוקדמת הדוח היה מסתיים כ-``completed`` גם +כשההודעה נחסמה על סף החומרה — הצלחה מדומה על משהו שלא קרה. +""" + +import asyncio +from datetime import datetime, timedelta, timezone + +import pytest + +UTC = timezone.utc + + +@pytest.fixture() +def main_mod(): + import main + + return main + + +# -------------------------------------------------------------------------- +# שער המסירה — 11, 11א, 11ב +# -------------------------------------------------------------------------- + + +@pytest.fixture() +def deliverable_env(monkeypatch): + """סביבה שבה ההודעה כן אמורה להגיע — נקודת המוצא לכל בדיקות השער.""" + monkeypatch.setenv("ALERT_TELEGRAM_BOT_TOKEN", "t") + monkeypatch.setenv("ALERT_TELEGRAM_CHAT_ID", "1") + monkeypatch.setenv("ALERT_TELEGRAM_MIN_SEVERITY", "warn") + import alert_forwarder as af + + monkeypatch.setattr(af, "_TELEGRAM_SUPPRESS_ALERTS", set()) + + +def test_gate_open_when_severity_is_allowed(main_mod, deliverable_env): + """‏warn מול סף warn — עובר. זה הצד ש'סוגר' חייב להיבדל ממנו.""" + assert main_mod._daily_report_gate_reason() == "" + + +def test_gate_blocks_when_min_severity_is_above_report(main_mod, deliverable_env, monkeypatch): + """הכשל שהתגלה בחקירה: סף ``critical`` בולע דוח ב-``warn`` בשקט מוחלט. + + בלי השער הזה ה-job היה מסתיים ב-``completed`` בזמן שאף הודעה לא נשלחה. + """ + monkeypatch.setenv("ALERT_TELEGRAM_MIN_SEVERITY", "critical") + assert main_mod._daily_report_gate_reason() == "below_min_severity" + + +def test_gate_blocks_when_alert_name_is_suppressed(main_mod, deliverable_env, monkeypatch): + """רשימת ההשתקה נקראת מה-forwarder עצמו, לא ממשתנה הסביבה. + + ``_TELEGRAM_SUPPRESS_ALERTS`` מחושב בזמן ה-import, ולכן קריאה עצמאית של + ``os.getenv`` הייתה יכולה לסתור את מה שקורה בפועל. + """ + import alert_forwarder as af + import services.daily_report_service as drs + + monkeypatch.setattr(af, "_TELEGRAM_SUPPRESS_ALERTS", {drs.REPORT_ALERT_NAME}) + assert main_mod._daily_report_gate_reason() == "suppressed" + + +@pytest.mark.parametrize( + "missing,expected", + [("ALERT_TELEGRAM_CHAT_ID", "no_chat"), ("ALERT_TELEGRAM_BOT_TOKEN", "no_token")], +) +def test_gate_blocks_when_telegram_is_not_configured(main_mod, deliverable_env, monkeypatch, missing, expected): + monkeypatch.delenv(missing, raising=False) + assert main_mod._daily_report_gate_reason() == expected + + +def test_gate_failure_fails_the_run_instead_of_reporting_success(main_mod, deliverable_env, monkeypatch): + """הטענה המרכזית: שער חסום ← ``fail_run``, ולא ``completed``.""" + monkeypatch.setenv("ALERT_TELEGRAM_MIN_SEVERITY", "critical") + + class Tracker: + def __init__(self): + self.failed_with = None + + def fail_run(self, _run_id, message): + self.failed_with = message + + class Run: + run_id = "r1" + + tracker = Tracker() + assert main_mod._daily_report_gate_ok(Run(), tracker) is False + assert tracker.failed_with == "telegram_gate:below_min_severity" + + monkeypatch.setenv("ALERT_TELEGRAM_MIN_SEVERITY", "warn") + tracker2 = Tracker() + assert main_mod._daily_report_gate_ok(Run(), tracker2) is True + assert tracker2.failed_with is None + + +# -------------------------------------------------------------------------- +# קונפיגורציה +# -------------------------------------------------------------------------- + + +@pytest.mark.parametrize( + "value,expected", + [("08:00", (8, 0)), ("6:30", (6, 30)), ("23:59", (23, 59))], +) +def test_hour_env_is_parsed(main_mod, monkeypatch, value, expected): + monkeypatch.setenv("DAILY_REPORT_HOUR_LOCAL", value) + assert main_mod._daily_report_hour_minute() == expected + + +@pytest.mark.parametrize("bad", ["", "abc", "25:00", "08:99"]) +def test_bad_hour_env_falls_back_to_eight_instead_of_crashing(main_mod, monkeypatch, bad): + """ערך פגום לא מפיל את התזמון — job בלי זמן פשוט לא ירוץ.""" + monkeypatch.setenv("DAILY_REPORT_HOUR_LOCAL", bad) + assert main_mod._daily_report_hour_minute() == (8, 0) + + +def test_correlation_window_env_is_clamped(main_mod, monkeypatch): + """חלון של אפס או של יומיים אינו חלון — הערך נחסם לטווח שפוי.""" + monkeypatch.setenv("DAILY_REPORT_CORRELATION_WINDOW_MINUTES", "0") + assert main_mod._daily_report_window_minutes() == 1 + monkeypatch.setenv("DAILY_REPORT_CORRELATION_WINDOW_MINUTES", "99999") + assert main_mod._daily_report_window_minutes() == 120 + monkeypatch.setenv("DAILY_REPORT_CORRELATION_WINDOW_MINUTES", "5") + assert main_mod._daily_report_window_minutes() == 5 + + +# -------------------------------------------------------------------------- +# תזמון +# -------------------------------------------------------------------------- + + +class _JobQueueSpy: + def __init__(self, daily_raises=None): + self.daily_calls = [] + self.repeating_calls = [] + self._daily_raises = daily_raises + + def run_daily(self, callback, time=None, name=None, job_kwargs=None): # noqa: A002 + self.daily_calls.append({"time": time, "name": name, "job_kwargs": job_kwargs}) + if self._daily_raises is not None: + raise self._daily_raises + + def run_repeating(self, callback, interval=None, first=None, name=None): + self.repeating_calls.append({"interval": interval, "first": first, "name": name}) + + +class _AppSpy: + def __init__(self, job_queue): + self.job_queue = job_queue + + +def test_schedule_uses_run_daily_with_an_explicit_timezone(main_mod, monkeypatch): + """ה-``time`` חייב לשאת ``tzinfo``. + + ה-``Defaults`` של הבוט מוגדר רק עם ``parse_mode``, וברירת המחדל של + JobQueue היא UTC — כלומר בלי אזור זמן מפורש הדוח היה נשלח בשעה הלא נכונה. + """ + monkeypatch.setenv("DAILY_REPORT_HOUR_LOCAL", "08:00") + jq = _JobQueueSpy() + main_mod._schedule_daily_morning_report(_AppSpy(jq), lambda *_a: None) + + assert len(jq.daily_calls) == 1 + call = jq.daily_calls[0] + assert call["name"] == "daily_morning_report", "השם חייב להיות זהה ל-job_id, אחרת טריגר ידני לא ימצא אותו" + assert (call["time"].hour, call["time"].minute) == (8, 0) + assert call["time"].tzinfo is not None + assert call["job_kwargs"]["misfire_grace_time"] == 3600 + assert jq.repeating_calls == [] + + +def test_schedule_falls_back_to_repeating_when_run_daily_is_unavailable(main_mod, monkeypatch): + """נפילה מבוקרת, באותה תבנית שכבר קיימת ב-``_safe_run_repeating``.""" + monkeypatch.setenv("DAILY_REPORT_HOUR_LOCAL", "08:00") + + class OnlyRepeating(_JobQueueSpy): + def run_daily(self, *a, **k): + raise TypeError("run_daily unsupported") + + jq = OnlyRepeating() + main_mod._schedule_daily_morning_report(_AppSpy(jq), lambda *_a: None) + assert len(jq.repeating_calls) == 1 + assert jq.repeating_calls[0]["interval"] == 24 * 3600 + assert jq.repeating_calls[0]["name"] == "daily_morning_report" + assert jq.repeating_calls[0]["first"] >= 60 + + +def test_scheduling_failure_never_raises(main_mod): + """כשל תזמון אינו מפיל את עליית הבוט.""" + + class Broken: + def run_daily(self, *a, **k): + raise RuntimeError("nope") + + def run_repeating(self, *a, **k): + raise RuntimeError("nope") + + main_mod._schedule_daily_morning_report(_AppSpy(Broken()), lambda *_a: None) + + +# -------------------------------------------------------------------------- +# 12 + 19 — זיהוי job מתוזמן שלא רץ +# -------------------------------------------------------------------------- + + +class _AsyncCursor: + def __init__(self, rows): + self._rows = rows + + async def to_list(self, length=None): # noqa: ARG002 + return list(self._rows) + + +class _AsyncJobRuns: + """דמה אסינכרונית של ``job_runs``, בסגנון motor.""" + + def __init__(self, rows=None): + self.rows = list(rows or []) + self.aggregate_calls = 0 + self.last_pipeline = None + + def aggregate(self, pipeline): + self.aggregate_calls += 1 + self.last_pipeline = pipeline + match = pipeline[0]["$match"] + wanted = set(match["job_id"]["$in"]) + statuses = set(match["status"]["$in"]) + cutoff = match["started_at"]["$gte"] + grouped = {} + for row in self.rows: + if row["job_id"] in wanted and row["status"] in statuses and row["started_at"] >= cutoff: + current = grouped.get(row["job_id"]) + if current is None or row["started_at"] > current: + grouped[row["job_id"]] = row["started_at"] + return _AsyncCursor( + [{"_id": job_id, "last_started_at": ts} for job_id, ts in grouped.items()] + ) + + +class _AsyncAdminReports: + """דמה של ``admin_reports`` שמתנהגת כמו מונגו, לא כמו שנוח לנו. + + זו הנקודה החשובה בקובץ הזה. ה-upsert המותנה + (``{"_id": ..., "day_key": {"$ne": today}}`` עם ``upsert=True``) **לא** + מחזיר "0 מסמכים עודכנו" כשהמסמך כבר קיים עם ה-``day_key`` של היום. + תיעוד MongoDB, בסעיף Upsert Behavior, אומר שהמסמך החדש נבנה *מסעיפי + השוויון בלבד* ושאופרטורי השוואה (``$ne``) אינם נכנסים אליו — ולכן מונגו + מנסה ליצור מסמך עם אותו ``_id`` שכבר קיים, ונכשל בהתנגשות מפתח ייחודי. + + הדמה הקודמת החזירה ``modified_count=0``, כלומר הייתה **סלחנית מהמציאות**, + וזו הייתה הסיבה היחידה שהבדיקה "לא מדווח פעמיים" עברה. עכשיו היא זורקת, + כמו השרת. + """ + + def __init__(self, raises=None): + self.docs = {} + self.calls = 0 + self._raises = raises + + async def update_one(self, query, update, upsert=False): # noqa: ARG002 + self.calls += 1 + if self._raises is not None: + raise self._raises + key = query["_id"] + blocked = query.get("day_key", {}).get("$ne") + existing = self.docs.get(key) + if existing is not None and existing.get("day_key") == blocked: + raise _duplicate_key_error() + self.docs[key] = dict(existing or {}, **update.get("$set", {})) + return type("R", (), {"modified_count": 1, "upserted_id": None})() + + +def _duplicate_key_error(): + """אותה חריגה שהקוד תופס — מיובאת מאותו מקום שממנו ``main`` מייבא אותה.""" + import main + + return main.DuplicateKeyError("E11000 duplicate key error") + + +class _AsyncDB: + def __init__(self, job_runs, admin_reports=None): + self.job_runs = job_runs + self.admin_reports = admin_reports or _AsyncAdminReports() + + +@pytest.fixture() +def registered_daily_job(): + """מוודא שה-job רשום עם ה-metadata שהבדיקה נשענת עליו.""" + from services.register_jobs import register_all_jobs + from services.job_registry import JobRegistry + + register_all_jobs() + job = JobRegistry().get("daily_morning_report") + assert job is not None, "ה-job חייב להיות רשום, אחרת הוא לא יופיע בדשבורד" + assert (job.metadata or {}).get("missed_after_hours") == 26 + return job + + +def test_missed_job_is_reported_once_and_a_recent_run_is_not(main_mod, registered_daily_job): + """שני הכיוונים: היעדר ריצה מדווח, וריצה טרייה לא. + + בלי הצד השני הבדיקה הייתה עוברת גם על קוד שמדווח על הכול תמיד. + """ + now = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + + silent = _AsyncDB(_AsyncJobRuns([])) + reported = asyncio.get_event_loop().run_until_complete( + main_mod._check_missed_scheduled_jobs(silent, now) + ) + assert "daily_morning_report" in reported + + recent = _AsyncDB( + _AsyncJobRuns( + [{"job_id": "daily_morning_report", "status": "completed", "started_at": now - timedelta(hours=3)}] + ) + ) + assert asyncio.get_event_loop().run_until_complete( + main_mod._check_missed_scheduled_jobs(recent, now) + ) == [] + + +def test_a_failed_run_still_counts_as_having_run(main_mod, registered_daily_job): + """כשל כבר מכוסה ב-``job_failed``; ``job_missed`` הוא על אי-התחלה בלבד.""" + now = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + db = _AsyncDB( + _AsyncJobRuns( + [{"job_id": "daily_morning_report", "status": "failed", "started_at": now - timedelta(hours=2)}] + ) + ) + assert asyncio.get_event_loop().run_until_complete( + main_mod._check_missed_scheduled_jobs(db, now) + ) == [] + + +def test_missed_job_is_not_reported_twice_in_the_same_day(main_mod, registered_daily_job): + """התראה אחת ליום — אחרת המנגנון מייצר רעש כל 60 שניות. + + מול הדמה המתוקנת, שזורקת ``DuplicateKeyError`` בהתנגשות כמו השרת, הבדיקה + הזו מבדילה בין "השער עובד" לבין "השער נכשל וה-``except`` הרחב בלע אותו". + """ + now = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + db = _AsyncDB(_AsyncJobRuns([])) + loop = asyncio.get_event_loop() + first = loop.run_until_complete(main_mod._check_missed_scheduled_jobs(db, now)) + second = loop.run_until_complete(main_mod._check_missed_scheduled_jobs(db, now)) + third = loop.run_until_complete(main_mod._check_missed_scheduled_jobs(db, now)) + assert first == ["daily_morning_report"] + assert second == [], "התנגשות מפתח ייחודי היא 'כבר דיווחנו', לא 'לא הצלחנו לבדוק'" + assert third == [] + + +def test_missed_check_uses_a_single_aggregate_not_a_loop(main_mod, registered_daily_job): + """הבדיקה רצה כל 60 שניות ואסור לה לייצר את בעיית הביצועים שהיא תופסת.""" + now = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + job_runs = _AsyncJobRuns([]) + asyncio.get_event_loop().run_until_complete( + main_mod._check_missed_scheduled_jobs(_AsyncDB(job_runs), now) + ) + assert job_runs.aggregate_calls == 1 + stages = [list(stage)[0] for stage in job_runs.last_pipeline] + assert stages == ["$match", "$group"] + + +def test_clock_skew_does_not_hide_a_real_run(main_mod, registered_daily_job): + """ריצה עם חותמת 'בעתיד' לא תיחשב כהיעדר ריצה.""" + now = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + db = _AsyncDB( + _AsyncJobRuns( + [{"job_id": "daily_morning_report", "status": "completed", "started_at": now + timedelta(minutes=5)}] + ) + ) + assert asyncio.get_event_loop().run_until_complete( + main_mod._check_missed_scheduled_jobs(db, now) + ) == [] + + +def test_missed_check_is_silent_when_nothing_declares_the_metadata(main_mod, registered_daily_job): + """המנגנון כללי ונשען על ``metadata``, ולא קשיח ל-job אחד. + + הפיקסצ'ר ``registered_daily_job`` חיוני כאן ולא קישוט: הוא זה שרושם את + ה-jobs. בלעדיו, כשהקובץ רץ לבדו, הרגיסטרי ריק — הלולאה שמנקה + ``missed_after_hours`` לא מוחקת כלום, והבדיקה עוברת בלי שבדקה דבר. + """ + from services.job_registry import JobRegistry + + registry = JobRegistry() + saved = {} + for job in registry.list_all(): + meta = getattr(job, "metadata", None) or {} + if meta.get("missed_after_hours"): + saved[job.job_id] = dict(meta) + job.metadata = {} + try: + job_runs = _AsyncJobRuns([]) + result = asyncio.get_event_loop().run_until_complete( + main_mod._check_missed_scheduled_jobs(_AsyncDB(job_runs), datetime(2026, 9, 7, 8, 0, tzinfo=UTC)) + ) + assert result == [] + assert job_runs.aggregate_calls == 0, "בלי job שמצהיר על ציפייה אין בכלל שאילתה" + finally: + for job_id, meta in saved.items(): + registry.get(job_id).metadata = meta + + +def test_missed_job_is_reported_again_on_a_new_day(main_mod, registered_daily_job): + """הצד השני: השער חוסם יום, לא לתמיד. + + בלי הטענה הזו, קוד שפשוט מפסיק לדווח לעד היה עובר את הבדיקה שמעל. + """ + db = _AsyncDB(_AsyncJobRuns([])) + loop = asyncio.get_event_loop() + day_one = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + day_two = datetime(2026, 9, 8, 8, 0, tzinfo=UTC) + assert loop.run_until_complete(main_mod._check_missed_scheduled_jobs(db, day_one)) == [ + "daily_morning_report" + ] + assert loop.run_until_complete(main_mod._check_missed_scheduled_jobs(db, day_two)) == [ + "daily_morning_report" + ] + + +def test_a_broken_gate_still_lets_the_alert_through(main_mod, registered_daily_job): + """כשל אחר בשער — fail-open, בכוונה. + + התראה שנעלמת גרועה מהתראה כפולה. זו המדיניות ההפוכה מזו של הדוח היומי, + ולכן היא נבדקת בנפרד: מי שיהפוך את ה-``except`` הרחב ל-``continue`` + יראה את הבדיקה הזו נופלת. + """ + now = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + reports = _AsyncAdminReports(raises=RuntimeError("mongo down")) + db = _AsyncDB(_AsyncJobRuns([]), admin_reports=reports) + result = asyncio.get_event_loop().run_until_complete( + main_mod._check_missed_scheduled_jobs(db, now) + ) + assert result == ["daily_morning_report"] + assert reports.calls == 1 + + +# -------------------------------------------------------------------------- +# שער האידמפוטנטיות של הדוח היומי +# -------------------------------------------------------------------------- + + +class _SyncAdminReports: + """דמה סינכרונית (pymongo), כי הדוח היומי רץ מול לקוח האפליקציה.""" + + def __init__(self, raises=None): + self.docs = {} + self.calls = 0 + self._raises = raises + + def update_one(self, query, update, upsert=False): # noqa: ARG002 + self.calls += 1 + if self._raises is not None: + raise self._raises + key = query["_id"] + blocked = query.get("day_key", {}).get("$ne") + existing = self.docs.get(key) + if existing is not None and existing.get("day_key") == blocked: + raise _duplicate_key_error() + self.docs[key] = dict(existing or {}, **update.get("$set", {})) + return type("R", (), {"modified_count": 0, "upserted_id": key})() + + +class _SyncDB: + def __init__(self, reports): + self._reports = reports + + def __getitem__(self, name): + assert name == "admin_reports" + return self._reports + + +def test_daily_report_claims_the_day_once(main_mod): + """התביעה הראשונה מצליחה, השנייה מזהה שהיום כבר נתפס.""" + now = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + db = _SyncDB(_SyncAdminReports()) + assert main_mod._claim_daily_report_day(db, "2026-09-07", now) == "claimed" + assert main_mod._claim_daily_report_day(db, "2026-09-07", now) == "already" + # יום חדש נתפס מחדש — אחרת הדוח היה נשלח פעם אחת ודי. + assert main_mod._claim_daily_report_day(db, "2026-09-08", now) == "claimed" + + +def test_daily_report_claim_fails_closed(main_mod): + """כשל בתביעה אינו 'claimed'. + + זו המדיניות ההפוכה מ-``job_missed``, ובכוונה: דוח כפול גרוע מדוח חסר. + """ + db = _SyncDB(_SyncAdminReports(raises=RuntimeError("mongo down"))) + assert main_mod._claim_daily_report_day(db, "2026-09-07", datetime(2026, 9, 7, tzinfo=UTC)) == "error" + + +def test_claim_outcome_reads_both_shapes_of_a_successful_write(main_mod): + """‏upsert מחזיר ``upserted_id``, עדכון מחזיר ``modified_count`` — שניהם תפיסה.""" + + def _res(modified=0, upserted=None): + return type("R", (), {"modified_count": modified, "upserted_id": upserted})() + + assert main_mod._claim_outcome(_res(upserted="x")) == "claimed" + assert main_mod._claim_outcome(_res(modified=1)) == "claimed" + assert main_mod._claim_outcome(_res()) == "already" + + +# -------------------------------------------------------------------------- +# שתי בדיקות המוניטור — עצמאיות +# -------------------------------------------------------------------------- + + +class _BrokenJobRuns(_AsyncJobRuns): + """‏``find`` נופל, ``aggregate`` תקין — בדיוק תרחיש הכשל החלקי.""" + + def find(self, *_a, **_k): + raise RuntimeError("find exploded") + + +def test_a_broken_stuck_check_does_not_silence_the_missed_check(main_mod, registered_daily_job, monkeypatch): + """הממצא: שתי הבדיקות חלקו גורל. + + ‏``job_stuck`` משתמש ב-``find`` ו-``job_missed`` ב-``aggregate``. עד + התיקון, יציאה מוקדמת או חריגה במסלול הראשון דילגה על השני לגמרי. + """ + import observability + + emitted = [] + monkeypatch.setattr(observability, "emit_event", lambda name, **kw: emitted.append((name, kw))) + + db = _AsyncDB(_BrokenJobRuns([])) + asyncio.get_event_loop().run_until_complete( + main_mod._jobs_monitor_tick(db, datetime(2026, 9, 7, 8, 0, tzinfo=UTC)) + ) + assert [name for name, _ in emitted] == ["job_missed"] + + +def test_a_collection_without_find_does_not_silence_the_missed_check(main_mod, registered_daily_job, monkeypatch): + """המסלול השני של אותו באג: יציאה מוקדמת, לא חריגה.""" + import observability + + emitted = [] + monkeypatch.setattr(observability, "emit_event", lambda name, **kw: emitted.append((name, kw))) + + class _NoFind(_AsyncJobRuns): + find = None + + db = _AsyncDB(_NoFind([])) + asyncio.get_event_loop().run_until_complete( + main_mod._jobs_monitor_tick(db, datetime(2026, 9, 7, 8, 0, tzinfo=UTC)) + ) + assert [name for name, _ in emitted] == ["job_missed"] + + +def test_the_missed_event_carries_the_declared_hours(main_mod, registered_daily_job, monkeypatch): + """האירוע נושא את ``missed_after_hours`` מה-metadata ולא מספר קשיח.""" + import observability + + emitted = [] + monkeypatch.setattr(observability, "emit_event", lambda name, **kw: emitted.append((name, kw))) + + db = _AsyncDB(_AsyncJobRuns([])) + asyncio.get_event_loop().run_until_complete( + main_mod._jobs_monitor_tick(db, datetime(2026, 9, 7, 8, 0, tzinfo=UTC)) + ) + assert emitted and emitted[0][0] == "job_missed" + assert emitted[0][1]["job_id"] == "daily_morning_report" + assert emitted[0][1]["hours"] == 26 + + +# -------------------------------------------------------------------------- +# מסלול השליחה המלא — שהשערים באמת נקראים, ולא רק קיימים +# -------------------------------------------------------------------------- + + +class _TrackerSpy: + def __init__(self): + self.logs = [] + self.skipped = None + self.failed = None + + def add_log(self, _run_id, level, message): + self.logs.append((level, message)) + + def skip_run(self, _run_id, reason): + self.skipped = reason + + def fail_run(self, _run_id, reason): + self.failed = reason + + +class _RunStub: + run_id = "r1" + + +@pytest.fixture() +def sending_report(main_mod, monkeypatch, deliverable_env): + """מרכיב מסלול שליחה מלא שבו רק שער היום עוד לא הוכרע. + + המקורות עצמם מוחלפים: מה שנבדק כאן הוא **החיווט** — האם הגוף באמת + קורא לשער לפני ``emit_internal_alert`` — ולא הלוגיקה של האיסוף, שיש לה + בדיקות משלה ב-``test_daily_report_service.py``. + """ + import internal_alerts + import services.daily_report_service as drs + + reports = _SyncAdminReports() + + class _DB: + def __getitem__(self, name): + if name == "admin_reports": + return reports + return object() + + sent = [] + monkeypatch.setattr(main_mod, "_daily_report_db", lambda: _DB()) + monkeypatch.setattr(main_mod, "_build_daily_report_deps", lambda _db: None) + monkeypatch.setattr(main_mod, "get_admin_ids", lambda: [1]) + monkeypatch.setattr(drs, "load_snapshot", lambda *_a, **_k: None) + monkeypatch.setattr(drs, "collect_snapshot", lambda **_k: {"_id": "d"}) + monkeypatch.setattr(drs, "save_snapshot", lambda *_a, **_k: {"_id": "d"}) + monkeypatch.setattr(drs, "compare", lambda *_a, **_k: drs.ReportDiff(day_label="07/09", sections=["alerts"])) + monkeypatch.setattr(drs, "render_report", lambda *_a, **_k: "📋 דוח") + monkeypatch.setattr(internal_alerts, "emit_internal_alert", lambda *a, **k: sent.append(k or a)) + monkeypatch.delenv("DISABLE_DAILY_REPORT", raising=False) + return sent, reports + + +def test_the_report_is_sent_once_a_day_even_across_restarts(main_mod, sending_report): + """הטענה שהריוויו לא כיסה, וזו שנשברה בפרודקשן בדוח השבועי. + + שתי הרצות באותו יום — כמו שקורה בכל עלייה מחדש של הבוט — שולחות פעם + אחת. מי שיסיר את השער מגוף ה-job יראה את הבדיקה הזו נופלת, ולא רק את + הבדיקה של הפונקציה העצמאית. + """ + sent, reports = sending_report + tracker_one, tracker_two = _TrackerSpy(), _TrackerSpy() + loop = asyncio.get_event_loop() + loop.run_until_complete(main_mod._daily_morning_report_body(tracker_one, _RunStub())) + loop.run_until_complete(main_mod._daily_morning_report_body(tracker_two, _RunStub())) + + assert len(sent) == 1, "הדוח נשלח פעמיים באותו יום — זה בדיוק מה שקרה לדוח השבועי" + assert tracker_one.skipped is None + assert tracker_two.skipped == "already_sent_today" + assert reports.calls == 2, "השער חייב להיקרא בשתי ההרצות, אחרת הוא לא באמת שער" + + +def test_a_failed_claim_blocks_the_send(main_mod, sending_report, monkeypatch): + """fail-closed לאורך כל המסלול, לא רק בפונקציה העצמאית.""" + sent, _reports = sending_report + monkeypatch.setattr(main_mod, "_claim_daily_report_day", lambda *_a: "error") + tracker = _TrackerSpy() + asyncio.get_event_loop().run_until_complete( + main_mod._daily_morning_report_body(tracker, _RunStub()) + ) + assert sent == [] + assert tracker.failed == "day_claim_failed" + + +def test_a_blocked_delivery_gate_never_reaches_the_day_claim(main_mod, sending_report, monkeypatch): + """סדר השערים: מסירה קודם, תפיסת היום אחריה. + + אילו התפיסה הייתה קודמת, יום שנחסם על סף החומרה היה "נשרף" — והרצה + חוזרת אחרי תיקון ההגדרות לא הייתה שולחת דבר. + """ + sent, reports = sending_report + monkeypatch.setenv("ALERT_TELEGRAM_MIN_SEVERITY", "critical") + tracker = _TrackerSpy() + asyncio.get_event_loop().run_until_complete( + main_mod._daily_morning_report_body(tracker, _RunStub()) + ) + assert sent == [] + assert tracker.failed == "telegram_gate:below_min_severity" + assert reports.calls == 0, "היום לא נתפס, ולכן הרצה חוזרת אחרי תיקון ההגדרות עדיין תוכל לשלוח" + + +def test_a_quiet_day_does_not_burn_the_day(main_mod, sending_report, monkeypatch): + """יום שקט אינו הודעה, ואינו תופס את היום. + + זו הסיבה שהשער יושב אחרי הרינדור: טריגר ידני מאוחר יותר, אחרי שכן קרה + משהו, חייב להיות מסוגל לשלוח. + """ + sent, reports = sending_report + import services.daily_report_service as drs + + monkeypatch.setattr(drs, "render_report", lambda *_a, **_k: None) + tracker = _TrackerSpy() + asyncio.get_event_loop().run_until_complete( + main_mod._daily_morning_report_body(tracker, _RunStub()) + ) + assert sent == [] + assert reports.calls == 0 + assert ("info", "nothing_to_report") in tracker.logs + assert tracker.skipped is None, "יום שקט הוא ריצה מוצלחת — הרשומה הזו היא מדד החיות של ה-job" + + +# -------------------------------------------------------------------------- +# job_stuck — רק מי שתפס את הרשומה מדווח +# -------------------------------------------------------------------------- + + +class _StuckCursor: + """מחקה את שרשרת ``find(...).sort(...).limit(...)`` של motor.""" + + def __init__(self, rows): + self._rows = rows + + def sort(self, *_a, **_k): + return self + + def limit(self, *_a, **_k): + return self + + async def to_list(self, length=None): # noqa: ARG002 + return list(self._rows) + + +class _StuckJobRuns: + """דמה של ``job_runs`` לבדיקת ה-stuck. + + ``modified`` הוא מה שה-``update_one`` המותנה יחזיר — כך נבדק ההבדל בין + "אני תפסתי את הדיווח" לבין "תהליך אחר הקדים אותי". + """ + + def __init__(self, rows, modified=1, raises=None): + self._rows = list(rows) + self._modified = modified + self._raises = raises + self.update_calls = [] + + def find(self, query, projection=None): # noqa: ARG002 + return _StuckCursor(self._rows) + + def aggregate(self, _pipeline): + return _AsyncCursor([]) + + async def update_one(self, query, update, upsert=False): # noqa: ARG002 + self.update_calls.append(query) + if self._raises is not None: + raise self._raises + return type("R", (), {"modified_count": self._modified, "upserted_id": None})() + + +def _stuck_row(now): + return { + "run_id": "run-1", + "job_id": "some_job", + "started_at": now - timedelta(minutes=90), + } + + +@pytest.fixture() +def stuck_events(monkeypatch): + import observability + + emitted = [] + monkeypatch.setattr(observability, "emit_event", lambda name, **kw: emitted.append((name, kw))) + return emitted + + +def test_only_the_process_that_marked_the_run_reports_it_stuck(main_mod, stuck_events): + """הממצא: תוצאת ה-``update_one`` המותנה נזרקה, וההתראה נפלטה בלי קשר. + + ה-``find`` וה-``update_one`` הם check-then-act קלאסי: שני תהליכים + (או שני סבבים שרצו במקביל) רואים את אותה הרצה ב-``find``, אבל רק + לאחד ``stuck_reported_at`` באמת נכתב. ``modified_count=0`` אצל השני + פירושו "מישהו אחר כבר דיווח" — וזה בדיוק מה שהופך את הסימון משדה + לוואי לשער אמיתי. + """ + now = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + coll = _StuckJobRuns([_stuck_row(now)], modified=0) + asyncio.get_event_loop().run_until_complete( + main_mod._emit_stuck_job_events(_AsyncDB(coll), now) + ) + assert coll.update_calls, "השער חייב להיקרא, אחרת אין מה לבדוק" + assert [name for name, _ in stuck_events] == [] + + +def test_the_process_that_won_the_mark_does_report(main_mod, stuck_events): + """הצד השני: מי שכן סימן — כן מדווח. + + בלי הטענה הזו, קוד שפשוט הפסיק לפלוט ``job_stuck`` לגמרי היה עובר את + הבדיקה שמעליה. + """ + now = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + coll = _StuckJobRuns([_stuck_row(now)], modified=1) + asyncio.get_event_loop().run_until_complete( + main_mod._emit_stuck_job_events(_AsyncDB(coll), now) + ) + assert [name for name, _ in stuck_events] == ["job_stuck"] + assert stuck_events[0][1]["job_id"] == "some_job" + assert stuck_events[0][1]["run_id"] == "run-1" + assert stuck_events[0][1]["minutes"] == 90 + + +def test_a_write_failure_does_not_silence_the_stuck_alert(main_mod, stuck_events): + """כשל כתיבה הוא לא "מישהו אחר דיווח". + + כשה-``update_one`` נופל אנחנו לא יודעים אם סימנו, והמדיניות כאן זהה + לזו של ``job_missed``: התראה שנעלמת גרועה מהתראה כפולה. הרצה תקועה + שאיש אינו יודע עליה היא בדיוק הכשל שהמנגנון נבנה כדי לתפוס. + """ + now = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) + coll = _StuckJobRuns([_stuck_row(now)], raises=RuntimeError("write failed")) + asyncio.get_event_loop().run_until_complete( + main_mod._emit_stuck_job_events(_AsyncDB(coll), now) + ) + assert [name for name, _ in stuck_events] == ["job_stuck"] diff --git a/tests/test_daily_report_service.py b/tests/test_daily_report_service.py new file mode 100644 index 000000000..85b40eec6 --- /dev/null +++ b/tests/test_daily_report_service.py @@ -0,0 +1,706 @@ +"""בדיקות ללוגיקה של דוח הבוקר היומי. + +כל בדיקה כאן נכתבה עם המוטציה שאמורה להפיל אותה, כי בדיקה שעוברת גם על הקוד +הקודם אינה ראיה לכיסוי. ביום שקט רוב הטענות מתקיימות טריוויאלית ("אין דפוס +חדש" נכון גם כשהקוד לא מסוגל לזהות דפוס חדש בכלל), ולכן כמעט לכל מקרה יש כאן +צד שני שמוודא שהבדיקה יודעת גם לומר "כן". + +הדמויות (סטאבים) הן מחלקות קטנות שכתובות ביד, כמוסכמת הריפו — אין mongomock. +זמן מוזרק כפרמטר ולא מוקפא, כי כל הפונקציות כאן מקבלות את החלון במפורש. +""" + +import copy +from datetime import datetime, timedelta, timezone + +import pytest + +import services.daily_report_service as drs + +UTC = timezone.utc +DAY_END = datetime(2026, 9, 7, 8, 0, tzinfo=UTC) +DAY_START = DAY_END - timedelta(days=1) +WINDOW = timedelta(minutes=5) + + +# -------------------------------------------------------------------------- +# דמויות +# -------------------------------------------------------------------------- + + +class FakeCollection: + """דמה של אוסף מונגו: מחזיקה רשימת מסמכים ומסננת אותה בפייתון. + + ``raises`` הופך אותה לאוסף שנופל — כך נבדק ההבדל בין "אין נתונים" לבין + "הקריאה נכשלה", שהוא כל העניין של :class:`~services.daily_report_service.SourceRead`. + """ + + def __init__(self, docs=None, raises=False): + self.docs = list(docs or []) + self.raises = raises + self.calls = {"find": 0, "aggregate": 0, "update_one": 0, "find_one": 0} + + # --- קריאה --- + def find(self, query, projection=None): # noqa: ARG002 + self.calls["find"] += 1 + if self.raises: + raise RuntimeError("boom") + return [d for d in self.docs if _matches(d, query)] + + def aggregate(self, pipeline): + self.calls["aggregate"] += 1 + if self.raises: + raise RuntimeError("boom") + match = next((s["$match"] for s in pipeline if "$match" in s), {}) + rows = [d for d in self.docs if _matches(d, match)] + # מספיק לדמות את הפייפליין של ה-endpoint האיטי: קיבוץ ובחירת המקסימום. + grouped = {} + for doc in rows: + key = (doc.get("path", "unknown"), doc.get("method", "UNKNOWN")) + entry = grouped.setdefault(key, {"count": 0, "max_duration": 0.0}) + entry["count"] += int(doc.get("count", 1) or 0) + entry["max_duration"] = max( + entry["max_duration"], float(doc.get("max_duration", 0.0) or 0.0) + ) + out = [ + {"_id": {"path": k[0], "method": k[1]}, "count": v["count"], "max_duration": v["max_duration"]} + for k, v in grouped.items() + ] + out.sort(key=lambda r: r["max_duration"], reverse=True) + return out[:1] + + def find_one(self, query): + self.calls["find_one"] += 1 + return next((copy.deepcopy(d) for d in self.docs if _matches(d, query)), None) + + # --- כתיבה --- + def update_one(self, query, update, upsert=False): + self.calls["update_one"] += 1 + existing = next((d for d in self.docs if _matches(d, query)), None) + if existing is not None: + existing.update(update.get("$set", {})) + return _Result(modified=1) + if upsert: + doc = {k: v for k, v in query.items() if not isinstance(v, dict)} + doc.update(update.get("$set", {})) + doc.update(update.get("$setOnInsert", {})) + self.docs.append(doc) + return _Result(upserted=doc.get("_id")) + return _Result() + + +class _Result: + def __init__(self, modified=0, upserted=None): + self.modified_count = modified + self.upserted_id = upserted + + +def _norm(value): + """מנרמל datetime כמו שמונגו עושה בפועל. + + ‏BSON שומר תאריכים כמילישניות UTC בלי אזור זמן, ולכן השרת האמיתי משווה + חותמת נאיבית לחותמת מודעת בלי למצמץ. דמה שמשווה ב-Python הייתה זורקת + ``TypeError`` — כשל של הדמה שנראה בדיוק כמו כשל של הקוד. + """ + if isinstance(value, datetime) and value.tzinfo is None: + return value.replace(tzinfo=UTC) + return value + + +def _matches(doc, query): + for key, cond in (query or {}).items(): + value = _norm(_dig(doc, key)) + if isinstance(cond, dict): + for op, operand in cond.items(): + operand = _norm(operand) + if op == "$gte" and not (value is not None and value >= operand): + return False + if op == "$lt" and not (value is not None and value < operand): + return False + if op == "$ne" and value == operand: + return False + if op == "$in" and value not in operand: + return False + elif value != cond: + return False + return True + + +def _dig(doc, dotted): + current = doc + for part in str(dotted).split("."): + if not isinstance(current, dict): + return None + current = current.get(part) + return current + + +class FakeDB: + def __init__(self, mapping=None, stats=None): + self._mapping = mapping or {} + self._stats = stats or {} + + def __getitem__(self, name): + return self._mapping.setdefault(name, FakeCollection()) + + def command(self, _cmd, name): + if name not in self._stats: + raise RuntimeError("no such collection") + return self._stats[name] + + +class FakeCacheStats: + def __init__(self, hits=0, misses=0, uptime=1000, enabled=True, error=""): + self.keyspace_hits = hits + self.keyspace_misses = misses + self.uptime_seconds = uptime + self.enabled = enabled + self.error = error + + +class FakeEndpointResult: + def __init__(self, rows=None, error_code="", has_more=False, last_refresh=""): + self.rows = list(rows or []) + self.error_code = error_code + self.has_more = has_more + self.last_refresh = last_refresh + + +def _alert(ts, *, severity="critical", name="High Error Rate", endpoint="", drill=False): + return { + "ts_dt": ts, + "name": name, + "severity": severity, + "endpoint": endpoint, + "details": {"is_drill": True} if drill else {}, + } + + +def _slow(ts, *, query_id="q1", collection="code_snippets", operation="find", withheld=None): + doc = { + "timestamp": ts, + "query_id": query_id, + "collection": collection, + "operation": operation, + "execution_time_ms": 1500.0, + } + if withheld: + doc["raw_withheld_reason"] = withheld + return doc + + +def _snapshot(day_key, **sources): + base = { + "_id": day_key, + "day_start_utc": DAY_START, + "day_end_utc": DAY_END, + "created_at": DAY_END, + "sources": {}, + } + base["sources"].update(sources) + return base + + +def _ok(**payload): + return dict({"ok": True, "error": ""}, **payload) + + +# -------------------------------------------------------------------------- +# 3 — ספירה, בלי חזרה על תוכן ההתראה +# -------------------------------------------------------------------------- + + +@pytest.mark.parametrize("count", [2, 3]) +def test_alert_counts_are_exact(count): + """הספירה היא הספירה. שני מקרים, כדי שהמספר לא יוכל להיות קבוע מקרי.""" + docs = [_alert(DAY_START + timedelta(hours=i + 1)) for i in range(count)] + coll = FakeCollection(docs) + read = drs.read_alerts(coll, start=DAY_START, end=DAY_END) + assert read.ok + assert read.value["critical"] == count + + diff = drs.compare(_snapshot("2026-09-06", alerts=read.to_doc()), None) + assert f"{count} CRITICAL" in drs.render_report(diff) + + +def test_alert_content_is_counted_not_repeated(): + """מה שכבר צעק בזמן אמת נספר, ולא נאמר שוב. + + חזרה על תוכן ההתראה היא הרעש שהורג דוחות כאלה, ולכן זו טענה שנאכפת + בבדיקה ולא רק בכוונה. + """ + coll = FakeCollection([_alert(DAY_START + timedelta(hours=2), endpoint="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/api/secret-path")]) + read = drs.read_alerts(coll, start=DAY_START, end=DAY_END) + text = drs.render_report(drs.compare(_snapshot("2026-09-06", alerts=read.to_doc()), None)) + assert "1 CRITICAL" in text + assert "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/api/secret-path" not in text + assert "High Error Rate" not in text + + +def test_drill_alerts_are_excluded(): + """התראת תרגול אינה אירוע — כמו בכל אגרגציה קיימת על האוסף הזה.""" + coll = FakeCollection([_alert(DAY_START + timedelta(hours=1), drill=True)]) + read = drs.read_alerts(coll, start=DAY_START, end=DAY_END) + assert read.value["critical"] == 0 + + +def test_report_itself_never_opens_a_correlation_window(): + """הדוח נרשם ל-alerts_log, ואסור לו להצליב מול עצמו.""" + coll = FakeCollection( + [_alert(DAY_START + timedelta(hours=1), severity="warn", name=drs.REPORT_ALERT_NAME)] + ) + read = drs.read_alerts(coll, start=DAY_START, end=DAY_END) + assert read.value["alert_windows"] == [] + + +# -------------------------------------------------------------------------- +# 4 — דפוס חדש, ושני הכיוונים +# -------------------------------------------------------------------------- + + +def test_new_pattern_is_flagged_and_known_pattern_is_not(): + """שני הכיוונים באותה בדיקה: 'חדש' חייב להיות מסוגל גם לומר 'לא חדש'.""" + ts = DAY_START + timedelta(hours=3) + coll = FakeCollection([_slow(ts, query_id="brand-new")]) + + fresh = drs.read_slow_queries( + coll, start=DAY_START, end=DAY_END, alert_windows=[], correlation_window=WINDOW, + known_query_ids=None, + ) + assert [p["query_id"] for p in fresh.value["new_patterns"]] == ["brand-new"] + + seen_before = drs.read_slow_queries( + coll, start=DAY_START, end=DAY_END, alert_windows=[], correlation_window=WINDOW, + known_query_ids={"brand-new": (DAY_START - timedelta(days=3)).isoformat()}, + ) + assert seen_before.value["new_patterns"] == [] + + +def test_analyzable_flag_follows_withheld_reason(): + """'ניתן לניתוח' אינו הבטחה גורפת — הוא נגזר מהרשומה עצמה.""" + ts = DAY_START + timedelta(hours=2) + plain = drs.read_slow_queries( + FakeCollection([_slow(ts, query_id="a")]), start=DAY_START, end=DAY_END, + alert_windows=[], correlation_window=WINDOW, + ) + withheld = drs.read_slow_queries( + FakeCollection([_slow(ts, query_id="b", withheld="owner_missing")]), + start=DAY_START, end=DAY_END, alert_windows=[], correlation_window=WINDOW, + ) + assert plain.value["new_patterns"][0]["analyzable"] is True + assert withheld.value["new_patterns"][0]["analyzable"] is False + + +# -------------------------------------------------------------------------- +# 5 — N+1 פר-דפוס, לא ממוצע +# -------------------------------------------------------------------------- + + +def test_pattern_spike_reported_but_spread_is_not(): + """‏40 חזרות של דפוס אחד הן ממצא; אותן 40 על שמונה דפוסים אינן. + + זה בדיוק ההבדל שיחס כולל (שאילתות חלקי דפוסים) היה ממסך. + """ + ts = DAY_START + timedelta(hours=4) + concentrated = FakeCollection([_slow(ts, query_id="hot") for _ in range(40)]) + spread = FakeCollection( + [_slow(ts, query_id=f"p{i % 8}") for i in range(40)] + ) + yesterday = _snapshot( + "2026-09-05", + profiler=_ok(top_pattern={"query_id": "hot", "count": 10}, known_query_ids={"hot": ts.isoformat()}), + ) + + def _diff(coll): + read = drs.read_slow_queries( + coll, start=DAY_START, end=DAY_END, alert_windows=[], correlation_window=WINDOW, + known_query_ids={"hot": ts.isoformat(), **{f"p{i}": ts.isoformat() for i in range(8)}}, + ) + return drs.compare(_snapshot("2026-09-06", profiler=read.to_doc()), yesterday) + + assert "N+1" in "\n".join(_diff(concentrated).lines) + assert "N+1" not in "\n".join(_diff(spread).lines) + + +# -------------------------------------------------------------------------- +# 6 + 17 — הצלבת חלונות, ושני הצדדים שלה +# -------------------------------------------------------------------------- + + +def test_correlation_links_inside_window_and_not_outside(): + """בדיקה שמסוגלת להיכשל: בלי הצד השני היא חסרת ערך.""" + alert_ts = DAY_START + timedelta(hours=5) + windows = [{"ts": alert_ts, "name": "HighLatency", "endpoint": "/x"}] + + near = drs.read_slow_queries( + FakeCollection([_slow(alert_ts + timedelta(minutes=2))]), + start=DAY_START, end=DAY_END, alert_windows=windows, correlation_window=WINDOW, + ) + far = drs.read_slow_queries( + FakeCollection([_slow(alert_ts + timedelta(minutes=20))]), + start=DAY_START, end=DAY_END, alert_windows=windows, correlation_window=WINDOW, + ) + + assert (near.value["slow_in_alert_windows"], near.value["slow_outside_alert_windows"]) == (1, 0) + assert (far.value["slow_in_alert_windows"], far.value["slow_outside_alert_windows"]) == (0, 1) + + +def test_correlation_treats_naive_timestamps_as_utc(): + """החוזה מפורש: חותמת נאיבית היא UTC, לא שעון מקומי. + + ``slow_queries_log`` נכתב ב-``datetime.utcnow()`` ולכן ההנחה נכונה היום. + הבדיקה קיימת כדי שהיא **תישבר ברעש** ביום שמישהו יחליף ל-``now()`` + המקומי, במקום שההצלבה תשתוק בשקט. + """ + alert_ts = datetime(2026, 9, 7, 10, 0, tzinfo=UTC) + windows = [{"ts": alert_ts, "name": "HighLatency", "endpoint": ""}] + start = datetime(2026, 9, 7, 0, 0, tzinfo=UTC) + end = datetime(2026, 9, 8, 0, 0, tzinfo=UTC) + + # 12:00 נאיבי = 12:00Z לפי החוזה, כלומר שעתיים אחרי ההתראה ← לא מקושר. + shifted = drs.read_slow_queries( + FakeCollection([_slow(datetime(2026, 9, 7, 12, 0))]), + start=start, end=end, alert_windows=windows, correlation_window=WINDOW, + ) + # 10:02 נאיבי = בתוך החלון ← כן מקושר. + aligned = drs.read_slow_queries( + FakeCollection([_slow(datetime(2026, 9, 7, 10, 2))]), + start=start, end=end, alert_windows=windows, correlation_window=WINDOW, + ) + assert shifted.value["slow_in_alert_windows"] == 0 + assert aligned.value["slow_in_alert_windows"] == 1 + + +def test_clock_skew_never_produces_negative_delta(): + """שאילתה שנכתבה 'לפני' ההתראה עדיין בתוך החלון, ולא נזרקת החוצה.""" + alert_ts = DAY_START + timedelta(hours=6) + read = drs.read_slow_queries( + FakeCollection([_slow(alert_ts - timedelta(minutes=2))]), + start=DAY_START, end=DAY_END, + alert_windows=[{"ts": alert_ts, "name": "x", "endpoint": ""}], + correlation_window=WINDOW, + ) + assert read.value["slow_in_alert_windows"] == 1 + + +# -------------------------------------------------------------------------- +# 16 — הכותב של slow_queries_log הוא UTC +# -------------------------------------------------------------------------- + + +def test_profiler_writer_uses_utc_not_local_time(monkeypatch): + """מוודא שהחותמת שנשמרת היא UTC ולא שעון מקומי. + + ההצלבה של הדוח נשענת על כך ש-``timestamp`` הנאיבי הוא UTC. ב-CI שרץ + ב-UTC אי אפשר להבדיל בין ``utcnow()`` ל-``now()``, ולכן הבדיקה **מזייפת + את השעון**: ``now()`` מחזיר UTC+2 ו-``utcnow()`` מחזיר UTC. מוטציה + שמחליפה את הקריאה בקוד הייצור מפילה את הבדיקה הזו. + """ + from services import query_profiler_service as qps + + real = qps.datetime + + class ShiftedClock(real): + @classmethod + def now(cls, tz=None): + return real(2026, 9, 7, 14, 0) # "מקומי" — UTC+2 + + @classmethod + def utcnow(cls): + return real(2026, 9, 7, 12, 0) # UTC + + monkeypatch.setattr(qps, "datetime", ShiftedClock) + + service = qps.QueryProfilerService(db_manager=None) + record = service.record_slow_query_sync( + collection="code_snippets", operation="find", query={"user_id": "1"}, + execution_time_ms=1500.0, + ) + assert record.timestamp == real(2026, 9, 7, 12, 0), ( + "הפרופיילר חייב לכתוב UTC; שעון מקומי היה מזיז את חלון ההצלבה בשעתיים" + ) + + +# -------------------------------------------------------------------------- +# 7 + 8 — בסיס להשוואה +# -------------------------------------------------------------------------- + + +def test_without_baseline_no_change_lines_and_with_baseline_there_are(): + """אין D-1 ← לא ממציאים שינוי. יש D-1 ← השינוי כן מדווח.""" + today = _snapshot( + "2026-09-06", + metrics=_ok(top_slow_endpoint={"endpoint": "/new", "method": "GET", "max_duration": 9.0, "count": 3}), + alerts=_ok(critical=1, error=0, deploy_count=0, alert_windows=[]), + ) + yesterday = _snapshot( + "2026-09-05", + metrics=_ok(top_slow_endpoint={"endpoint": "/old", "method": "GET", "max_duration": 4.0, "count": 2}), + ) + + without = drs.compare(today, None) + with_base = drs.compare(today, yesterday) + + assert not any("השתנה" in line for line in without.lines) + assert "אין בסיס להשוואה" in drs.render_report(without) + assert any("השתנה" in line for line in with_base.lines) + + +def test_previous_day_key_is_explicit_so_a_gap_is_not_silently_bridged(): + """‏D-1 מפורש: יום שה-job לא רץ בו לא יגרום להשוואה מול שלשום.""" + coll = FakeCollection([_snapshot("2026-09-04")]) + assert drs.previous_day_key("2026-09-06") == "2026-09-05" + assert drs.load_snapshot(coll, drs.previous_day_key("2026-09-06")) is None + + +# -------------------------------------------------------------------------- +# 9 — כשל קריאה אינו אפס +# -------------------------------------------------------------------------- + + +def test_failed_source_reports_no_data_and_never_a_change(): + """הממצא המרכזי: מקור שנפל חייב להיראות אחרת ממקור שהחזיר אפס. + + בלי זה הסנאפשוט נשמר עם אפס, ומחר הדוח מכריז על שיפור. + """ + read = drs.read_alerts(FakeCollection(raises=True), start=DAY_START, end=DAY_END) + assert read.ok is False and read.value is None + doc = read.to_doc() + assert doc["ok"] is False and "critical" not in doc + + today = _snapshot("2026-09-06", alerts=doc, jobs=_ok(failed=2, stuck=0, zero_items_jobs=[])) + text = drs.render_report(drs.compare(today, None)) + assert "אין נתון" in text + assert "ירד" not in text and "השתפר" not in text + # כשל של מקור אחד אינו משתיק את השאר. + assert "2 כשלים" in text + + +def test_zero_and_failure_are_distinguishable(): + """אפס אמיתי ← ``ok=True``; כשל ← ``ok=False``. זו כל ההבחנה.""" + empty = drs.read_alerts(FakeCollection([]), start=DAY_START, end=DAY_END) + broken = drs.read_alerts(FakeCollection(raises=True), start=DAY_START, end=DAY_END) + assert empty.ok and empty.value["critical"] == 0 + assert not broken.ok + + +def test_cache_error_is_a_failure_not_a_zero_hit_rate(): + """``get_cache_stats`` מחזיר ``hit_rate=0.0`` בכשל — האפס הזה אסור להישמר.""" + failing = drs.read_cache(lambda: FakeCacheStats(enabled=True, error="Connection refused")) + disabled = drs.read_cache(lambda: FakeCacheStats(enabled=False)) + healthy = drs.read_cache(lambda: FakeCacheStats(hits=90, misses=10)) + assert not failing.ok and not disabled.ok + assert healthy.ok and healthy.value["keyspace_hits"] == 90 + + +# -------------------------------------------------------------------------- +# 10 — אתחול של Redis +# -------------------------------------------------------------------------- + + +def test_redis_restart_reports_no_baseline_instead_of_fake_change(): + """``uptime`` שקטן מאתמול פירושו שהמונים אופסו — ואז ההפרש חסר משמעות.""" + today = _snapshot("2026-09-06", cache=_ok(keyspace_hits=50, keyspace_misses=5, uptime_seconds=100)) + yesterday = _snapshot("2026-09-05", cache=_ok(keyspace_hits=9000, keyspace_misses=1000, uptime_seconds=90000)) + lines = "\n".join(drs.compare(today, yesterday).lines) + assert "הופעל מחדש" in lines + assert "Hit Rate יומי" not in lines + + +def test_daily_hit_rate_is_derived_from_the_delta(): + """ה-Hit Rate המדווח הוא של היממה, לא הממוצע המצטבר מאז עליית Redis.""" + today = _snapshot("2026-09-06", cache=_ok(keyspace_hits=1500, keyspace_misses=1500, uptime_seconds=200000)) + yesterday = _snapshot("2026-09-05", cache=_ok(keyspace_hits=1000, keyspace_misses=0, uptime_seconds=100000)) + lines = "\n".join(drs.compare(today, yesterday).lines) + # ‏500 פגיעות מול 1500 החטאות ביממה = 25%, בזמן שהמצטבר הוא 50%. + assert "25.0%" in lines + + +# -------------------------------------------------------------------------- +# 13 + 18 — שמירת הסנאפשוט +# -------------------------------------------------------------------------- + + +def test_first_write_wins_and_the_stored_doc_is_returned(): + """שתי ריצות באותו יום: הראשונה מנצחת, והשנייה מקבלת אותה בחזרה. + + מוטציה שמחליפה ``$setOnInsert`` ב-``$set`` מפילה את הבדיקה — וזה בדיוק + התרחיש של טריגר ידני שרץ במקביל לריצה המתוזמנת. + """ + coll = FakeCollection() + first = drs.save_snapshot(coll, _snapshot("2026-09-06", alerts=_ok(critical=7))) + second = drs.save_snapshot(coll, _snapshot("2026-09-06", alerts=_ok(critical=99))) + assert first["sources"]["alerts"]["critical"] == 7 + assert second["sources"]["alerts"]["critical"] == 7 + assert len(coll.docs) == 1 + + +def test_save_snapshot_raises_when_nothing_was_persisted(): + """כשל שמירה נזרק ואינו נבלע: דוח בלי סנאפשוט הופך את מחר לשקר.""" + + class Silent(FakeCollection): + def update_one(self, *a, **k): # noqa: ARG002 + return _Result() + + def find_one(self, _query): + return None + + with pytest.raises(RuntimeError): + drs.save_snapshot(Silent(), _snapshot("2026-09-06")) + + +# -------------------------------------------------------------------------- +# 2 + 14 — יום שקט ואורך ההודעה +# -------------------------------------------------------------------------- + + +def test_quiet_day_renders_nothing_and_an_event_renders_something(): + """יום שקט אינו מייצר הודעה — אבל הרינדור כן יודע לייצר אחת.""" + quiet = drs.compare(_snapshot("2026-09-06", alerts=_ok(critical=0, error=0, deploy_count=0)), None) + noisy = drs.compare(_snapshot("2026-09-06", alerts=_ok(critical=1, error=0, deploy_count=0)), None) + assert drs.render_report(quiet) is None + assert drs.render_report(noisy) is not None + + +def test_long_report_is_trimmed_on_a_line_boundary(): + """הודעה ארוכה נחתכת ולא נכשלת מעל מגבלת Telegram.""" + diff = drs.ReportDiff(day_label="07/09", lines=[f"שורה מספר {i} " + "x" * 80 for i in range(200)]) + text = drs.render_report(diff) + assert len(text) <= drs.MAX_MESSAGE_CHARS + assert text.endswith("…") + + +def test_warnings_survive_the_trim_because_they_come_first(): + """אזהרת "אין נתון" חייבת לשרוד חיתוך של הודעה ארוכה. + + החיתוך מוריד מהסוף. כשהאזהרות ישבו אחרי השורות, הדבר הראשון שנפל היה + בדיוק המידע שאומר שהדוח **חלקי** — כלומר הודעה חתוכה נראתה כמו יום שבו + כל המקורות נקראו בהצלחה. זו טעות מסוכנת יותר מאשר לאבד שורת תוכן אחת. + """ + diff = drs.ReportDiff( + day_label="07/09", + lines=[f"שורה מספר {i} " + "x" * 80 for i in range(200)], + warnings=["⚠️ מקור slow_queries: אין נתון"], + ) + text = drs.render_report(diff) + assert len(text) <= drs.MAX_MESSAGE_CHARS + assert "⚠️ מקור slow_queries: אין נתון" in text + + +def test_warnings_stay_close_to_the_header_in_a_short_report(): + """גם בלי חיתוך: האזהרה מופיעה לפני שורות התוכן, לא בזנב ההודעה.""" + diff = drs.ReportDiff( + day_label="07/09", + lines=["🚨 התראות: 2 CRITICAL"], + warnings=["⚠️ מקור cache: אין נתון"], + ) + lines = drs.render_report(diff).split("\n") + assert lines.index("⚠️ מקור cache: אין נתון") < lines.index("🚨 התראות: 2 CRITICAL") + + +# -------------------------------------------------------------------------- +# זיכרון מתגלגל +# -------------------------------------------------------------------------- + + +def test_known_items_roll_forward_and_expire(): + """סט ה'כבר ראינו' מתגלגל, ונגזם כשהוא יוצא מהחלון. + + בלי הגזימה הרשימה תופחת בלי גבול; בלי הגלגול, דפוס שנעלם וחזר היה + מדווח כחדש פעמים רבות. + """ + now = DAY_END + fresh = (now - timedelta(days=2)).isoformat() + stale = (now - timedelta(days=drs.KNOWN_ITEMS_WINDOW_DAYS + 5)).isoformat() + merged = drs._roll_known({"old": stale, "kept": fresh}, {"new": now.isoformat()}, now=now) + assert set(merged) == {"kept", "new"} + + +def test_collstats_growth_line_needs_both_days(): + """קצב גדילה דורש שני צדדים; בלי אתמול אין שורה.""" + today = _snapshot("2026-09-06", collstats=_ok(per_collection={"job_runs": {"count": 1200, "size_bytes": 2048}})) + yesterday = _snapshot("2026-09-05", collstats=_ok(per_collection={"job_runs": {"count": 1000, "size_bytes": 1024}})) + assert not any("DB:" in line for line in drs.compare(today, None).lines) + assert any("+200" in line for line in drs.compare(today, yesterday).lines) + + +def test_collection_sizes_skip_missing_collections_without_failing(): + """אוסף שאינו קיים אינו כשל של המקור כולו.""" + db = FakeDB(stats={"job_runs": {"count": 5, "size": 100}}) + read = drs.read_collection_sizes(db, names=("job_runs", "does_not_exist")) + assert read.ok + assert set(read.value["per_collection"]) == {"job_runs"} + + +def test_mcp_new_error_type_needs_to_be_both_new_and_recent(): + """סוג שגיאה מדווח כחדש רק אם הוא גם ביממה וגם לא מוכר.""" + inside = (DAY_START + timedelta(hours=3)).isoformat() + outside = (DAY_START - timedelta(days=4)).isoformat() + + def runner(name, _limit=None): + if name == "ck_mcp_tool_failures": + return FakeEndpointResult( + rows=[ + {"error_type": "ValidationError", "failed_at": inside}, + {"error_type": "OldError", "failed_at": outside}, + ], + last_refresh="2026-09-07T07:55:00Z", + ) + return FakeEndpointResult(rows=[]) + + read = drs.read_mcp(runner, start=DAY_START, end=DAY_END, known_error_types={}) + assert read.value["new_error_types"] == ["ValidationError"] + + known = drs.read_mcp( + runner, start=DAY_START, end=DAY_END, known_error_types={"ValidationError": outside} + ) + assert known.value["new_error_types"] == [] + + +def test_mcp_endpoint_error_is_a_failure_not_an_empty_result(): + """``error_code`` מלא הוא כשל, גם כשהשורות ריקות — זה החוזה של השירות.""" + read = drs.read_mcp( + lambda *a, **k: FakeEndpointResult(error_code="unauthorized"), + start=DAY_START, end=DAY_END, + ) + assert not read.ok and read.error == "mcp:unauthorized" + + +def test_mcp_line_carries_the_posthog_refresh_stamp(): + """נתון ממטמון של PostHog לא יוצג תחת 'אתמול' בלי לומר מתי הוא נכון.""" + today = _snapshot( + "2026-09-06", + mcp=_ok(new_error_types=["ValidationError"], missing_capabilities_today=1, last_refresh="07:55"), + ) + line = next(line for line in drs.compare(today, None).lines if "MCP" in line) + assert "נכון ל-07:55" in line + + +def test_collect_snapshot_survives_a_failing_source(): + """כשל של מקור אחד אינו מפיל את האיסוף ואינו משתיק את השאר.""" + ts = DAY_START + timedelta(hours=2) + deps = drs.ReportDeps( + alerts_coll=FakeCollection(raises=True), + metrics_coll=FakeCollection([]), + slow_coll=FakeCollection([_slow(ts)]), + job_runs_coll=FakeCollection([{"started_at": ts, "job_id": "x", "status": "failed"}]), + db_for_collstats=FakeDB(stats={"job_runs": {"count": 1, "size": 10}}), + cache_stats_fn=lambda: FakeCacheStats(hits=1, misses=1), + mcp_run_endpoint_fn=lambda *a, **k: FakeEndpointResult(rows=[]), + ) + snap = drs.collect_snapshot( + day_key="2026-09-06", day_start_utc=DAY_START, day_end_utc=DAY_END, + deps=deps, previous=None, correlation_window=WINDOW, now=DAY_END, + ) + assert snap["sources"]["alerts"]["ok"] is False + assert snap["sources"]["jobs"]["ok"] is True + assert snap["sources"]["jobs"]["failed"] == 1 + assert "known_query_ids" in snap["sources"]["profiler"] + + +def test_jobs_zero_items_needs_two_consecutive_days(): + """ריצה אחת על אפס פריטים אינה ממצא; חזרה יומיים ברצף כן.""" + today = _snapshot("2026-09-06", jobs=_ok(failed=0, stuck=0, zero_items_jobs=["drive_reschedule"])) + yesterday_same = _snapshot("2026-09-05", jobs=_ok(failed=0, stuck=0, zero_items_jobs=["drive_reschedule"])) + yesterday_other = _snapshot("2026-09-05", jobs=_ok(failed=0, stuck=0, zero_items_jobs=[])) + assert any("אפס פריטים" in line for line in drs.compare(today, yesterday_same).lines) + assert not any("אפס פריטים" in line for line in drs.compare(today, yesterday_other).lines)