لماذا تتوقف السجلات عن كونها مفيدة في الأنظمة الحقيقية

باختصار: تعمل السجلات الأساسية بشكل جيد مع التدفقات البسيطة، ولكن بمجرد ظهور التزامن والتأخيرات والمستخدمين المتعددين، تتوقف عن سرد القصص الكاملة.

2025-10-19 22:55:56,577 INFO demo.DemoApplication بدء تشغيل DemoApplication باستخدام Java 24.0.1 مع PID 188600 (/home/john-doe/Projects/demo/target/classes بدأها john_doe في /home/john-doe/Projects/demo) 2025-10-19 22:55:56,581 INFO demo.DemoApplication لم يتم تعيين ملف تعريف نشط، والرجوع إلى ملف تعريف افتراضي واحد: "default" 2025-10-19 22:55:57,198 INFO o.s.boot.web.embedded.tomcat.TomcatWebServer تم تهيئة Tomcat على المنفذ 8080 (http) 2025-10-19 22:55:57,204 INFO org.apache.coyote.http11.Http11NioProtocol تهيئة ProtocolHandler ["http-nio-8080"] 2025-10-19 22:55:57,205 INFO org.apache.catalina.core.StandardService بدء الخدمة [Tomcat] 2025-10-19 22:55:57,205 INFO org.apache.catalina.core.StandardEngine بدء محرك Servlet: [Apache Tomcat/10.1.46] 2025-10-19 22:55:57,223 INFO o.a.c.c.ContainerBase.[Tomcat].[localhost].[/] تهيئة Spring embedded WebApplicationContext 2025-10-19 22:55:57,223 INFO o.s.b.w.s.c.ServletWebServerApplicationContext Root WebApplicationContext: اكتملت التهيئة في 589 ms 2025-10-19 22:55:57,426 INFO org.apache.coyote.http11.Http11NioProtocol بدء ProtocolHandler ["http-nio-8080"] 2025-10-19 22:55:57,431 INFO o.s.boot.web.embedded.tomcat.TomcatWebServer تم بدء Tomcat على المنفذ 8080 (http) مع مسار السياق '/' 2025-10-19 22:55:59,568 INFO o.s.boot.web.embedded.tomcat.GracefulShutdown بدء الإيقاف التدريجي. في انتظار اكتمال الطلبات النشطة 2025-10-19 22:55:59,571 INFO o.s.boot.web.embedded.tomcat.GracefulShutdown اكتمل الإيقاف التدريجي

بفضل مفهوم السجلات، أصبح من الأسهل فهم ما يجري في نظام قيد التشغيل – خاصةً عندما تبدأ المشكلات في الظهور.

يوضح المثال أعلاه بدء وإيقاف خدمة Spring Framework، وهو مشهد شائع جدًا في تطبيقات Java المؤسسية. غالبًا ما يُستخدم Logback كخلفية للتسجيل.

في هذا المقال، سنلقي نظرة أولاً على التسجيل في أبسط صوره، ثم نحسّن التكوين تدريجيًا في تطبيقنا. الهدف النهائي بسيط: حل يقلل الوقت اللازم لفهم ما حدث من خطأ.

على الرغم من أن الأمثلة تركز على Logback، إلا أن الأفكار ليست خاصة به. يمكن تحقيق نتائج مماثلة بغض النظر عن التقنية أو لغة البرمجة أو إطار العمل.

فهم الأساسيات

المشكلة الجوهرية التي ينبغي أن تساعد السجلات في حلها هي تحديد when و ما هو بالتحديد حدث.

لنلقِ نظرة أقرب على السجلات في تكوينها الأدنى:

2025-10-18 16:02:35,338 INFO demo.HelloPrinter Hello world 2025-10-18 16:02:35,838 INFO demo.HelloPrinter How are you 2025-10-18 16:02:36,339 INFO demo.HelloPrinter Good bye | | | | | | | +--- the message | | | | | +--- class name | | | +--- log level | +--- timestamp

يتم ضمان الترتيب الزمني بطريقتين.

أولاً، يُظهر الطابع الزمني ترتيب الأحداث. ثانيًا، بنية بيانات السجل نفسها تسمح فقط بإضافة إدخالات جديدة، مما يضمن أن قراءة السجلات من الأعلى إلى الأسفل تحافظ على التسلسل.

يميز 'مستوى السجل' بين السلوك المتوقع (DEBUG، INFO) والمشكلات المحتملة (WARN، ERROR). يخبرنا 'اسم الفئة' بمكان إنتاج السجل في الكود. 'الرسالة' هي نص مخصص أعده المطور.

لنتأكد من أن هذا يتطابق مع الكود:

package demo; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.stereotype.Component; @Component public class HelloPrinter { private static final Logger logger = LoggerFactory.getLogger(HelloPrinter.class); public void print() { logger.info("Hello world"); logger.info("How are you"); logger.info("Good bye"); } }

حتى الآن، كل شيء يتصرف تمامًا كما هو متوقع.

إعداد Logback (بسيط لكن كافٍ)

لإنتاج سجلات بهذا التنسيق باستخدام Logback، يُستخدم الإعداد التالي:

<configuration> <appender name="Console" class="ch.qos.logback.core.ConsoleAppender"> <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"> <pattern> %d{ISO8601} %highlight(%-5level) %yellow(%-48logger{48}) %msg %n%throwable </pattern> </encoder> </appender> <!-- root level="INFO" يعني أنني لا أرغب في رؤية DEBUG أو TRACE. بدون ذلك عند بدء تشغيل خادم Spring سنرى الكثير من سجلات DEBUG المتعلقة بالتفاصيل الداخلية لإطار عمل Spring --> <root level="INFO"> <appender-ref ref="Console"/> </root> </configuration>

العناصر الرئيسية:

  • الطابع الزمني،
  • مستوى السجل (عرض ثابت لسهولة القراءة)،
  • اسم الفئة / المسجل،
  • الرسالة،
  • تتبع المكدس الاختياري.
%d{ISO8601} %-5level %-48logger{48} %msg %n%throwable | | | | | | | | | | | +--- تتبع مكدس منسق | | | | | …في حال وجود استثناء | | | | | | | | | +--- سطر جديد لفصل سطر السجل | | | | | | | +--- الرسالة | | | | | +--- اسم الفئة / المسجل | | …يشير إلى موضع في الكود المصدري ينتج هذا السجل | | …بطول 48 حرفًا بالضبط، لسهولة القراءة | | | +--- مستوى السجل | …بطول 5 أحرف بالضبط | …ERROR هو 5 أحرف، لكن INFO هو 4 أحرف فقط | …ونريد الحفاظ على الاتساق | +--- الطابع الزمني

هذا الإعداد نظيف وقابل للقراءة ويعمل بشكل جيد –حتى تحدث الحياة الواقعية. 

❌ المشكلة: المستخدمون المتزامنون يشوّشون على القصة

الآن لنلقِ نظرة على سيناريو أكثر واقعية قليلًا.

ثلاثة مستخدمين يعدّلون الطلبات في الوقت نفسه. تُسجَّل الكمية وسعر الصنف والسعر الإجمالي في أماكن مختلفة:

2025-10-18 16:56:28,415 INFO demo.PrintingDemo سعر العنصر = 15 2025-10-18 16:56:28,465 INFO demo.PrintingDemo سعر العنصر = 36 2025-10-18 16:56:28,571 INFO demo.PrintingDemo العناصر في الطلب = [1] 2025-10-18 16:56:28,581 INFO demo.PrintingDemo سعر العنصر = 47 2025-10-18 16:56:28,611 INFO demo.PrintingDemo العناصر في الطلب = [5] 2025-10-18 16:56:28,640 INFO demo.PrintingDemo السعر الإجمالي = 75 2025-10-18 16:56:28,714 INFO demo.PrintingDemo السعر الإجمالي = 36 2025-10-18 16:56:28,715 INFO demo.PrintingDemo العناصر في الطلب = [3] 2025-10-18 16:56:28,746 INFO demo.PrintingDemo السعر الإجمالي = 141

في هذه المرحلة، لم تعد السجلات مفيدة. لا يمكننا تحديد:

  • أي الأحداث تنتمي إلى نفس الطلب،
  • ما إذا كانت الإجماليات تُحسب بشكل صحيح،
  • أو أي مستخدم أطلق أي تسلسل.

✅ الحل المُجرَّب: PID ومعرّف الخيط

إذا كنت تستخدم Spring Boot (الذي يعتمد افتراضيًا على Logback)، فإن الإعداد الافتراضي يتضمن بالفعل:

  • معرّف العملية (PID)،
  • معرّف سلسلة الرسائل.

لنجعلها صريحة في النمط:

%d{ISO8601} %-5level ${PID} [t=%thread] %-48logger{48} %msg %n%throwable | | | +--- معرف الخيط | …مع تحسين بصري بسيط | …سيبدو هكذا: [t=Thread-1] | +--- PID

يساعد PID في التمييز بين:

  • نسخ خدمات مختلفة،
  • عمليات إعادة التشغيل،
  • عمليات نشر متعددة النسخ.

يساعد معرف الخيط في إظهار:

  • الطلبات التي تُعالج بشكل متزامن،
  • أي مسارات التنفيذ تعمل بالتوازي.

مع هذا التغيير، يصبح اتباع السيناريو نفسه أسهل:

2025-10-18 17:02:51,199 INFO 151993 [t=Thread-2] demo.PrintingDemo Price of item = 63 2025-10-18 17:02:51,206 INFO 151993 [t=Thread-1] demo.PrintingDemo Price of item = 34 2025-10-18 17:02:51,223 INFO 153222 [t=Thread-1] demo.PrintingDemo Price of item = 58 2025-10-18 17:02:51,246 INFO 151993 [t=Thread-5] demo.PrintingDemo Price of item = 94 2025-10-18 17:02:51,331 INFO 151993 [t=Thread-2] demo.PrintingDemo Items in order = [1] 2025-10-18 17:02:51,354 INFO 151993 [t=Thread-2] demo.PrintingDemo Total price = 63 2025-10-18 17:02:51,355 INFO 153222 [t=Thread-1] demo.PrintingDemo Items in order = [4] 2025-10-18 17:02:51,355 INFO 151993 [t=Thread-4] demo.PrintingDemo Price of item = 68 2025-10-18 17:02:51,358 INFO 151993 [t=Thread-5] demo.PrintingDemo Items in order = [2] 2025-10-18 17:02:51,367 INFO 151993 [t=Thread-1] demo.PrintingDemo Items in order = [2] 2025-10-18 17:02:51,371 INFO 151993 [t=Thread-1] demo.PrintingDemo Total price = 68 2025-10-18 17:02:51,429 INFO 153222 [t=Thread-1] demo.PrintingDemo Total price = 232 2025-10-18 17:02:51,456 INFO 151993 [t=Thread-5] demo.PrintingDemo Total price = 188 2025-10-18 17:02:51,460 INFO 151993 [t=Thread-4] demo.PrintingDemo Items in order = [5] 2025-10-18 17:02:51,629 INFO 151993 [t=Thread-4] demo.PrintingDemo Total price = 340

من خلال التصفية حسب الخيط ومعرّف العملية (PID)، يمكننا أخيرًا إعادة بناء طلب واحد.

2025-10-18 17:02:51,206 INFO 151993 [t=Thread-1] demo.PrintingDemo Price of item = 34 2025-10-18 17:02:51,367 INFO 151993 [t=Thread-1] demo.PrintingDemo Items in order = [2] 2025-10-18 17:02:51,371 INFO 151993 [t=Thread-1] demo.PrintingDemo Total price = 68

❌ المشكلة: الوقت والنطاق يقوضان هذا النهج

هذا الحل يعمل فقط عندما نعرف بالضبط متى حدثت المشكلة.

في الأنظمة الحقيقية:

  • يبلغ المستخدمون عن مشكلات بعد ساعات،
  • تتم إعادة استخدام الخيوط،
  • تتداخل مئات من عمليات التنفيذ.

خذ بعين الاعتبار سجلات كهذه:

2025-10-19 18:29:53,428 INFO 169232 [t=Thread-2] demo.PrintingDemo سعر العنصر = 2 2025-10-19 18:29:53,467 INFO 169232 [t=Thread-3] demo.PrintingDemo سعر العنصر = 9 2025-10-19 18:29:53,484 INFO 169232 [t=Thread-1] demo.PrintingDemo سعر العنصر = 26 2025-10-19 18:29:53,493 INFO 169232 [t=Thread-2] demo.PrintingDemo العناصر في الطلب = [2] 2025-10-19 18:29:53,529 INFO 169232 [t=Thread-3] demo.PrintingDemo العناصر في الطلب = [5] 2025-10-19 18:29:53,545 INFO 169232 [t=Thread-1] demo.PrintingDemo العناصر في الطلب = [3] 2025-10-19 18:29:53,631 INFO 169232 [t=Thread-1] demo.PrintingDemo السعر الإجمالي = 78 2025-10-19 18:29:53,645 INFO 169232 [t=Thread-2] demo.PrintingDemo السعر الإجمالي = 4 2025-10-19 18:29:53,694 INFO 169232 [t=Thread-3] demo.PrintingDemo السعر الإجمالي = 45 2025-10-19 18:29:53,720 INFO 169232 [t=Thread-1] demo.PrintingDemo سعر العنصر = 26 2025-10-19 18:29:53,797 INFO 169232 [t=Thread-3] demo.PrintingDemo سعر العنصر = 27 2025-10-19 18:29:53,801 INFO 169232 [t=Thread-2] demo.PrintingDemo سعر العنصر = 89 2025-10-19 18:29:53,847 INFO 169232 [t=Thread-2] demo.PrintingDemo العناصر في الطلب = [5] 2025-10-19 18:29:53,895 INFO 169232 [t=Thread-1] demo.PrintingDemo العناصر في الطلب = [2] 2025-10-19 18:29:53,919 INFO 169232 [t=Thread-1] demo.PrintingDemo السعر الإجمالي = 52 2025-10-19 18:29:53,970 INFO 169232 [t=Thread-3] demo.PrintingDemo العناصر في الطلب = [2] 2025-10-19 18:29:53,990 INFO 169232 [t=Thread-2] demo.PrintingDemo السعر الإجمالي = 445 2025-10-19 18:29:54,057 INFO 169232 [t=Thread-1] demo.PrintingDemo سعر العنصر = 47 2025-10-19 18:29:54,109 INFO 169232 [t=Thread-1] demo.PrintingDemo العناصر في الطلب = [4] 2025-10-19 18:29:54,163 INFO 169232 [t=Thread-3] demo.PrintingDemo السعر الإجمالي = 54 2025-10-19 18:29:54,298 INFO 169232 [t=Thread-1] demo.PrintingDemo السعر الإجمالي = 188

حتى لو قمنا بالتصفية حسب معرّف الخيط = Thread-1…

2025-10-19 18:29:53,484 INFO 169232 [t=Thread-1] demo.PrintingDemo Price of item = 26 2025-10-19 18:29:53,545 INFO 169232 [t=Thread-1] demo.PrintingDemo Items in order = [3] 2025-10-19 18:29:53,631 INFO 169232 [t=Thread-1] demo.PrintingDemo Total price = 78 2025-10-19 18:29:53,720 INFO 169232 [t=Thread-1] demo.PrintingDemo Price of item = 26 2025-10-19 18:29:53,895 INFO 169232 [t=Thread-1] demo.PrintingDemo Items in order = [2] 2025-10-19 18:29:53,919 INFO 169232 [t=Thread-1] demo.PrintingDemo Total price = 52 2025-10-19 18:29:54,057 INFO 169232 [t=Thread-1] demo.PrintingDemo Price of item = 47 2025-10-19 18:29:54,109 INFO 169232 [t=Thread-1] demo.PrintingDemo Items in order = [4] 2025-10-19 18:29:54,298 INFO 169232 [t=Thread-1] demo.PrintingDemo Total price = 188

يتعامل نفس الخيط الآن مع عمليات تنفيذ متعددة وغير مترابطة. أصبحت التصفية حسب معرّف الخيط أو PID تنتج قصصاً مختلطة.

في هذه المرحلة، تصبح محاولة تجميع السجلات بفعالية بهذه الطريقة أمراً مملاً – مما يعني أننا نضيّع وقتاً ثميناً.

إلى أين يوصلنا هذا

في هذه المرحلة، السجلات صحيحة تقنياً، ومنسقة بشكل جيد، ولكنها لا تزال غير مكتملة. فهي تصف الأحداث، ولكن ليس التنفيذات. تخبرنا بما حدث — ولكن ليس إلى أي قصة تنتمي تلك الأحداث.

ما التالي

بدلاً من استخراج المزيد من المعنى من الخيوط والطوابع الزمنية، نحتاج إلى سجلات تتذكر السياق.

في الجزء التالي، سنتناول كيفية إرفاق سياق المستخدم بالسجلات دون تمرير المعرّفات عبر كل طريقة:

→ الجزء 2: سياق المستخدم دون الإخلال بتصميمك

ولاحقًا، عندما لا يوجد مستخدمون ولا تكفي الخيوط:

→ الجزء 3: معرفات الارتباط والتتبع الشامل من البداية إلى النهاية

arrow_circle_right جدول المحتويات

wiktor sztwiertnia

فيكتور شتفيرتنيا

مهندس برمجيات Java أول

مقالات ذات صلة