'\" t .\" Title: trace-cmd-profile .\" Author: [see the "AUTHOR" section] .\" Generator: DocBook XSL Stylesheets vsnapshot .\" Date: 03/09/2026 .\" Manual: libtracefs Manual .\" Source: libtracefs .\" Language: English .\" .TH "TRACE\-CMD\-PROFILE" "1" "03/09/2026" "libtracefs" "libtracefs Manual" .\" ----------------------------------------------------------------- .\" * Define some portability stuff .\" ----------------------------------------------------------------- .\" ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ .\" http://bugs.debian.org/507673 .\" http://lists.gnu.org/archive/html/groff/2009-02/msg00013.html .\" ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ .ie \n(.g .ds Aq \(aq .el .ds Aq ' .\" ----------------------------------------------------------------- .\" * set default formatting .\" ----------------------------------------------------------------- .\" disable hyphenation .nh .\" disable justification (adjust text to left margin only) .ad l .\" ----------------------------------------------------------------- .\" * MAIN CONTENT STARTS HERE * .\" ----------------------------------------------------------------- .SH "نام (NAME)" trace\-cmd\-profile \- پروفایل‌سازی زنده وظایف در حال اجرا .SH "خلاصه دستور (SYNOPSIS)" .sp \fBtrace\-cmd profile [\fR\fB\fIOPTIONS\fR\fR\fB]\fR [\fIcommand\fR] .SH "توضیحات (DESCRIPTION)" .sp دستور trace\-cmd(1) profile ردگیری را درست مانند trace\-cmd\-record(1) با گزینهٔ \fB\-\-profile\fR آغاز می‌کند، با این تفاوت که داده‌ها را در یک فایل نمی‌نویسد، بلکه رویدادها را در لحظهٔ وقوع می‌خواند و آمار و محاسبات مربوط به رویدادها را به‌روزرسانی می‌کند\&. هنگامی که ردگیری پایان یابد، نتایج را درست مانند trace\-cmd\-report(1) با گزینهٔ \fB\-\-profile\fR گزارش می‌دهد\&. به بیان دیگر، دستور profile کارهای trace\-cmd record \-\-profile و trace\-cmd report \-\-profile را بدون نیاز به ضبط داده‌ها روی دیسک در این بین انجام می‌دهد\&. .sp مزیت استفاده از دستور profile این است که عمل پروفایل‌سازی می‌تواند در یک بازهٔ زمانی طولانی انجام گیرد، در شرایطی که ضبط همهٔ رویدادها فضای بسیار زیادی از دیسک را اشغال خواهد کرد\&. .sp این دستور چندین رویداد و همچنین ردیاب function graph با عمق یک را (در صورت پشتیبانی هسته) فعال خواهد کرد\&. هدف از این کار نشان دادن زمان ورود و خروج وظایف به هسته و مدت زمان حضور آن‌ها در هسته است\&. .sp برای غیرفعال کردن فراخوانی function graph، از گزینهٔ \fB\-p\fR برای فعال‌سازی یک ردیاب دیگر استفاده کنید\&. برای عدم فعال‌سازی هیچ ردیابی، از \fB\-p nop\fR استفاده نمایید\&. .sp در حال حاضر تمامی زمان‌بندی‌ها بر حسب نانوثانیه هستند\&. .SH "گزینه‌ها (OPTIONS)" .sp این گزینه‌ها همانند گزینه‌های trace\-cmd\-record(1) با گزینهٔ \fB\-\-profile\fR هستند\&. .PP \fB\-p\fR \fItracer\fR .RS 4 تنظیم یک افزونهٔ ردیاب برای اجرا به جای ردگیری function graph با عمق ۱\&. برای اجرا نشدن هیچ ردیابی، از \fB\-p nop\fR استفاده کنید\&. .RE .PP \fB\-S\fR .RS 4 تنها ردیاب یا رویدادهای مشخص‌شده در خط فرمان را فعال می‌کند\&. با این گزینه، ردیاب function_graph و هیچ رویدادی (مانند sched_switch) فعال نمی‌شوند، مگر اینکه صراحتاً در خط فرمان مشخص شده باشند (برای مثال \-p function \-e sched_switch \-e sched_wakeup)\&. .RE .PP \fB\-G\fR .RS 4 تنظیم رویدادهای وقفه (نرم‌افزاری و سخت‌افزاری) به صورت سراسری (global - منتسب به CPU به جای وظایف)\&. .RE .PP \fB\-o\fR \fIfile\fR .RS 4 نوشتن خروجی پروفایل در \fIfile\fR\&. این گزینه بر \fB\-\-stderr\fR تقدم دارد\&. .RE .PP \fB\-H\fR \fIevent\-hooks\fR .RS 4 افزودن تطبیق رویداد سفارشی برای متصل کردن هر دو رویداد به یکدیگر\&. قالب به این صورت است: [:],[,]/ [:],[,] .sp .if n \{\ .RS 4 .\} .nf بخش start_system:start_event (که start_system اختیاری است)، رویدادی است که زمان‌بندی را آغاز می‌کند\&. .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf فیلد start_match فیلدی در رویداد شروع است که باید با end_match در رویداد پایان مطابقت داده شود\&. .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf فیلد start_pid اختیاری است؛ از آنجا که تطابق‌ها به وظایفی متصل می‌شوند که رویدادها را اجرا می‌کنند، اگر باید از فیلد دیگری برای یافتن آن وظیفه استفاده شود، با start_pid مشخص می‌گردد\&. .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf بخش end_system:end_event رویدادی است که به زمان‌بندی پایان می‌دهد (بخش end_system اختیاری است)\&. .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf فیلد end_match فیلدی در end_event است که با فیلد start_match در رویداد شروع مطابقت خواهد داشت\&. .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf پرچم‌ها (flags) اختیاری هستند و می‌توانند مقادیر زیر باشند (بدون حساسیت به حروف بزرگ و کوچک): .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf p : این دو رویداد به همان CPU مقید شده‌اند (شروع و پایان همیشه روی همان CPU رخ می‌دهند)\&. .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf s : رویداد باید یک پشتهٔ ردگیری‌شده به همراه داشته باشد (فعال‌سازی ردگیری پشته برای رویداد شروع)\&. .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf g : رویداد سراسری (global) است (به وظیفه‌ای منتسب نیست)\&. پارامتر start_pid همراه با این پرچم کاربرد ندارد\&. .fi .if n \{\ .RE .\} .RE .PP \fB\-\-stderr\fR .RS 4 تغییر مسیر خروجی به stderr\&. خروجی دستوری که در حال اجرا است تغییر نمی‌کند\&. این قابلیت اجازه می‌دهد اجرای دستور را مشاهده کرده و هم‌زمان خروجی پروفایل را در فایل دیگری ذخیره کنید\&. .RE .PP \fB\-\-verbose\fR[=\fIlevel\fR] .RS 4 تعیین سطح ثبت گزارش (log level)\&. سطوح گزارش پشتیبانی‌شده عبارتند از "none"، "critical"، "error"، "warning"، "info"، "debug"، "all" یا شناسه‌های آن‌ها "0"، "1"، "2"، "3"، "4"، "5"، "6"\&. تنظیم سطح گزارش روی مقداری مشخص، تمامی گزارش‌های آن سطح و تمام سطوح قبلی را فعال می‌سازد\&. در صورت مشخص نشدن، مقدار پیش‌فرض "info" خواهد بود\&. .sp .if n \{\ .RS 4 .\} .nf مثال: فعال‌سازی تمام گزارش‌های critical، error و warning .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf trace\-cmd profile \-\-verbose=warning .fi .if n \{\ .RE .\} .RE.SH "مثال‌ها (EXAMPLES)" .sp .if n \{\ .RS 4 .\} .nf \-\-\- # trace\-cmd profile \-F sleep 1 [\&.\&.] task: sleep\-1121 Event: sched_switch:R (2) Total: 234559 Avg: 117279 Max: 129886 Min:104673 | + ftrace_raw_event_sched_switch (0xffffffff8109f310) 100% (2) time:234559 max:129886 min:104673 avg:117279 __schedule (0xffffffff816c1e81) preempt_schedule (0xffffffff816c236e) ___preempt_schedule (0xffffffff81351a59) | + unmap_single_vma (0xffffffff81198c05) | 55% (1) time:129886 max:129886 min:0 avg:129886 | stop_one_cpu (0xffffffff8110909a) | sched_exec (0xffffffff810a119b) | do_execveat_common\&.isra\&.31 (0xffffffff811de528) | do_execve (0xffffffff811dea8c) | SyS_execve (0xffffffff811ded1e) | return_to_handler (0xffffffff816c8458) | stub_execve (0xffffffff816c6929) | + unmap_single_vma (0xffffffff81198c05) 45% (1) time:104673 max:104673 min:0 avg:104673 unmap_vmas (0xffffffff81199174) exit_mmap (0xffffffff811a1f5b) mmput (0xffffffff8107699a) flush_old_exec (0xffffffff811ddb75) load_elf_binary (0xffffffff812287df) search_binary_handler (0xffffffff811dd3e0) do_execveat_common\&.isra\&.31 (0xffffffff811de8bd) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) stub_execve (0xffffffff816c6929) .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf Event: sched_switch:S (1) Total: 1000513242 Avg: 1000513242 Max: 1000513242 Min:1000513242 | + ftrace_raw_event_sched_switch (0xffffffff8109f310) 100% (1) time:1000513242 max:1000513242 min:0 avg:1000513242 __schedule (0xffffffff816c1e81) schedule (0xffffffff816c23b9) do_nanosleep (0xffffffff816c4f1c) hrtimer_nanosleep (0xffffffff810dcd86) SyS_nanosleep (0xffffffff810dcea6) return_to_handler (0xffffffff816c8458) tracesys_phase2 (0xffffffff816c65b0) .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf Event: sched_wakeup:1121 (1) Total: 43405 Avg: 43405 Max: 43405 Min:43405 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:43405 max:43405 min:0 avg:43405 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate\&.constprop\&.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) wake_up_process (0xffffffff810a4057) hrtimer_wakeup (0xffffffff810db772) __run_hrtimer (0xffffffff810dbd91) hrtimer_interrupt (0xffffffff810dc6b7) local_apic_timer_interrupt (0xffffffff810363e7) smp_trace_apic_timer_interrupt (0xffffffff816c8c6a) trace_apic_timer_interrupt (0xffffffff816c725a) finish_task_switch (0xffffffff8109c3a4) __schedule (0xffffffff816c1e01) schedule (0xffffffff816c23b9) ring_buffer_wait (0xffffffff811323a3) wait_on_pipe (0xffffffff81133d93) tracing_buffers_splice_read (0xffffffff811350b0) do_splice_to (0xffffffff8120476f) SyS_splice (0xffffffff81206c1f) tracesys_phase2 (0xffffffff816c65b0) .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf Event: func: sys_nanosleep() (1) Total: 1000598016 Avg: 1000598016 Max: 1000598016 Min:1000598016 Event: func: sys_munmap() (1) Total: 14300 Avg: 14300 Max: 14300 Min:14300 Event: func: sys_arch_prctl() (1) Total: 571 Avg: 571 Max: 571 Min:571 Event: func: sys_mprotect() (4) Total: 14382 Avg: 3595 Max: 7196 Min:2190 Event: func: SyS_read() (1) Total: 2640 Avg: 2640 Max: 2640 Min:2640 Event: func: sys_close() (5) Total: 4001 Avg: 800 Max: 1252 Min:414 Event: func: sys_newfstat() (3) Total: 11684 Avg: 3894 Max: 10206 Min:636 Event: func: SyS_open() (3) Total: 23615 Avg: 7871 Max: 10535 Min:4743 Event: func: sys_access() (1) Total: 5924 Avg: 5924 Max: 5924 Min:5924 Event: func: SyS_mmap() (8) Total: 39153 Avg: 4894 Max: 12354 Min:1518 Event: func: smp_trace_apic_timer_interrupt() (1) Total: 10298 Avg: 10298 Max: 10298 Min:10298 Event: func: SyS_brk() (4) Total: 2407 Avg: 601 Max: 1564 Min:206 Event: func: do_notify_resume() (2) Total: 4095 Avg: 2047 Max: 2521 Min:1574 Event: func: sys_execve() (5) Total: 1625251 Avg: 325050 Max: 1605698 Min:3570 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:1605698 max:1605698 min:0 avg:1605698 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate\&.constprop\&.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) wake_up_process (0xffffffff810a4057) cpu_stop_queue_work (0xffffffff81108df8) stop_one_cpu (0xffffffff8110909a) sched_exec (0xffffffff810a119b) do_execveat_common\&.isra\&.31 (0xffffffff811de528) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) stub_execve (0xffffffff816c6929) stub_execve (0xffffffff816c6929) .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf Event: func: syscall_trace_enter_phase2() (38) Total: 21544 Avg: 566 Max: 1066 Min:329 Event: func: syscall_trace_enter_phase1() (38) Total: 9202 Avg: 242 Max: 376 Min:150 Event: func: __do_page_fault() (53) Total: 257672 Avg: 4861 Max: 27745 Min:458 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:27745 max:27745 min:0 avg:27745 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate\&.constprop\&.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) default_wake_function (0xffffffff810a4002) autoremove_wake_function (0xffffffff810b50fd) __wake_up_common (0xffffffff810b4958) __wake_up (0xffffffff810b4cb8) rb_wake_up_waiters (0xffffffff8112f126) irq_work_run_list (0xffffffff81157d0f) irq_work_run (0xffffffff81157d5e) smp_trace_irq_work_interrupt (0xffffffff810082fc) trace_irq_work_interrupt (0xffffffff816c7aaa) return_to_handler (0xffffffff816c8458) trace_do_page_fault (0xffffffff810478b2) trace_page_fault (0xffffffff816c7dd2) .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf Event: func: syscall_trace_leave() (38) Total: 26145 Avg: 688 Max: 1264 Min:381 Event: func: __sb_end_write() (1) Total: 373 Avg: 373 Max: 373 Min:373 Event: func: fsnotify() (1) Total: 598 Avg: 598 Max: 598 Min:598 Event: func: __fsnotify_parent() (1) Total: 286 Avg: 286 Max: 286 Min:286 Event: func: mutex_unlock() (2) Total: 39636 Avg: 19818 Max: 39413 Min:223 Event: func: smp_trace_irq_work_interrupt() (6) Total: 236459 Avg: 39409 Max: 100671 Min:634 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (4) time:234348 max:100671 min:38745 avg:58587 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate\&.constprop\&.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) default_wake_function (0xffffffff810a4002) autoremove_wake_function (0xffffffff810b50fd) __wake_up_common (0xffffffff810b4958) __wake_up (0xffffffff810b4cb8) rb_wake_up_waiters (0xffffffff8112f126) irq_work_run_list (0xffffffff81157d0f) irq_work_run (0xffffffff81157d5e) smp_trace_irq_work_interrupt (0xffffffff810082fc) return_to_handler (0xffffffff816c8458) trace_irq_work_interrupt (0xffffffff816c7aaa) | + ftrace_return_to_handler (0xffffffff81140840) | 84% (3) time:197396 max:100671 min:38745 avg:65798 | return_to_handler (0xffffffff816c846d) | trace_page_fault (0xffffffff816c7dd2) | + ftrace_return_to_handler (0xffffffff81140840) 16% (1) time:36952 max:36952 min:0 avg:36952 ftrace_graph_caller (0xffffffff816c8428) mutex_unlock (0xffffffff816c3f75) rb_simple_write (0xffffffff81133142) vfs_write (0xffffffff811d7727) SyS_write (0xffffffff811d7acf) tracesys_phase2 (0xffffffff816c65b0) .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf Event: sys_enter:35 (1) Total: 1000599765 Avg: 1000599765 Max: 1000599765 Min:1000599765 Event: sys_enter:11 (1) Total: 55025 Avg: 55025 Max: 55025 Min:55025 Event: sys_enter:158 (1) Total: 1584 Avg: 1584 Max: 1584 Min:1584 Event: sys_enter:10 (4) Total: 18359 Avg: 4589 Max: 8764 Min:2933 Event: sys_enter:0 (1) Total: 4223 Avg: 4223 Max: 4223 Min:4223 Event: sys_enter:3 (5) Total: 9948 Avg: 1989 Max: 2606 Min:1203 Event: sys_enter:5 (3) Total: 15530 Avg: 5176 Max: 11840 Min:1405 Event: sys_enter:2 (3) Total: 28002 Avg: 9334 Max: 12035 Min:5656 Event: sys_enter:21 (1) Total: 7814 Avg: 7814 Max: 7814 Min:7814 Event: sys_enter:9 (8) Total: 49583 Avg: 6197 Max: 14137 Min:2362 Event: sys_enter:12 (4) Total: 108493 Avg: 27123 Max: 104079 Min:922 Event: sys_enter:59 (5) Total: 1631608 Avg: 326321 Max: 1607529 Min:4563 Event: page_fault_user:0x398d86b630 (1) Event: page_fault_user:0x398d844de0 (1) Event: page_fault_user:0x398d8d9020 (1) Event: page_fault_user:0x1d37008 (1) Event: page_fault_user:0x7f0b89e91074 (1) Event: page_fault_user:0x7f0b89d98ed0 (1) Event: page_fault_user:0x7f0b89ec8950 (1) Event: page_fault_user:0x7f0b89d83644 (1) Event: page_fault_user:0x7f0b89d622a8 (1) Event: page_fault_user:0x7f0b89d5a560 (1) Event: page_fault_user:0x7f0b89d34010 (1) Event: page_fault_user:0x1d36008 (1) Event: page_fault_user:0x398d900510 (1) Event: page_fault_user:0x398dbb3ae8 (1) Event: page_fault_user:0x398d87f490 (1) Event: page_fault_user:0x398d8eb660 (1) Event: page_fault_user:0x398d8bd730 (1) Event: page_fault_user:0x398d9625d9 (1) Event: page_fault_user:0x398d931810 (1) Event: page_fault_user:0x398dbb7114 (1) Event: page_fault_user:0x398d837610 (1) Event: page_fault_user:0x398d89e860 (1) Event: page_fault_user:0x398d8f23b0 (1) Event: page_fault_user:0x398dbb4510 (1) Event: page_fault_user:0x398dbad6f0 (1) Event: page_fault_user:0x398dbb1018 (1) Event: page_fault_user:0x398d977b37 (1) Event: page_fault_user:0x398d92eb60 (1) Event: page_fault_user:0x398d8abff0 (1) Event: page_fault_user:0x398dbb0d30 (1) Event: page_fault_user:0x398dbb6c24 (1) Event: page_fault_user:0x398d821c50 (1) Event: page_fault_user:0x398dbb6c20 (1) Event: page_fault_user:0x398d886350 (1) Event: page_fault_user:0x7f0b90125000 (1) Event: page_fault_user:0x7f0b90124740 (1) Event: page_fault_user:0x7f0b90126000 (1) Event: page_fault_user:0x398d816230 (1) Event: page_fault_user:0x398d8002b8 (1) Event: page_fault_user:0x398dbb0b40 (1) Event: page_fault_user:0x398dbb2880 (1) Event: page_fault_user:0x7f0b90141cc6 (1) Event: page_fault_user:0x7f0b9013b85c (1) Event: page_fault_user:0x7f0b90127000 (1) Event: page_fault_user:0x606e70 (1) Event: page_fault_user:0x7f0b90144010 (1) Event: page_fault_user:0x7fffcb31b038 (1) Event: page_fault_user:0x606da8 (1) Event: page_fault_user:0x400040 (1) Event: page_fault_user:0x398d222218 (1) Event: page_fault_user:0x398d015120 (1) Event: page_fault_user:0x398d220ce8 (1) Event: page_fault_user:0x398d220b80 (1) Event: page_fault_user:0x7fffcb2fcff8 (1) Event: page_fault_user:0x398d001590 (1) Event: page_fault_user:0x398d838490 (1) Event: softirq_raise:RCU (3) Total: 252931 Avg: 84310 Max: 243288 Min:4639 Event: softirq_raise:SCHED (2) Total: 241249 Avg: 120624 Max: 239076 Min:2173 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:239076 max:239076 min:0 avg:239076 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate\&.constprop\&.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) default_wake_function (0xffffffff810a4002) autoremove_wake_function (0xffffffff810b50fd) __wake_up_common (0xffffffff810b4958) __wake_up (0xffffffff810b4cb8) rb_wake_up_waiters (0xffffffff8112f126) irq_work_run_list (0xffffffff81157d0f) irq_work_run (0xffffffff81157d5e) smp_trace_irq_work_interrupt (0xffffffff810082fc) trace_irq_work_interrupt (0xffffffff816c7aaa) irq_exit (0xffffffff8107dd66) smp_trace_apic_timer_interrupt (0xffffffff816c8c7a) trace_apic_timer_interrupt (0xffffffff816c725a) prepare_ftrace_return (0xffffffff8103d4fd) ftrace_graph_caller (0xffffffff816c8428) mem_cgroup_begin_page_stat (0xffffffff811cfd25) page_remove_rmap (0xffffffff811a4fc5) stub_execve (0xffffffff816c6929) unmap_single_vma (0xffffffff81198b1c) unmap_vmas (0xffffffff81199174) exit_mmap (0xffffffff811a1f5b) mmput (0xffffffff8107699a) flush_old_exec (0xffffffff811ddb75) load_elf_binary (0xffffffff812287df) search_binary_handler (0xffffffff811dd3e0) do_execveat_common\&.isra\&.31 (0xffffffff811de8bd) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf Event: softirq_raise:HI (3) Total: 72472 Avg: 24157 Max: 64186 Min:3430 Event: softirq_entry:RCU (2) Total: 3191 Avg: 1595 Max: 1788 Min:1403 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:1788 max:1788 min:0 avg:1788 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate\&.constprop\&.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) default_wake_function (0xffffffff810a4002) autoremove_wake_function (0xffffffff810b50fd) __wake_up_common (0xffffffff810b4958) __wake_up (0xffffffff810b4cb8) rb_wake_up_waiters (0xffffffff8112f126) irq_work_run_list (0xffffffff81157d0f) irq_work_run (0xffffffff81157d5e) smp_trace_irq_work_interrupt (0xffffffff810082fc) trace_irq_work_interrupt (0xffffffff816c7aaa) irq_work_queue (0xffffffff81157e95) ring_buffer_unlock_commit (0xffffffff8113039f) __buffer_unlock_commit (0xffffffff811367d5) trace_buffer_unlock_commit (0xffffffff811376a2) ftrace_event_buffer_commit (0xffffffff81146d5f) ftrace_raw_event_sched_process_exec (0xffffffff8109c511) do_execveat_common\&.isra\&.31 (0xffffffff811de9a3) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) stub_execve (0xffffffff816c6929) .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf Event: softirq_entry:SCHED (2) Total: 2289 Avg: 1144 Max: 1350 Min:939 Event: softirq_entry:HI (3) Total: 180146 Avg: 60048 Max: 178969 Min:499 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:178969 max:178969 min:0 avg:178969 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate\&.constprop\&.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) wake_up_process (0xffffffff810a4057) wake_up_worker (0xffffffff8108de74) insert_work (0xffffffff8108fca6) __queue_work (0xffffffff8108fe12) delayed_work_timer_fn (0xffffffff81090088) call_timer_fn (0xffffffff810d8f89) run_timer_softirq (0xffffffff810da8a1) __do_softirq (0xffffffff8107d8fa) irq_exit (0xffffffff8107dd66) smp_trace_apic_timer_interrupt (0xffffffff816c8c7a) trace_apic_timer_interrupt (0xffffffff816c725a) prepare_ftrace_return (0xffffffff8103d4fd) ftrace_graph_caller (0xffffffff816c8428) mem_cgroup_begin_page_stat (0xffffffff811cfd25) page_remove_rmap (0xffffffff811a4fc5) stub_execve (0xffffffff816c6929) unmap_single_vma (0xffffffff81198b1c) unmap_vmas (0xffffffff81199174) exit_mmap (0xffffffff811a1f5b) mmput (0xffffffff8107699a) flush_old_exec (0xffffffff811ddb75) load_elf_binary (0xffffffff812287df) search_binary_handler (0xffffffff811dd3e0) do_execveat_common\&.isra\&.31 (0xffffffff811de8bd) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) \-\-\- .fi .if n \{\ .RE .\} .sp دستور بالا از \fB\-F\fR برای دنبال کردن تسک sleep استفاده می‌کند\&. این گزینه تنها رویدادهایی را فیلتر می‌کند که به sleep مربوط هستند\&. توجه داشته باشید، برای دنبال کردن انشعاب‌ها (forks)، باید پرچم \fB\-c\fR را نیز لحاظ کنید\&. .sp اگر رویدادها به بیش از یک تسک ارجاع دهند، تسک‌های دیگر نیز در پروفایل ظاهر خواهند شد (مانند آنچه sched_switch و sched_wakeup انجام می‌دهند؛ فیلدهای "prev_pid" و "next_pid" مربوط به sched_switch، و "common_pid" و "pid" مربوط به sched_wakeup)\&. .sp ردپای پشته‌ها (Stack traces) به رویدادهایی که به آن‌ها مرتبط هستند متصل شده‌اند\&. .sp با نگاهی به خروجی بالا: .sp .if n \{\ .RS 4 .\} .nf Event: sched_switch:R (2) Total: 234559 Avg: 117279 Max: 129886 Min:104673 .fi .if n \{\ .RE .\} .sp این نشان می‌دهد که تسک قبضه (preempt) شده است (در وضعیت در حال اجرای \fIR\fR قرار دارد)\&. تسک دو بار \fI(2)\fR برای مجموع 234,559 نانوثانیه قبضه شده است، با میانگین زمان قبضه 117,279 نانوثانیه، حداکثر 128,886 نانوثانیه و حداقل 104,673 نانوثانیه\&. .sp این ساختار درختی نشان می‌دهد که تسک در کجا قبضه شده است: .sp .if n \{\ .RS 4 .\} .nf | + ftrace_raw_event_sched_switch (0xffffffff8109f310) 100% (2) time:234559 max:129886 min:104673 avg:117279 __schedule (0xffffffff816c1e81) preempt_schedule (0xffffffff816c236e) ___preempt_schedule (0xffffffff81351a59) | + unmap_single_vma (0xffffffff81198c05) | 55% (1) time:129886 max:129886 min:0 avg:129886 | stop_one_cpu (0xffffffff8110909a) | sched_exec (0xffffffff810a119b) | do_execveat_common\&.isra\&.31 (0xffffffff811de528) | do_execve (0xffffffff811dea8c) | SyS_execve (0xffffffff811ded1e) | return_to_handler (0xffffffff816c8458) | stub_execve (0xffffffff816c6929) | + unmap_single_vma (0xffffffff81198c05) 45% (1) time:104673 max:104673 min:0 avg:104673 unmap_vmas (0xffffffff81199174) exit_mmap (0xffffffff811a1f5b) mmput (0xffffffff8107699a) flush_old_exec (0xffffffff811ddb75) load_elf_binary (0xffffffff812287df) search_binary_handler (0xffffffff811dd3e0) do_execveat_common\&.isra\&.31 (0xffffffff811de8bd) do_execve (0xffffffff811dea8c) SyS_execve (0xffffffff811ded1e) return_to_handler (0xffffffff816c8458) stub_execve (0xffffffff816c6929) .fi .if n \{\ .RE .\} .sp .if n \{\ .RS 4 .\} .nf Event: sched_switch:S (1) Total: 1000513242 Avg: 1000513242 Max: 1000513242 Min:10005132 .fi .if n \{\ .RE .\} .sp این خروجی نشان می‌دهد که تسک یک بار در وضعیت INTERRUPTIBLE از زمان‌بندی خارج شده (scheduled out) که در مجموع 1,000,513,242 نانوثانیه (~1s) به طول انجامیده است، و با توجه به اینکه تسک "sleep 1" بوده، منطقی است\&. .sp پس از رویدادهای زمان‌بندی (schedule)، رویدادهای تابع (function) نشان داده می‌شوند\&. به‌طور پیش‌فرض در صورتی که تنظیم عمق توسط هسته پشتیبانی شود، نمایه‌ساز از ردیاب گراف تابع (function graph tracer) استفاده خواهد کرد\&. این ابزار عمق را روی یک تنظیم می‌کند که تنها نخستین تابعی را که وارد هسته می‌شود ردگیری می‌نماید\&. همچنین مدت زمانی را که در هسته سپری کرده است ضبط می‌کند\&. .sp .if n \{\ .RS 4 .\} .nf Event: func: sys_nanosleep() (1) Total: 1000598016 Avg: 1000598016 Max: 1000598016 Min:1000598016 Event: func: sys_munmap() (1) Total: 14300 Avg: 14300 Max: 14300 Min:14300 Event: func: sys_arch_prctl() (1) Total: 571 Avg: 571 Max: 571 Min:571 Event: func: sys_mprotect() (4) Total: 14382 Avg: 3595 Max: 7196 Min:2190 Event: func: SyS_read() (1) Total: 2640 Avg: 2640 Max: 2640 Min:2640 Event: func: sys_close() (5) Total: 4001 Avg: 800 Max: 1252 Min:414 Event: func: sys_newfstat() (3) Total: 11684 Avg: 3894 Max: 10206 Min:636 Event: func: SyS_open() (3) Total: 23615 Avg: 7871 Max: 10535 Min:4743 Event: func: sys_access() (1) Total: 5924 Avg: 5924 Max: 5924 Min:5924 Event: func: SyS_mmap() (8) Total: 39153 Avg: 4894 Max: 12354 Min:1518 Event: func: smp_trace_apic_timer_interrupt() (1) Total: 10298 Avg: 10298 Max: 10298 Min:10298 Event: func: SyS_brk() (4) Total: 2407 Avg: 601 Max: 1564 Min:206 Event: func: do_notify_resume() (2) Total: 4095 Avg: 2047 Max: 2521 Min:1574 Event: func: sys_execve() (5) Total: 1625251 Avg: 325050 Max: 1605698 Min:3570 .fi .if n \{\ .RE .\} .sp تعداد دفعاتی که رویداد فراخوانی شده است همواره درون پرانتز \fI(5)\fR نشان داده می‌شود\&. .sp ردیابی گراف تابع ممکن است بار اضافی (overhead) بیش از حدی تولید کند زیرا همچنان روی تمام توابع فعال می‌شود (صرفاً آن‌ها را ردیابی نمی‌کند)\&. برای محدود کردن توابع تنها به فراخوانی‌های سیستمی (و نه وقفه‌ها)، گزینه زیر را اضافه کنید: .sp .if n \{\ .RS 4 .\} .nf \-l \*(Aqsys_*\*(Aq \-l \*(AqSyS_*\*(Aq .fi .if n \{\ .RE .\} .sp برای غیرفعال کردن کامل ردیابی گراف تابع، استفاده کنید از: .sp .if n \{\ .RS 4 .\} .nf \-p nop .fi .if n \{\ .RE .\} .sp برای استفاده از ردیابی تابع به جای آن (توجه داشته باشید که این کار زمان‌ها را ثبت نمی‌کند، بلکه تنها تعداد دفعات فراخوانی یک تابع را می‌شمارد): .sp .if n \{\ .RS 4 .\} .nf \-p function .fi .if n \{\ .RE .\} .sp پس از توابع، رویدادهایی که ضبط شده‌اند نمایش داده می‌شوند\&. .sp .if n \{\ .RS 4 .\} .nf Event: sys_enter:35 (1) Total: 1000599765 Avg: 1000599765 Max: 1000599765 Min:1000599765 Event: sys_enter:11 (1) Total: 55025 Avg: 55025 Max: 55025 Min:55025 Event: sys_enter:158 (1) Total: 1584 Avg: 1584 Max: 1584 Min:1584 Event: sys_enter:10 (4) Total: 18359 Avg: 4589 Max: 8764 Min:2933 Event: sys_enter:0 (1) Total: 4223 Avg: 4223 Max: 4223 Min:4223 Event: sys_enter:3 (5) Total: 9948 Avg: 1989 Max: 2606 Min:1203 Event: sys_enter:5 (3) Total: 15530 Avg: 5176 Max: 11840 Min:1405 Event: sys_enter:2 (3) Total: 28002 Avg: 9334 Max: 12035 Min:5656 Event: sys_enter:21 (1) Total: 7814 Avg: 7814 Max: 7814 Min:7814 Event: sys_enter:9 (8) Total: 49583 Avg: 6197 Max: 14137 Min:2362 Event: sys_enter:12 (4) Total: 108493 Avg: 27123 Max: 104079 Min:922 Event: sys_enter:59 (5) Total: 1631608 Avg: 326321 Max: 1607529 Min:4563 .fi .if n \{\ .RE .\} .sp این‌ها رویدادهای خام فراخوانی سیستمی هستند، همراه با شناسه خام فراخوانی سیستمی پس از "sys_enter:"\&. به عنوان مثال، "59" همان execve(2) است\&. چرا ۵ بار اجرا شد؟ با نگاهی به strace این اجرا، می‌توانیم ببینیم: .sp .if n \{\ .RS 4 .\} .nf execve("/usr/lib64/ccache/sleep", ["sleep", "1"], [/* 27 vars */] <\&.\&.\&. execve resumed> ) = \-1 ENOENT (No such file or directory) execve("/usr/local/sbin/sleep", ["sleep", "1"], [/* 27 vars */] <\&.\&.\&. execve resumed> ) = \-1 ENOENT (No such file or directory) execve("/usr/local/bin/sleep", ["sleep", "1"], [/* 27 vars */] <\&.\&.\&. execve resumed> ) = \-1 ENOENT (No such file or directory) execve("/usr/sbin/sleep", ["sleep", "1"], [/* 27 vars */] <\&.\&.\&. execve resumed> ) = \-1 ENOENT (No such file or directory) execve("/usr/bin/sleep", ["sleep", "1"], [/* 27 vars */] <\&.\&.\&. execve resumed> ) = 0 .fi .if n \{\ .RE .\} .sp برنامه تلاش کرده است تا دستور "sleep" را با execve برای هر مسیر موجود در $PATH اجرا کند تا زمانی که یکی را پیدا کند\&. .sp رویدادهای page_fault_user نشان می‌دهند که چه آدرسی در فضای کاربری دچار نقص صفحه (page fault) شده است\&. .sp .if n \{\ .RS 4 .\} .nf Event: softirq_raise:RCU (3) Total: 252931 Avg: 84310 Max: 243288 Min:4639 Event: softirq_raise:SCHED (2) Total: 241249 Avg: 120624 Max: 239076 Min:2173 | + ftrace_raw_event_sched_wakeup_template (0xffffffff8109d960) 100% (1) time:239076 max:239076 min:0 avg:239076 ttwu_do_wakeup (0xffffffff810a01a2) ttwu_do_activate\&.constprop\&.122 (0xffffffff810a0236) try_to_wake_up (0xffffffff810a3ec3) default_wake_function (0xffffffff810a4002) autoremove_wake_function (0xffffffff810b50fd) __wake_up_common (0xffffffff810b4958) __wake_up (0xffffffff810b4cb8) rb_wake_up_waiters (0xffffffff8112f126) irq_work_run_list (0xffffffff81157d0f) irq_work_run (0xffffffff81157d5e) smp_trace_irq_work_interrupt (0xffffffff810082fc) trace_irq_work_interrupt (0xffffffff816c7aaa) irq_exit (0xffffffff8107dd66) .fi .if n \{\ .RE .\} .sp زمان‌بندی‌ها برای رویدادهای softirq_raise مدت زمانی را که از برانگیخته شدن softirq تا زمان اجرای آن طول کشیده است اندازه‌گیری می‌کنند\&. .sp زمان‌بندی‌ها برای رویدادهای softirq_entry مدت زمانی را که اجرای softirq به طول انجامیده است اندازه‌گیری می‌کنند\&. .sp ردپای پشته‌ها برای softirqها (و احتمالاً سایر رویدادها) زمانی استفاده می‌شوند که یک رویداد پشته‌ای متصل به خود داشته باشد\&. این موضوع زمانی رخ می‌دهد که پروفایل پشته‌های بیشتری را فراتر از رویدادهای sched اجرا کرده باشد، یا زمانی که رویدادها نادیده گرفته شوند و پشته‌ها .sp برای کنترل کامل بر آنچه ردیابی می‌شود، از گزینه \fB\-S\fR استفاده کنید که باعث می‌شود trace\-cmd هیچ رویدادی یا ردیاب function_graph را فعال نکند\&. تنها رویدادهای ذکرشده در خط فرمان نمایش داده می‌شوند\&. .sp اگر تنها دیدن مدت زمان kmalloc و جایی که ثبت شده است مورد نیاز باشد، استفاده از گزینه \fB\-S\fR و فعال‌سازی function_graph و ردیابی پشته صرفاً برای تابع مورد نیاز، پروفایل مربوط به تنها همان تابع را ارائه خواهد داد\&. .sp .if n \{\ .RS 4 .\} .nf \-\-\- # trace\-cmd profile \-S \-p function_graph \-l \*(Aq*kmalloc*\*(Aq \-l \*(Aq*kmalloc*:stacktrace\*(Aq sleep 1 task: sshd\-11786 Event: func: __kmalloc_reserve\&.isra\&.59() (2) Total: 149684 Avg: 74842 Max: 75598 Min:74086 | + __alloc_skb (0xffffffff815a8917) | 67% (2) time:149684 max:75598 min:74086 avg:74842 | __kmalloc_node_track_caller (0xffffffff811c6635) | __kmalloc_reserve\&.isra\&.59 (0xffffffff815a84ac) | return_to_handler (0xffffffff816c8458) | sk_stream_alloc_skb (0xffffffff81604ea1) | tcp_sendmsg (0xffffffff8160592c) | inet_sendmsg (0xffffffff8162fed1) | sock_aio_write (0xffffffff8159f9fc) | do_sync_write (0xffffffff811d694a) | vfs_write (0xffffffff811d7825) | SyS_write (0xffffffff811d7adf) | system_call_fastpath (0xffffffff816c63d2) | + __alloc_skb (0xffffffff815a8917) 33% (1) time:74086 max:74086 min:74086 avg:74086 __alloc_skb (0xffffffff815a8917) sk_stream_alloc_skb (0xffffffff81604ea1) tcp_sendmsg (0xffffffff8160592c) inet_sendmsg (0xffffffff8162fed1) sock_aio_write (0xffffffff8159f9fc) do_sync_write (0xffffffff811d694a) vfs_write (0xffffffff811d7825) SyS_write (0xffffffff811d7adf) system_call_fastpath (0xffffffff816c63d2) [\&.\&.] \-\-\- .fi .if n \{\ .RE .\} .sp برای مشاهده اجرای دستور و در عین حال ذخیره خروجی پروفایل در یک فایل، از \-\-stderr استفاده کنید و stderr را به یک فایل تغییر مسیر دهید .sp # trace\-cmd profile \-\-stderr cyclictest \-p 80 \-n \-t1 2> profile\&.out .sp یا به سادگی از \fB\-o\fR استفاده کنید .sp # trace\-cmd profile \-o profile\&.out cyclictest \-p 80 \-n \-t1.SH "همچنین ببینید (SEE ALSO)" .sp trace\-cmd(1), trace\-cmd\-record(1), trace\-cmd\-report(1), trace\-cmd\-start(1), trace\-cmd\-stop(1), trace\-cmd\-reset(1), trace\-cmd\-split(1), trace\-cmd\-list(1), trace\-cmd\-listen(1) .SH "نویسنده (AUTHOR)" .sp نوشته‌شده توسط Steven Rostedt، <\m[blue]\fBrostedt@goodmis\&.org\fR\m[]\&\s-2\u[1]\d\s+2> .SH "منابع (RESOURCES)" .sp \m[blue]\fBhttps://git\&.kernel\&.org/pub/scm/utils/trace\-cmd/trace\-cmd\&.git\fR\m[] .SH "کپی‌رایت و تکثیر (COPYING)" .sp حق نشر (C) 2014 متعلق به Red Hat, Inc\&. استفاده آزاد از این نرم‌افزار تحت شرایط پروانه عمومی همگانی گنو (GPL) مجاز است\&. .SH "نکات (NOTES)" .IP " 1." 4 rostedt@goodmis.org .RS 4 \%mailto:rostedt@goodmis.org .RE