#!/usr/bin/perl
use Getopt::Long;
+use Term::ANSIColor;
+
GetOptions("pid=i" => \$pid,
"trace!" => \$trace,
- "nonet!" => \$nonet);
-
-# print "$pid\n";
-
-
-$subsys->{UNDEFINED} = 0;
-$subsys->{MDC} = 1;
-$subsys->{MDS} = 2;
-$subsys->{OSC} = 3;
-$subsys->{OST} = 4;
-$subsys->{CLASS} = 5;
-$subsys->{OBDFS} = 6;
-$subsys->{LLITE} = 7;
-$subsys->{RPC} = 8;
-$subsys->{EXT2OBD} = 9;
-$subsys->{PORTALS} = 10;
-$subsys->{SOCKNAL} = 11;
-$subsys->{QSWNAL} = 12;
-$subsys->{PINGER} = 13;
-$subsys->{FILTER} = 14;
-$subsys->{TRACE} = 15; # obdtrace, not to be confused with D_TRACE */
-$subsys->{ECHO} = 16;
-$subsys->{LDLM} = 17;
-$subsys->{LOV} = 18;
-$subsys->{GMNAL} = 19;
-$subsys->{PTLROUTER} = 20;
+ "silent!" => \$silent,
+ "rpctrace!" => \$rpctrace,
+ "nodlm!" => \$nodlm,
+ "dlm_ns=s" => \$dlm_ns,
+ "noclass!" => \$noclass,
+ "nonet!" => \$nonet,
+ "extract_start=s" => \$extract_start,
+ "extract_end=s" => \$extract_end);
+
+
+
+$subsys->{UNDEFINED} = 1 << 0;
+$subsys->{MDC} = 1 << 1;
+$subsys->{MDS} = 1 << 2;
+$subsys->{OSC} = 1 << 3;
+$subsys->{OST} = 1 << 4;
+$subsys->{CLASS} = 1 << 5;
+$subsys->{LOG} = 1 << 6;
+$subsys->{LLITE} = 1 << 7;
+$subsys->{RPC} = 1 << 8;
+$subsys->{MGMT} = 1 << 9;
+$subsys->{PORTALS} = 1 << 10;
+$subsys->{SOCKNAL} = 1 << 11;
+$subsys->{QSWNAL} = 1 << 12;
+$subsys->{PINGER} = 1 << 13;
+$subsys->{FILTER} = 1 << 14;
+$subsys->{PTLBD} = 1 << 15;
+$subsys->{ECHO} = 1 << 16;
+$subsys->{LDLM} = 1 << 17;
+$subsys->{LOV} = 1 << 18;
+$subsys->{GMNAL} = 1 << 19;
+$subsys->{PTLROUTER} = 1 << 20;
+$subsys->{COBD} = 1 << 21;
+$subsys->{OPENIBNAL} = 1 << 22;
$masks->{TRACE} = 1 << 0; # /* ENTRY/EXIT markers */
$masks->{ERROR} = 1 << 17; # /* CERROR} = ...) == CDEBUG} = D_ERROR, ...) */
$masks->{EMERG} = 1 << 18; # /* CEMERG} = ...) == CDEBUG} = D_EMERG, ...) */
$masks->{HA} = 1 << 19; # /* recovery and failover */
-
-
+$masks->{RPCTRACE} = 1 << 19; # /* recovery and failover */
sub extractpid
{
- $_ = shift;
+ $line = shift;
+# print "$_\n";
+ if ($line =~ /(\d+)\:(\d+)\:(\d+)\:(\d+\.\d+)\:(\d+)\:(\d+)\:.*/) {
+ return $6;
+ }
+}
+
+sub extracthostpid
+{
+ $line = shift;
# print "$_\n";
- /l. [0-9]* (.*)\):/;
- return $1;
+ if ($line =~ /(\d+)\:(\d+)\:(\d+)\:(\d+\.\d+)\:(\d+)\:(\d+)\:(\d+)\:.*/) {
+ return $7;
+ }
+}
+
+sub entering_rpc
+{
+ $_ = shift;
+ $entering_rpc = /Handling RPC/;
+ if($entering_rpc) {
+ $oldpid=$pid;
+ $pid = extractpid($_);
+ $leaving_rpc = 0;
+ }
+}
+
+sub leaving_rpc
+{
+ $_ = shift;
+ $leaving_rpc = /Handled RPC/;
+ if($leaving_rpc) {
+ $pid = $oldpid;
+ $entering_rpc = 0;
+ }
}
sub entering
sub getsubsys
{
my ($subsys, $mask) = split ":";
- return $subsys;
+ return hex($subsys);
}
sub getmask
{
my ($subsys, $mask) = split ":";
- return $mask;
+ return hex($mask);
}
-while (<STDIN>) {
+sub setcolor
+{
+ my $linemask = shift;
+ my $line = shift;
+ if ($linemask == $masks->{TRACE}) {
+ if(leaving($line)){
+ print color("yellow on_black");
+ } else {
+ print color("green on_black");
+ }
+ }
+ if ($linemask == $masks->{DLMTRACE}) {
+ print color("magenta on_black");
+ }
+ if ($linemask == $masks->{DLM}) {
+ print color("magenta on_black");
+ }
+ if ($linemask == $masks->{DENTRY}) {
+ print color("red on_black");
+ }
+}
+
+sub study_lock
+{
+ $_ = shift;
+ my $rc;
+
+ $rc = /completion callback handler START ns: (.*) lock: (.*) lrc: (.*) mode/;
+ if ($rc) {
+ $completion_callbacks{$1}->{$2} = $3;
+# print color("white");
+# print "---CP CB START: $1 $2 $3\n";
+# print color("reset");
+ }
+ $rc = /callback handler finished.* ns: (.*) lock: (.*) lrc: (.*) mode/;
+ if ($rc) {
+# print color("white");
+# print "---CP CB END: $1 $2 $3 deleting $completion_callbacks{$1}->{$2}\n";
+# print color("reset");
+ delete $completion_callbacks{$1}->{$2};
+ }
+
+ if ($rc) {
+ $rc = /client blocking AST callback handler START ns: (.*) lock: (.*) lrc: (.*) mode/;
+ $blocking_callbacks{$1}->{$2} = $3;
+# print color("white");
+# print "---BL CB START: $1 $2\n";
+# print color("reset");
+ }
+ $rc = /client blocking callback handler END ns: (.*) lock: (.*) lrc: (.*) mode/;
+ if ($rc) {
+# print color("white");
+# print "---BL CB END: $1 $2 $3 deleting $blocking_callbacks{$1}->{$2}\n";
+# print color("reset");
+ delete $blocking_callbacks{$1}->{$2};
+ }
+
+ $rc = /ldlm_lock_addref.*ns: (.*) lock: (.*) lrc: (.*) mode/;
+# print color("white");
+# print "------>addref ns: $1 lock: $2 lrc: $3\n" if ($rc);
+# print color("reset");
+ $locks{$1}->{$2} = {$3} if ($rc);
+ $rc = /ldlm_lock_decref.*ns: (.*) lock: (.*) lrc: (.*) mode/;
+# print color("white");
+# print "------>decref ns: $1 lock: $2 lrc: $3\n" if ($rc);
+# print color("reset");
+ $locks{$1}->{$2} = {$3} if ($rc);
+}
+
+sub hanging_locks
+{
+ my $found;
+ my $ns;
+
+ foreach (keys %completion_callbacks) {
+ $ns = $_;
+ $found = 0;
+ foreach (keys %{$completion_callbacks{$ns}}) {
+ if (!$found) {
+ print "Unfinished completions in ns $ns: \n";
+ $found =1;
+ }
+ print " lock: $_ lrc: $completion_callbacks{$ns}->{$_}\n";
+ }
+ }
+ foreach (keys %blocking_callbacks) {
+ $ns = $_;
+ $found = 0;
+ foreach (keys %{$blocking_callbacks{$ns}}) {
+ if (!$found) {
+ print "Unfinished blocking in ns $ns: \n";
+ $found =1;
+ }
+ printf(" lock: $_ lrc: %s\n", $blocking_callbacks{$ns}->{$_});
+ }
+ }
+
+}
+
+sub study_intent
+{
+ $_ = shift;
+ my $rc;
+
+ $rc = /D_IT UP dentry (.*) fsdata/;
+ delete $it{$1} if ($rc);
+ $rc = /D_IT DOWN dentry (.*) fsdata/;
+ $it{$1} = "yes" if ($rc);
+}
+
+sub unmatched_intents {
+ my $found;
+ foreach (keys %it) {
+ if (!$found) {
+ print "Unmatched intents: \n";
+ $found =1;
+ }
+ print " $_\n";
+ }
+}
+
+sub usage
+{
+ print "Usage : llanalyze LOGFILE\n";
+ exit;
+}
+
+if ($ARGV[0]) {
+ if(!open(LOG, "<$ARGV[0]")){
+ print "Cannot open $ARGV[0]\n";
+ exit;
+ }
+} else {
+ usage();
+}
+$width = 0;
+if ($ARGV[1]) {
+ $width = $ARGV[1];
+}
+
+print "nodlm $nodlm, nonet $nonet, trace $trace\n";
+print "pid: $pid, dlm_ns: $dlm_ns\n";
+print "extract_start: $extract_start\n";
+print "extract_end: $extract_end\n";
+while (<LOG>) {
+ if ($extract_start && $extract_start ne "LLANAYZE_FOUND") {
+ next if (index($_, $extract_start, 0) == -1);
+ $extract_start = "LLANAYZE_FOUND";
+ }
+
+ if ($extract_end) {
+ next if ($extract_end eq "LLANAYZE_FOUND");
+ if (index($_, $extract_end, 0) != -1) {
+ $extract_end = "LLANAYZE_FOUND";
+ }
+ }
+
$linepid = extractpid($_);
+ $linehpid = extracthostpid($_);
$linemask = getmask($_);
$linesubsys = getsubsys($_);
chop $prefix->{$linepid};
chop $prefix->{$linepid};
}
- if ( !$pid || $linepid == $pid) {
+
+ if ($linemask == $masks->{DENTRY}) {
+ study_intent($_);
+ }
+ if ($linemask == $masks->{DLMTRACE}) {
+ study_lock($_);
+ }
+
+ if ( !$pid || $linepid == $pid || $linehpid == $pid) {
+ next if (!$entering_rpc && $rpctrace && $linemask != $masks->{RPCTRACE});
next if ($trace && $linemask != $masks->{TRACE});
+ next if ($nodlm &&
+ ( $linesubsys == $subsys->{LDLM}));
+ next if ($dlm_ns &&
+ ( $linesubsys != $subsys->{LDLM}));
+ next if (($found_dlm_ns = index( $_, $dlm_ns, 0)) == -1);
+ next if ($noclass &&
+ ( $linesubsys == $subsys->{CLASS}));
next if ($nonet &&
( $linesubsys == $subsys->{RPC} ||
$linesubsys == $subsys->{NET} ||
$linesubsys == $subsys->{PORTALS} ||
$linesubsys == $subsys->{SOCKNAL} ||
$linesubsys == $subsys->{QSWNAL} ||
+ $linesubsys == $subsys->{OPENIBNAL} ||
$linesubsys == $subsys->{GMNAL}));
+ if(!$entering_rpc) {entering_rpc($_);}
+ if(!$leaving_rpc) {leaving_rpc($_);}
# printf "sub/mask: %s - %s\n", getsubsys($_), getmask($_);
-
- printf "%s%s", $prefix->{$linepid}, $_;
- last if $count++ > 100;
+ if (!$silent) {
+ setcolor($linemask, $_);
+ my $string = $prefix->{$linepid}.$_;
+ if($width){
+ $string = substr($string, 0, $width)."\n";
+ }
+ printf("%s", $string);
+ print color("reset");
+ }
+ # last if $count++ > 100;
}
if (entering($_)) {
$prefix->{$linepid} .= ' ';
}
}
+
+unmatched_intents();
+hanging_locks();
# printf "argv %s pid %d\n", $ARGV[0], extractpid($ARGV[0]);
git://git.whamcloud.com / fs / lustre-release.git / blobdiff