از تأخیر بالای Ceph تا پچ هسته با استفاده از eBPF/BCC

از تأخیر بالای Ceph تا پچ هسته با استفاده از eBPF/BCC

لینوکس تعداد زیادی ابزار برای اشکال زدایی هسته و برنامه ها دارد. اکثر آنها تأثیر منفی بر عملکرد برنامه دارند و نمی توان از آنها در تولید استفاده کرد.

یکی دو سال پیش وجود داشت ابزار دیگری توسعه یافته است - eBPF این امکان ردیابی هسته و برنامه های کاربر را با سربار کم و بدون نیاز به بازسازی برنامه ها و بارگذاری ماژول های شخص ثالث در هسته فراهم می کند.

در حال حاضر برنامه های کاربردی بسیاری وجود دارند که از eBPF استفاده می کنند، و در این مقاله به نحوه نوشتن ابزار پروفایل خود بر اساس کتابخانه خواهیم پرداخت. PythonBCC. مقاله بر اساس وقایع واقعی است. ما از یک مشکل به حل دیگر می رویم تا نشان دهیم چگونه می توان از ابزارهای موجود در موقعیت های خاص استفاده کرد.

Ceph کند است

یک میزبان جدید به خوشه Ceph اضافه شده است. پس از انتقال برخی از داده ها به آن، متوجه شدیم که سرعت پردازش درخواست های نوشتن توسط آن بسیار کمتر از سایر سرورها است.

از تأخیر بالای Ceph تا پچ هسته با استفاده از eBPF/BCC
برخلاف سایر پلتفرم ها، این هاست از bcache و هسته جدید لینوکس 4.15 استفاده می کرد. این اولین باری بود که میزبانی از این پیکربندی در اینجا استفاده شد. و در آن لحظه مشخص بود که ریشه مشکل از نظر تئوری می تواند هر چیزی باشد.

تحقیق در مورد میزبان

بیایید با نگاهی به آنچه در داخل فرآیند ceph-osd اتفاق می افتد شروع کنیم. برای این ما استفاده خواهیم کرد پرفیوم и شعله نما (اطلاعات بیشتری در مورد آن می توانید بخوانید اینجا):

از تأخیر بالای Ceph تا پچ هسته با استفاده از eBPF/BCC
تصویر به ما می گوید که تابع fdatasync() زمان زیادی را صرف ارسال درخواست به توابع کرد generic_make_request(). این بدان معنی است که به احتمال زیاد علت مشکلات جایی خارج از خود دیمون osd است. این می تواند هسته یا دیسک باشد. خروجی iostat تأخیر بالایی در پردازش درخواست‌ها توسط دیسک‌های bcache نشان داد.

هنگام بررسی میزبان، متوجه شدیم که دیمون systemd-udevd مقدار زیادی از زمان CPU را مصرف می کند - حدود 20٪ در چندین هسته. این رفتار عجیبی است، بنابراین باید دلیل آن را پیدا کنید. از آنجایی که Systemd-udevd با uevents کار می‌کند، تصمیم گرفتیم به طور کامل به آنها نگاه کنیم مانیتور udevadm. به نظر می رسد که تعداد زیادی رویداد تغییر برای هر دستگاه بلوک در سیستم ایجاد شده است. این کاملاً غیرعادی است، بنابراین ما باید ببینیم که چه چیزی باعث ایجاد همه این رویدادها می شود.

با استفاده از جعبه ابزار BCC

همانطور که قبلا متوجه شدیم، هسته (و دیمون ceph در فراخوانی سیستم) زمان زیادی را در generic_make_request(). بیایید سعی کنیم سرعت این تابع را اندازه گیری کنیم. که در BCC در حال حاضر یک ابزار فوق العاده وجود دارد - کارایی. ما دیمون را با PID آن با فاصله 1 ثانیه ای بین خروجی ها ردیابی می کنیم و نتیجه را در میلی ثانیه می گیریم.

از تأخیر بالای Ceph تا پچ هسته با استفاده از eBPF/BCC
این ویژگی معمولا به سرعت کار می کند. تنها کاری که انجام می دهد ارسال درخواست به صف درایور دستگاه است.

حافظه پنهان دستگاه پیچیده ای است که در واقع از سه دیسک تشکیل شده است:

  • دستگاه پشتیبان (دیسک کش) در این مورد یک هارد دیسک کند است.
  • دستگاه کش (دیسک کش)، در اینجا این یکی از پارتیشن های دستگاه 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 trigger برای تولید uevents، مشکل را بازتولید کنیم.

نوشتن ابزارهای مبتنی بر BCC

بیایید سعی کنیم یک ابزار ساده برای ردیابی و نمایش کندترین تماس ها بنویسیم generic_make_request(). ما همچنین به نام درایوی که این تابع برای آن فراخوانی شده است علاقه مند هستیم.

طرح ساده است:

  • ثبت نام kprobe بر generic_make_request():
    • ما نام دیسک را در حافظه ذخیره می کنیم که از طریق آرگومان تابع قابل دسترسی است.
    • ما مهر زمانی را ذخیره می کنیم.

  • ثبت نام kretprobe برای بازگشت از generic_make_request():
    • ما مهر زمانی فعلی را دریافت می کنیم.
    • ما به دنبال مُهر زمانی ذخیره شده می‌گردیم و آن را با زمان فعلی مقایسه می‌کنیم.
    • اگر نتیجه بیشتر از مقدار مشخص شده باشد، نام دیسک ذخیره شده را پیدا کرده و در ترمینال نمایش می دهیم.

Kprobes и کرت پروب ها از مکانیزم نقطه شکست برای تغییر کد تابع در پرواز استفاده کنید. تو میتوانی بخوانی مستندات и خوب مقاله در مورد این موضوع اگر به کد برنامه های کاربردی مختلف در BCC، سپس می توانید ببینید که آنها ساختار یکسانی دارند. بنابراین در این مقاله از تجزیه آرگومان های اسکریپت صرف نظر می کنیم و به سراغ خود برنامه BPF می رویم.

متن eBPF داخل اسکریپت پایتون به شکل زیر است:

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

برای تبادل داده بین توابع، برنامه های eBPF استفاده می کنند جداول هش. ما هم همین کار را خواهیم کرد. ما از PID فرآیند به عنوان کلید استفاده می کنیم و ساختار را به عنوان مقدار تعریف می کنیم:

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 و مقدار نوع struct data_t. جدول در چارچوب برنامه BPF ما در دسترس خواهد بود. ماکرو BPF_PERF_OUTPUT جدول دیگری را به نام ثبت می کند حوادثکه برای انتقال داده به فضای کاربر

هنگام اندازه‌گیری تأخیر بین فراخوانی یک تابع و بازگشت از آن، یا بین تماس‌های توابع مختلف، باید در نظر داشته باشید که داده‌های دریافتی باید به یک زمینه تعلق داشته باشند. به عبارت دیگر، شما باید راه اندازی موازی احتمالی توابع را به خاطر بسپارید. ما توانایی اندازه‌گیری تأخیر بین فراخوانی یک تابع در زمینه یک فرآیند و بازگشت از آن تابع در زمینه یک فرآیند دیگر را داریم، اما این احتمالاً بی‌فایده است. یک مثال خوب در اینجا خواهد بود ابزار بیولانسی، جایی که کلید جدول هش روی یک اشاره گر تنظیم شده است درخواست ساختار، که منعکس کننده یک درخواست دیسک است.

در مرحله بعد، باید کدی را بنویسیم که با فراخوانی تابع مورد مطالعه اجرا می شود:

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(). پس از این، PID فرآیندی را که در زمینه آن کار می کنیم و مهر زمانی فعلی را بر حسب نانوثانیه دریافت می کنیم. ما همه را در یک انتخاب تازه می نویسیم struct 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 فعلی، در جدول هش یک ساختار از قبل موجود را جستجو می کنیم. اگر ساختار پیدا شد، نام فرآیند در حال اجرا را پیدا کرده و به آن اضافه می کنیم.

شیفت باینری که در اینجا استفاده می کنیم برای بدست آوردن GID رشته مورد نیاز است. آن ها PID فرآیند اصلی که موضوعی را شروع کرده است که در زمینه آن کار می کنیم. تابعی که ما فراخوانی می کنیم bpf_get_current_pid_tgid() هم GID رشته و هم PID آن را در یک مقدار 64 بیتی برمی گرداند.

هنگام خروجی به ترمینال، ما در حال حاضر علاقه ای به thread نداریم، اما به فرآیند اصلی علاقه مندیم. پس از مقایسه تاخیر حاصل با یک آستانه معین، از ساختار خود عبور می کنیم داده ها به فضای کاربر از طریق جدول حوادث، پس از آن ورودی را از آن حذف می کنیم p.

در اسکریپت پایتون که این کد را بارگذاری می کند، باید 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()

خود اسکریپت در دسترس است GitHub. بیایید سعی کنیم آن را روی یک پلتفرم آزمایشی اجرا کنیم که در آن fio در حال اجرا است، در bcache می‌نویسد و مانیتور udevadm را فراخوانی می‌کند:

از تأخیر بالای Ceph تا پچ هسته با استفاده از eBPF/BCC
سرانجام! اکنون می بینیم که چیزی که شبیه یک دستگاه bcache در حال توقف است، در واقع یک تماس متوقف شده است generic_make_request() برای یک دیسک کش

درون هسته حفاری کنید

در حین انتقال درخواست دقیقاً چه چیزی کاهش می یابد؟ می بینیم که تاخیر حتی قبل از شروع حسابداری درخواست رخ می دهد، یعنی. حسابداری یک درخواست خاص برای خروجی بیشتر آمار روی آن (/proc/diskstats یا iostat) هنوز آغاز نشده است. این را می توان به راحتی با اجرای iostat در حین بازتولید مشکل تأیید کرد، یا بیولانسی اسکریپت 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().

زمانی که طول می کشد تا این صف پاک شود معادل تاخیر دیسک است زیرا هسته منتظر می ماند تا تمام عملیات های صف تکمیل شود. پس از خالی شدن صف، تغییرات تنظیمات اعمال می شود. پس از آن نامیده می شود blk_mq_unfreeze_queue()، کاهش شمارنده انجماد_عمق.

اکنون ما به اندازه کافی برای اصلاح وضعیت می دانیم. دستور udevadm trigger باعث می شود تنظیمات دستگاه بلوک اعمال شود. این تنظیمات در قوانین udev توضیح داده شده است. ما می‌توانیم با تلاش برای تغییر آن‌ها از طریق sysfs یا با نگاه کردن به کد منبع هسته، متوجه شویم که کدام تنظیمات صف را مسدود می‌کنند. ما همچنین می توانیم ابزار BCC را امتحان کنیم رد، که برای هر تماس با ترمینال، ردیابی پشته هسته و فضای کاربر را خروجی می دهد 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، که به شما امکان می دهد تک لاینرهای قدرتمند و برنامه های کوچک را به زبان awk مانند بنویسید. یکی دیگر - ebpf_exporter، به شما امکان می دهد معیارهای سطح پایین و با وضوح بالا را مستقیماً در سرور prometheus خود جمع آوری کنید، با این قابلیت که بعداً تصاویر زیبا و حتی هشدار دریافت کنید.

منبع: www.habr.com

اضافه کردن نظر