يعني إيه Logging؟

الموديل اتدرّب امبارح بالليل زي كل أسبوع…
والنهارده الصبح توقعاته كلها غلط. ومفيش ولا سطر يقولك ليه.

خليني أحكيلك القصة من الأول.

القصة #

عندك Model بيتوقع مين من العملاء هيلغي اشتراكه الشهر ده (Churn Prediction).
وعشان يفضل متحدّث، عامل Script بيشتغل لوحده كل نهاية أسبوع الساعة 2 بالليل:

• بيسحب داتا العملاء من الـAPI.
• بينضّفها ويجهّزها.
• بيدرّب الموديل من جديد.
• بيقيّم أداءه ويحفظه.
• والصبح التطبيق بيستخدم آخر نسخة.

شهور والدنيا تمام.

لحد النهارده الصبح، لما فريق المبيعات بعتلك:

الموديل بيقول إن نص العملاء هيمشوا الشهر ده! ده بجد؟

فتحت الجهاز.
الـScript كان بيعمل print() وهو شغال… بس محدش كان قاعد يتفرج. الكلام راح.

وقدامك أسئلة كتير:

• هو الـScript اشتغل أصلًا امبارح؟
• الداتا اللي جت من الـAPI كانت سليمة؟
• التدريب خلص، ولا وقع في النص والتطبيق شغال بنسخة قديمة؟
• الـF1 كانت كام؟
• وهل الموديل الجديد يستحق إنه يستبدل النسخة القديمة؟

ومفيش إجابة واضحة لأي سؤال فيهم.

تقدر تشغّل الـScript تاني وتتفرج؟
ممكن. بس داتا امبارح مش هي داتا النهارده، والمشكلة ممكن ما تظهرش تاني.

هنا بالظبط بييجي دور الـLogging.

يعني إيه Logging؟ #

إن البرنامج نفسه يسجّل الأحداث المهمة اللي بتحصل وهو شغال، ويحفظها في ملف أو مكان تاني، عشان تقدر ترجع لها بعدين.

الاسم جاي من الـLogbook بتاع السفن:
دفتر بيتسجّل فيه اللي حصل في الرحلة، وإمتى حصل.
ولو ظهرت مشكلة، تقدر ترجع للدفتر وتعرف إيه اللي حصل بدل ما تعتمد على الذاكرة والتخمين.

والفرق بينه وبين الـprint() بسيط:

• الـprint() بتعرضلك كلام على الشاشة وإنت بتشغّل البرنامج.
• الـLogging بيديك طريقة منظّمة لتسجيل الأحداث، مع الوقت ومستوى الأهمية ومصدر الرسالة، وحفظها عشان تراجعها حتى لو مكنتش موجود وقت التشغيل.

بعد أسبوعين: نفس المشكلة، بس المرة دي فيه Log #

قررت إن الـScript يسجّل Log في كل مرحلة مهمة.

وبعد أسبوعين، نفس الموقف اتكرر: التوقعات غريبة تاني.
بس المرة دي فتحت ملف الـLog ولقيت ده:

02:00:01 INFO     job: weekly retrain started02:00:04 INFO     data: fetched 48,210 customers from the API in 2.8 s02:00:04 WARNING  data: last_login is empty for 31% of rows (usual: under 1%)02:00:05 INFO     clean: dropped 14,950 rows with no last_login, 33,260 left02:00:05 DEBUG    train: params n_estimators=200, max_depth=8, random_state=4202:01:11 INFO     train: fitted in 66 s on 26,608 rows02:01:12 INFO     evaluate: f1=0.61 (last run: 0.78)02:01:12 WARNING  evaluate: f1 dropped by more than 0.05 since the last run02:01:13 INFO     model: saved model_2026_10_25.joblib02:01:13 INFO     job: finished in 72 s

نقرا الـLog سطر سطر #

١. الـScript اشتغل وخلص.

بدأ الساعة 2:00 وخلص في 72 ثانية.
يبقى الـJob اشتغل، ومفيش دليل هنا على إنه وقع أثناء التنفيذ.

٢. فيه مشكلة واضحة في الداتا.

الـAPI رجّع 48,210 عميل، لكن عمود last_login فاضي في 31% من الصفوف، والطبيعي أقل من 1%.
دي علامة تستحق التحقيق.

٣. التنضيف قلّل حجم الداتا بشكل كبير.

الـPipeline شال 14,950 صف، وبقى عندنا 33,260 صف بدل 48,210.
يعني خسرنا حوالي 31% من الداتا قبل التدريب.

٤. إعدادات التدريب مش باين إنها اتغيرت.

الـHyperparameters المسجّلة هي نفسها اللي كنا متوقعينها.
ده مش دليل قاطع إن كل حاجة في الكود سليمة، لكنه بيساعدنا نستبعد تغيير الإعدادات كسبب محتمل.

٥. أداء الموديل اتراجع بشكل واضح.

الـF1 نزل من 0.78 إلى 0.61.
والمقارنة دي تكون مفيدة فعلًا لما الـMetrics تتحسب بنفس الطريقة، ويفضل على Validation Set ثابتة بين الـRuns.

٦. الموديل السيئ اتحفظ رغم إن أداءه نزل!

يعني الـPipeline سجّلت المشكلة، لكنها ما منعتش الموديل الجديد من إنه يحل محل القديم.
ودي مشكلة تانية هنرجعلها في آخر المقال.

في دقيقتين بقى عندك دليل قوي إن المشكلة مرتبطة بالداتا أو بطريقة تجهيزها، بدل ما تضيّع وقتك في تغيير الموديل عشوائيًا.
ممكن يكون حصل تغيير في الـAPI، أو في مصدر الداتا، أو في مرحلة من مراحل الـPreprocessing.
لسه محتاج تتأكد من السبب، لكن بدل ما تخمّن، بقى عندك نقطة واضحة تبدأ منها.

وكمان عرفت إن فيه تحذير اتسجّل الساعة 2 بالليل.
لو كان فيه Alert مربوط بالتحذير ده، كان ممكن تعرف بالمشكلة قبل فريق المبيعات. 😅

إيه اللي في كل سطر؟ #

بص على السطر ده:

02:00:04 WARNING  data: last_login is empty for 31% of rows

• الوقت: إمتى حصل الحدث.
• الـLevel: قد إيه الحدث مهم.
• المصدر: أنهي جزء في الكود سجّل الرسالة، وهنا data.
• الرسالة: إيه اللي حصل، ومعاه أرقام تساعدك تفهم حجم المشكلة.

كل ما الرسالة كانت محددة وواضحة، كل ما كان تشخيص المشكلة أسهل.

الـLogging Levels #

مش كل حدث في البرنامج ليه نفس الأهمية.

• DEBUG: تفاصيل تساعدك وإنت بتدور على مشكلة، زي إعدادات التدريب أو تفاصيل الـPreprocessing.
• INFO: أحداث طبيعية ومهمة، زي عدد الصفوف اللي اتسحبت أو إن التدريب خلص.
• WARNING: حاجة غير متوقعة تستحق الانتباه، لكن البرنامج ممكن يكمل، زي زيادة نسبة القيم الناقصة أو انخفاض الـF1.
• ERROR: عملية فشلت، زي فشل الاتصال بالـAPI أو فشل حفظ الموديل. ومش شرط البرنامج كله يقف.
• CRITICAL: مشكلة خطيرة ممكن تمنع البرنامج من الاستمرار أو تخلي تشغيله غير آمن.

والحلو إنك تقدر تتحكم في مستوى التفاصيل اللي بتسجّلها.
مثلًا، تخلي التشغيل العادي يبدأ من INFO، ولما تحتاج تفاصيل أكتر تغيّر المستوى إلى DEBUG.

بس خد بالك: الـHandler هو الجزء اللي بيحدد السطور تروح فين (الشاشة أو الملف)، وكل Handler ليه Level خاص بيه.
فلو الملف مضبوط على INFO، سطور الـDEBUG مش هتوصله، حتى لو غيّرت الـLevel في الكود.

شكله في Python #

مش محتاج تثبّت حاجة: مكتبة logging موجودة في الـStandard Library.

أول حاجة، بتظبط الـLogging مرة واحدة في أول البرنامج: Handler للشاشة، وHandler للملف، وكل واحد بالـLevel بتاعه.

import logging
from pathlib import Path


def setup_logging(path="logs/retrain.log"):
    Path(path).parent.mkdir(exist_ok=True)
    formatter = logging.Formatter(
        "%(asctime)s %(levelname)-8s %(name)s: %(message)s", datefmt="%H:%M:%S"
    )

    console = logging.StreamHandler()  # the screen: INFO and up
    console.setLevel(logging.INFO)
    console.setFormatter(formatter)

    file = logging.FileHandler(path, encoding="utf-8")  # the file: everything
    file.setLevel(logging.DEBUG)
    file.setFormatter(formatter)

    root = logging.getLogger()
    root.setLevel(logging.DEBUG)
    root.addHandler(console)
    root.addHandler(file)

وبعدها، أي جزء في الكود بياخد Logger باسمه، ويسجّل بالـLevel المناسب:

logger = logging.getLogger("data")  # in a real project: logging.getLogger(__name__)


def check_data(df):
    logger.info("fetched %s customers", f"{len(df):,}")
    missing = df["last_login"].isna().mean()
    if missing > 0.01:
        logger.warning(
            "last_login is empty for %.0f%% of rows (usual: under 1%%)", missing * 100
        )

02:00:04 WARNING  data: last_login is empty for 31% of rows (usual: under 1%)

ولاحظ: أي سطر DEBUG هيتكتب في الملف بس، لأن Handler الشاشة مضبوط على INFO.

في كود الـML نسجّل إيه؟ #

بص على كل مرحلة واسأل نفسك:
لو حاجة باظت هنا، هحتاج أعرف إيه عشان أشخّص المشكلة؟

• الداتا: مصدرها، عدد الصفوف، أسماء الأعمدة، ونسبة القيم الناقصة، مع مقارنتها بالمعدلات المعتادة.
• التنضيف: كام صف اتشال، وليه، وكام صف فاضل.
• الـFeatures والـPreprocessing: الإعدادات والقرارات المهمة، زي طريقة التعامل مع القيم الناقصة.
• التدريب: الـHyperparameters، عدد صفوف التدريب، مدة التدريب، وأي تحذيرات مهمة من المكتبات.
• التقييم: الـMetrics، ومقارنتها بالـBaseline أو آخر Run، مع التأكد إن المقارنة عادلة.
• حفظ الموديل: اسم النسخة، مكان حفظها، وهل الحفظ نجح فعلًا.
• التوقعات: عدد الـRequests، ونسخة الموديل اللي ردّت عليها، ومعدل الأخطاء وزمن الاستجابة.

السطر اللي بيقول dropped 14,950 rows ممكن يبان مش مهم.
لكنه في القصة دي كان دليل أساسي لفهم المشكلة.

3 أخطاء بتحصل كتير #

١. رسالة من غير سياق

أول سطر مش بيقولك أي حاجة تقريبًا.
التاني بيقولك إيه اللي حصل، وحجم المشكلة مقارنة بالمعتاد.
اسأل نفسك: لو قريت السطر ده بعد شهر، هفهم منه إيه اللي حصل؟

٢. تسجيل Secrets أو بيانات العملاء

الـAPI Keys، وكلمات سر قواعد البيانات، والتوكنز، أو صفوف فيها أسماء وأرقام تليفونات.
ملفات الـLogs ممكن تتنسخ وتتشارك وتتخزن على سيرفرات مختلفة.
سجّل حقائق عن الداتا، زي عدد الصفوف ونسبة القيم الناقصة، بدل ما تسجّل الداتا نفسها.
وخلي بالك كمان من البيانات الحساسة اللي ممكن تظهر داخل رسائل الأخطاء.

٣. تسجّل كل حاجة

لو كل سطر في الكود عمل Log، الملف هيبقى مليان تفاصيل، والسطر المهم ممكن يضيع وسط آلاف السطور.
استخدم INFO للأحداث المهمة، وDEBUG للتفاصيل اللي تحتاجها وقت التحقيق.

الـLogging لوحده مش هيحمي التطبيق #

الـLogging عرّفنا إيه اللي حصل، بس ما منعش الموديل السيئ إنه يوصل للتطبيق.
الـF1 نزل من 0.78 إلى 0.61، ومع ذلك الموديل اتحفظ واستبدل القديم.

عشان كده، قبل ما أي موديل جديد يستبدل القديم، اعمل Quality Checks:

• الداتا سليمة وفي الحدود المتوقعة.
• الأداء على Validation Set ثابتة مش أقل من الـBaseline أو الحد الأدنى المقبول.
• لو الموديل فشل، وقّف النشر وخلّي النسخة القديمة شغالة.

كده هتكتشف المشكلة جوه الـPipeline نفسها، مش من فريق المبيعات الصبح.

الـLogging بيساعدك تعرف المشكلة.
والـQuality Checks بتمنعها توصل للمستخدمين.

لما الـRuns تكتر: MLflow #

بين التدريب الأسبوعي والتجارب اللي بتجربها بإعدادات مختلفة، هيبقى عندك عشرات الـRuns، وهتلاقي نفسك بتسأل:

• أنهي إعدادات طلّعت أحسن F1؟
• هل الموديل الجديد أحسن فعلًا من القديم؟
• أنهي نسخة نرجعلها لو حصلت مشكلة؟

هنا بييجي دور أدوات الـExperiment Tracking، وأشهرها MLflow.
بتسجّل لكل Run:

• الـParameters اللي استخدمتها.
• الـMetrics اللي حققتها.
• الـArtifacts، بما فيها ملفات الموديل.

وبعدها تقارن الـRuns جنب بعض، وتعرف كل نتيجة مرتبطة بأنهي إعدادات وتجربة.

وخلي بالك إن MLflow مش بديل عن الـLogging، ومش بديل عن الـMonitoring أو اختبارات الجودة. كل أداة ليها دور:

• Logging: البرنامج عمل إيه؟ وإيه اللي حصل أثناء التشغيل؟
• Experiment Tracking: أنهي تجربة حققت أفضل نتيجة؟ وبأي إعدادات؟
• Monitoring: هل النظام أو الداتا أو أداء الموديل اتغير بعد النشر؟

والتلاتة بيكمّلوا بعض في مشروع ML حقيقي.