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...@hitachi.com
#!/usr/bin/perl
#
# Tool for merging and sorting trace data of a guest and host
#
# Created by Yoshihiro YUNOMAE <yoshihiro.yunomae...@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);
}
