أخطاء التسجيل الشائعة

مرحبا يا هبر!


أعتقد أن كل برنامج تقريبا لديه تسجيل. علاوة على ذلك ، في عدد من التطبيقات الجديدة بالفعل (والتي تعني بحرًا من الظروف غير التقليدية) ، غالبًا ما تصبح السجلات حيوية على خادم قتال.


ومع ذلك ، على الرغم من أهمية هذه التقنية وانتشارها ، لاحظت أن الناس غالباً ما يرتكبون أخطاء قياسية عند العمل معهم. توضح هذه المقالة سلوك .Net في كثير من النواحي ، ومع ذلك ، فقد أدخلت إدخالات صغيرة من عالم Java ، لمجرد المقارنة.


المخصصات (تخصيص الذاكرة)


الخطأ الأكثر شيوعًا (وفقًا لملاحظاتي) هو الإهمال بالنسبة لتخصيصات الذاكرة الصغيرة بالقرب من مكان الاستدعاء log.Debug(...) .


لذلك ، لدينا رمز القياسية في. صافي:


 private static readonly ILog Log4NetLog = LogManager.GetLogger(typeof(Program)); private static readonly Logger NLogLog = NLog.LogManager.GetCurrentClassLogger(); private static void PublishData(int id, string name, EMail email, decimal amount) { Log4NetLog.Debug($"Id={id}"); // 1 Log4NetLog.DebugFormat("Id={0}", id); // 2 Log4NetLog.Debug($"Id={id}; name={name}; email={email.Normalize()}; amount={amount}"); // 3 Log4NetLog.DebugFormat("Id={0}; name={1}; email={2}; amount={3}", id, name, email.Normalize(), amount); // 4 NLogLog.Debug($"Id={id}"); // 5 NLogLog.Debug("Id={0}", id); // 6 NLogLog.Debug($"Id={id}; name={name}; email={email.Normalize()}; amount={amount}"); // 7 NLogLog.Debug("Id={0}; name={1}; email={2}; amount={3}", id, name, email.Normalize(), amount); // 8 } 

في نواح كثيرة ، رأيت فقط مكتبات log4net و NLog ، وبالتالي سأستخدمها في الأمثلة.


لذا فإن الأسئلة هي:


  • في أي خطوط سيتم تخصيص الذاكرة حتى إذا تم إيقاف تشغيل Debug؟
  • إذا تم تخصيص الذاكرة ، ما مدى سهولة اكتشافها في نفس dotTrace التي يتحمل المسؤولون عنها على وجه التحديد مسؤولية تخصيص الذاكرة هذا؟

الإجابة الصحيحة على السؤال الأول: الذاكرة غير مخصصة فقط في الفقرة "6". والإجابة على السؤال الثاني: إنه أمر صعب للغاية ، لأنه يتم نشر هذه الشفرة في الغالب على المشروع. قد تتذكر تطبيق .Net نموذجي. غالباً ما يكون هناك كود مشابه يجعل GC تعمل.


ومع ذلك ، دعنا ننتقل إلى التفاصيل الفنية لنفهم بالضبط أين سيكون لنا تأثير على الأداء.


لذلك النقطة الأولى:


 Log4NetLog.Debug($"Id={id}"); // 1 

في الواقع ، سيقوم المحول البرمجي بتحويله إلى:


 var temp = string.Format("Id={0}", id); // <--       Log4NetLog.Debug(temp); 

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


المثال الثاني أكثر فعالية بعض الشيء ، نظرًا لعدم إنشاء سطر فيه:


 Log4NetLog.DebugFormat("Id={0}", id); 

ومع ذلك ، لا يزال يتم تخصيص الذاكرة هنا ، حيث ستحدث الملاكمة. اسمح لي بتذكيرك بتوقيع أسلوب DebugFormat:


 void DebugFormat(string format, object arg0) 

كما ترى ، فإن الإدخال يتطلب نوعًا مرجعيًا. ومع ذلك ، فنحن نحاول اجتياز نوع int ذي معنى. نتيجة لذلك ، سينتج عن كل استدعاء id معلمة كومة الذاكرة المؤقتة لتمريرها إلى الأسلوب. واسمحوا لي أن أذكركم بأن المعلمة نفسها ليست ضرورية في الطريقة نفسها ، حيث إن Debug متوقف عن العمل من خلال شرط المهمة.


المثال التالي هو تحميل وبسيط:


 Log4NetLog.Debug($"Id={id}; name={name}; email={email.Normalize()}; amount={amount}"); // 3 

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


 Log4NetLog.DebugFormat("Id={0}; name={1}; email={2}; amount={3}", id, name, email.Normalize(), amount); // 4 

ومع ذلك ، دعونا نحسب عدد المرات التي تحتاج فيها إلى تخصيص قطعة من الذاكرة:


  • email.Normalize() يؤدي إلى إنشاء نوع من الكائنات. لذلك ، سيتم تخصيص هذا الكائن على كومة الذاكرة المؤقتة (أو على المكدس - لا يهم ، لأن الملاكمة ستجعل من الضروري تحديد كل شيء على كومة الذاكرة المؤقتة)
  • سوف id يذهب إلى كومة ، كما اعتبرنا بالفعل في وقت سابق.
  • يحتوي Log4net على الواجهة التالية لمكالمات التنسيق الطويلة هذه: void DebugFormat(string format, params object[] args) . كما ترون ، ستقوم .Net بإنشاء صفيف على الكومة لتمريرها إلى أسلوب DebugFormat .

نتيجة لذلك ، فإن استدعاء نموذجي إلى حد ما لعملية تسجيل سيؤدي إلى كومة من الكائنات في الذاكرة. إنه أمر مخيب للآمال إلى حد ما ، لأن تسجيل الدخول نفسه غالبًا ما يكون مغلقًا. ومع ذلك ، دعنا ننتقل إلى NLog.


سوف يستفز هذا الخط تخصيص الكائن على الكومة:


 NLogLog.Debug($"Id={id}"); 

كل شيء واضح هنا ، لكن السطر أدناه لم يعد له عيب:


 NLogLog.Debug("Id={0}", id); 

والسبب هو أن NLog له توقيع خاص لـ ints: void Debug(string message, int argument) . علاوة على ذلك ، حتى إذا قمت بنقل بنية مختلفة ، void Debug<TArgument>([Localizable(false)] string message, TArgument argument) . وهذه الطريقة لا تتطلب الملاكمة ، لأنه بعد JIT سيتم إنشاء وظيفة منفصلة لكل نوع (بالطبع ، هذا ليس صحيحًا تمامًا ، ولكن النقطة المهمة هي: لن يكون هناك ملاكمة).


سوف أتخطى البرنامج النصي السهل الفهم بخط إدخال كبير وأذهب مباشرة إلى:


 NLogLog.Debug("Id={0}; name={1}; email={2}; amount={3}", id, name, email.Normalize(), amount); 

من الغريب أن NLog لم يزيد عدد المعلمات العامة للطرق ، وبالتالي سيتم استخدام التوقيع: void Debug([Localizable(false)] string message, params object[] args) . وسوف يؤدي مرة أخرى إلى إنشاء كائنات في أكوام وهلم جرا.


الاستنتاجات والتحسينات


الاستنتاج الرئيسي: إذا كان لديك الكثير من المكالمات إلى أساليب التسجيل في البرنامج والتي لا تؤدي إلى الكتابة الفعلية للملف ، فيمكنك الخروج من البداية لتخصيص الكثير من الكائنات غير الضرورية على الكومة. وبالتالي تثبيط عمل البرنامج.


الاستنتاج 2: إذا قمت بتمرير العديد من الكائنات إلى أسلوب ، استخدم NLog. نظرًا لحقيقة أنها اهتمت بالمعلمات Generic ، يمكنك أن تكون أكثر استرخاءًا بشأن الأداء.


ومع ذلك ، من أجل أن تكون آمنة تمامًا ، فمن المنطقي القيام بذلك:


 if (NLogLog.IsDebugEnabled) { NLogLog.Debug($"Id={id}; name={name}; email={email.Normalize()}; amount={amount}"); } 

هنا لن يتم استدعاء طريقة التسجيل إذا لم تكن ضرورية. ومع ذلك ، إذا كنت لا تزال بحاجة إلى تفريغ البيانات في السجل ، فسيتم استخدام Interpolation المريح في السلسلة. من الداخل ، تتمتع أدوات قطع الأشجار (على الأقل نفس NLog) بتحسينات لكتابة خط للسجلات مباشرة (على سبيل المثال ، سيحدث التنسيق فورًا في Stream ، بدلاً من إنشاء سطر في الذاكرة). ومع ذلك ، فإن هذا التحسين لـ NLog يتلاشى مع ضرورة إعادة تعيين البيانات إلى ملف.


مثال Kotlin


لتخفيف وصف عمل الحطابين المشهورين في .Net ، سأقدم طريقة مثيرة للاهتمام لتصفية المكالمات في kotlin. تستند الفكرة حرفيًا إلى ميزة واحدة مثيرة للاهتمام للغة: الطرق المضمنة . لذلك ، رمز بسيط لإخراج شيء لتصحيح:


 class SomeService{ private companion object : KLogging() fun publishData(id: Int){ logger.debug { "Identity: $id" } } } 

وسيتم تحويلها من قبل المترجم إلى شيء مثل هذا:


 class SomeService{ private companion object : KLogging() fun publishData(id: Int){ if(logger.isDebugEnabled){ try{ val message = "Identity: $id" logger.debug(message) }catch (e: Exception){ /*handle*/ } } } } 

من المهم هنا: كل شيء داخل الأقواس القريبة من debug هو لامدا. ومع ذلك ، سيتم تضمينه في طريقتك ، أي أنه لن يتم إنشاء كائن دالة في أكوام. وبالتالي ، يمكنك إخفاء العمليات الكبيرة في الداخل ، والتي لن يتم استدعاؤها إلا إذا كنت ترغب في إخراج النتيجة debug . على سبيل المثال:


 class SomeService{ private companion object : KLogging() fun publishData(id: Int){ logger.debug { val idList = getIdList() "Identity: $idList" } } } 

هنا سيتم استدعاء getIdList فقط إذا كنت بحاجة إلى إرسال شيء إلى الملف. وكل ذلك بسبب تحويل الرمز إلى:


 class SomeService{ private companion object : KLogging() fun publishData(id: Int){ if(logger.isDebugEnabled){ try{ val idList = getIdList() val message = "Identity: $idList" logger.debug(message) }catch (){ /*handle*/ } } logger.debug { "Identity: $id" } } } 

كائن كبير ==> كائن كبير كومة


بالإضافة إلى المثال السابق. أنا متأكد من أن الكثير من الناس يعرفون أن .Net / JVM لديه مفهوم "كومة كائن كبير". بتعبير أدق ، لا يوجد أي تعريف خاص في Java ، ومع ذلك ، فغالبًا ما ينشئ المُخصصون كائنات كبيرة على الفور في أحدث جيل (لتقليل حركة الكائنات وتقليل مشكلة الاختراق السريع للذاكرة لمخصص تدفق متدفق).


العودة إلى المثال:


 NLogLog.Debug($"Id={id}"); 

كما فهمت ، إذا كان كائن id له تطبيق ToString ، والذي ينشئ سلسلة بحجم ميغابايت ، ثم يضرب التالية في وجه LOH:


  • ToString استدعاء نفسها
  • تنسيق $"Id={id}"
  • وإذا لم يكتشف مطورو المسجل كل هذه الأشياء (وكان من الصعب للغاية كتابة اختبار لعدم وجود كائنات في LOH) ، فإن المسجل سيضيف مشاكل.

وهنا يمكنك استخدام ثلاث طرق لتسجيل مثل هذه الأشياء:


  • استخدم تصميمًا خاصًا ولا تحتاج إلى مكالمة ToString . على سبيل المثال ، يحتوي NLog على JsonLayout . وبالتالي ، يمكنك ببساطة نقل كائن إلى المسجل ، والذي سيتم تسلسله على الفور إلى الدفق الناتج (على سبيل المثال ، إلى ملف).
  • اكتب إلى الملف بنفسك. أو بعبارة أخرى - لا تستخدم المسجل. لا يمكنني تقديم النصح بمفردي عن كيفية معرفة أي ملف سيكتب NLog إلى: var filePath = NLog.LogManager.Configuration.AllTargets.OfType<FileTarget>().First().FileName.Render(LogEventInfo.CreateNullEvent()) . من الواضح أن هذه الوظيفة ستُرجع أول FileTarget الذي يظهر ، ولكن إذا قام الجميع بالكتابة إلى نفس المجلد ، بطريقة مماثلة ، يمكنك العثور على المجلد للتسجيل ، ثم إرسال تفريغ للكائن مباشرة إلى الملف.
  • إذا كان لديك log4j2 (الثاني مهم) ، فيمكنك استخدام StringBuilderFormattable . لقد تم إنشاؤه للتو من أجل إخراج البيانات إلى المسجل قطعًا (علاوة على ذلك ، حتى لا يتم تخصيص جزء من القطع في الكومة ، نظرًا لأنها محددة بالفعل).

 public interface StringBuilderFormattable { /** * Writes a text representation of this object into the specified {@code StringBuilder}, ideally without allocating * temporary objects. * * @param buffer the StringBuilder to write into */ void formatTo(StringBuilder buffer); } 

التزامن (ومشاكل عدم التزامن)


مرة واحدة ، في أحد البرامج ، لاحظت أنه أثناء العمليات المحملة ، تم حساب حوالي نصف وقت انتظار واجهة المستخدم من خلال عمليات التسجيل. مرة أخرى: تم إنفاق نصف وقت البرنامج على المكالمة لتسجيل logger.Debug أو شيء من هذا القبيل. والسبب في ذلك بسيط: استخدمنا log4net ، والذي يمكنه كتابة الملفات بشكل متزامن فقط.


من هنا استنتجت القاعدة 1 : يجب أن يعمل المسجل دائمًا في موضوع آخر. يجب عدم حظر رمز التطبيق من أجل التتبع ، لأنه غريب بشكل لا يصدق. بمعنى آخر - باستخدام NLog - يلزمك دائمًا وضع async=true في علامة nlog (وهي العلامة الرئيسية). أو كما يقول المثال :


 <targets async="true"> ... your targets go here ... </targets> 

إذا كنت تستخدم log4net ، فقم إما بإعادة التوجيه منه إلى NLog أو إنشاء AsyncFileAppender.


بالنسبة لعالم Java: يتمتع كل من Logback و Log4J2 بالقدرة على القيام بتسجيل غير متزامن. هنا مقارنة من الموقع الرسمي :


صور


ومع ذلك ، عندما يتم كتابة كل شيء بشكل غير متزامن ، تنشأ مشكلة أخرى - ما يجب القيام به في حالة وجود أخطاء فادحة؟ بعد كل شيء ، يحدث أن البرنامج لا يخرج لأنه ترك مؤشر الترابط Main (على سبيل المثال ، يمكن للبرنامج الخروج عن طريق استدعاء Application.Exit أو Environment.FailFast ، وهي ليست جميلة جدًا ، ولكنها تحدث بالفعل). في هذه الحالة ، يجب عليك دائمًا الاتصال بـ Flush قبل قتل العملية. وإلا ، إذا وقعت على خادم المعركة ، فستضيع المعلومات الأكثر قيمة.


استنتاج


آمل أن تساعدك هذه المقالة على كتابة برامج سريعة مع تسجيل مناسب. لقد أبرزت جزءًا فقط من المشكلات التي أراها جزءًا من الكود. كلهم ليسوا الأكثر وضوحًا ، لكن ليسوا الأكثر صعوبة.


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

Source: https://habr.com/ru/post/ar458436/


All Articles