جمع المعلومات السياقية لتسجيل الدخول

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

بيان المشكلة

افترض أن لدينا خدمة ASP.NET MVC We. يقبل طلبات POST التي تحتوي على وصف لما يجب فعله بتنسيق JSON. بعد تحليل مثل هذا الوصف ، تقوم الخدمة بإنشاء وتنفيذ العديد من استعلامات SQL لقاعدة البيانات. ثم يجمع النتائج ويرسلها إلى العميل.

يجب أن يقال أن هذه الخدمة تستفيد بشكل كبير من التزامن و multithreading من خلال async / ينتظر Task .

الآن بعد أن فهمنا ما نتعامل معه ، دعنا ننتقل إلى المشاكل.

جمع معلومات الخطأ السياقي

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

لا توجد مشكلة في تسجيل الاستثناء نفسه. يمكننا التقاطها في طريقة عمل وحدة التحكم الخاصة بنا:

 public class ServiceController : ApiController { [Route("api/service")] [HttpPost] public async Task<HttpResponseMessage> ServiceAction( [FromBody] RequestModel requestModel ) { try { ... } catch (Exception ex) { Logger.LogError(ex); throw; } } } 

أو يمكننا إنشاء سمة متخصصة لهذا:

 public class LogErrorAttribute : ActionFilterAttribute { public override void OnActionExecuted(HttpActionExecutedContext actionExecutedContext) { base.OnActionExecuted(actionExecutedContext); if (actionExecutedContext.Exception != null) { Logger.LogError(actionExecutedContext.Exception); } } } 

واستخدامها على طريقة العمل:

 [Route("api/service")] [HttpPost] [LogError] public async Task<HttpResponseMessage> ServiceAction( [FromBody] RequestModel requestModel ) { ... } 

لكننا بحاجة إلى المزيد. لكل خطأ ، نريد تخزين معلومات إضافية:

• نص نص JSON للطلب.
• نص جميع استعلامات SQL التي تم إنشاؤها.

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

ليس من الصعب القيام بذلك لنص الطلب:

 public class ServiceController : ApiController { [Route("api/service")] [HttpPost] public async Task<HttpResponseMessage> ServiceAction( [FromBody] RequestModel requestModel ) { var requestText = await Request.Content.ReadAsStringAsync(); try { ... } catch (Exception ex) { Logger.LogError(ex); Logger.LogError($"Request test is {requestText}"); throw; } } } 

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

أحد الخيارات هو استخدام قائمة الرسائل (مثل List<string> ). نقوم بإنشائه في أسلوب العمل الخاص بنا ( ServiceAction ) ونقوم ServiceAction إلى الطريقة التي تنشئ SQL. هناك سنضيف نص استعلام SQL إلى هذه القائمة. في حالة حدوث خطأ ، ستحتوي طريقة الإجراء على قائمة بالرسائل التي يجب وضعها في السجل.

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

إذا كنت تستخدم حاوية DI ويمكنك إنشاء فصولك منها ، فيمكنك محاولة وضع قائمة الرسائل في الحاوية بعمر "لكل طلب". ستقبل فئة إنشاء SQL قائمة الرسائل هذه كمعلمة مُنشئ. ثم سيتمكن كل من مثيل هذه الفئة ومثيل وحدة التحكم من الوصول إلى نفس مثيل قائمة الرسائل.

ولكن هناك طريقة أكثر ملاءمة لجمع المعلومات السياقية حتى إذا كنت لا تستخدم حاوية DI. سيكون من الجيد أن نتمكن من الوصول إلى قائمة الرسائل من خلال خاصية ثابتة:

 public static async Task<SqlDataReader> RunReaderAsync(this SqlCommand cmd) { var message = $"SQL Server query is: {cmd.CommandText}"; ErrorContext.Current.AttachMessage(message); ... } 

هناك مشكلة خطيرة هنا. يمكن أن تخدم خدمتنا في وقت واحد عدة طلبات. ويجب أن يكون لكل طلب من هذا النوع قائمة خاصة به من الرسائل. علاوة على ذلك ، عند معالجة طلب واحد ، يمكن أن تفرز الشفرة الخاصة بنا العديد من سلاسل الرسائل (على سبيل المثال ، باستخدام غير متزامن / انتظار ). ويجب أن يكون لجميع سلاسل الرسائل هذه حق الوصول إلى نفس قائمة الرسائل. كيف يمكن تنفيذ ذلك؟

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

دعونا نلقي نظرة على تطبيق فئة ErrorContext :

 public class ErrorContext { private static readonly object Lock = new object(); private static readonly AsyncLocal<ErrorContext> CurrentErrorContext = new AsyncLocal<ErrorContext>(); private readonly Lazy<ConcurrentBag<string>> _attachedMessages = new Lazy<ConcurrentBag<string>>(() => new ConcurrentBag<string>()); private ErrorContext() {} public static ErrorContext Current { get { lock (Lock) { var errorContext = CurrentErrorContext.Value; if (errorContext == null) { CurrentErrorContext.Value = errorContext = new ErrorContext(); } return errorContext; } } } public static ErrorContext CreateNewErrorContext() { lock (Lock) { var errorContext = new ErrorContext(); CurrentErrorContext.Value = errorContext; return errorContext; } } public void AttachMessage(string message) { if (!string.IsNullOrWhiteSpace(message)) { _attachedMessages.Value.Add(message); } } public IReadOnlyList<string> GetMessages() { return _attachedMessages.Value.ToArray(); } } 

يقوم الأسلوب CreateNewErrorContext بإنشاء قائمة رسائل جديدة فورًا CurrentErrorContext حقل CurrentErrorContext ، وهو من نوع AsyncLocal . يمكنك الوصول إلى القائمة الحالية في أي مكان في التعليمات البرمجية باستخدام الخاصية الثابتة Current . يضيف أسلوب AttachMessage رسالة جديدة إلى القائمة. يقوم بتخزين الرسائل في مثيل ConcurrentBag ، لأنه يمكن استدعاء هذه الطريقة من سلاسل رسائل متعددة في نفس الوقت. تقوم طريقة GetMessages بإرجاع جميع الرسائل المحفوظة ، بحيث يمكن كتابتها في السجل.

الآن يمكنك بسهولة تهيئة واستخدام ErrorContext داخل LogErrorAttribute :

 public class LogErrorAttribute : ActionFilterAttribute { public override void OnActionExecuting(HttpActionContext actionContext) { ErrorContext.CreateNewErrorContext(); base.OnActionExecuting(actionContext); } public override void OnActionExecuted(HttpActionExecutedContext actionExecutedContext) { base.OnActionExecuted(actionExecutedContext); if (actionExecutedContext.Exception != null) { foreach(var message in ErrorContext.Current.GetMessages()) { Logger.LogError(message); } Logger.LogError(actionExecutedContext.Exception); } } } 

في أي مكان في التعليمات البرمجية ، يمكنك إضافة رسالتك إلى سياق الخطأ الحالي على النحو التالي:

 ErrorContext.Current.AttachMessage(message); 

تسجيل الأداء

أحيانًا تكون خدمتي بطيئة. ليس لجميع الاستفسارات ، ولكن بالنسبة للبعض يستغرق وقتًا طويلاً لإكمالها. أود الاحتفاظ بمعلومات حول هذه الطلبات من أجل تحليلها لاحقًا. كيف يمكن تنفيذ ذلك ، وما هي المعلومات التي نحتاجها؟

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

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

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

كيف يمكن تحقيق ذلك؟ مرة أخرى ، باستخدام فئة AsyncLocal :

 public class Timer : IDisposable { private static readonly object Lock = new object(); private static readonly AsyncLocal<Timer> CurrentTimer = new AsyncLocal<Timer>(); private readonly Stopwatch _stopwatch = new Stopwatch(); private readonly Lazy<ConcurrentQueue<Timer>> _attachedTimers = new Lazy<ConcurrentQueue<Timer>>(() => new ConcurrentQueue<Timer>()); private readonly Lazy<ConcurrentQueue<string>> _attachedMessages = new Lazy<ConcurrentQueue<string>>(() => new ConcurrentQueue<string>()); private readonly string _description; private readonly TimeSpan? _threshold; private readonly Timer _previousCurrent; private bool _isDisposed; private bool _suspendLogging; private Timer(Timer previousCurrent, string description = null, TimeSpan? threshold = null) { _previousCurrent = previousCurrent; _description = description; _threshold = threshold; _stopwatch.Start(); } public static Timer Current { get { lock (Lock) { var timer = CurrentTimer.Value; if (timer == null) { CurrentTimer.Value = timer = new Timer(null); } return timer; } } } public static Timer SetCurrentTimer(string description, TimeSpan? threshold = null) { lock (Lock) { var currentTimer = CurrentTimer.Value; var timer = new Timer(currentTimer, description, threshold); CurrentTimer.Value = timer; currentTimer?._attachedTimers.Value.Enqueue(timer); return timer; } } public void AttachMessage(string message) { if (!string.IsNullOrWhiteSpace(message)) { _attachedMessages.Value.Enqueue(message); } } public void Dispose() { if (!_isDisposed) { _isDisposed = true; _stopwatch.Stop(); if (_attachedTimers.IsValueCreated) { foreach (var attachedTimer in _attachedTimers.Value) { attachedTimer.Dispose(); } } if (!_suspendLogging && _threshold.HasValue && _stopwatch.Elapsed > _threshold.Value) { Log(); } if (_previousCurrent != null) { CurrentTimer.Value = _previousCurrent; } } } private JObject Message { get { Dispose(); var message = new StringBuilder($"It took {_stopwatch.ElapsedMilliseconds} ms to execute {_description}."); if (_threshold.HasValue) { message.Append($" Duration threshold is {_threshold.Value.TotalMilliseconds} ms."); } var messageObj = new JObject { ["message"] = message.ToString(), }; if (_attachedTimers.IsValueCreated && _attachedTimers.Value.Any()) { messageObj["attachedTimers"] = new JArray(_attachedTimers.Value.Select(t => t.Message)); } if (_attachedMessages.IsValueCreated && _attachedMessages.Value.Any()) { messageObj["attachedMessages"] = new JArray(_attachedMessages.Value); } return messageObj; } } public void Log() { try { _suspendLogging = true; Dispose(); if (_stopwatch.Elapsed < _threshold) { Logger.LogDebug(Message.ToString()); } else { Logger.LogWarning(Message.ToString()); } } finally { _suspendLogging = false; } } } 

دعونا نرى كيف يعمل. ينشئ الأسلوب SetCurrentTimer وقت جديد. هنا يمكنك تحديد وصفه وحد وقت تشغيل اختياري.

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

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

 using (Timer.SetCurrentTimer("The whole block")) { ... using (Timer.SetCurrentTimer("Part 1")) { ... } ... using (Timer.SetCurrentTimer("Part 2")) { ... } ... } 

تتيح الخاصية Current الوصول إلى المؤقت الحالي. هذا مفيد إذا كنت تريد إضافة بعض الرسائل إليه:

 var message = $"SQL Server query is: {cmd.CommandText}"; Timer.Current.AttachMessage(message); 

هنا ، يتم تخزين الرسائل المرفقة والموقتات المتداخلة في مثيلات ConcurrentQueue ، حيث قد يكون ترتيبها مهمًا.

تقوم خاصية Message بإرجاع الرسائل التي تم جمعها في وحدة واحدة من التيار وجميع الموقتات المكدسة فيه. هنا أستخدم فئات JSON من مكتبة JSON.NET لتنظيم جميع الرسائل. ولكن في الواقع ليست مهمة جدا. يمكنك استخدام أي تنسيق.

يكتب أسلوب Log المعلومات المخزنة في المؤقت إلى السجل ، بغض النظر عما إذا تم تعيين حد وقت التشغيل أم لا. في الوقت نفسه ، لا يكتب أسلوب Dispose المعلومات إلى السجل إلا إذا تم تجاوز حد وقت التشغيل المحدد.

الآن يمكننا إنشاء سمة أخرى لطرق وحدات التحكم لدينا:

 public class TimerContextAttribute : ActionFilterAttribute { private readonly string _timerDescription; private readonly int _durationThresholdMs; private readonly AsyncLocal<Timer> _timer = new AsyncLocal<Timer>(); public TimerContextAttribute(string timerDescription, int durationThresholdMs) { if (string.IsNullOrWhiteSpace(timerDescription)) throw new ArgumentNullException(nameof(timerDescription)); _timerDescription = timerDescription; _durationThresholdMs = durationThresholdMs; } public override void OnActionExecuting(HttpActionContext actionContext) { _timer.Value = Timer.SetCurrentTimer(_timerDescription, TimeSpan.FromMilliseconds(_durationThresholdMs)); base.OnActionExecuting(actionContext); } public override void OnActionExecuted(HttpActionExecutedContext actionExecutedContext) { base.OnActionExecuted(actionExecutedContext); _timer.Value?.Dispose(); } } 

واستخدامها على طرق العمل مثل هذا:

 [Route("api/service")] [HttpPost] [TimerContext("For ServiceAction method", 3000)] public async Task<HttpResponseMessage> ServiceAction( [FromBody] RequestModel requestModel ) { ... } 

الخلاصة

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

آمل أن تكون المقالة مفيدة لتحسين نظام التسجيل في تطبيقاتك.