X-Git-Url: https://git.whamcloud.com/?a=blobdiff_plain;f=lustre%2Futils%2Fllanalyze;h=0b5eb88394a650f42d0c2f046c1f3e7d8506d09e;hb=4c90aef2f0712d8da720f6a66cd09b88df7d0573;hp=5548f9b1b9c0472880dd15deb1b30f806d167c0a;hpb=7312616768bfed768ecc00ba20322c37568138d0;p=fs%2Flustre-release.git diff --git a/lustre/utils/llanalyze b/lustre/utils/llanalyze index 5548f9b..0b5eb88 100644 --- a/lustre/utils/llanalyze +++ b/lustre/utils/llanalyze @@ -8,33 +8,46 @@ GetOptions("pid=i" => \$pid, "silent!" => \$silent, "rpctrace!" => \$rpctrace, "nodlm!" => \$nodlm, + "dlm_ns=s" => \$dlm_ns, "noclass!" => \$noclass, - "nonet!" => \$nonet); - -print "pid: $pid, nodlm $nodlm nonet $nonet trace $trace\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; + "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->{LNET} = 1 << 10; +$subsys->{LND} = 1 << 11; +$subsys->{PINGER} = 1 << 12; +$subsys->{FILTER} = 1 << 13; +# /* 1<< 14 unused */ +$subsys->{ECHO} = 1 << 15; +$subsys->{LDLM} = 1 << 16; +$subsys->{LOV} = 1 << 17; +$subsys->{LQUOTA} = 1 << 18; +$subsys->{OSD} = 1 << 19; +$subsys->{LFSCK} = 1 << 20; +# /* 1<< 21 unused */ +# /* 1<< 22 unused */ +$subsys->{LMV} = 1 << 23; #/* b_new_cmd */ +# /* 1<< 24 unused */ +$subsys->{SEC} = 1 << 25; #/* upcall cache */ +$subsys->{GSS} = 1 << 26; #/* b_new_cmd */ +# /* 1<< 27 unused */ +$subsys->{MGC} = 1 << 28; +$usbsys->{MGS} = 1 << 29; +$subsys->{FID} = 1 << 30; #/* b_new_cmd */ +$subsys->{FLD} = 1 << 31; #/* b_new_cmd */ $masks->{TRACE} = 1 << 0; # /* ENTRY/EXIT markers */ @@ -45,26 +58,66 @@ $masks->{MALLOC} = 1 << 4; # /* print malloc, free information */ $masks->{CACHE} = 1 << 5; # /* cache-related items */ $masks->{INFO} = 1 << 6; # /* general information */ $masks->{IOCTL} = 1 << 7; # /* ioctl related information */ -$masks->{BLOCKS} = 1 << 8; # /* ext2 block allocation */ +$masks->{NETERROR} = 1 << 8; # /* network errors */ $masks->{NET} = 1 << 9; # /* network communications */ $masks->{WARNING} = 1 << 10; # $masks->{BUFFS} = 1 << 11; # $masks->{OTHER} = 1 << 12; # $masks->{DENTRY} = 1 << 13; # -$masks->{PORTALS} = 1 << 14; # /* ENTRY/EXIT markers */ +$masks->{NETTRACE} = 1 << 14; # /* ENTRY/EXIT markers */ $masks->{PAGE} = 1 << 15; # /* bulk page handling */ $masks->{DLMTRACE} = 1 << 16; # $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 */ +$masks->{RPCTRACE} = 1 << 20; # /* recovery and failover */ +$masks->{VFSTRACE} = 1 << 21; +$masks->{READA} = 1 << 22; #/* read-ahead */ +$masks->{MMAP} = 1 << 23; +$masks->{CONFIG} = 1 << 24; +$masks->{CONSOLE} = 1 << 25; +$masks->{QUOTA} = 1 << 26; +$masks->{SEC} = 1 << 27; +$masks->{LFSCK} = 1 << 28; +$masks->{HSM} = 1 << 29; sub extractpid { - $_ = shift; + $line = shift; +# print "$_\n"; + if ($line =~ /(\d+)\:(\d+)\:(\d+\.\d+)\:(\d+\.\d+)\:(\d+)\:(\d+)\:.*/) { + return $6; + } +} + +sub extracthostpid +{ + $line = shift; # print "$_\n"; - /\(\) ([0-9]*)\+[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 @@ -94,8 +147,13 @@ sub getmask sub setcolor { my $linemask = shift; + my $line = shift; if ($linemask == $masks->{TRACE}) { - print color("yellow on_black"); + if(leaving($line)){ + print color("yellow on_black"); + } else { + print color("green on_black"); + } } if ($linemask == $masks->{DLMTRACE}) { print color("magenta on_black"); @@ -113,14 +171,14 @@ sub study_lock $_ = shift; my $rc; - $rc = /completion callback handler START ns: (.*) lock: (.*) lrc: (.*) mode/; + $rc = /client-side enqueue returned a blocked.* 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/; + $rc = /client-side enqueue:.* ns: (.*) lock: (.*) lrc: (.*) mode/; if ($rc) { # print color("white"); # print "---CP CB END: $1 $2 $3 deleting $completion_callbacks{$1}->{$2}\n"; @@ -128,8 +186,8 @@ sub study_lock delete $completion_callbacks{$1}->{$2}; } + $rc = /client blocking AST callback handler ns: (.*) lock: (.*) lrc: (.*) mode/; 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"; @@ -207,8 +265,46 @@ sub unmatched_intents { } } -while () { +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 "rpctrace: $rpctrace\n"; +print "extract_start: $extract_start\n"; +print "extract_end: $extract_end\n"; +print "width: $width\n"; +while () { + 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($_); @@ -226,29 +322,32 @@ while () { study_lock($_); } - if ( !$pid || $linepid == $pid) { - next if ($rpctrace && $linemask != $masks->{RPCTRACE}); + if ( !$pid || $linepid == $pid || $linehpid == $pid) { + next if ($rpctrace && !$entering_rpc && $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->{GMNAL})); - + $linesubsys == $subsys->{LNET} || + $linesubsys == $subsys->{LND})); + if($rpctrace && !$entering_rpc) {entering_rpc($_);} + if($rpctrace && !$leaving_rpc) {leaving_rpc($_);} # printf "sub/mask: %s - %s\n", getsubsys($_), getmask($_); - if (!$silent) { - setcolor($linemask); - printf("%s%s", $prefix->{$linepid}, $_); + 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;