lustre/utils/llanalyze

   1 #!/usr/bin/perl
   2
   3 use Getopt::Long;
   4 use Term::ANSIColor;
   5
   6 GetOptions("pid=i" => \$pid,
   7            "trace!" => \$trace,
   8            "silent!" => \$silent,
   9            "rpctrace!" => \$rpctrace,
  10            "nodlm!" => \$nodlm,
  11            "noclass!" => \$noclass,
  12            "nonet!" => \$nonet);
  13
  14 print "pid: $pid, nodlm $nodlm nonet $nonet trace $trace\n";
  15
  16
  17 $subsys->{UNDEFINED} = 0;
  18 $subsys->{MDC} = 1;
  19 $subsys->{MDS} = 2;
  20 $subsys->{OSC} = 3;
  21 $subsys->{OST} = 4;
  22 $subsys->{CLASS} = 5;
  23 $subsys->{OBDFS} = 6;
  24 $subsys->{LLITE} = 7;
  25 $subsys->{RPC} = 8;
  26 $subsys->{EXT2OBD} = 9;
  27 $subsys->{PORTALS} = 10;
  28 $subsys->{SOCKNAL} = 11;
  29 $subsys->{QSWNAL} = 12;
  30 $subsys->{PINGER} = 13;
  31 $subsys->{FILTER} = 14;
  32 $subsys->{TRACE} = 15; # obdtrace, not to be confused with D_TRACE */
  33 $subsys->{ECHO} = 16;
  34 $subsys->{LDLM} = 17;
  35 $subsys->{LOV} = 18;
  36 $subsys->{GMNAL} = 19;
  37 $subsys->{PTLROUTER} = 20;
  38
  39
  40 $masks->{TRACE} = 1 << 0; # /* ENTRY/EXIT markers */
  41 $masks->{INODE} = 1 << 1; #
  42 $masks->{SUPER} = 1 << 2; #
  43 $masks->{EXT2} = 1 << 3; # /* anything from ext2_debug */
  44 $masks->{MALLOC} = 1 << 4; # /* print malloc, free information */
  45 $masks->{CACHE} = 1 << 5; # /* cache-related items */
  46 $masks->{INFO} = 1 << 6; # /* general information */
  47 $masks->{IOCTL} = 1 << 7; # /* ioctl related information */
  48 $masks->{BLOCKS} = 1 << 8; # /* ext2 block allocation */
  49 $masks->{NET} = 1 << 9; # /* network communications */
  50 $masks->{WARNING} = 1 << 10; #
  51 $masks->{BUFFS} = 1 << 11; #
  52 $masks->{OTHER} = 1 << 12; #
  53 $masks->{DENTRY} = 1 << 13; #
  54 $masks->{PORTALS} = 1 << 14; # /* ENTRY/EXIT markers */
  55 $masks->{PAGE} = 1 << 15; # /* bulk page handling */
  56 $masks->{DLMTRACE} = 1 << 16; #
  57 $masks->{ERROR} = 1 << 17; # /* CERROR} = ...) == CDEBUG} = D_ERROR, ...) */
  58 $masks->{EMERG} = 1 << 18; # /* CEMERG} = ...) == CDEBUG} = D_EMERG, ...) */
  59 $masks->{HA} = 1 << 19; # /* recovery and failover */
  60 $masks->{RPCTRACE} = 1 << 19; # /* recovery and failover */
  61
  62 sub extractpid
  63 {
  64     $line = shift;
  65 #    print "$_\n";
  66     if ($line =~ m/\(\) ([0-9]*)\+[0-9]*\):/) {
  67         return $1;
  68     }
  69     if ($line =~ m/\(\) ([0-9]*) \| [0-9]*\+[0-9]*\):/) {
  70         return $1;
  71     }
  72 }
  73
  74 sub extracthostpid
  75 {
  76     $line = shift;
  77 #    print "$_\n";
  78     if ($line =~ m/\(\) [0-9]* \| ([0-9]*)\+[0-9]*\):/) {
  79         return $1;
  80     }
  81 }
  82
  83 sub entering
  84 {
  85     $_ = shift;
  86     $entering = /Process entered/;
  87 }
  88
  89 sub leaving
  90 {
  91     $_ = shift;
  92     $entering = /Process leaving/;
  93 }
  94
  95 sub getsubsys
  96 {
  97     my ($subsys, $mask) = split ":";
  98     return hex($subsys);
  99 }
 100
 101 sub getmask
 102 {
 103     my ($subsys, $mask) = split ":";
 104     return hex($mask);
 105 }
 106
 107 sub setcolor
 108 {
 109     my $linemask = shift;
 110     if ($linemask == $masks->{TRACE}) {
 111         print color("yellow on_black");
 112     }
 113     if ($linemask == $masks->{DLMTRACE}) {
 114         print color("magenta on_black");
 115     }
 116     if ($linemask == $masks->{DLM}) {
 117         print color("magenta on_black");
 118     }
 119     if ($linemask == $masks->{DENTRY}) {
 120         print color("red on_black");
 121     }
 122 }
 123
 124 sub study_lock
 125 {
 126     $_ = shift;
 127     my $rc;
 128
 129     $rc = /completion callback handler START ns: (.*) lock: (.*) lrc: (.*) mode/;
 130     if ($rc) {
 131         $completion_callbacks{$1}->{$2} = $3;
 132 #         print color("white");
 133 #         print "---CP CB START: $1 $2 $3\n";
 134 #         print color("reset");
 135     }
 136     $rc = /callback handler finished.* ns: (.*) lock: (.*) lrc: (.*) mode/;
 137     if ($rc) {
 138 #         print color("white");
 139 #         print "---CP CB END: $1 $2 $3 deleting $completion_callbacks{$1}->{$2}\n";
 140 #         print color("reset");
 141         delete $completion_callbacks{$1}->{$2};
 142     }
 143
 144     if ($rc) {
 145         $rc = /client blocking AST callback handler START ns: (.*) lock: (.*) lrc: (.*) mode/;
 146         $blocking_callbacks{$1}->{$2} = $3;
 147 #         print color("white");
 148 #         print "---BL CB START: $1 $2\n";
 149 #         print color("reset");
 150     }
 151     $rc = /client blocking callback handler END ns: (.*) lock: (.*) lrc: (.*) mode/;
 152     if ($rc) {
 153 #         print color("white");
 154 #         print "---BL CB END: $1 $2 $3 deleting $blocking_callbacks{$1}->{$2}\n";
 155 #         print color("reset");
 156         delete $blocking_callbacks{$1}->{$2};
 157     }
 158
 159     $rc = /ldlm_lock_addref.*ns: (.*) lock: (.*) lrc: (.*) mode/;
 160 #     print color("white");
 161 #     print "------>addref ns: $1 lock: $2 lrc: $3\n" if ($rc);
 162 #     print color("reset");
 163     $locks{$1}->{$2} = {$3} if ($rc);
 164     $rc = /ldlm_lock_decref.*ns: (.*) lock: (.*) lrc: (.*) mode/;
 165 #     print color("white");
 166 #     print "------>decref ns: $1 lock: $2 lrc: $3\n" if ($rc);
 167 #     print color("reset");
 168     $locks{$1}->{$2} = {$3} if ($rc);
 169 }
 170
 171 sub hanging_locks
 172 {
 173     my $found;
 174     my $ns;
 175
 176     foreach (keys %completion_callbacks) {
 177         $ns = $_;
 178         $found = 0;
 179         foreach (keys %{$completion_callbacks{$ns}}) {
 180             if (!$found) {
 181                 print "Unfinished completions in ns $ns: \n";
 182                 $found =1;
 183             }
 184             print "  lock: $_ lrc: $completion_callbacks{$ns}->{$_}\n";
 185         }
 186     }
 187     foreach (keys %blocking_callbacks) {
 188         $ns = $_;
 189         $found = 0;
 190         foreach (keys %{$blocking_callbacks{$ns}}) {
 191             if (!$found) {
 192                 print "Unfinished blocking in ns $ns: \n";
 193                 $found =1;
 194             }
 195             printf("  lock: $_ lrc: %s\n", $blocking_callbacks{$ns}->{$_});
 196         }
 197     }
 198
 199 }
 200
 201 sub study_intent
 202 {
 203     $_ = shift;
 204     my $rc;
 205
 206     $rc = /D_IT UP dentry (.*) fsdata/;
 207     delete $it{$1} if ($rc);
 208     $rc = /D_IT DOWN dentry (.*) fsdata/;
 209     $it{$1} = "yes"  if ($rc);
 210 }
 211
 212 sub unmatched_intents {
 213     my $found;
 214     foreach (keys %it) {
 215         if (!$found) {
 216             print "Unmatched intents: \n";
 217             $found =1;
 218         }
 219         print "  $_\n";
 220     }
 221 }
 222
 223 while (<STDIN>) {
 224     $linepid = extractpid($_);
 225     $linehpid = extracthostpid($_);
 226     $linemask = getmask($_);
 227     $linesubsys = getsubsys($_);
 228
 229 #    printf "---> mask %x subsys %x\n", $linemask, $linesubsys;
 230
 231     if (leaving($_)) {
 232         chop $prefix->{$linepid};
 233         chop $prefix->{$linepid};
 234     }
 235
 236     if ($linemask == $masks->{DENTRY}) {
 237         study_intent($_);
 238     }
 239     if ($linemask == $masks->{DLMTRACE}) {
 240         study_lock($_);
 241     }
 242
 243     if ( !$pid || $linepid == $pid || $linehpid == $pid) {
 244         next if ($rpctrace && $linemask != $masks->{RPCTRACE});
 245         next if ($trace && $linemask != $masks->{TRACE});
 246
 247
 248         next if ($nodlm &&
 249                  (  $linesubsys == $subsys->{LDLM}));
 250         next if ($noclass &&
 251                  (  $linesubsys == $subsys->{CLASS}));
 252
 253         next if ($nonet &&
 254                  (  $linesubsys == $subsys->{RPC} ||
 255                     $linesubsys == $subsys->{NET} ||
 256                     $linesubsys == $subsys->{PORTALS} ||
 257                     $linesubsys == $subsys->{SOCKNAL} ||
 258                     $linesubsys == $subsys->{QSWNAL} ||
 259                     $linesubsys == $subsys->{GMNAL}));
 260
 261
 262 #        printf "sub/mask: %s - %s\n", getsubsys($_), getmask($_);
 263         if (!$silent) {
 264             setcolor($linemask);
 265             printf("%s%s", $prefix->{$linepid}, $_);
 266             print color("reset");
 267         }
 268             #        last if $count++ > 100;
 269     }
 270     if (entering($_)) {
 271         $prefix->{$linepid} .= '  ';
 272     }
 273 }
 274
 275
 276 unmatched_intents();
 277 hanging_locks();
 278 # printf "argv %s pid %d\n", $ARGV[0], extractpid($ARGV[0]);