code drop for the trace facility of xcat

git-svn-id: https://svn.code.sf.net/p/xcat/code/xcat-core/trunk@11119 8638fb3e-16cb-4fca-ae20-7b5d299a9bcd
This commit is contained in:
daniceexi 2011-12-04 13:04:58 +00:00
parent 966eaadba0
commit 9931cd58a5
5 changed files with 505 additions and 45 deletions

View File

@ -0,0 +1,53 @@
#!/usr/bin/env perl
# IBM(c) 2007 EPL license http://www.eclipse.org/legal/epl-v10.html
package xCAT::Enabletrace;
use Filter::Util::Call;
our @ISA = qw(Exporter);
our @EXPORT_OK = qw(loadtrace filter);
sub loadtrace{
my (undef, $filename) = caller();
my (%args) = (
filename => $filename,
inside => 0,
lineno => 0,
);
filter_add(bless \%args);
}
sub filter {
my ($self) = @_;
my $line= filter_read();
$self->{lineno}++;
# deal with EOF/error first
if ($line<= 0) {
if ($self->{inside}) {
die "Do not find the END of the trace block. [$self->{filename}:$self->{lineno}]";
}
return $line;
}
if ($self->{inside}) {
if (/^\s*##\s*TRACE_BEGIN/ ) {
die "The trace block is nested. [$self->{filename}:$self->{lineno}]";
} elsif (/^\s*##\s*TRACE_END/) {
$self->{inside} = 0;
} else {
# remove the #.. at the begin of the line
s/^\s*#+//;
}
} elsif ( /^\s*##\s*TRACE_BEGIN/ ) {
$self->{inside} = 1;
} elsif ( /^\s*##\s*TRACE_END/ ) {
die "Do not see the BEGIN of the trace block. [$self->{filename}:$self->{lineno}]";
} elsif ( /^\s*##\s*TRACE_LINE/ ) {
s/^\s*##\s*TRACE_LINE//;
}
return $line;
}
1;

View File

@ -616,6 +616,8 @@ sub start_logging
$::LOG_FILE_HANDLE = \*LOGFILE;
$::LOG_FILE_NAME = $logfile;
# Make the file to be unbuffered
binmode( $::LOG_FILE_HANDLE, ":unix" );
# Print the program name and date to the top of the logfile
my $sdate = `/bin/date`;
chomp $sdate;

View File

@ -1,48 +1,152 @@
=head1 NAME
B<xcatdebug> - Starts the xCAT daemon (xcatd) in trace mode.
B<xcatdebug> - Enable or disable the trace facilities for xCAT.
B<xcatdebug> {B<levelnumber>}
B<xcatdebug> { [B<-f enable|disable> [B<-c configuration file | subroutine list>]] | [ B<-d enable |disable>]}
=head1 DESCRIPTION
The xcatdebug command starts the xcatd daemon in Perl Debug Trace mode. It is to be used for diagnosing xCAT problems. The trace outputs the paramters passed into the xcatd subroutines, listed in the tracefiles. The tracefiles are located in /opt/xcat/share/xcat/tools/tracelevel<levelnumber>. The amount of trace data collected varies with the levelnumber. levelnumber 0 being the least amount of trace and increasing with the number. You can add more tracelevel files to suit the problem being debugged.
xCAT offers two trace facilities to debug the xCAT:
You must have perl-Debug-Trace installed.
=over 3
Before running this command, you should stop xcatd on your system.
After running the command, you will have to kill all the xcatd processes and possibly the xcatdebug process.
Run ps -ef | grep xcatd and kill any processes
Run ps -ef | grep xcatdebug
=item *
B<Subroutine calling trace>
Display the calling trace for subroutine when it is called.
The trace message includes: The name of the called subroutine; The arguments which passed to the called subroutine; The calling stack of the subroutine. By default, the trace will be enabled to all the subroutines in the xcatd and plugin modules. The target subroutine can be configured by configuration file or through xcatdebug command line.
The flag B<-c> is used to specify the subroutine list for B<subroutine calling trace>, it can only work with B<-f>. The value of B<-c> can be a configuration file or a subroutine list.
B<configuration file>: a file contains multiple lines of B<SUBROUTINE_DEFINITION>
B<subroutine list>: B<SUBROUTINE_DEFINITION>|B<SUBROUTINE_DEFINITION>|...
B<SUBROUTINE_DEFINITION>: is the element for the B<-c> to specify the subroutine list.
The format of B<SUBROUTINE_DEFINITION>: [plugin](subroutine1,subroutine2,...)
If ignoring the [plugin], the subroutines in the () should be defined in the xcatd.
e.g. (daemonize,do_installm_service,do_udp_service)
Otherwise, the package name of the plugin should be specified.
e.g. xCAT::Utils(isMN,Version)
e.g. xCAT_plugin::DBobjectdefs(defls,process_request)
The trace log will be written to /var/log/xcat/subcallingtrace. The log file subcallingtrace will be backed up for each running of the B<xcatdebug -f enable>.
=item *
B<Commented trace log>
The trace log code is presented as comments in the code of xCAT. In general mode, it will be kept as comments. But in debug mode, it will be commented back as common code to display the trace log.
NOTE: This facility can be enabled by pass the B<ENABLE_TRACE_CODE=1> global variable when running the xcatd. e.g. ENABLE_TRACE_CODE=1 xcatd -f
This facility offers two formats for the trace log code:
=over 2
=item *
Trace section
## TRACE_BEGIN
# print "In the debug\n";
## TRACE_END
=item *
Trace in a single line
## TRACE_LINE print "In the trace line\n";
=back
The B<commented trace log> can be added in xcatd and plugin modules. But following section has been added into the BEGIN {} section of the target plugin module to enable the facility.
if (defined $ENV{ENABLE_TRACE_CODE}) {
use xCAT::Enabletrace qw(loadtrace filter);
loadtrace();
}
=back
=head1 OPTIONS
=over 6
=item B<levelnumber>
=item B<-f>
The levelnumber that will be run. This determines the filename of trace input
from /opt/xcat/share/xcat/tools/tracelevel<levelnumber>
Enable or disable the B<subroutine calling trace>.
=back
For B<enable>, if ignoring the B<-c> flag, all the subroutines in the xcatd and plugin modules will be enabled.
=head1 ENVIRONMENT VARIABLES
For B<disable>, all the subroutines which has been enabled by B<-f enable> will be disabled. B<-c> will be ignored.
=head1 EXAMPLES
=item B<-c>
Specify the configuration file or subroutine list.
=over 2
=item *
Run the xcatdebug routine with /opt/xcat/share/xcat/tools/tracelevel0 and output to the screen:
B<configuration file>: a file contains multiple lines of B<SUBROUTINE_DEFINITION>
e.g.
(plugin_command)
xCAT_plugin::DBobjectdefs(defls,process_request)
xCAT::DBobjUtils(getobjdefs)
=item *
B<subroutine list>: a string like B<SUBROUTINE_DEFINITION>|B<SUBROUTINE_DEFINITION>|...
e.g.
"(plugin_command)|xCAT_plugin::DBobjectdefs(defls,process_request)|xCAT::DBobjUtils(getobjdefs)"
=back
=item B<-d>
Enable or disable the B<commented trace log>.
Note: The xcatd will be restarted for the performing of B<-d>.
=back
=head1 EXAMPLES
=over 4
=item 1
Enable the B<subroutine calling trace> for all the subroutines in the xcatd and plugin modules.
B<xcatdebug> -f enable
=item 2
Enable the B<subroutine calling trace> for the subroutines configured in the /opt/xcat/share/xcat/tools/tracelevel0
B<xcatdebug> -f enable -c /opt/xcat/share/xcat/tools/tracelevel0
=item 3
Enable the B<subroutine calling trace> for the plugin_command in xcatd and defls,process_request in the xCAT_plugin::DBobjectdefs module.
B<xcatdebug> -f enable -c "xCAT_plugin::DBobjectdefs(defls,process_request)|(plugin_command)"
=item 4
Disable the B<subroutine calling trace> for all the subroutines which have been enabled by B<xcatdebug -f enable>.
B<xcatdebug> -f disable
=item 5
Enable the B<commented trace log>
B<xcatdebug> -d enable
=item 6
Enable both the B<subroutine calling trace> and B<commented trace log>
B<xcatdebug> -f enable -c /opt/xcat/share/xcat/tools/tracelevel0 -d enable
B<xcatdebug> I<0>
=item *
Run the xcatdebug routine with /opt/xcat/share/xcat/tools/tracelevel1 and output to /tmp/traceoutput:
B<xcatdebug> I<1> > /tmp/traceoutput 2>&1
=back

View File

@ -9,6 +9,13 @@ BEGIN
# Required when using DB2 as the xCAT database:
$ENV{'DB2INSTANCE'} = 'xcatdb';
$ENV{'EXTSHM'} = 'ON';
if (defined $ENV{ENABLE_TRACE_CODE}) {
use lib "$ENV{'XCATROOT'}/lib/perl";
use lib "/opt/xcat/lib/perl";
use xCAT::Enabletrace qw(loadtrace filter);
loadtrace();
}
}
# if AIX - make sure we include perl 5.8.2 in INC path.
@ -72,7 +79,7 @@ $XML::Simple::PREFERRED_PARSER='XML::Parser';
use xCAT::Table;
my $dbmaster;
use xCAT::ExtTab;
#use Data::Dumper;
use Data::Dumper;
use Getopt::Long;
use Sys::Syslog qw(:DEFAULT setlogsock);
openlog("xcatd",,"local4");
@ -700,6 +707,10 @@ unless ($pid_MON) {
}
$$progname="xcatd: SSL listener";
# Enable the signals for the subroutine calling trace
$SIG{NUM50} = \&enable_callingtrace;
$SIG{NUM51} = \&disable_callingtrace;
#setup signal in NotifHandler so that the cache can be updated
xCAT::NotifHandler::setup($$, $dbmaster);
@ -2000,3 +2011,210 @@ sub validate {
return 0;
}
# Enable the trace of subroutine calling.
# Replace the original subroutine with a trace added subroutine to output more debug trace
sub enable_callingtrace{
my $enableall = 0; # if $enableall=1, enable trace for all the functions of xcat
my @pluginfuncs = (); # function list that will be enabled for plugins
my @xcatdfuncs = (); # function list that will be enabled for xcatd
# Backup the trace log
my ($sec,$min,$hour,$mday,$mon,$year) = localtime();
$year -= 100;
$mon += 1;
my $time = sprintf "%02s%02s%02s%02s%02s%02s", $year, $mon, $mday, $hour, $min, $sec;
if (-e "/var/log/xcat/subcallingtrace") {
system("mv /var/log/xcat/subcallingtrace /var/log/xcat/subcallingtrace$time");
}
# Start the trace log
xCAT::MsgUtils->start_logging("subcallingtrace");
# Read the subroutine list from the configuration file
if (-f "/tmp/xcatcallingtrace.cfg") {
if (! open (FUNLIST, "</tmp/xcatcallingtrace.cfg")) {
xCAT::MsgUtils->message("SL", "Enable subroutine calling trace failed: cannot open /tmp/xcatcallingtrace.cfg");
xCAT::MsgUtils->stop_logging();
return 1;
}
my $cfg = <FUNLIST>;
chomp($cfg);
my @funlist;
if (-f $cfg) { # Specified a configuration file
if (! open (CFG, "<$cfg")) {
xCAT::MsgUtils->message("SL", "Enable subroutine calling trace failed: cannot open $cfg");
xCAT::MsgUtils->stop_logging();
return 1;
} else { # read the configuration file
while (<CFG>) {
push @funlist, $_;
}
close (CFG);
}
} else {
# Specified the function list
# The format of the function list should be package(func1,func2,...),package(func1,func2,...)
push @funlist, split /\|/, $cfg;
}
# Parse the function list
foreach (@funlist) {
if (/(.*::.*)\((.*)\)/) { # if the format is xCAT::plugin(f1,f2)
my $pkg = $1;
my @funcs = split /,/, $2;
foreach (@funcs) {
chomp;
s/^\s*//;
push @pluginfuncs, "\*".$pkg."::".$_;
}
} else { # if the format is f1,f2, only for the functions in the xcatd
s/^\s*\(//;
s/\)\s*$//;
my @funcs = split /,/;
foreach (@funcs) {
chomp;
s/^\s*//;
push @xcatdfuncs, "\*main::".$_;
}
}
}
close (FUNLIST);
} else {
$enableall = 1;
}
no strict 'refs';
my @debugfuns = ();
# Get the functions of xcatd
my $xcatdpath = $::XCATROOT."/sbin/xcatd";
if (! open (XCATDLINES, "<$xcatdpath")) {
xCAT::MsgUtils->message("SL", "Enable subroutine calling trace failed: cannot open $xcatdpath");
} else {
my @sub_in_xcatd;
# Get all the name of subroutines except the xxx_callingtrace
while (<XCATDLINES>) {
if (/^\s*sub\s+([^\s]*)/) {
if (! /enable_callingtrace|disable_callingtrace|add_callingtrace/) {
push @sub_in_xcatd, $1;
}
}
}
close(XCATDLINES);
# Get all the symbols from the %main:: space
foreach my $fun (keys %main::) {
my $symfun = $main::{$fun};
if (($symfun =~ /^\*/) # must be a symbol
&& *{$symfun}{CODE} # must be a subroutine
&& grep (/\Q$fun\E/, @sub_in_xcatd) # must be defined in the xcatd
&& ($enableall || grep (/\Q$symfun\E/, @xcatdfuncs))) { # all or configured in the configuration file
push @debugfuns, $symfun;
}
}
}
# Get the functions of xCAT plugins
foreach my $plugin (\%xCAT::, \%xCAT_plugin::) {
# Get the path of the plugins
my $path = "";
foreach (keys %$plugin) {
my $glob = $plugin->{$_};
if ($glob =~ /\*([^:]*)::/) {
$path = $::XCATROOT."/lib/perl/$1/";
last;
}
}
# For each plugin moduel, search the matched functions
foreach my $xcatplugin (keys %$plugin) {
if ($xcatplugin =~ /[^\*].*::$/) {
# get the subroutines in the plugin file
my $pluginfile = $xcatplugin;
$pluginfile =~ s/:://;
# Ignore to enable the trace for the subroutines in the MsgUtils
if ($pluginfile eq "MsgUtils") {
next;
}
my $module_file = $path.$pluginfile.".pm";
my @sub_in_pm = ();
if (-r $module_file) {
open (LINES, "<$module_file") or last;
while (<LINES>) {
if (/^\s*sub\s+([^\s]*)/) {
push @sub_in_pm, $1;
}
}
close (LINES);
}
# Search the symbol from the space of plugin
foreach my $fun (keys %{$plugin->{$xcatplugin}}) {
my $symfun = $plugin->{$xcatplugin}{$fun};
if ($symfun =~ /^\*/ # must be a symbol
&& *{$symfun}{CODE} # must be a subroutine
&& grep (/\Q$fun\E/, @sub_in_pm) # must be defined in the plugin modules
&& ($enableall || grep (/\Q$symfun\E/, @pluginfuncs))) { # all or configured in the configuration file
push @debugfuns, $symfun;
}
}
}
}
}
# return a new subroutine with some debug code to output the trace log
# and calling the original subroutine at the last
sub add_callingtrace {
my ($funname, $orig) = @_;
sub {
my $args = Dumper(@_);
#$args =~ s{\A\$VAR\d+\s*=\s*}{};
my $callstack = Carp::longmess;
# write the trace log to the trace file
print $::LOG_FILE_HANDLE "\n***************Calling of subroutine $funname***************\n";
print $::LOG_FILE_HANDLE localtime()."\n";
print $::LOG_FILE_HANDLE "Arguments: \n$args\n";
print $::LOG_FILE_HANDLE "Calling stack: \n $callstack\n";
&$orig;
};
}
# Replace the original subroutine with a trace log added one
print $::LOG_FILE_HANDLE "##########Enabled the calling trace for: ###########\n";
foreach my $debugfun (@debugfuns) {
print $::LOG_FILE_HANDLE " $debugfun\n";
if (defined ($::DEBUG_FUN{"$debugfun"}{'debug'})) {
# if the trace added subroutine has been defined
*{"$debugfun"} = $::DEBUG_FUN{"$debugfun"}{'debug'};
#print " => $::DEBUG_FUN{$debugfun}{debug}\n";
} else {
my $oldfun = *{$debugfun}{CODE};
# Bakcup the original subroutine
$::DEBUG_FUN{"$debugfun"}{'orig'} = $oldfun;
#print "$debugfun".": $::DEBUG_FUN{$debugfun}{orig}";
# otherise creating a trace added subroutine from scratch
*{"$debugfun"} = add_callingtrace($debugfun, $oldfun);
$::DEBUG_FUN{"$debugfun"}{'debug'} = *{"$debugfun"}{CODE};
#print " => $::DEBUG_FUN{$debugfun}{debug}\n";
}
}
print $::LOG_FILE_HANDLE "####################################################\n";
}
# Go through all the trace log added subroutines, replace it with the original one
sub disable_callingtrace {
no strict 'refs';
print $::LOG_FILE_HANDLE "##########Disabled the calling trace for: ##########\n" if ($::LOG_FILE_HANDLE);
foreach my $glob (keys %::DEBUG_FUN) {
if (defined $::DEBUG_FUN{$glob}{'orig'}) {
*{"$glob"} = $::DEBUG_FUN{$glob}{'orig'};
print $::LOG_FILE_HANDLE "$glob\n";
#print "$glob".": => $::DEBUG_FUN{$glob}{orig}\n";
}
}
print $::LOG_FILE_HANDLE "####################################################\n" if ($::LOG_FILE_HANDLE);
xCAT::MsgUtils->stop_logging();
}

View File

@ -1,24 +1,107 @@
#!/bin/sh
#!/usr/bin/env perl
# IBM(c) 2007 EPL license http://www.eclipse.org/legal/epl-v10.html
#-------------------------------------------------------------------------------
#=head1 xcatdebug
# To run: xcatdebug 0 where 0 is the number of the tracelevel (0,1)
#=head2 xcatdebug provides a debug trace of the xcatd daemon.
# Perl Debug::Trace must be installed from the xcat deps package
# Shutdown xcatd
# Link /opt/xcat/share/xcat/tools/tracelevel to the traceleve* file you
# wish to use
# run xcatdebug > /mydir/myoutput file or just to STDOUT
# To stop ctl-C, you may have to kill processes after
# ps -ef |grep xcatd, kill the listener process, it should stop the
# other xcatd processes
# 7405808 8454216 0 10:04:37 pts/1 0:03 xcatd: SSL listener
# You may also have to kill the xcatdebug process, check for it.
#
#=cut
#-------------------------------------------------------------------------------
export PERL5DEBUGTRACE=":warn:indent(2):nomaxdepth:quotekeys"
echo "running:perl -MDebug::Trace=`cat /opt/xcat/share/xcat/tools/tracelevel$1` /opt/xcat/sbin/xcatd -f"
perl -MDebug::Trace=`cat /opt/xcat/share/xcat/tools/tracelevel$1` /opt/xcat/sbin/xcatd -f
exit 0
# This command can be used to
# 1. Enable/Disbale the subroutine calling trace.
# 2. Enable the commented trace log inside a subroutine.
# The example of -c
# (daemonize,do_installm_service,do_udp_service)|xCAT::Utils(isMN,Version)|xCAT_plugin::DBobjectdefs(defls,process_request)
# If specifying a file
# (daemonize,do_installm_service,do_udp_service)
# xCAT::Utils(isMN,Version)
# xCAT_plugin::DBobjectdefs(defls,process_request)
#
# Following three lines need to be added to enable the capability of commented trace
#if (defined $ENV{ENABLE_TRACE_CODE}) {
# use xCAT::Enabletrace qw(loadtrace filter);
# loadtrace();
#}
#The commented trace can be two formats:
#1. trace section
# ## TRACE_BEGIN
# # print "In the debug\n";
# ## TRACE_END
#2. trace in single line
# ## TRACE_LINE print "In the trace line\n";
use Getopt::Long;
my $usage = "xcatdebug { [-f enable|disable [-c configuration file | subroutine list]] | [ -d enable |disable]}
-f: enable or disable the subroutine calling trace
-c: configure the subroutine list
configuration file: a file contains multiple lines of <SUBROUTINE_DEFINITION>
subroutine list: SUBROUTINE_DEFINITION|SUBROUTINE_DEFINITION|...
SUBROUTINE_DEFINITION: [plugin](subroutine1,subroutine2,...)
e.g. (daemonize,do_installm_service,do_udp_service)
e.g. xCAT::Utils(isMN,Version)
e.g. xCAT_plugin::DBobjectdefs(defls,process_request)
-d: enable or disable the commented trace log inside a subroutine\n";
Getopt::Long::Configure("bundling");
Getopt::Long::Configure("no_pass_through");
if (
!GetOptions(
'f=s' => \$::FUNC,
'c=s' => \$::CONFIG,
'd=s' => \$::DEBUG,)) {
print "$usage";
exit 1;
}
if (!($::FUNC || $::DEBUG)) {
print "$usage";
exit 1;
}
# The action that enable the commented debug log should be done firstly
# In this case the xcatd need to be restart
if (defined($::DEBUG)) {
if ($::DEBUG eq "enable") {
`XCATRELOAD=yes ENABLE_TRACE_CODE=1 xcatd -p /var/run/xcatd.pid`;
print "Enabled the commented trace log.\n";
} elsif ($::DEBUG eq "disable") {
`XCATRELOAD=yes xcatd -p /var/run/xcatd.pid`;
print "Disabled the commented trace log.\n";
} else {
print "$usage";
exit 1;
}
}
if (defined($::FUNC)) {
# Get the pid of xcatd
my $pid;
if (-e "/var/run/xcatd.pid") {
open (PID, "</var/run/xcatd.pid") or die "Cannot open /var/run/xcatd.pid\n";
$pid = <PID>;
close (PID);
} elsif ($pid = `ps -ef | grep 'xcatd: SSL listener' | grep -v 'grep' | awk '{print \$2}'`) {
} else {
die "Cannot find the pid in the /var/run/xcatd.pid\n";
}
if ($::FUNC eq "enable") {
# Enable the function trace
if (defined $::CONFIG) {
open(CFG, ">/tmp/xcatcallingtrace.cfg") or die "Cannot open /tmp/xcatcallingtrace.cfg\n";
print CFG $::CONFIG;
close (CFG);
} else {
unlink "/tmp/xcatcallingtrace.cfg";
}
kill 50, $pid;
print "Enabled the subroutine calling trace.\n";
} elsif ($::FUNC eq "disable") {
kill 51, $pid;
print "Disabled the subroutine calling trace.\n";
} else {
print "$usage";
exit 1;
}
print " Get the trace log from the /var/log/xcat/subcallingtrace\n";
}
0