Messages in this thread | | | Date | Wed, 12 Jun 2013 16:46:43 +0900 | From | Yoshihiro YUNOMAE <> | Subject | [EXAMPLE] tools: a tool for merging trace data of a guest and a host |
| |
This tool merges trace data of a guest and a host in chronological order. Restrictions of this tool is as follows: - one guest (not for multiple guests) - stable TSC (not backward TSC) - synchronized TSC - unchanged TSC offset (the guest does not execute write_TSC)
- How to use 1. [host] Enable kvm_write_tsc_offset before booting a guest # cd /sys/kernel/debug/tracing/instances # mkdir tsc_offset # cd tsc_offset # echo x86-tsc > trace_clock # echo 1 > events/kvm/kvm_write_tsc_offset/enable
2. [host] Enable events you want Note: I recommend to enable kvm_exit/entry events. # cd /sys/kernel/debug/tracing # echo kvm_entry >> set_event # echo kvm_exit >> set_event # [snip] # echo x86-tsc > trace_clock
3. [host] Boot the guest
4. [guest] Enable events you want # cd /sys/kernel/debug/tracing # echo sched_wakeup >> set_event # echo sched_switch >> set_event # [snip] # echo x86-tsc > trace_clock
5. [guest] Run programs
6. [guest/host] Get trace data # echo 0 > tracing_on # cat trace > /home/yourdir/log/guest_trace.txt (for the guest) (cat trace > /home/yourdir/log/host_trace.txt (for the host)) # scp [host_IP]:/home/yourdir/log/guest_trace.txt (only for the guest)
7. [host] Get next TSC offset # cat /sys/kernel/debug/tracing/instances/tsc_offset/trace qemu-kvm-22089 [000] d...4300151845072: kvm_write_tsc_offset: vcpu=0 prev=0 next=18446739773557710924
8. [host] Run this tool with the next TSC offset for -t option. $ ./trace-merge.pl -g ~/log/guest_trace.txt -h ~/log/host_trace.txt \ -t 18446739773557710924
h qemu-kvm-2687 [003] d...50550079203669: kvm_exit: [detail] h qemu-kvm-2687 [003] d...50550079206816: kvm_entry: [detail] g comm-3826 [000] d.h.50550079226331: sched_wakeup: [detail] h qemu-kvm-2687 [003] d...50550079240656: kvm_exit: [detail] h qemu-kvm-2687 [003] d...50550079243467: kvm_entry: [detail] h qemu-kvm-2687 [003] d...50550079256103: kvm_exit: [detail] h qemu-kvm-2687 [003] d...50550079268391: kvm_entry: [detail] g comm-3826 [000] d...50550079279266: sched_switch: [detail] h qemu-kvm-2687 [003] d...50550079280829: kvm_exit: [detail] h qemu-kvm-2687 [003] d...50550079286028: kvm_entry: [detail] | \----guest/host
Thanks,
-- Yoshihiro YUNOMAE Software Platform Research Dept. Linux Technology Center Hitachi, Ltd., Yokohama Research Laboratory E-mail: yoshihiro.yunomae.ez@hitachi.com
#!/usr/bin/perl # # Tool for merging and sorting trace data of a guest and host # # Created by Yoshihiro YUNOMAE <yoshihiro.yunomae.ez@hitachi.com> # # - How to use # ./trace-merge.pl <-h host_data -g guest_data -t tsc_offset_value> # use strict; use bigint; use warnings; use Getopt::Long qw(:config posix_default no_ignore_case);
my @merged_data = (); my @sorted_data = ();
my ($opt_host, $opt_guest, $opt_offset); GetOptions( "host_data|h=s" => ¥$opt_host, "guest_data|g=s"=> ¥$opt_guest, "tsc_offset|t=i"=> ¥$opt_offset );
my $tsc_offset = 0; my $MASK64 = (1 << 64) - 1;
&get_tsc_offset(); &read_all_data();
sub read_all_data { my $h_tsc = 0; my $g_comm = ""; my $g_tsc = 0; my $g_event = ""; my $h_line = ""; my $g_line = "";
open HOST_DATA, "<", $opt_host or die "Cannot open host file: $!"; open GUEST_DATA, "<", $opt_guest or die "Cannot open guest file: $!";
# skip header information of trace files while (!$h_tsc) { $h_line = <HOST_DATA>; if ($h_line =‾ /¥[[0-9]+¥]¥s.{4}¥s([0-9]+):/) { $h_tsc = $1; } }
# skip header information of trace files while (!$g_tsc) { $g_line = <GUEST_DATA>; if ($g_line =‾ /^(.+¥[[0-9]+¥]¥s.{4}¥s)([0-9]+)(:.+)/) { $g_comm = $1; $g_tsc = ($2 - $tsc_offset) & $MASK64; $g_event = $3; } }
# sort trace data by tsc while ($h_line) { if ($h_tsc < $g_tsc) { print "h $h_line"; $h_line = <HOST_DATA>; if (!$h_line) { last; } if ($h_line =‾ /¥[[0-9]+¥]¥s.{4}¥s([0-9]+):/) { $h_tsc = $1; } } else { print "g $g_comm$g_tsc$g_event¥n"; $g_line = <GUEST_DATA>; if (!$g_line) { last; } if ($g_line =‾ /^(.+¥[[0-9]+¥]¥s.{4}¥s)([0-9]+)(:.+)/) { $g_comm = $1; $g_tsc = ($2 - $tsc_offset) & $MASK64; $g_event = $3; } } }
#flush host data while ($h_line) { print "h $h_line"; $h_line = <HOST_DATA>; if (!$h_line) { last; } }
#flush guest data while ($g_line) { print "g $g_comm$g_tsc$g_event¥n"; $g_line = <GUEST_DATA>; if (!$g_line) { last; } if ($g_line =‾ /^(.+¥[[0-9]+¥]¥s.{4}¥s)([0-9]+)(:.+)/) { $g_comm = $1; $g_tsc = ($2 - $tsc_offset) & $MASK64; $g_event = $3; } }
close HOST_DATA; close GUEST_DATA; }
sub get_tsc_offset { if (!$opt_offset) { $tsc_offset = 0; } else { $tsc_offset = &convert_tscoffset($opt_offset); } }
sub convert_tscoffset { my $offset = shift;
return $offset - (1 << 64); }
| |