من ارتفاع زمن الانتقال إلى تصحيح Kernel باستخدام eBPF / BCC

صورة

يحتوي Linux على عدد كبير من أدوات وتطبيقات تصحيح أخطاء kernel. تؤثر معظمها بشكل سلبي على أداء التطبيق ولا يمكن استخدامها في الإنتاج.

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

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

Ceph بطيء


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


على عكس الأنظمة الأساسية الأخرى ، تم استخدام bcache و linux 4.15 kernel الجديد على هذا المضيف. تم استخدام مجموعة من هذا التكوين هنا لأول مرة. وفي ذلك الوقت كان من الواضح أن أي شيء من الناحية النظرية يمكن أن يكون أصل المشكلة.

التحقيق في المضيف


بادئ ذي بدء ، دعونا نرى ما يحدث داخل عملية ceph-osd. للقيام بذلك ، نستخدم perf و flamescope (المزيد حوله يمكن قراءته هنا ):


تخبرنا الصورة أن وظيفة fdatasync () قضت الكثير من الوقت في إرسال طلب إلى generic_make_request () . هذا يعني أن سبب المشكلات على الأرجح خارج مكان البرنامج الخفي نفسه. يمكن أن يكون إما نواة أو أقراص. أظهر إخراج iostat زمن انتقال عالٍ في معالجة الطلبات باستخدام أقراص bcache.

عند التحقق من المضيف ، وجدنا أن البرنامج الخفي systemd-udevd يستهلك كمية كبيرة من وقت وحدة المعالجة المركزية - حوالي 20٪ على عدة مراكز. هذا سلوك غريب ، لذلك تحتاج إلى معرفة السبب. نظرًا لأن Systemd-udevd يعمل مع uevents ، فقد قررنا أن ننظر إليهم من خلال شاشة udevadm . اتضح أنه تم إنشاء عدد كبير من أحداث التغيير لكل جهاز كتلة في النظام. هذا غير معتاد للغاية ، لذلك سوف تحتاج إلى معرفة ما يولد كل هذه الأحداث.

باستخدام مجموعة أدوات BCC


كما اكتشفنا بالفعل ، تقضي kernel (و daemon ceph في استدعاء النظام) الكثير من الوقت في generic_make_request () . دعنا نحاول قياس سرعة هذه الوظيفة. BCC لديها بالفعل فائدة كبيرة - funclatency . سنقوم بتتبع البرنامج الخفي بواسطة معرف المنتج الخاص به مع فاصل زمني بين مخرجات المعلومات من 1 ثانية وإخراج النتيجة بالمللي ثانية.


عادة ما تكون هذه الوظيفة سريعة. كل ما تفعله هو إرسال الطلب إلى قائمة انتظار برنامج تشغيل الجهاز.

Bcache هو جهاز معقد يتكون في الواقع من ثلاثة أقراص:

  • دعم الجهاز (القرص المؤقت) ، في هذه الحالة هو HDD بطيء.
  • جهاز التخزين المؤقت (قرص التخزين المؤقت) ، وهنا قسم واحد من جهاز NVMe ؛
  • bcache الجهاز الظاهري الذي يعمل به التطبيق.

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

نحن نعلم الآن أن الاحمرار يسبب مشاكل. العثور على ما يسبب جيلهم بالضبط ليس بهذه البساطة. افترض أن هذا هو نوع من البرامج التي يتم تشغيلها بشكل دوري. دعونا نرى أي نوع من البرامج يتم تشغيله على النظام باستخدام البرنامج النصي execsnoop من نفس مجموعة أدوات BCC المساعدة . تشغيله وتوجيه الإخراج إلى ملف.

على سبيل المثال ، مثل هذا:

/usr/share/bcc/tools/execsnoop | tee ./execdump 

لن نعطي الناتج الكامل لـ execsnoop هنا ، ولكن يبدو أن أحد أوجه الاهتمام بالنسبة لنا كما يلي:

 sh 1764905 5802 0 sudo arcconf getconfig 1 AD | grep Temperature | awk -F '[:/]' '{print $2}' | sed 's/^ \([0-9]*\) C.*/\1/' 

العمود الثالث هو PPID (أصل PID) للعملية. تحولت العملية مع PID 5802 إلى واحدة من خيوط نظام المراقبة لدينا. عند التحقق من تكوين نظام المراقبة ، تم العثور على معلمات خاطئة. تم أخذ درجة حرارة محول HBA مرة واحدة كل 30 ثانية ، وهو أكثر بكثير من اللازم. بعد تغيير الفاصل الزمني للتحقق إلى فترة أطول ، وجدنا أن التأخير في معالجة الطلبات على هذا المضيف قد توقف عن الظهور من بقية المضيفين.

لكن ما زال من غير الواضح سبب بطء جهاز bcache. قمنا بإعداد منصة اختبار بتكوين مماثل وحاولنا إعادة إنتاج المشكلة عن طريق تشغيل fio على bcache ، وبدء تشغيل مشغل udevadm دوريًا لإنشاء موجات.

كتابة الأدوات المستندة إلى BCC


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

الخطة بسيطة:

  • تسجيل kprobe إلى generic_make_request () :
    • نحفظ اسم القرص يمكن الوصول إليها من خلال وسيطة وظيفة.
    • حفظ الطابع الزمني.

  • سجل kretprobe للعودة من generic_make_request () :
    • الحصول على الطابع الزمني الحالي.
    • نحن نبحث عن الطابع الزمني المحفوظ ومقارنته مع الحالي ؛
    • إذا كانت النتيجة أكبر من النتيجة المحددة ، فسنجد اسم القرص المحفوظ ونعرضه على الجهاز الطرفي.

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

يبدو النص eBPF داخل البرنامج النصي بيثون كما يلي:

 bpf_text = “”” # Here will be the bpf program code “”” 

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

 struct data_t { u64 pid; u64 ts; char comm[TASK_COMM_LEN]; u64 lat; char disk[DISK_NAME_LEN]; }; BPF_HASH(p, u64, struct data_t); BPF_PERF_OUTPUT(events); 

نحن هنا نسجل جدول تجزئة يسمى p ، مع مفتاح من النوع u64 وقيمة type struct data_t . سيكون الجدول متاحًا في سياق برنامج BPF الخاص بنا. يسجل الماكرو BPF_PERF_OUTPUT جدولًا آخر يسمى الأحداث ، والذي يتم استخدامه لنقل البيانات إلى مساحة المستخدم.

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

بعد ذلك ، نحتاج إلى كتابة الكود الذي سيتم تشغيله عند استدعاء الوظيفة قيد التحقيق:

 void start(struct pt_regs *ctx, struct bio *bio) { u64 pid = bpf_get_current_pid_tgid(); struct data_t data = {}; u64 ts = bpf_ktime_get_ns(); data.pid = pid; data.ts = ts; bpf_probe_read_str(&data.disk, sizeof(data.disk), (void*)bio->bi_disk->disk_name); p.update(&pid, &data); } 

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

سيتم استدعاء الوظيفة التالية عند الرجوع من generic_make_request () :

 void stop(struct pt_regs *ctx) { u64 pid = bpf_get_current_pid_tgid(); u64 ts = bpf_ktime_get_ns(); struct data_t* data = p.lookup(&pid); if (data != 0 && data->ts > 0) { bpf_get_current_comm(&data->comm, sizeof(data->comm)); data->lat = (ts - data->ts)/1000; if (data->lat > MIN_US) { FACTOR data->pid >>= 32; events.perf_submit(ctx, data, sizeof(struct data_t)); } p.delete(&pid); } } 

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

هناك حاجة إلى التحول الثنائي الذي نستخدمه هنا للحصول على مؤشر ترابط دائرة المخابرات العامة. أي معرف العملية الخاص بالعملية الرئيسية التي بدأت الخيط في السياق الذي نعمل فيه. تقوم دالة bpf_get_current_pid_tgid () التي ندعوها بإرجاع كل من GID لمؤشر الترابط و PID الخاص به بقيمة واحدة 64 بت.

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

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

 bpf_text = bpf_text.replace('MIN_US',str(min_usec)) if args.milliseconds: bpf_text = bpf_text.replace('FACTOR','data->lat /= 1000;') label = "msec" else: bpf_text = bpf_text.replace('FACTOR','') label = "usec" 

نحتاج الآن إلى إعداد برنامج BPF من خلال ماكرو BPF وتسجيل العينات:

 b = BPF(text=bpf_text) b.attach_kprobe(event="generic_make_request",fn_name="start") b.attach_kretprobe(event="generic_make_request",fn_name="stop") 

سيتعين علينا أيضًا تحديد struct data_t في نصنا ، وإلا فلن نتمكن من قراءة أي شيء:

 TASK_COMM_LEN = 16 # linux/sched.h DISK_NAME_LEN = 32 # linux/genhd.h class Data(ct.Structure): _fields_ = [("pid", ct.c_ulonglong), ("ts", ct.c_ulonglong), ("comm", ct.c_char * TASK_COMM_LEN), ("lat", ct.c_ulonglong), ("disk",ct.c_char * DISK_NAME_LEN)] 

الخطوة الأخيرة هي إخراج البيانات إلى المحطة:

 def print_event(cpu, data, size): global start event = ct.cast(data, ct.POINTER(Data)).contents if start == 0: start = event.ts time_s = (float(event.ts - start)) / 1000000000 print("%-18.9f %-16s %-6d %-1s %s %s" % (time_s, event.comm, event.pid, event.lat, label, event.disk)) b["events"].open_perf_buffer(print_event) # format output start = 0 while 1: try: b.perf_buffer_poll() except KeyboardInterrupt: exit() 

البرنامج النصي نفسه متاح على جيثب . دعونا نحاول تشغيله على منصة اختبار حيث تتم كتابة fio في bcache واستدعاء شاشة udevadm:


وأخيرا! الآن نرى أن ما يشبه جهاز bcache الكبح هو في الواقع مكالمة كبح إلى generic_make_request () على محرك أقراص مخبأ .

حفر في النواة


ما الذي يبطئ بالضبط أثناء إرسال الطلب؟ نرى أن التأخير يحدث حتى قبل بدء محاسبة الطلب ، أي لم يبدأ بعد حساب طلب محدد لمزيد من الإحصاءات حوله (/ proc / diskstats أو iostat). يمكن التحقق من ذلك بسهولة عن طريق تشغيل iostat أثناء إعادة إنتاج المشكلة ، أو البرنامج النصي biolatency BCC ، الذي يستند إلى بداية ونهاية محاسبة الطلبات. لن تظهر أي من هذه الأدوات المساعدة مشاكل للاستعلامات إلى محرك الأقراص المخزن مؤقتاً.

إذا ألقينا نظرة على الدالة generic_make_request () ، فسنرى أنه يتم استدعاء وظيفتين أخريين قبل تسجيل الطلب. أول واحد ، generic_make_request_checks () ، يتحقق من شرعية طلب إعدادات القرص. والثاني هو blk_queue_enter () ، الذي لديه دعوة مثيرة للاهتمام wait_event_interruptible () :

 ret = wait_event_interruptible(q->mq_freeze_wq, (atomic_read(&q->mq_freeze_depth) == 0 && (preempt || !blk_queue_preempt_only(q))) || blk_queue_dying(q)); 

في ذلك ، نواة ينتظر إزالة الجليد من قائمة الانتظار. نقيس التأخير blk_queue_enter () :

 ~# /usr/share/bcc/tools/funclatency blk_queue_enter -i 1 -m Tracing 1 functions for "blk_queue_enter"... Hit Ctrl-C to end. msecs : count distribution 0 -> 1 : 341 |****************************************| msecs : count distribution 0 -> 1 : 316 |****************************************| msecs : count distribution 0 -> 1 : 255 |****************************************| 2 -> 3 : 0 | | 4 -> 7 : 0 | | 8 -> 15 : 1 | | 

يبدو أننا قريبون من الحل. الوظائف المستخدمة "لتجميد / إلغاء تجميد" قائمة الانتظار هي blk_mq_freeze_queue و blk_mq_unfreeze_queue . يتم استخدامها عند الضرورة لتغيير إعدادات قائمة انتظار الاستعلام ، والتي من المحتمل أن تكون خطرة بالنسبة للاستعلامات في قائمة الانتظار هذه. عندما يتم استدعاء blk_mq_freeze_queue () ، فإن الدالة blk_freeze_queue_start () تزيد العداد q-> mq_freeze_depth . بعد ذلك ، تنتظر النواة إفراغ قائمة الانتظار في blk_mq_freeze_queue_wait () .

يعادل وقت الانتظار لمسح قائمة الانتظار هذه زمن انتقال القرص ، نظرًا لأن kernel ينتظر أن تكتمل جميع عمليات الانتظار. بمجرد أن تكون قائمة الانتظار فارغة ، يتم تطبيق التغييرات على الإعدادات. ثم يتم استدعاء blk_mq_unfreeze_queue () ، مما يقلل من عداد freeze_depth .

الآن نحن نعرف ما يكفي لتصحيح الوضع. ينتج عن الأمر udevadm trigger تطبيق الإعدادات لجهاز الكتلة. هذه الإعدادات موصوفة في قواعد udev. يمكننا أن نعرف بالضبط أي الإعدادات "تجميد" قائمة الانتظار من خلال محاولة تغييرها من خلال sysfs أو من خلال النظر في شفرة المصدر kernel. يمكننا أيضًا تجربة الأداة المساعدة BCC trace ، التي تعرض مكدس kernel وتتبع مساحة المستخدم للمحطة لكل مكالمة blk_freeze_queue ، على سبيل المثال:

 ~# /usr/share/bcc/tools/trace blk_freeze_queue -K -U PID TID COMM FUNC 3809642 3809642 systemd-udevd blk_freeze_queue blk_freeze_queue+0x1 [kernel] elevator_switch+0x29 [kernel] elv_iosched_store+0x197 [kernel] queue_attr_store+0x5c [kernel] sysfs_kf_write+0x3c [kernel] kernfs_fop_write+0x125 [kernel] __vfs_write+0x1b [kernel] vfs_write+0xb8 [kernel] sys_write+0x55 [kernel] do_syscall_64+0x73 [kernel] entry_SYSCALL_64_after_hwframe+0x3d [kernel] __write_nocancel+0x7 [libc-2.23.so] [unknown] 3809631 3809631 systemd-udevd blk_freeze_queue blk_freeze_queue+0x1 [kernel] queue_requests_store+0xb6 [kernel] queue_attr_store+0x5c [kernel] sysfs_kf_write+0x3c [kernel] kernfs_fop_write+0x125 [kernel] __vfs_write+0x1b [kernel] vfs_write+0xb8 [kernel] sys_write+0x55 [kernel] do_syscall_64+0x73 [kernel] entry_SYSCALL_64_after_hwframe+0x3d [kernel] __write_nocancel+0x7 [libc-2.23.so] [unknown] 

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

استنتاج


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

هناك أدوات تصحيح أخطاء وميزات تعريف أخرى مبنية على eBPF. أحدها هو bpftrace ، والذي يسمح لك بكتابة برامج قوية ذات سطر واحد وصغيرة بلغة تشبه النكات . آخر - ebpf_exporter ، يسمح لك بجمع مقاييس عالية الدقة منخفضة المستوى مباشرة في خادم prometheus الخاص بك ، مع القدرة على الحصول على تصور جميل وحتى تنبيهات في المستقبل.

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


All Articles