Skip to content
GitLab
Menu
Projects
Groups
Snippets
Help
Help
Support
Community forum
Keyboard shortcuts
?
Submit feedback
Contribute to GitLab
Sign in / Register
Toggle navigation
Menu
Open sidebar
emulab
emulab-devel
Commits
d70a867a
Commit
d70a867a
authored
Feb 21, 2007
by
David Johnson
Browse files
Better.
parent
c7e68f58
Changes
1
Hide whitespace changes
Inline
Side-by-side
pelab/supafly/logparse.pl
View file @
d70a867a
...
...
@@ -114,16 +114,18 @@ foreach my $logtuple (@logs) {
open
(
ML
,"
$mlog
")
or
die
"
couldn't open
$mlog
!
";
while
(
$line
=
<
ML
>
)
{
if
(
$line
=~
/^BLOCKTIME\((\w+)\).+m(\d+).+b(\d+).+f(\d+).+read\=(\d+\.\d+).+compute\=(\d+\.\d+).+send\=(\d+\.\d+)/
)
{
$bs
{"
m$2 b$3 f$4
"}{'
M_cryptotime
'}
=
int
(
$
4
);
$bs
{"
m$2 b$3 f$4
"}{'
M_read
'}
=
$
5
+
0.0
;
$bs
{"
m$2 b$3 f$4
"}{'
M_endcomp
'}
=
$
6
+
0.0
;
$bs
{"
m$2 b$3 f$4
"}{'
M_send
'}
=
$
7
+
0.0
;
#BLOCKTIME(de): m0 b0 f0 1112; read=1172014045.737621; compute=1172014045.739196; send=1172014045.739301
if
(
$line
=~
/BLOCKTIME\((\w+)\).+m(\d+).+b(\d+).+f(\d+)\s+(\d+);.+read\=(\d+\.\d+).+compute\=(\d+\.\d+).+send\=(\d+\.\d+)/
)
{
$bs
{"
m$2 b$3 f$4
"}{'
M_cryptotime
'}
=
$
5
+
0
;
#debug("ctime = " . $bs{"m$2 b$3 f$4"}{'M_cryptotime'} . "\n");
$bs
{"
m$2 b$3 f$4
"}{'
M_read
'}
=
$
6
+
0.0
;
$bs
{"
m$2 b$3 f$4
"}{'
M_endcomp
'}
=
$
7
+
0.0
;
$bs
{"
m$2 b$3 f$4
"}{'
M_send
'}
=
$
8
+
0.0
;
$bs
{"
m$2 b$3 f$4
"}{'
M_cryptoop
'}
=
$
1
;
#debug("a");
++
$mlc
;
}
elsif
(
$line
=~
/
^
ACKTIME: recv m(\d+) b(\d+) f(\d+) at (\d+\.\d+)/
)
{
elsif
(
$line
=~
/ACKTIME: recv m(\d+) b(\d+) f(\d+) at (\d+\.\d+)/
)
{
$bs
{"
m$1 b$2 f$3
"}{'
M_ack
'}
=
$
4
+
0.0
;
++
$mlc
;
}
...
...
@@ -132,12 +134,12 @@ foreach my $logtuple (@logs) {
open
(
SL
,"
$slog
")
or
die
"
couldn't open
$slog
!
";
while
(
$line
=
<
SL
>
)
{
if
(
$line
=~
/
^
TIME m(\d+) b(\d+) f(\d+) (\d+\.\d+)/
)
{
$bs
{"
m$1 b$2 f$3
"}{'
S_
send
'}
=
$
4
+
0.0
;
if
(
$line
=~
/
ACK
TIME m(\d+) b(\d+) f(\d+) (\d+\.\d+)/
)
{
$bs
{"
m$1 b$2 f$3
"}{'
S_
ack
'}
=
$
4
+
0.0
;
++
$slc
;
}
elsif
(
$line
=~
/
^ACK
TIME m(\d+) b(\d+) f(\d+) (\d+\.\d+)/
)
{
$bs
{"
m$1 b$2 f$3
"}{'
S_
ack
'}
=
$
4
+
0.0
;
elsif
(
$line
=~
/TIME m(\d+) b(\d+) f(\d+) (\d+\.\d+)/
)
{
$bs
{"
m$1 b$2 f$3
"}{'
S_
send
'}
=
$
4
+
0.0
;
++
$slc
;
}
}
...
...
@@ -145,12 +147,12 @@ foreach my $logtuple (@logs) {
open
(
RL
,"
$rlog
")
or
die
"
couldn't open
$rlog
!
";
while
(
$line
=
<
RL
>
)
{
if
(
$line
=~
/
^
TIME m(\d+) b(\d+) f(\d+) (\d+\.\d+)/
)
{
$bs
{"
m$1 b$2 f$3
"}{'
R_
recv
'}
=
$
4
+
0.0
;
if
(
$line
=~
/
ACK
TIME
: sent
m(\d+) b(\d+) f(\d+)
at
(\d+\.\d+)/
)
{
$bs
{"
m$1 b$2 f$3
"}{'
R_
ack
'}
=
$
4
+
0.0
;
++
$rlc
;
}
elsif
(
$line
=~
/
^ACKTIME: sent
m(\d+) b(\d+) f(\d+)
at
(\d+\.\d+)/
)
{
$bs
{"
m$1 b$2 f$3
"}{'
R_
ack
'}
=
$
4
+
0.0
;
elsif
(
$line
=~
/
TIME
m(\d+) b(\d+) f(\d+) (\d+\.\d+)/
)
{
$bs
{"
m$1 b$2 f$3
"}{'
R_
recv
'}
=
$
4
+
0.0
;
++
$rlc
;
}
}
...
...
@@ -158,7 +160,8 @@ foreach my $logtuple (@logs) {
debug
("
read
$mlc
,
$slc
,
$rlc
valid lines from
$logtuple
\n
");
$rtts
=
0
;
my
$rtts
=
0
;
my
$cryptotime_count
=
0
;
# try to figure out for each msg/block/frag chunk, the recv->send time,
# and how much of that time was compute time.
...
...
@@ -171,9 +174,13 @@ foreach my $logtuple (@logs) {
#debug("str = $str\n");
if
(
defined
(
$bs
{
$str
}{'
S_ack
'})
&&
defined
(
$bs
{
$str
}{'
S_send
'}))
{
#
oneway
time in microseconds
$tstats
{
$str
}{'
oneway
'}
=
int
((
$bs
{
$str
}{'
S_ack
'}
-
#
rtt, including cpu
time
,
in microseconds
$tstats
{
$str
}{'
rtt
'}
=
int
((
$bs
{
$str
}{'
S_ack
'}
-
$bs
{
$str
}{'
S_send
'})
*
1000000.0
);
# est oneway as rtt/2, then add back in half cputime.
$tstats
{
$str
}{'
oneway
'}
=
int
(((
$bs
{
$str
}{'
S_ack
'}
-
$bs
{
$str
}{'
S_send
'})
*
1000000.0
)
/
2
+
$bs
{
$str
}{'
M_cryptotime
'}
/
2
);
++
$rtts
;
...
...
@@ -182,11 +189,15 @@ foreach my $logtuple (@logs) {
# $tstats{$str}{'oneway'} = $bs{$str}{'R_recv'} -
# $bs{$str}{'S_send'};
debug
("
$str
oneway time =
"
.
$tstats
{
$str
}{'
oneway
'}
.
"
\n
");
debug
("
$str
rtt time =
"
.
$tstats
{
$str
}{'
rtt
'}
.
"
\n
");
#debug("s = ".$bs{$str}{'S_send'}."; r = ".$bs{$str}{'R_recv'}."\n");
}
if
(
defined
(
$bs
{
$str
}{'
M_cryptotime
'}))
{
$tstats
{
$str
}{'
cryptotime
'}
=
$bs
{
$str
}{'
M_cryptotime
'};
debug
("
$str
crypto time =
"
.
$tstats
{
$str
}{'
cryptotime
'}
.
"
\n
");
++
$cryptotime_count
;
}
else
{
$tstats
{
$str
}{'
cryptotime
'}
=
-
1
;
...
...
@@ -197,15 +208,33 @@ foreach my $logtuple (@logs) {
# print out compute time stats and recv->send time stats
# ugh.
# oneway
my
@ows
=
();
# rtt
my
@rws
=
();
# cpu
my
@cws
=
();
for
(
my
$i
=
0
;
$i
<
1000
;
++
$i
)
{
$ows
[
$i
]
=
0
;
$rws
[
$i
]
=
0
;
$cws
[
$i
]
=
0
;
}
foreach
my
$id
(
keys
(
%tstats
))
{
if
(
defined
(
$tstats
{
$id
}{'
oneway
'}))
{
my
$slot
=
int
(
$tstats
{
$id
}{'
oneway
'}
/
1000
);
++
(
$ows
[
$slot
]);
}
if
(
defined
(
$tstats
{
$id
}{'
rtt
'}))
{
my
$slot
=
int
(
$tstats
{
$id
}{'
rtt
'}
/
1000
);
++
(
$rws
[
$slot
]);
}
if
(
defined
(
$tstats
{
$id
}{'
cryptotime
'}))
{
my
$slot
=
int
(
$tstats
{
$id
}{'
cryptotime
'}
/
1000
);
++
(
$cws
[
$slot
]);
}
}
# then, once have times, print out a cdf of them:
...
...
@@ -213,9 +242,9 @@ foreach my $logtuple (@logs) {
# 1000000-line file. We'll do millisecond granularity.
# 2) for now, don't include failures?
my
$cdfdatfile
=
"
$outputdir
/
$basename
.onewaycdf.dat
";
open
(
CDFDAT
,"
>
$cdfdatfile
")
or
die
"
couldn't open
$cdfdatfile
!
";
my
$
oneway
cdfdatfile
=
"
$outputdir
/
$basename
.onewaycdf.dat
";
open
(
CDFDAT
,"
>
$
oneway
cdfdatfile
")
or
die
"
couldn't open
$
oneway
cdfdatfile
!
";
my
$cdf_counter
=
0
;
for
(
my
$i
=
0
;
$i
<
1000
;
++
$i
)
{
$cdf_counter
+=
$ows
[
$i
];
...
...
@@ -228,19 +257,46 @@ foreach my $logtuple (@logs) {
}
close
(
CDFDAT
);
my
$cryptotimesdatfile
=
"
$outputdir
/
$basename
.cryptotimes.dat
";
open
(
CRYPTODAT
,"
>
$cryptotimesdatfile
")
or
die
"
couldn't open
$cryptotimesdatfile
!
";
my
$i
=
0
;
for
(
my
$mi
=
0
;
$mi
<
$msg_count
;
++
$mi
)
{
for
(
my
$bi
=
0
;
$bi
<
$block_count
;
++
$bi
)
{
for
(
my
$fi
=
0
;
$fi
<
$frag_count
;
++
$fi
)
{
my
$str
=
"
m
$mi
b
$bi
f
$fi
";
print
CRYPTODAT
"
$i
"
.
$tstats
{
$str
}{'
cryptotime
'};
++
$i
;
}
my
$rttcdfdatfile
=
"
$outputdir
/
$basename
.rttcdf.dat
";
open
(
DAT
,"
>
$rttcdfdatfile
")
or
die
"
couldn't open
$rttcdfdatfile
!
";
$cdf_counter
=
0
;
for
(
my
$i
=
0
;
$i
<
1000
;
++
$i
)
{
$cdf_counter
+=
$rws
[
$i
];
print
DAT
"
$i
"
.
(
$cdf_counter
/
$block_count
*
100
)
.
"
\n
";
if
(
$cdf_counter
==
$rtts
)
{
last
;
}
}
close
(
DAT
);
my
$cpudatfile
=
"
$outputdir
/
$basename
.cpu.dat
";
open
(
CRYPTODAT
,"
>
$cpudatfile
")
or
die
"
couldn't open
$cpudatfile
!
";
# my $i = 0;
# for (my $mi = 0; $mi < $msg_count; ++$mi) {
# for (my $bi = 0; $bi < $block_count; ++$bi) {
# for (my $fi = 0; $fi < $frag_count; ++$fi) {
# my $str = "m$mi b$bi f$fi";
# print CRYPTODAT "$i " . $tstats{$str}{'cryptotime'};
# ++$i;
# }
# }
# }
$cdf_counter
=
0
;
for
(
my
$i
=
0
;
$i
<
1000
;
++
$i
)
{
$cdf_counter
+=
$cws
[
$i
];
print
CRYPTODAT
"
$i
"
.
(
$cdf_counter
/
$block_count
*
100
)
.
"
\n
";
if
(
$cdf_counter
==
$cryptotime_count
||
(
$cdf_counter
/
$block_count
*
100
)
==
100
)
{
last
;
}
}
close
(
CRYPTODAT
);
# generate gnuplot src files:
...
...
@@ -256,7 +312,67 @@ foreach my $logtuple (@logs) {
print
CDFGNP
"
set xlabel 'Deadline (ms)'
\n
";
print
CDFGNP
"
set key bottom right
\n
";
print
CDFGNP
"
plot
\\\n
";
print
CDFGNP
"
'
$cdfdatfile
' title
\"
graph
\"
with lines 2
\n
";
print
CDFGNP
"
'
$onewaycdfdatfile
' title
\"
oneway
\"
with lines 2
\n
";
# print CDFGNP "\n";
close
(
CDFGNP
);
# run gnuplot
system
("
gnuplot <
$file
");
$file
=
"
$outputdir
/
$basename
.rttcdf.gnp
";
$graphfile
=
"
$outputdir
/
$basename
.rttcdf.eps
";
open
(
CDFGNP
,"
>
$file
")
or
die
("
couldn't open
$file
!
");
print
CDFGNP
"
set terminal postscript eps
\n
";
print
CDFGNP
"
set output '
$graphfile
'
\n
";
print
CDFGNP
"
set yrange [0:]
\n
";
print
CDFGNP
"
set xrange [0:]
\n
";
print
CDFGNP
"
set ylabel 'Percent Complete'
\n
";
print
CDFGNP
"
set xlabel 'Deadline (ms)'
\n
";
print
CDFGNP
"
set key bottom right
\n
";
print
CDFGNP
"
plot
\\\n
";
print
CDFGNP
"
'
$rttcdfdatfile
' title
\"
rtt
\"
with lines 2
\n
";
print
CDFGNP
"
\n
";
close
(
CDFGNP
);
# run gnuplot
system
("
gnuplot <
$file
");
# both oneway and rtt cdfs
$file
=
"
$outputdir
/
$basename
.bothcdf.gnp
";
my
$graphfile
=
"
$outputdir
/
$basename
.bothcdf.eps
";
open
(
CDFGNP
,"
>
$file
")
or
die
("
couldn't open
$file
!
");
print
CDFGNP
"
set terminal postscript eps
\n
";
print
CDFGNP
"
set output '
$graphfile
'
\n
";
print
CDFGNP
"
set yrange [0:]
\n
";
print
CDFGNP
"
set xrange [0:]
\n
";
print
CDFGNP
"
set ylabel 'Percent Complete'
\n
";
print
CDFGNP
"
set xlabel 'Deadline (ms)'
\n
";
print
CDFGNP
"
set key bottom right
\n
";
print
CDFGNP
"
plot
\\\n
";
print
CDFGNP
"
'
$onewaycdfdatfile
' title
\"
oneway
\"
with lines 2,
\\\n
";
# combining oneway and rtt graphs
print
CDFGNP
"
'
$rttcdfdatfile
' title
\"
rtt
\"
with lines 2
\n
";
# print CDFGNP "\n";
close
(
CDFGNP
);
# run gnuplot
system
("
gnuplot <
$file
");
$file
=
"
$outputdir
/
$basename
.cpu.gnp
";
$graphfile
=
"
$outputdir
/
$basename
.cpu.eps
";
open
(
CDFGNP
,"
>
$file
")
or
die
("
couldn't open
$file
!
");
print
CDFGNP
"
set terminal postscript eps
\n
";
print
CDFGNP
"
set output '
$graphfile
'
\n
";
print
CDFGNP
"
set yrange [0:]
\n
";
print
CDFGNP
"
set xrange [0:]
\n
";
print
CDFGNP
"
set ylabel 'Percent Complete'
\n
";
print
CDFGNP
"
set xlabel 'Deadline (ms)'
\n
";
print
CDFGNP
"
set key bottom right
\n
";
print
CDFGNP
"
plot
\\\n
";
print
CDFGNP
"
'
$cpudatfile
' title
\"
graph
\"
with lines 2
\n
";
# print CDFGNP "\n";
close
(
CDFGNP
);
...
...
Write
Preview
Supports
Markdown
0%
Try again
or
attach a new file
.
Attach a file
Cancel
You are about to add
0
people
to the discussion. Proceed with caution.
Finish editing this message first!
Cancel
Please
register
or
sign in
to comment