In meinem vorherigen Artikel habe ich die Verwendung erklärt ftrace Kernelfunktionen zu verfolgen. Verwenden von ftrace Durch das Schreiben und Lesen von Dateien kann es mühsam werden, daher habe ich einen Wrapper verwendet, um Befehle mit Optionen zum Aktivieren und Deaktivieren der Ablaufverfolgung, zum Festlegen von Filtern, zum Anzeigen der Ausgabe, zum Löschen der Ausgabe und mehr auszuführen.
Der Befehl trace-cmd ist ein Dienstprogramm, das Ihnen dabei hilft. In diesem Artikel verwende ich trace-cmd um die gleichen Aufgaben auszuführen, die ich in meinem ftrace Artikel. Da ich mich häufig auf diesen Artikel beziehe, empfehle ich Ihnen, ihn zu lesen, bevor Sie diesen lesen.
Trace-cmd installieren
Ich führe die Befehle in diesem Artikel als Root-Benutzer aus.
Die ftrace Mechanismus ist in den Kernel integriert, und Sie können überprüfen, ob er aktiviert ist mit:
# mount | grep tracefs
none on /sys/kernel/tracing type tracefs (rw,relatime,seclabel)
Sie müssen jedoch die trace-cmd Dienstprogramm manuell.
# dnf install trace-cmd -yVerfügbare Tracer auflisten
Beim Benutzen ftrace, müssen Sie den Inhalt einer Datei anzeigen, um zu sehen, welche Tracer verfügbar sind. Aber mit trace-cmd, erhalten Sie diese Informationen mit:
# trace-cmd list -t
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
Aktivieren Sie den Funktions-Tracer
In meinem früheren Artikel habe ich zwei Tracer verwendet, und ich werde hier dasselbe tun. Aktivieren Sie Ihren ersten Tracer, function, mit:
$ trace-cmd start -p function
plugin 'function'
Anzeigen der Trace-Ausgabe
Sobald der Tracer aktiviert ist, können Sie die Ausgabe anzeigen, indem Sie die show Argumente. Dies zeigt nur die ersten 20 Zeilen, um das Beispiel kurz zu halten (siehe meinen früheren Artikel für eine Erklärung der Ausgabe):
# trace-cmd show | head -20
## tracer: function
#
# entries-in-buffer/entries-written: 410142/3380032 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
gdbus-2606 [004] ..s. 10520.538759: __msecs_to_jiffies <-rebalance_domains
gdbus-2606 [004] ..s. 10520.538760: load_balance <-rebalance_domains
gdbus-2606 [004] ..s. 10520.538761: idle_cpu <-load_balance
gdbus-2606 [004] ..s. 10520.538762: group_balance_cpu <-load_balance
gdbus-2606 [004] ..s. 10520.538762: find_busiest_group <-load_balance
gdbus-2606 [004] ..s. 10520.538763: update_group_capacity <-update_sd_lb_stats.constprop.0
gdbus-2606 [004] ..s. 10520.538763: __msecs_to_jiffies <-update_group_capacity
gdbus-2606 [004] ..s. 10520.538765: idle_cpu <-update_sd_lb_stats.constprop.0
gdbus-2606 [004] ..s. 10520.538766: __msecs_to_jiffies <-rebalance_domains
Stoppen Sie die Verfolgung und löschen Sie den Puffer
Die Ablaufverfolgung läuft weiterhin im Hintergrund und Sie können die Ausgabe weiterhin mit anzeigen show.
Um die Verfolgung zu beenden, führen Sie trace-cmd mit dem stop Streit:
# trace-cmd stopUm den Puffer zu löschen, führen Sie ihn mit dem clear Streit:
# trace-cmd clearAktivieren Sie den function_graph-Tracer
Aktivieren Sie den zweiten Tracer, function_graph, indem Sie Folgendes ausführen:
# trace-cmd start -p function_graph
plugin 'function_graph'
Betrachten Sie die Ausgabe noch einmal mit dem show Streit. Wie erwartet unterscheidet sich die Ausgabe geringfügig von der ersten Ablaufverfolgungsausgabe. Diesmal beinhaltet es a function calls Kette:
# trace-cmd show | head -20
## tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
4) 0.079 us | } /* rcu_all_qs */
4) 0.327 us | } /* __cond_resched */
4) 0.081 us | rcu_read_unlock_strict();
4) | __cond_resched() {
4) 0.078 us | rcu_all_qs();
4) 0.243 us | }
4) 0.080 us | rcu_read_unlock_strict();
4) | __cond_resched() {
4) 0.078 us | rcu_all_qs();
4) 0.241 us | }
4) 0.080 us | rcu_read_unlock_strict();
4) | __cond_resched() {
4) 0.079 us | rcu_all_qs();
4) 0.235 us | }
4) 0.095 us | rcu_read_unlock_strict();
4) | __cond_resched() {
Verwenden Sie die stop und clear Befehle zum Stoppen der Ablaufverfolgung und Löschen des Puffers:
# trace-cmd stop
# trace-cmd clear
Optimieren Sie die Verfolgung, um die Tiefe zu erhöhen
Wenn Sie mehr Tiefe in den Funktionsaufrufen sehen möchten, können Sie den Tracer optimieren:
# trace-cmd start -p function_graph --max-graph-depth 5
plugin 'function_graph'
Wenn Sie nun diese Ausgabe mit dem vergleichen, was Sie zuvor gesehen haben, sollten Sie mehr verschachtelte Funktionsaufrufe sehen:
# trace-cmd show | head -20
## tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
6) | __fget_light() {
6) 0.804 us | __fget_files();
6) 2.708 us | }
6) 3.650 us | } /* __fdget */
6) 0.547 us | eventfd_poll();
6) 0.535 us | fput();
6) | __fdget() {
6) | __fget_light() {
6) 0.946 us | __fget_files();
6) 1.895 us | }
6) 2.849 us | }
6) | sock_poll() {
6) 0.651 us | unix_poll();
6) 1.905 us | }
6) 0.475 us | fput();
6) | __fdget() {
Informieren Sie sich über die verfügbaren Funktionen zum Nachverfolgen
Wenn Sie nur bestimmte Funktionen verfolgen und den Rest ignorieren möchten, müssen Sie die genauen Funktionsnamen kennen. Du bekommst sie mit dem list Argument gefolgt von -f. In diesem Beispiel wird nach der allgemeinen Kernelfunktion gesucht kmalloc, die verwendet wird, um Speicher im Kernel zuzuweisen:
# trace-cmd list -f | grep kmalloc
bpf_map_kmalloc_node
mempool_kmalloc
__traceiter_kmalloc
__traceiter_kmalloc_node
kmalloc_slab
kmalloc_order
kmalloc_order_trace
kmalloc_large_node
__kmalloc
__kmalloc_track_caller
__kmalloc_node
__kmalloc_node_track_caller
[...]
Hier ist die Gesamtzahl der auf meinem Testsystem verfügbaren Funktionen:
# trace-cmd list -f | wc -l
63165
Kernelmodulbezogene Funktionen verfolgen
Sie können auch Funktionen verfolgen, die sich auf ein bestimmtes Kernelmodul beziehen. Stellen Sie sich vor, Sie möchten nachverfolgen kvm Kernelmodulbezogene Funktionen. Stellen Sie sicher, dass das Modul geladen ist:
# lsmod | grep kvm_intel
kvm_intel 335872 0
kvm 987136 1 kvm_intel
Lauf trace-cmd wieder mit dem list Argument und aus der Ausgabe grep für Zeilen, die auf enden ]. Dadurch werden die Kernel-Module herausgefiltert. Dann grep das Kernel-Modul kvm_intel, und Sie sollten alle Funktionen sehen, die sich auf dieses Kernel-Modul beziehen:
# trace-cmd list -f | grep ]$ | grep kvm_intel
vmx_can_emulate_instruction [kvm_intel]
vmx_update_emulated_instruction [kvm_intel]
vmx_setup_uret_msr [kvm_intel]
vmx_set_identity_map_addr [kvm_intel]
handle_machine_check [kvm_intel]
handle_triple_fault [kvm_intel]
vmx_patch_hypercall [kvm_intel]
[...]
vmx_dump_dtsel [kvm_intel]
vmx_dump_sel [kvm_intel]
Trace-spezifische Funktionen
Nachdem Sie nun wissen, wie Sie interessante Funktionen finden, können Sie dieses Wissen anhand eines Beispiels anwenden. Versuchen Sie wie im vorherigen Artikel, dateisystembezogene Funktionen zu verfolgen. Das Dateisystem, das ich auf meinem Testsystem hatte, war ext4.
Dieses Verfahren ist etwas anders; Anstatt von start, führen Sie den Befehl mit dem aus record Argument gefolgt vom “Muster” der Funktionen, die Sie verfolgen möchten. Sie müssen auch den gewünschten Tracer angeben; in diesem Fall ist das function_graph. Der Befehl zeichnet den Trace so lange auf, bis Sie ihn mit stoppen Strg+C. Drücken Sie also nach ein paar Sekunden Strg+C um die Verfolgung zu beenden:
# trace-cmd list -f | grep ^ext4_
# trace-cmd record -l ext4_* -p function_graph
plugin 'function_graph'
Hit Ctrl^C to stop recording
^C
CPU0 data recorded at offset=0x856000
8192 bytes in size
[...]
Sehen Sie sich die aufgezeichnete Spur an
Um den zuvor aufgezeichneten Trace anzuzeigen, führen Sie den Befehl mit der report Streit. Aus der Ausgabe geht hervor, dass der Filter funktioniert hat, und Sie sehen nur den ext4-bezogenen Funktionstrace:
# trace-cmd report | head -20
[...]
cpus=8
trace-cmd-12697 [000] 11303.928103: funcgraph_entry: | ext4_show_options() {
trace-cmd-12697 [000] 11303.928104: funcgraph_entry: 0.187 us | ext4_get_dummy_policy();
trace-cmd-12697 [000] 11303.928105: funcgraph_exit: 1.583 us | }
trace-cmd-12697 [000] 11303.928122: funcgraph_entry: | ext4_create() {
trace-cmd-12697 [000] 11303.928122: funcgraph_entry: | ext4_alloc_inode() {
trace-cmd-12697 [000] 11303.928123: funcgraph_entry: 0.101 us | ext4_es_init_tree();
trace-cmd-12697 [000] 11303.928123: funcgraph_entry: 0.083 us | ext4_init_pending_tree();
trace-cmd-12697 [000] 11303.928123: funcgraph_entry: 0.141 us | ext4_fc_init_inode();
trace-cmd-12697 [000] 11303.928123: funcgraph_exit: 0.931 us | }
trace-cmd-12697 [000] 11303.928124: funcgraph_entry: 0.081 us | ext4_get_dummy_policy();
trace-cmd-12697 [000] 11303.928124: funcgraph_entry: 0.133 us | ext4_get_group_desc();
trace-cmd-12697 [000] 11303.928124: funcgraph_entry: 0.115 us | ext4_free_inodes_count();
trace-cmd-12697 [000] 11303.928124: funcgraph_entry: 0.114 us | ext4_get_group_desc();
Verfolgen Sie eine bestimmte PID
Angenommen, Sie möchten Funktionen verfolgen, die sich auf einen bestimmten persistenten Identifikator (PID) beziehen. Öffnen Sie ein anderes Terminal und notieren Sie sich die PID der laufenden Shell:
# echo $$
10885
Führen Sie die record Befehl erneut und übergeben Sie die PID mit dem -P Möglichkeit. Lassen Sie dieses Mal das Terminal laufen (dh drücken Sie nicht Strg+C noch):
# trace-cmd record -P 10885 -p function_graph
plugin 'function_graph'
Hit Ctrl^C to stop recording
Führen Sie einige Aktivitäten auf der Shell aus
Gehen Sie zurück zu dem anderen Terminal, auf dem eine Shell mit einer bestimmten PID ausgeführt wurde, und führen Sie einen beliebigen Befehl aus, z. ls Dateien auflisten:
# ls
Temp-9b61f280-fdc1-4512-9211-5c60f764d702
tracker-extract-3-files.1000
v8-compile-cache-1000
[...]
Gehen Sie zurück zu dem Terminal, in dem Sie die Verfolgung aktiviert haben, und drücken Sie Strg+C um die Verfolgung zu beenden:
# trace-cmd record -P 10885 -p function_graph
plugin 'function_graph'
Hit Ctrl^C to stop recording
^C
CPU1 data recorded at offset=0x856000
618496 bytes in size
[...]
In der Ausgabe des Trace sehen Sie links die PID und die Bash-Shell und rechts die damit verbundenen Funktionsaufrufe. Dies kann sehr praktisch sein, um Ihre Ablaufverfolgung einzugrenzen:
# trace-cmd report | head -20
cpus=8
<idle>-0 [001] 11555.380581: funcgraph_entry: | switch_mm_irqs_off() {
<idle>-0 [001] 11555.380583: funcgraph_entry: 1.703 us | load_new_mm_cr3();
<idle>-0 [001] 11555.380586: funcgraph_entry: 0.493 us | switch_ldt();
<idle>-0 [001] 11555.380587: funcgraph_exit: 7.235 us | }
bash-10885 [001] 11555.380589: funcgraph_entry: 1.046 us | finish_task_switch.isra.0();
bash-10885 [001] 11555.380591: funcgraph_entry: | __fdget() {
bash-10885 [001] 11555.380592: funcgraph_entry: 2.036 us | __fget_light();
bash-10885 [001] 11555.380594: funcgraph_exit: 3.256 us | }
bash-10885 [001] 11555.380595: funcgraph_entry: | tty_poll() {
bash-10885 [001] 11555.380597: funcgraph_entry: | tty_ldisc_ref_wait() {
bash-10885 [001] 11555.380598: funcgraph_entry: | ldsem_down_read() {
bash-10885 [001] 11555.380598: funcgraph_entry: | __cond_resched() {
Versuche es
Diese kurzen Beispiele zeigen, wie die Verwendung von trace-cmd statt des Basiswertes ftrace Mechanismus ist sowohl einfach zu bedienen als auch reich an Funktionen, darunter viele, die ich hier nicht behandelt habe. Um mehr zu erfahren und besser darin zu werden, konsultieren Sie die Manpage und probieren Sie die anderen nützlichen Befehle aus.