diff --git a/perl-xCAT/xCAT/MsgUtils.pm b/perl-xCAT/xCAT/MsgUtils.pm index 0e9cd3028..6c0dd48cc 100644 --- a/perl-xCAT/xCAT/MsgUtils.pm +++ b/perl-xCAT/xCAT/MsgUtils.pm @@ -740,5 +740,86 @@ sub verbose_message xCAT::MsgUtils->message("I", $data); } } + +#-------------------------------------------------------------------------------- + +=head3 trace + + Display different level trace message in syslog. + + Arguments: + $verbose: indicate whether current command is with -V option. 1 is yes and 0 is no. + $level: the level of trace message, can be one of "I","W","E","D","i","w","e","d". + "I" or "i": means information level. + "W" or "w": means warning level. + "E" or "e": means error level. + "D" or "d": means debug level. + + As long as the trace subroutine is called, "information", "warning" and "error" level message will be displayed in syslog. + The "debug" level message is displayed in syslog only when any one of the below two conditions is true + 1. The current command with -V option. i.e. $verbose=1. + 2. The xcatdebugmode, which is an attribute of site table, equals 1. + + If $level is not any one of "I","W","E","D","i","w","e","d", the trace subroutine do nothing. + + $logcontent: the specific message wanted to be displayed in syslog + Returns: + none + + Error: + none + + Note: + Label "xcat" and trace message level, such as "INFO", "ERR", "WARNING" AND "DEBUG", will be added before real trace message automatically. It's convenient to filter in syslog. + + Example: + xCAT::MsgUtils->trace(1,"D","this is debug trace message"); + xCAT::MsgUtils->trace(0,"i","this is information trace message"); + xCAT::MsgUtils->trace(0,"E","this is error trace message"); +=cut + +#-------------------------------------------------------------------------------- +sub trace(){ + shift; + my $verbose = shift; + my $level = shift; + my $logcontent = shift; + + my $prefix = ""; + if(($level eq "E")||($level eq "e")){$prefix="ERR";} + if(($level eq "W")||($level eq "w")){$prefix="WARNING";} + if(($level eq "I")||($level eq "i")){$prefix="INFO";} + if(($level eq "D")||($level eq "d")){$prefix="DEBUG";} + + my @tmp = xCAT::TableUtils->get_site_attribute("xcatdebugmode"); + my $xcatdebugmode=$tmp[0]; + + if (($level eq "E") + ||($level eq "e") + ||($level eq "I") + ||($level eq "i") + ||($level eq "W") + ||($level eq "w")){ + my $msg = $prefix." ".$logcontent; + eval { + openlog("xcat", "nofatal,pid", "local4"); + syslog("$prefix", $msg); + closelog(); + }; + } + + if (($level eq "D") + ||($level eq "d")){ + if(($verbose == 1 )||($xcatdebugmode eq "1")){ + my $msg = $prefix." ".$logcontent; + eval { + openlog("xcat", "nofatal,pid", "local4"); + syslog("$prefix", $msg); + closelog(); + } + } + } +} + 1; diff --git a/perl-xCAT/xCAT/Schema.pm b/perl-xCAT/xCAT/Schema.pm index a79a792fc..7fb5347e6 100755 --- a/perl-xCAT/xCAT/Schema.pm +++ b/perl-xCAT/xCAT/Schema.pm @@ -1207,6 +1207,7 @@ site => { " Value must be less than xcatmaxconnections. Default is 50.\n\n". " xcatdport: The port used by the xcatd daemon for client/server communication.\n\n". " xcatiport: The port used by xcatd to receive install status updates from nodes.\n\n". + " xcatlport: The port used by xcatd command log writer process to collect command output.\n\n". " xcatsslversion: The ssl version by xcatd. Default is SSLv3.\n\n". " xcatsslciphers: The ssl cipher by xcatd. Default is 3DES.\n\n", value => 'The value of the attribute specified in the "key" column.', diff --git a/xCAT-server/lib/xcat/plugins/anaconda.pm b/xCAT-server/lib/xcat/plugins/anaconda.pm old mode 100755 new mode 100644 index c9ce10bed..f348d0026 --- a/xCAT-server/lib/xcat/plugins/anaconda.pm +++ b/xCAT-server/lib/xcat/plugins/anaconda.pm @@ -952,6 +952,20 @@ sub mkinstall $installroot = "/install"; $globaltftpdir = "/tftpboot"; + #>>>>>>>used for trace log start>>>>>>> + my @args=(); + my %opt; + if (ref($request->{arg})) { + @args=@{$request->{arg}}; + } else { + @args=($request->{arg}); + } + @ARGV = @args; + GetOptions('V' => \$opt{V}); + my $verbose_on_off=0; + if($opt{V}){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + #if ($sitetab) #{ # (my $ref) = $sitetab->getAttribs({key => 'installdir'}, 'value'); @@ -961,6 +975,7 @@ sub mkinstall { $installroot = $site_ent; } + #( $ref) = $sitetab->getAttribs({key => 'tftpdir'}, 'value'); @ents = xCAT::TableUtils->get_site_attribute("tftpdir"); $site_ent = $ents[0]; @@ -968,6 +983,7 @@ sub mkinstall { $globaltftpdir = $site_ent; } + xCAT::MsgUtils->trace($verbose_on_off,"d","anaconda->mkinstall: installroot=$installroot globaltftpdir=$globaltftpdir"); #} my $node; @@ -1034,7 +1050,7 @@ sub mkinstall } else { $xcatmaster = '!myipfn!'; } - + my $osinst; if ($rents{$node}->[0] and $rents{$node}->[0]->{tftpdir}) { $tftpdir = $rents{$node}->[0]->{tftpdir}; @@ -1042,6 +1058,10 @@ sub mkinstall $tftpdir = $globaltftpdir; } my $ent = $osents{$node}->[0]; #$ostab->getNodeAttribs($node, ['profile', 'os', 'arch']); + xCAT::MsgUtils->trace($verbose_on_off,"d","anaconda->mkinstall: xcatmaster=$xcatmaster tftpdir=$tftpdir provmethod=$ent->{provmethod}"); + + + if ($ent and $ent->{provmethod} and ($ent->{provmethod} ne 'install') and ($ent->{provmethod} ne 'netboot') and ($ent->{provmethod} ne 'statelite')) { $imagename=$ent->{provmethod}; #print "imagename=$imagename\n"; @@ -1152,9 +1172,11 @@ sub mkinstall } $pkglistfile=$ph->{pkglist}; - $netdrivers = $ph->{netdrivers}; - $driverupdatesrc = $ph->{driverupdatesrc}; - $osupdir = $ph->{'osupdir'}; + $netdrivers = $ph->{netdrivers}; + $driverupdatesrc = $ph->{driverupdatesrc}; + $osupdir = $ph->{'osupdir'}; + + xCAT::MsgUtils->trace($verbose_on_off,"d","anaconda->mkinstall: imagename=$imagename pkgdir=$pkgdir pkglistfile=$pkglistfile tmplfile=$tmplfile partfile=$partfile"); } else { $os = $ent->{os}; @@ -1184,6 +1206,8 @@ sub mkinstall #get the partition file from the linuximage table my $imgname = "$os-$arch-install-$profile"; + xCAT::MsgUtils->trace($verbose_on_off,"d","anaconda->mkinstall: imagename=$imgname pkgdir=$pkgdir pkglistfile=$pkglistfile tmplfile=$tmplfile"); + if ( ! $linuximagetab ) { $linuximagetab = xCAT::Table->new('linuximage'); } @@ -1192,6 +1216,7 @@ sub mkinstall (my $ref1) = $linuximagetab->getAttribs({imagename => $imgname}, 'partitionfile'); if ( $ref1 and $ref1->{'partitionfile'}){ $partfile = $ref1->{'partitionfile'}; + xCAT::MsgUtils->trace($verbose_on_off,"d","anaconda->mkinstall: partfile = $partfile"); } } #can not find the linux osiamge object, tell users to run "nodeset osimage=***" @@ -1366,6 +1391,7 @@ sub mkinstall &insert_dd($callback, $os, $arch, "$tftppath/initrd.img", "$tftppath/vmlinuz", $driverupdatesrc, $netdrivers, $osupdir, $ignorekernelchk); } } + xCAT::MsgUtils->trace($verbose_on_off,"d","anaconda->mkinstall: copy initrd.img and vmlinuz to $tftppath"); } #We have a shot... @@ -1581,7 +1607,9 @@ sub mkinstall $k = "$rtftppath/vmlinuz"; $i = "$rtftppath/initrd.img"; } - + + xCAT::MsgUtils->trace($verbose_on_off,"d","anaconda->mkinstall: kcmdline=$kcmdline kernal=$k initrd=$i"); + $bptab->setNodeAttribs( $node, { diff --git a/xCAT-server/lib/xcat/plugins/debian.pm b/xCAT-server/lib/xcat/plugins/debian.pm old mode 100755 new mode 100644 index c23c99498..90a18bf7c --- a/xCAT-server/lib/xcat/plugins/debian.pm +++ b/xCAT-server/lib/xcat/plugins/debian.pm @@ -445,6 +445,20 @@ sub mkinstall { my $osimagetab; my %img_hash=(); + #>>>>>>>used for trace log start>>>>>>> + my @args=(); + my %opt; + if (ref($request->{arg})) { + @args=@{$request->{arg}}; + } else { + @args=($request->{arg}); + } + @ARGV = @args; + GetOptions('V' => \$opt{V}); + my $verbose_on_off=0; + if($opt{V}){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + my $installroot; $installroot = "/install"; if ($sitetab) @@ -455,7 +469,9 @@ sub mkinstall { $installroot = $ref->{value}; } } - + + xCAT::MsgUtils->trace($verbose_on_off,"d","debian->mkinstall: installroot=$installroot"); + my $node; my $ostab = xCAT::Table->new('nodetype'); my %donetftp; @@ -602,6 +618,8 @@ sub mkinstall { $pkgdir="$installroot/$os/$arch"; } $pkglistfile=$ph->{pkglist}; + + xCAT::MsgUtils->trace($verbose_on_off,"d","debian->mkinstall: imagename=$imagename pkgdir=$pkgdir pkglistfile=$pkglistfile tmplfile=$tmplfile"); } else { $os = $ent->{os}; @@ -622,6 +640,7 @@ sub mkinstall { } $pkgdir="$installroot/$os/$arch"; + xCAT::MsgUtils->trace($verbose_on_off,"d","debian->mkinstall: pkgdir=$pkgdir pkglistfile=$pkglistfile tmplfile=$tmplfile"); } if ($arch eq "x86_64") { @@ -880,6 +899,8 @@ sub mkinstall { $kcmdline .= " live-installer/net-image=http://${instserver}${pkgdir}/install/filesystem.squashfs"; } + xCAT::MsgUtils->trace($verbose_on_off,"d","debian->mkinstall: kcmdline=$kcmdline kernal=$rtftppath/vmlinuz initrd=$rtftppath/initrd.img"); + $bptab->setNodeAttribs($node, { kernel => "$rtftppath/vmlinuz", initrd => "$rtftppath/initrd.img", kcmdline => $kcmdline }); diff --git a/xCAT-server/lib/xcat/plugins/destiny.pm b/xCAT-server/lib/xcat/plugins/destiny.pm index a62d00abb..fd0525356 100755 --- a/xCAT-server/lib/xcat/plugins/destiny.pm +++ b/xCAT-server/lib/xcat/plugins/destiny.pm @@ -93,9 +93,17 @@ sub setdestiny { @ARGV = @{$req->{arg}}; my $noupdateinitrd; my $ignorekernelchk; + #>>>>>>>used for trace log>>>>>>> + my $verbose; GetOptions('noupdateinitrd' => \$noupdateinitrd, - 'ignorekernelchk' => \$ignorekernelchk,); - + 'ignorekernelchk' => \$ignorekernelchk, + 'V' => \$verbose); #>>>>>>>used for trace log>>>>>>> + + #>>>>>>>used for trace log start>>>>>>> + my $verbose_on_off=0; + if($verbose){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + my $state = $ARGV[0]; my $reststates; @@ -360,6 +368,7 @@ sub setdestiny { foreach my $tempstate (keys %state_hash1) { my $samestatenodes=$state_hash1{$tempstate}; #print "state=$tempstate nodes=@$samestatenodes\n"; + xCAT::MsgUtils->trace($verbose_on_off,"d","destiny->process_request: issue mk$tempstate request"); $errored=0; $subreq->({command=>["mk$tempstate"], node=>$samestatenodes, diff --git a/xCAT-server/lib/xcat/plugins/dhcp.pm b/xCAT-server/lib/xcat/plugins/dhcp.pm old mode 100755 new mode 100644 index 96ef87cf7..0fb5d45e2 --- a/xCAT-server/lib/xcat/plugins/dhcp.pm +++ b/xCAT-server/lib/xcat/plugins/dhcp.pm @@ -1020,7 +1020,9 @@ sub preprocess_request my $callback = shift; my $rc = 0; - + #>>>>>>>used for trace log>>>>>>> + my $verbose_on_off=0; + Getopt::Long::Configure("bundling"); $Getopt::Long::ignorecase = 0; Getopt::Long::Configure("no_pass_through"); @@ -1042,7 +1044,8 @@ sub preprocess_request 'n' => \$opt{n}, 'r' => \$opt{r}, 's=s' => \$statements, # $statements is declared globally - 'q' => \$opt{q} + 'q' => \$opt{q}, + 'V' => \$opt{V} #>>>>>>>used for trace log>>>>>>> )) { # If the arguements do not pass GetOptions then issue error message and return @@ -1052,9 +1055,13 @@ sub preprocess_request return 1; } + #>>>>>>>used for trace log>>>>>>> + if($opt{V}){ $verbose_on_off=1;} + # check the syntax $rc = check_options($req, \%opt,$callback); if ( $rc ) { + xCAT::MsgUtils->trace($verbose_on_off,"e","dhcp: command syntax error"); return []; } @@ -1064,6 +1071,7 @@ sub preprocess_request if (defined($t_entry)) { $snonly=$t_entry; } + xCAT::MsgUtils->trace($verbose_on_off,"d","dhcp: disjointdhcps=$t_entry"); my @requests=(); my $hasHierarchy=0; @@ -1132,7 +1140,11 @@ sub preprocess_request xCAT::MsgUtils->message("I", $rsp, $callback); } } - } + } + + #>>>>>>>used for trace log>>>>>>> + my $str_node=join(" ",@nodes); + xCAT::MsgUtils->trace($verbose_on_off,"d","dhcp: nodes are $str_node"); # If service node and not -n option if (($snonly == 1) && (!$opt{n})) { @@ -1193,6 +1205,8 @@ sub preprocess_request } } + xCAT::MsgUtils->trace($verbose_on_off,"d","dhcp: hasHierarchy=$hasHierarchy"); + if ( $hasHierarchy) { #hierarchy detected, enforce more rigorous sanity @@ -1228,6 +1242,9 @@ sub process_request my $rsp; #print Dumper($req); + #>>>>>>>used for trace log>>>>>>> + my $verbose_on_off=0; + Getopt::Long::Configure("bundling"); $Getopt::Long::ignorecase = 0; Getopt::Long::Configure("no_pass_through"); @@ -1247,7 +1264,8 @@ sub process_request 'n' => \$opt{n}, 'r' => \$opt{r}, 's=s' => \$statements, # $statements is declared globally - 'q' => \$opt{q} + 'q' => \$opt{q}, + 'V' => \$opt{V} #>>>>>>>used for trace log>>>>>>> )) { # If the arguements do not pass GetOptions then issue error message and return @@ -1257,12 +1275,15 @@ sub process_request return 1; } - + #>>>>>>>used for trace log>>>>>>> + if($opt{V}){ $verbose_on_off=1;} + # Check options again in case we are called from plugin and options have not been processed my $rc = 0; $rc = check_options($req, \%opt,$callback); if ( $rc ) { + xCAT::MsgUtils->trace($verbose_on_off,"e","dhcp: there is invalid option in command"); return []; } @@ -1293,6 +1314,7 @@ sub process_request } if($isok == 0) { #do nothing if it is a service node, but not dhcpserver + xCAT::MsgUtils->trace($verbose_on_off,"d","dhcp: it is a service node, but not dhcpserver. Do nothing"); print "Do nothing\n"; return; } @@ -1386,7 +1408,9 @@ sub process_request # return; } else { $site_domain = $t_entry; - } + } + + xCAT::MsgUtils->trace($verbose_on_off,"d","dhcp: sitelogservers=$sitelogservers sitentpservers=$sitentpservers sitenameservers=$sitenameservers site_domain=$site_domain"); } @dhcpconf = (); @@ -1397,6 +1421,7 @@ sub process_request flock($dhcplockfd,LOCK_EX); if ($::XCATSITEVALS{externaldhcpservers}) { # do nothing if remote dhcpservers at this point + xCAT::MsgUtils->trace($verbose_on_off,"d","dhcp: remote dhcpservers at this point, do nothing"); } elsif ($opt{n}) { if (-e $dhcpconffile) { if ($^O eq 'aix') { @@ -1426,10 +1451,12 @@ sub process_request my $bakname = "$dhcpconffile.xcatbak"; rename("$dhcpconffile", $bakname); + xCAT::MsgUtils->trace($verbose_on_off,"d","dhcp: Renamed existing dhcp configuration file to $dhcpconffile.xcatbak"); } } else { + xCAT::MsgUtils->trace($verbose_on_off,"d","dhcp: load dhcp config file $dhcpconffile"); my $rconf; open($rconf, $dhcpconffile); # Read file into memory if ($rconf) @@ -1920,6 +1947,7 @@ sub process_request } writeout(); if (not $::XCATSITEVALS{externaldhcpservers} and $restartdhcp) { + xCAT::MsgUtils->trace($verbose_on_off,"d","dhcp: restart dhcp service"); if ( $^O eq 'aix') { restart_dhcpd_aix(); diff --git a/xCAT-server/lib/xcat/plugins/grub2.pm b/xCAT-server/lib/xcat/plugins/grub2.pm index 5aea7433e..018566e0f 100644 --- a/xCAT-server/lib/xcat/plugins/grub2.pm +++ b/xCAT-server/lib/xcat/plugins/grub2.pm @@ -341,9 +341,15 @@ sub preprocess_request { @ARGV = @args; my $nodes = $req->{node}; #use Getopt::Long; + my $HELP; + my $VERSION; + my $VERBOSE; Getopt::Long::Configure("bundling"); Getopt::Long::Configure("pass_through"); - if (!GetOptions('h|?|help' => \$HELP, 'v|version' => \$VERSION) ) { + if (!GetOptions('h|?|help' => \$HELP, + 'v|version' => \$VERSION, + 'V' => \$VERBOSE #>>>>>>>used for trace log>>>>>>> + ) ) { if($usage{$command}) { my %rsp; $rsp{data}->[0]=$usage{$command}; @@ -352,6 +358,11 @@ sub preprocess_request { return; } + #>>>>>>>used for trace log start>>>>>> + my $verbose_on_off=0; + if($VERBOSE){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + if ($HELP) { if($usage{$command}) { my %rsp; @@ -384,6 +395,8 @@ sub preprocess_request { my @entries = xCAT::TableUtils->get_site_attribute("sharedtftp"); my $t_entry = $entries[0]; + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: sharedtftp=$t_entry"); + if ( defined($t_entry) and ($t_entry eq "0" or $t_entry eq "no" or $t_entry eq "NO")) { # check for computenodes and servicenodes from the noderange, if so error out my @SN; @@ -423,6 +436,20 @@ sub process_request { my @args; my @nodes; my @rnodes; + + #>>>>>>>used for trace log start>>>>>>> + my %opt; + my $verbose_on_off=0; + if (ref($::XNBA_request->{arg})) { + @args=@{$::XNBA_request->{arg}}; + } else { + @args=($::XNBA_request->{arg}); + } + @ARGV = @args; + GetOptions('V' => \$opt{V}); + if($opt{V}){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + if (ref($request->{node})) { @rnodes = @{$request->{node}}; } else { @@ -448,7 +475,11 @@ sub process_request { } else { @nodes = @rnodes; } - + + #>>>>>>>used for trace log>>>>>>> + my $str_node = join(" ",@nodes); + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: nodes are $str_node"); + # return directly if no nodes in the same network unless (@nodes) { xCAT::MsgUtils->message("S", "xCAT: grub2 netboot: no valid nodes. Stop the operation on this server."); @@ -465,11 +496,15 @@ sub process_request { unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') { $errored=0; if ($request->{'_disparatetftp'}->[0]) { #the call is distrubuted to the service node already, so only need to handles my own children - $sub_req->({command=>['runbeginpre'], + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: the call is distrubuted to the service node already, so only need to handles my own children"); + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: issue runbeginpre request"); + $sub_req->({command=>['runbeginpre'], node=>\@nodes, arg=>[$args[0], '-l']},\&pass_along); } else { #nodeset did not distribute to the service node, here we need to let runednpre to distribute the nodes to their masters - $sub_req->({command=>['runbeginpre'], + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: nodeset did not distribute to the service node"); + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: issue runbeginpre request"); + $sub_req->({command=>['runbeginpre'], node=>\@rnodes, arg=>[$args[0]]},\&pass_along); } @@ -488,7 +523,8 @@ sub process_request { if (!$inittime) { $inittime=0;} $errored=0; unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') { - $sub_req->({command=>['setdestiny'], + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: issue setdestiny request"); + $sub_req->({command=>['setdestiny'], node=>\@nodes, inittime=>[$inittime], arg=>\@args},\&pass_along); @@ -594,9 +630,11 @@ sub process_request { } if ($do_dhcpsetup) { if ($request->{'_disparatetftp'}->[0]) { #reading hint from preprocess_command + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=>\@{$osimagenodehash{$osimage}}}, $callback); } else { + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=>\@{$osimagenodehash{$osimage}}},$callback); } @@ -610,10 +648,12 @@ sub process_request { } if ($do_dhcpsetup) { if ($request->{'_disparatetftp'}->[0]) { #reading hint from preprocess_command + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=>\@breaknetboot, arg=>['-l']},$callback); } else { + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=>\@breaknetboot},$callback); } @@ -624,11 +664,13 @@ sub process_request { unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') $errored=0; if ($request->{'_disparatetftp'}->[0]) { #the call is distrubuted to the service node already, so only need to handles my own children - $sub_req->({command=>['runendpre'], + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: issue runendpre request"); + $sub_req->({command=>['runendpre'], node=>\@nodes, arg=>[$args[0], '-l']},\&pass_along); } else { #nodeset did not distribute to the service node, here we need to let runednpre to distribute the nodes to their masters - $sub_req->({command=>['runendpre'], + xCAT::MsgUtils->trace($verbose_on_off,"d","grub2: issue runendpre request"); + $sub_req->({command=>['runendpre'], node=>\@rnodes, arg=>[$args[0]]},\&pass_along); } diff --git a/xCAT-server/lib/xcat/plugins/petitboot.pm b/xCAT-server/lib/xcat/plugins/petitboot.pm index 789eaf385..6346d4e93 100644 --- a/xCAT-server/lib/xcat/plugins/petitboot.pm +++ b/xCAT-server/lib/xcat/plugins/petitboot.pm @@ -248,9 +248,15 @@ sub preprocess_request { @ARGV = @args; my $nodes = $req->{node}; #use Getopt::Long; + my $HELP; + my $VERSION; + my $VERBOSE; Getopt::Long::Configure("bundling"); Getopt::Long::Configure("pass_through"); - if (!GetOptions('h|?|help' => \$HELP, 'v|version' => \$VERSION) ) { + if (!GetOptions('h|?|help' => \$HELP, + 'v|version' => \$VERSION, + 'V' => \$VERBOSE #>>>>>>>used for trace log>>>>>>> + ) ) { if($usage{$command}) { my %rsp; $rsp{data}->[0]=$usage{$command}; @@ -259,6 +265,11 @@ sub preprocess_request { return; } + #>>>>>>>used for trace log start>>>>>> + my $verbose_on_off=0; + if($VERBOSE){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + if ($HELP) { if($usage{$command}) { my %rsp; @@ -290,6 +301,7 @@ sub preprocess_request { #if they specify no sharedtftp in site table my @entries = xCAT::TableUtils->get_site_attribute("sharedtftp"); my $t_entry = $entries[0]; + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: sharedtftp = $t_entry"); if ( defined($t_entry) and ($t_entry == 0 or $t_entry =~ /no/i)) { # check for computenodes and servicenodes from the noderange, if so error out my @SN; @@ -324,10 +336,24 @@ sub process_request { my $command = $request->{command}->[0]; %breaknetbootnodes=(); %normalnodes=(); + + #>>>>>>>used for trace log start>>>>>>> + my @args=(); + my %opt; + my $verbose_on_off=0; + if (ref($::request->{arg})) { + @args=@{$::request->{arg}}; + } else { + @args=($::request->{arg}); + } + @ARGV = @args; + GetOptions('V' => \$opt{V}); + if($opt{V}){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + if ($::XCATSITEVALS{"httpmethod"}) { $httpmethod = $::XCATSITEVALS{"httpmethod"}; } if ($::XCATSITEVALS{"httpport"}) { $httpport = $::XCATSITEVALS{"httpport"}; } - my @args; my @nodes; my @rnodes; if (ref($request->{node})) { @@ -356,6 +382,10 @@ sub process_request { @nodes = @rnodes; } + #>>>>>>>used for trace log>>>>>>> + my $str_node = join(" ",@nodes); + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: nodes are $str_node"); + # return directly if no nodes in the same network unless (@nodes) { xCAT::MsgUtils->message("S", "xCAT: petitboot netboot: no valid nodes. Stop the operation on this server."); @@ -372,10 +402,14 @@ sub process_request { unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') { $errored=0; if ($request->{'_disparatetftp'}->[0]) { #the call is distrubuted to the service node already, so only need to handles my own children + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: the call is distrubuted to the service node already, so only need to handles my own children"); + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: issue runbeginpre request"); $sub_req->({command=>['runbeginpre'], node=>\@nodes, arg=>[$args[0], '-l']},\&pass_along); } else { #nodeset did not distribute to the service node, here we need to let runednpre to distribute the nodes to their masters + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: nodeset did not distribute to the service node"); + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: issue runbeginpre request"); $sub_req->({command=>['runbeginpre'], node=>\@rnodes, arg=>[$args[0]]},\&pass_along); @@ -395,6 +429,7 @@ sub process_request { if (!$inittime) { $inittime=0;} $errored=0; unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') { + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: issue setdestiny request"); $sub_req->({command=>['setdestiny'], node=>\@nodes, inittime=>[$inittime], @@ -475,11 +510,13 @@ sub process_request { if ($do_dhcpsetup) { foreach my $node (@normalnodeset) { if ($request->{'_disparatetftp'}->[0]) { #reading hint from preprocess_command + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=> [$node], arg=>['-l']},$callback); #arg=>['-l','-s','option conf-file \"'.$fpath.'\";']},$callback); } else { + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=> [$node]}, $callback); #arg=>['-s','option conf-file \"'.$fpath.'\";']},$callback); @@ -492,10 +529,12 @@ sub process_request { unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') $errored=0; if ($request->{'_disparatetftp'}->[0]) { #the call is distrubuted to the service node already, so only need to handles my own children + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: issue runendpre request"); $sub_req->({command=>['runendpre'], node=>\@nodes, arg=>[$args[0], '-l']},\&pass_along); } else { #nodeset did not distribute to the service node, here we need to let runednpre to distribute the nodes to their masters + xCAT::MsgUtils->trace($verbose_on_off,"d","petitboot: issue runendpre request"); $sub_req->({command=>['runendpre'], node=>\@rnodes, arg=>[$args[0]]},\&pass_along); diff --git a/xCAT-server/lib/xcat/plugins/prescripts.pm b/xCAT-server/lib/xcat/plugins/prescripts.pm index 505e2659f..6181b5acc 100644 --- a/xCAT-server/lib/xcat/plugins/prescripts.pm +++ b/xCAT-server/lib/xcat/plugins/prescripts.pm @@ -43,6 +43,20 @@ sub preprocess_request my $req = shift; my $cb = shift; + #>>>>>>>used for trace log start>>>>>>> + my @args=(); + my %opt; + my $verbose_on_off=0; + if (ref($req->{arg})) { + @args=@{$req->{arg}}; + } else { + @args=($req->{arg}); + } + @ARGV = @args; + GetOptions('V' => \$opt{V}); + if($opt{V}){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + #if already preprocessed, go straight to request if ($req->{_xcatpreprocessed}->[0] == 1) { return [$req]; } @@ -78,10 +92,13 @@ sub preprocess_request } # if no nodes left to process, we are done - if (! @nodes) { return; } + if (! @nodes) { + xCAT::MsgUtils->trace($verbose_on_off,"d","prescripts->preprocess_request: no nodes left to process, we are done"); + return; + } my $service = "xcat"; - my @args=(); + @args=(); if (ref($req->{arg})) { @args=@{$req->{arg}}; } else { @@ -91,6 +108,11 @@ sub preprocess_request #print "prepscripts: preprocess_request get called, args=@args, nodes=@$nodes\n"; + #>>>>>>>used for trace log>>>>>> + my $str_node=join(" ",@nodes); + my $str_args=join(" ",@args); + xCAT::MsgUtils->trace($verbose_on_off,"d","prescripts->preprocess_request: get called, args='$str_args', nodes='$str_node'"); + #use Getopt::Long; Getopt::Long::Configure("bundling"); Getopt::Long::Configure("pass_through"); @@ -117,6 +139,7 @@ sub preprocess_request $reqcopy->{'_xcatdest'} = $hostinfo[0]; $reqcopy->{_xcatpreprocessed}->[0] = 1; push @requests, $reqcopy; + xCAT::MsgUtils->trace($verbose_on_off,"d","prescripts: handle request in $hostinfo[0]"); return \@requests; } } else { #run on mn and need to dispatch the requests to the service nodes @@ -130,6 +153,7 @@ sub preprocess_request $reqcopy->{node} = $sn->{$snkey}; $reqcopy->{'_xcatdest'} = $snkey; $reqcopy->{_xcatpreprocessed}->[0] = 1; + xCAT::MsgUtils->trace($verbose_on_off,"d","prescripts: handle request in $snkey"); push @requests, $reqcopy; } # end foreach diff --git a/xCAT-server/lib/xcat/plugins/pxe.pm b/xCAT-server/lib/xcat/plugins/pxe.pm index abc766aef..49d2b82b2 100644 --- a/xCAT-server/lib/xcat/plugins/pxe.pm +++ b/xCAT-server/lib/xcat/plugins/pxe.pm @@ -295,9 +295,15 @@ sub preprocess_request { @args=($req->{arg}); } @ARGV = @args; + my $HELP; + my $VERSION; + my $VERBOSE; Getopt::Long::Configure("bundling"); Getopt::Long::Configure("pass_through"); - if (!GetOptions('h|?|help' => \$HELP, 'v|version' => \$VERSION) ) { + if (!GetOptions('h|?|help' => \$HELP, + 'v|version' => \$VERSION, + 'V' => \$VERBOSE #>>>>>>>used for trace log>>>>>>> + ) ) { if($usage{$command}) { my %rsp; $rsp{data}->[0]=$usage{$command}; @@ -306,6 +312,11 @@ sub preprocess_request { return; } + #>>>>>>>used for trace log start>>>>>> + my $verbose_on_off=0; + if($VERBOSE){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + if ($HELP) { if($usage{$command}) { my %rsp; @@ -335,6 +346,7 @@ sub preprocess_request { #my $sent = $stab->getAttribs({key=>'sharedtftp'},'value'); my @entries = xCAT::TableUtils->get_site_attribute("sharedtftp"); my $t_entry = $entries[0]; + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: sharedtftp=$t_entry"); if ( defined($t_entry) and ($t_entry eq "0" or $t_entry eq "no" or $t_entry eq "NO")) { # check for computenodes and servicenodes from the noderange, if so error out my @SN; @@ -370,6 +382,20 @@ sub process_request { my @args; my @nodes; my @rnodes; + + #>>>>>>>used for trace log start>>>>>>> + my %opt; + my $verbose_on_off=0; + if (ref($::PXE_request->{arg})) { + @args=@{$::PXE_request->{arg}}; + } else { + @args=($::PXE_request->{arg}); + } + @ARGV = @args; + GetOptions('V' => \$opt{V}); + if($opt{V}){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + if (ref($::PXE_request->{node})) { @rnodes = @{$::PXE_request->{node}}; } else { @@ -397,6 +423,10 @@ sub process_request { @nodes = @rnodes; } + #>>>>>>>used for trace log>>>>>>> + my $str_node = join(" ",@nodes); + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: nodes are $str_node"); + # return directly if no nodes in the same network unless (@nodes) { xCAT::MsgUtils->message("S", "xCAT: pxe netboot: no valid nodes. Stop the operation on this server."); @@ -413,11 +443,15 @@ sub process_request { unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') { $errored=0; if ($::PXE_request->{'_disparatetftp'}->[0]) { #the call is distrubuted to the service node already, so only need to handles my own children + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: the call is distrubuted to the service node already, so only need to handles my own children"); + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: issue runbeginpre request"); $sub_req->({command=>['runbeginpre'], node=>\@nodes, arg=>[$args[0], '-l']},\&pass_along); } else { #nodeset did not distribute to the service node, here we need to let runednpre to distribute the nodes to their masters - $sub_req->({command=>['runbeginpre'], + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: nodeset did not distribute to the service node"); + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: issue runbeginpre request"); + $sub_req->({command=>['runbeginpre'], node=>\@rnodes, arg=>[$args[0]]},\&pass_along); } @@ -453,6 +487,7 @@ sub process_request { if (exists($::PXE_request->{inittime})) { $inittime= $::PXE_request->{inittime}->[0];} if (!$inittime) { $inittime=0;} unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') { + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: issue setdestiny request"); $sub_req->({command=>['setdestiny'], node=>\@nodes, inittime=>[$inittime], @@ -518,9 +553,11 @@ sub process_request { if ($do_dhcpsetup) { if ($::PXE_request->{'_disparatetftp'}->[0]) { #reading hint from preprocess_command + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: issue makedhcp request"); $sub_req->({command=>['makedhcp'],arg=>['-l'], node=>\@nodes},$::PXE_callback); } else { + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=>\@nodes},$::PXE_callback); } @@ -575,10 +612,12 @@ sub process_request { unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') $errored=0; if ($::PXE_request->{'_disparatetftp'}->[0]) { #the call is distrubuted to the service node already, so only need to handles my own children + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: issue runendpre request"); $sub_req->({command=>['runendpre'], node=>\@nodes, arg=>[$args[0], '-l']},\&pass_along); } else { #nodeset did not distribute to the service node, here we need to let runednpre to distribute the nodes to their masters + xCAT::MsgUtils->trace($verbose_on_off,"d","pxe: issue runendpre request"); $sub_req->({command=>['runendpre'], node=>\@rnodes, arg=>[$args[0]]},\&pass_along); diff --git a/xCAT-server/lib/xcat/plugins/sles.pm b/xCAT-server/lib/xcat/plugins/sles.pm old mode 100755 new mode 100644 index ff0fbbc0a..0a0967ae7 --- a/xCAT-server/lib/xcat/plugins/sles.pm +++ b/xCAT-server/lib/xcat/plugins/sles.pm @@ -752,6 +752,20 @@ sub mkinstall my $osimagetab; my $osdistrouptab; + #>>>>>>>used for trace log start>>>>>>> + my @args=(); + my %opt; + if (ref($request->{arg})) { + @args=@{$request->{arg}}; + } else { + @args=($request->{arg}); + } + @ARGV = @args; + GetOptions('V' => \$opt{V}); + my $verbose_on_off=0; + if($opt{V}){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + my $ntents = $ostab->getNodesAttribs($request->{node}, ['os', 'arch', 'profile', 'provmethod']); my %img_hash=(); my $installroot; @@ -779,7 +793,9 @@ sub mkinstall $installroot = $t_entry; } #} - + + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: installroot=$installroot"); + my %donetftp; require xCAT::Template; #only used here, load so memory can be COWed # Define a variable for driver update list @@ -829,7 +845,9 @@ sub mkinstall } else { $tftpdir = $globaltftpdir; } - + + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: tftpdir=$tftpdir"); + if ($ent and $ent->{provmethod} and ($ent->{provmethod} ne 'install') and ($ent->{provmethod} ne 'netboot') and ($ent->{provmethod} ne 'statelite')) { $imagename=$ent->{provmethod}; if (!exists($img_hash{$imagename})) { @@ -914,6 +932,8 @@ sub mkinstall $netdrivers = $ph->{netdrivers}; $driverupdatesrc = $ph->{driverupdatesrc}; $osupdir = $ph->{'osupdir'}; + + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: imagename=$imagename pkgdir=$pkgdir pkglistfile=$pkglistfile tmplfile=$tmplfile partfile=$partfile"); } else { $os = $ent->{os}; @@ -939,7 +959,9 @@ sub mkinstall #get the partition file from the linuximage table my $imgname = "$os-$arch-install-$profile"; - + + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: imagename=$imgname pkgdir=$pkgdir pkglistfile=$pkglistfile tmplfile=$tmplfile"); + if (! $linuximagetab) { $linuximagetab = xCAT::Table->new('linuximage'); } @@ -948,6 +970,7 @@ sub mkinstall (my $ref1) = $linuximagetab->getAttribs({imagename => $imgname}, 'partitionfile'); if ( $ref1 and $ref1->{'partitionfile'}){ $partfile = $ref1->{'partitionfile'}; + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: partfile=$partfile"); } } else { @@ -1080,18 +1103,21 @@ sub mkinstall copy("$pkgdir/1/boot/$arch/loader/linux", "$tftppath"); copy("$pkgdir/1/boot/$arch/loader/initrd", "$tftppath"); @dd_drivers = &insert_dd($callback, $os, $arch, "$tftppath/initrd", "$tftppath/linux", $driverupdatesrc, $netdrivers, $osupdir, $ignorekernelchk); + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: copy initrd.img and linux to $tftppath"); } } elsif ($arch =~ /x86/) { unless ($noupdateinitrd) { copy("$pkgdir/1/boot/i386/loader/linux", "$tftppath"); copy("$pkgdir/1/boot/i386/loader/initrd", "$tftppath"); @dd_drivers = &insert_dd($callback, $os, $arch, "$tftppath/initrd", "$tftppath/linux", $driverupdatesrc, $netdrivers, $osupdir, $ignorekernelchk); + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: copy initrd.img and linux to $tftppath"); } } elsif ($arch eq "ppc64le") { unless ($noupdateinitrd) { copy("$pkgdir/1/boot/$arch/linux", "$tftppath"); copy("$pkgdir/1/boot/$arch/initrd", "$tftppath"); @dd_drivers = &insert_dd($callback, $os, $arch, "$tftppath/initrd", "$tftppath/linux", $driverupdatesrc, $netdrivers, $osupdir, $ignorekernelchk); + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: copy initrd.img and linux to $tftppath"); } } elsif ($arch =~ /ppc/) @@ -1099,6 +1125,7 @@ sub mkinstall unless ($noupdateinitrd) { copy("$pkgdir/1/suseboot/inst64", "$tftppath"); @dd_drivers = &insert_dd($callback, $os, $arch, "$tftppath/inst64", undef, $driverupdatesrc, $netdrivers, $osupdir, $ignorekernelchk); + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: copy inst64 to $tftppath"); } } } @@ -1278,6 +1305,7 @@ sub mkinstall { $kernelpath = "$rtftppath/linux"; $initrdpath = "$rtftppath/initrd"; + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: kcmdline=$kcmdline kernal=$kernelpath initrd=$initrdpath"); $bptab->setNodeAttribs( $node, { @@ -1290,6 +1318,7 @@ sub mkinstall elsif ($arch =~ /ppc/) { $kernelpath = "$rtftppath/inst64"; + xCAT::MsgUtils->trace($verbose_on_off,"d","sles->mkinstall: kcmdline=$kcmdline kernal=$kernelpath initrd="); $bptab->setNodeAttribs( $node, { diff --git a/xCAT-server/lib/xcat/plugins/xnba.pm b/xCAT-server/lib/xcat/plugins/xnba.pm index 78012e387..0c65661f6 100644 --- a/xCAT-server/lib/xcat/plugins/xnba.pm +++ b/xCAT-server/lib/xcat/plugins/xnba.pm @@ -317,7 +317,11 @@ sub preprocess_request { Getopt::Long::Configure("pass_through"); my $HELP; my $VERSION; - if (!GetOptions('h|?|help' => \$HELP, 'v|version' => \$VERSION) ) { + my $VERBOSE; + if (!GetOptions('h|?|help' => \$HELP, + 'v|version' => \$VERSION, + 'V' => \$VERBOSE #>>>>>>>used for trace log>>>>>>> + ) ) { if($usage{$command}) { my %rsp; $rsp{data}->[0]=$usage{$command}; @@ -326,6 +330,11 @@ sub preprocess_request { return; } + #>>>>>>>used for trace log start>>>>>> + my $verbose_on_off=0; + if($VERBOSE){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + if ($HELP) { if($usage{$command}) { my %rsp; @@ -357,6 +366,7 @@ sub preprocess_request { #they specify no sharedtftp in site table my @entries = xCAT::TableUtils->get_site_attribute("sharedtftp"); my $t_entry = $entries[0]; + xCAT::MsgUtils->trace($verbose_on_off,"d","xnba: sharedtftp=$t_entry"); if ( defined($t_entry) and ($t_entry eq "0" or $t_entry eq "no" or $t_entry eq "NO")) { # check for computenodes and servicenodes from the noderange, if so error out my @SN; @@ -392,6 +402,20 @@ sub process_request { my @args; my @nodes; my @rnodes; + + #>>>>>>>used for trace log start>>>>>>> + my %opt; + my $verbose_on_off=0; + if (ref($::XNBA_request->{arg})) { + @args=@{$::XNBA_request->{arg}}; + } else { + @args=($::XNBA_request->{arg}); + } + @ARGV = @args; + GetOptions('V' => \$opt{V}); + if($opt{V}){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + if (ref($::XNBA_request->{node})) { @rnodes = @{$::XNBA_request->{node}}; } else { @@ -413,12 +437,16 @@ sub process_request { push @nodes,$_; } else { xCAT::MsgUtils->message("S", "$_: xnba netboot: stop configuration because of none sharedtftp and not on same network with its xcatmaster."); - } + } } } else { @nodes = @rnodes; } + #>>>>>>>used for trace log>>>>>>> + my $str_node = join(" ",@nodes); + xCAT::MsgUtils->trace(0,"d","xnba: nodes are $str_node"); + # return directly if no nodes in the same network unless (@nodes) { xCAT::MsgUtils->message("S", "xCAT: xnba netboot: no valid nodes. Stop the operation on this server."); @@ -435,10 +463,14 @@ sub process_request { unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') { $errored=0; if ($::XNBA_request->{'_disparatetftp'}->[0]) { #the call is distrubuted to the service node already, so only need to handles my own children + xCAT::MsgUtils->trace($verbose_on_off,"d","xnba: the call is distrubuted to the service node already, so only need to handles my own children"); + xCAT::MsgUtils->trace($verbose_on_off,"d","xnba: issue runbeginpre request"); $sub_req->({command=>['runbeginpre'], node=>\@nodes, arg=>[$args[0], '-l']},\&pass_along); } else { #nodeset did not distribute to the service node, here we need to let runednpre to distribute the nodes to their masters + xCAT::MsgUtils->trace($verbose_on_off,"d","xnba: nodeset did not distribute to the service node"); + xCAT::MsgUtils->trace($verbose_on_off,"d","xnba: issue runbeginpre request"); $sub_req->({command=>['runbeginpre'], node=>\@rnodes, arg=>[$args[0]]},\&pass_along); @@ -472,7 +504,8 @@ sub process_request { if (!$inittime) { $inittime=0;} $errored=0; unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') { - $sub_req->({command=>['setdestiny'], + xCAT::MsgUtils->trace($verbose_on_off,"d","xnba: issue setdestiny request"); + $sub_req->({command=>['setdestiny'], node=>\@nodes, inittime=>[$inittime], arg=>\@args},\&pass_along); @@ -550,9 +583,11 @@ sub process_request { if ($do_dhcpsetup) { if ($::XNBA_request->{'_disparatetftp'}->[0]) { #reading hint from preprocess_command + xCAT::MsgUtils->trace($verbose_on_off,"d","xnba: issue makedhcp request"); $sub_req->({command=>['makedhcp'],arg=>['-l'], node=>\@nodes},$::XNBA_callback); } else { + xCAT::MsgUtils->trace($verbose_on_off,"d","xnba: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=>\@nodes},$::XNBA_callback); } @@ -563,10 +598,12 @@ sub process_request { unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') $errored=0; if ($::XNBA_request->{'_disparatetftp'}->[0]) { #the call is distrubuted to the service node already, so only need to handles my own children + xCAT::MsgUtils->trace($verbose_on_off,"d","xnba: issue runendpre request"); $sub_req->({command=>['runendpre'], node=>\@nodes, arg=>[$args[0], '-l']},\&pass_along); } else { #nodeset did not distribute to the service node, here we need to let runednpre to distribute the nodes to their masters + xCAT::MsgUtils->trace($verbose_on_off,"d","xnba: issue runendpre request"); $sub_req->({command=>['runendpre'], node=>\@rnodes, arg=>[$args[0]]},\&pass_along); diff --git a/xCAT-server/lib/xcat/plugins/yaboot.pm b/xCAT-server/lib/xcat/plugins/yaboot.pm index 7061270ba..37b939631 100644 --- a/xCAT-server/lib/xcat/plugins/yaboot.pm +++ b/xCAT-server/lib/xcat/plugins/yaboot.pm @@ -358,9 +358,15 @@ sub preprocess_request { @ARGV = @args; my $nodes = $req->{node}; #use Getopt::Long; + my $HELP; + my $VERSION; + my $VERBOSE; Getopt::Long::Configure("bundling"); Getopt::Long::Configure("pass_through"); - if (!GetOptions('h|?|help' => \$HELP, 'v|version' => \$VERSION) ) { + if (!GetOptions('h|?|help' => \$HELP, + 'v|version' => \$VERSION, + 'V' => \$VERBOSE #>>>>>>>used for trace log>>>>>>> + ) ) { if($usage{$command}) { my %rsp; $rsp{data}->[0]=$usage{$command}; @@ -368,7 +374,12 @@ sub preprocess_request { } return; } - + + #>>>>>>>used for trace log start>>>>>> + my $verbose_on_off=0; + if($VERBOSE){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + if ($HELP) { if($usage{$command}) { my %rsp; @@ -401,6 +412,8 @@ sub preprocess_request { my @entries = xCAT::TableUtils->get_site_attribute("sharedtftp"); my $t_entry = $entries[0]; + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: sharedtftp=$t_entry"); + if ( defined($t_entry) and ($t_entry eq "0" or $t_entry eq "no" or $t_entry eq "NO")) { # check for computenodes and servicenodes from the noderange, if so error out my @SN; @@ -438,6 +451,22 @@ sub process_request { %normalnodes=(); my @args; + + #>>>>>>>used for trace log start>>>>>>> + my @args=(); + my %opt; + my $verbose_on_off=0; + if (ref($::YABOOT_request->{arg})) { + @args=@{$::YABOOT_request->{arg}}; + } else { + @args=($::YABOOT_request->{arg}); + } + @ARGV = @args; + GetOptions('V' => \$opt{V}); + if($opt{V}){$verbose_on_off=1;} + #>>>>>>>used for trace log end>>>>>>> + + my @nodes; my @rnodes; if (ref($::YABOOT_request->{node})) { @@ -466,6 +495,10 @@ sub process_request { @nodes = @rnodes; } + #>>>>>>>used for trace log>>>>>>> + my $str_node = join(" ",@nodes); + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: nodes are $str_node"); + # return directly if no nodes in the same network unless (@nodes) { xCAT::MsgUtils->message("S", "xCAT: yaboot netboot: no valid nodes. Stop the operation on this server."); @@ -482,10 +515,14 @@ sub process_request { unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') { $errored=0; if ($::YABOOT_request->{'_disparatetftp'}->[0]) { #the call is distrubuted to the service node already, so only need to handles my own children + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: the call is distrubuted to the service node already, so only need to handles my own children"); + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue runbeginpre request"); $sub_req->({command=>['runbeginpre'], node=>\@nodes, arg=>[$args[0], '-l']},\&pass_along); } else { #nodeset did not distribute to the service node, here we need to let runednpre to distribute the nodes to their masters + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: nodeset did not distribute to the service node"); + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue runbeginpre request"); $sub_req->({command=>['runbeginpre'], node=>\@rnodes, arg=>[$args[0]]},\&pass_along); @@ -504,6 +541,7 @@ sub process_request { if (!$inittime) { $inittime=0;} $errored=0; unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') { + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue setdestiny request"); $sub_req->({command=>['setdestiny'], node=>\@nodes, inittime=>[$inittime], @@ -710,10 +748,12 @@ sub process_request { } } if ($::YABOOT_request->{'_disparatetftp'}->[0]) { #reading hint from preprocess_command + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=>\@{$osimagenodehash{$osimage}}, arg=>['-l']},$::YABOOT_callback); } else { + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=>\@{$osimagenodehash{$osimage}}},$::YABOOT_callback); } @@ -725,20 +765,24 @@ sub process_request { } if ($::YABOOT_request->{'_disparatetftp'}->[0]) { #reading hint from preprocess_command, only change local settings if already farmed - $sub_req->({command=>['makedhcp'],arg=>['-l'], + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue makedhcp request"); + $sub_req->({command=>['makedhcp'],arg=>['-l'], node=>\@{$osimagenodehash{$osimage}}},$::YABOOT_callback); } else { - $sub_req->({command=>['makedhcp'], + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue makedhcp request"); + $sub_req->({command=>['makedhcp'], node=>\@{$osimagenodehash{$osimage}}},$::YABOOT_callback); } } } } else { if ($::YABOOT_request->{'_disparatetftp'}->[0]) { #reading hint from preprocess_command, only change local settings if already farmed - $sub_req->({command=>['makedhcp'],arg=>['-l'], + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue makedhcp request"); + $sub_req->({command=>['makedhcp'],arg=>['-l'], node=>\@normalnodeset},$::YABOOT_callback); } else { - $sub_req->({command=>['makedhcp'], + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue makedhcp request"); + $sub_req->({command=>['makedhcp'], node=>\@normalnodeset},$::YABOOT_callback); } } @@ -748,10 +792,12 @@ sub process_request { } } if ($::YABOOT_request->{'_disparatetftp'}->[0]) { #reading hint from preprocess_command + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=>\@breaknetboot, arg=>['-l']},$::YABOOT_callback); } else { + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue makedhcp request"); $sub_req->({command=>['makedhcp'], node=>\@breaknetboot}, $::YABOOT_callback); } @@ -762,10 +808,12 @@ sub process_request { unless ($args[0] eq 'stat') { # or $args[0] eq 'enact') $errored=0; if ($::YABOOT_request->{'_disparatetftp'}->[0]) { #the call is distrubuted to the service node already, so only need to handles my own children + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue runendpre request"); $sub_req->({command=>['runendpre'], node=>\@nodes, arg=>[$args[0], '-l']},\&pass_along); } else { #nodeset did not distribute to the service node, here we need to let runednpre to distribute the nodes to their masters + xCAT::MsgUtils->trace($verbose_on_off,"d","yaboot: issue runendpre request"); $sub_req->({command=>['runendpre'], node=>\@rnodes, arg=>[$args[0]]},\&pass_along); diff --git a/xCAT-server/sbin/xcatd b/xCAT-server/sbin/xcatd old mode 100755 new mode 100644 index d6ad7304b..16bb3046a --- a/xCAT-server/sbin/xcatd +++ b/xCAT-server/sbin/xcatd @@ -27,6 +27,11 @@ my $sslctl; my $udpctl; my $pid_UDP; my $pid_MON; + +#----used for command log start--------- +my $cmdlog_svrpid; +#----used for command log end--------- + # if AIX - make sure we include perl 5.8.2 in INC path. # Needed to find perl dependencies shipped in deps tarball. if ($^O =~ /^aix/i) { @@ -156,7 +161,6 @@ if (xCAT::Utils->isLinux()) { } } - my $quit = 0; my $port; my $sport; @@ -197,7 +201,18 @@ my $plugins_dir=$::XCATROOT.'/lib/perl/xCAT_plugin'; ($tmp) = $sitetab->getAttribs({'key'=>'xcatconfdir'},'value'); $xcatdir = (($tmp and $tmp->{value}) ? $tmp->{value} : "/etc/xcat"); +#----used for command log start------- +my $cmdlog_logfile="/var/log/xcat/commands.log"; +my $cmdlog_port=3003; +($tmp) = $sitetab->getAttribs({'key'=>'xcatlport'},'value'); +if ($tmp) { + $cmdlog_port = $tmp->{value}; +} +my $cmdlog_alllog="====================================================\n"; +#----used for command log end--------- + $sitetab->close; + my $progname; my $pipeexpected; $SIG{PIPE} = sub { @@ -943,6 +958,13 @@ $SIG{TERM} = $SIG{INT} = sub { if ($dbmaster) { kill 2, $dbmaster; } + + #----used for command log start--------- + if ($cmdlog_svrpid) + kill 2, $cmdlog_svrpid; + } + #----used for command log end--------- + $SIG{ALRM} = sub { xexit 0; }; #die "Did not close out in time for 5 second grace period"; }; alarm(2); }; @@ -1122,6 +1144,59 @@ if ($startupparent) { close($startupparent); } +#----used for command log start--------- +$cmdlog_svrpid = fork(); +if( !defined($cmdlog_svrpid)){ + print "xCAT command log sever unable to fork"; + xCAT::MsgUtils->message("S","xCAT command log sever unable to fork"); +}elsif($cmdlog_svrpid ==0){ + $$progname="xcatd: Command log writer"; + my $clientsock; + my @waittowritepro; + my $cmdlogsvrlistener; + my $cmdlogfile; + + $SIG{TERM} = $SIG{INT} = sub { + xCAT::MsgUtils->message("S","INFO xcatd: 'Command log writer' process is terminated by TERM or INT signal"); + if($cmdlogfile){close($cmdlogfile);} + if($cmdlogsvrlistener){close($cmdlogsvrlistener);} + if($clientsock){close($clientsock);} + exit(0); + }; + + xCAT::MsgUtils->trace(0,"I","xcatd: command log process start"); + + unless (open ($cmdlogfile, ">>$cmdlog_logfile")) { + xCAT::MsgUtils->trace(0,"E","xcatd: Can't open xcat command log file $cmdlog_logfile"); + xCAT::MsgUtils->trace(0,"I","xcatd: command log process stop"); + exit(0); + } + select($cmdlogfile); + $|=1; + + $cmdlogsvrlistener = IO::Socket::INET->new(LocalPort => $cmdlog_port, + Type => SOCK_STREAM, + Reuse => 1, + Listen => 8192); + while (1) + { + $clientsock = $cmdlogsvrlistener->accept; + unless ($clientsock) { next; } + my $log = ""; + my $bytesread; + do { + $bytesread=sysread($clientsock,$log,65536,length($log)) + } while ($bytesread); + close($clientsock); + print $cmdlogfile $log; + } + + close($cmdlogsvrlistener); + close($cmdlogfile); + + xCAT::MsgUtils->trace(0,"I","xcatd: command log process stop"); +} +#----used for command log end--------- #only write to pid file if we have listener, listener ownership serves as lock to protect integrity open($mainpidfile,">","/var/run/xcat/mainservice.pid"); #if here, everyone else has unlinked mainservicepid or doesn't care @@ -1281,8 +1356,15 @@ if ($inet6support) { $peerhost && $peerhost =~ s/-myri\d*$//; $peerhost && $peerhost =~ s/-ib\d*$//; #printf('info'.": xcatd: connection from ".($peername ? $peername . "@" . $peerhost : $peerhost)."\n"); + + my $debugmsg = "xcatd: connection from ".($peername ? $peername . "@" . $peerhost : $peerhost)."\n"; + xCAT::MsgUtils->trace(0,"D","$debugmsg"); + $$progname="xCATd SSL: Instance for ".($peername ? $peername ."@".$peerhost : $peerhost) if $peerhost; service_connection($connection,$peername,$peerhost,$peerfqdn,$peerhostorg); + + $debugmsg = "xcatd: close connection with ".($peername ? $peername . "@" . $peerhost : $peerhost)."\n"; + xCAT::MsgUtils->trace(0,"D","$debugmsg"); xexit(0); } if ($sslfudgefactor) { $sslfudgefactor -= 1; } @@ -1552,6 +1634,9 @@ sub plugin_command { store_fd(\$rescanrequest,$rescanwritepipe); } } else { + my $debuglog= "xcatd: call plugin <$modname> to handle command <$req->{command}->[0]>"; + xCAT::MsgUtils->trace(0,"D","$debuglog"); + ${"xCAT_plugin::".$modname."::"}{process_request}->($req,$callback,\&do_request); } } @@ -1822,6 +1907,23 @@ sub dispatch_request { # save the old signal my $old_sig_chld = $SIG{CHLD}; + #----used for trace start--------- + my $str_cmd=$req->{command}->[0]." "; + if(exists($req->{noderange})){ + foreach my $n (@{$req->{noderange}}) { + $str_cmd .= $n.","; + } + $str_cmd =~ s/(.+),$/$1 /g; + } + if(exists($req->{arg})){ + foreach my $arg (@{$req->{arg}}) { + $str_cmd .= $arg." "; + } + $str_cmd =~ s/(.+) $/$1/g; + } + xCAT::MsgUtils->trace(0,"D","xcatd: dispatch request '$str_cmd' to plugin '$modname'"); + #----used for trace end--------- + #Hierarchy support. Originally, the default scope for noderange commands was #going to be the servicenode associated unless overriden. #However, assume for example that you have blades and a blade is the service node @@ -1832,6 +1934,7 @@ sub dispatch_request { #If the plugin offers a preprocess method, use it to set the request array if ((not (defined $req->{_xcatpreprocessed}->[0] and $req->{_xcatpreprocessed}->[0] == 1)) and (defined(${"xCAT_plugin::".$modname."::"}{preprocess_request}))) { $SIG{CHLD}='DEFAULT'; + xCAT::MsgUtils->trace(0,"D","xcatd: handle request '$req->{command}->[0]' by plugin '$modname''s preprocess_request"); $reqs = ${"xCAT_plugin::".$modname."::"}{preprocess_request}->($req,$dispatch_cb,\&do_request); } else { #otherwise, pass it in without hierarchy support $reqs = [$req]; @@ -1889,6 +1992,7 @@ sub dispatch_request { store_fd(\$rescanrequest,$rescanwritepipe); } } else { + xCAT::MsgUtils->trace(0,"D","xcatd: handle request '$_->{command}->[0]' by plugin '$modname''s process_request"); ${"xCAT_plugin::".$modname."::"}{process_request}->($_,$dispatch_cb,\&do_request); } return; @@ -1951,6 +2055,8 @@ sub dispatch_request { undef $_->{'_xcatdest'}; #mainly used by SN to filter out the incorrect module that xcat command came into $_->{'_modname'} = $modname; + + xCAT::MsgUtils->trace(0,"D","dispatch hierarchical sub-command $_->{command}->[0] to $ENV{XCATHOST}"); xCAT::Client::submit_request($_,\&dispatch_callback,$xcatdir."/cert/server-cred.pem",$xcatdir."/cert/server-cred.pem",$xcatdir."/cert/ca.pem"); }; if ($@) { @@ -1984,6 +2090,7 @@ sub dispatch_request { store_fd(\$rescanrequest,$rescanwritepipe); } } else { + xCAT::MsgUtils->trace(0,"D","handle command $_->{command}->[0] by plugin $modname 's process_request"); ${"xCAT_plugin::".$modname."::"}{process_request}->($_,\&dispatch_callback,\&do_request); } last; @@ -2203,6 +2310,11 @@ sub send_response { } while (($! == EAGAIN) or ($! == ECHILD)); } }; + + #----used for command log start------- + cmdlog_collectlog($response); + #----used for command log end -------- + } elsif ($encode eq "storable") { if ($response->{xcatresponse}) { $response = $response->{xcatresponse}; @@ -2279,6 +2391,32 @@ sub service_connection { #} $req = get_request($sock,$globalencode,$line); unless ($req) { last; } + + #----used for command log start---------- + my ($sec,$min,$hour,$mday,$mon,$year) = localtime(time()); + $year += 1900; + $cmdlog_alllog .= "[Date] $year-$mon-$mday $hour:$min:$sec\n"; + + #print ">>>>>>>cmdlog request dumper>>>>>>>>\n"; + #print Dumper $req; + + $cmdlog_alllog .= "[ClientType] ".$req->{clienttype}->[0]." \n"; + $cmdlog_alllog .= "[Request] ".$req->{command}->[0]." "; + if(exists($req->{noderange})){ + foreach my $node (@{$req->{noderange}}) { + $cmdlog_alllog .= $node.","; + } + $cmdlog_alllog =~ s/(.+),$/$1 /g; + } + + if(exists($req->{arg})){ + foreach my $arg (@{$req->{arg}}) { + $cmdlog_alllog .= $arg." "; + } + } + $cmdlog_alllog .= "\n[Response]\n"; + #----used for command log end---------- + { #TODO: find closing brace.. #first change peername on 'becomeuser' tag if present and valid if (defined $req->{becomeuser}) { @@ -2344,6 +2482,10 @@ sub service_connection { if($peerhost){ $$progname .= " for ".($peername ? $peername ."@".$peerhost : $peerhost); } + + my $debuglog= "xcatd: open new process : $$progname"; + xCAT::MsgUtils->trace(0,"D","$debuglog"); + if ($req->{command}->[0] eq "authcheck") { #provide a method for UI to verify a user without actually requesting action my $resp; if ($peername or $peername eq "0") { @@ -2432,6 +2574,11 @@ sub service_connection { #should be no longer possible to hit this condition. send_response({error=>"A child jumped to where it should never ever be, this shouldn't be possible, please report this bug"},$sock); } + + #----used for command log start------- + cmdlog_submitlog(); + #----used for command log end--------- + $SIG{ALRM}= sub { xCAT::MsgUtils->message("S","$$ failed shutting down"); die;}; alarm(10); foreach (keys %tables) { @@ -2493,6 +2640,12 @@ sub relay_fds { #Relays file descriptors from pipes to children to the SSL socke close($cin); } xCAT::MsgUtils->message("S", "Client abort requested"); + + #----used for command log start------- + $cmdlog_alllog .= "Client abort requested\n"; + cmdlog_submitlog(); + #----used for command log end--------- + exit(0); } } @@ -2709,5 +2862,245 @@ sub disable_callingtrace { xCAT::MsgUtils->stop_logging(); } +#-------------------------------------------------------------------------------- +=head3 cmdlog_collectlog + Used by recording command output feature. + collecting each output for one specific command + The most part of this subroutine logic comes from handle_response subroutine in Client.pm + + Returns: + 0 -> successful + 1 -> failed +=cut +#-------------------------------------------------------------------------------- +sub cmdlog_collectlog(){ + my $rsponse= shift; + my $rsp_log=""; + + if((exists($rsponse->{serverdone})) && (! exists($rsponse->{error}) )){return 0;} + my $rsp; + if(exists($rsponse->{xcatresponse})){ + $rsp = $rsponse->{xcatresponse}; + }else{ + $rsp = $rsponse; + } + if (ref($rsp) ne 'ARRAY') {return 0;} + if (scalar(@$rsp) == 0) {return 0;} + + foreach my $tmprsp (@{$rsp}) { + $rsp = $tmprsp; + + #handle response + #Handle errors + if ($rsp->{error}) { + if (ref($rsp->{error}) eq 'ARRAY') { + foreach my $text (@{$rsp->{error}}) { + if ($rsp->{NoErrorPrefix}) { + $rsp_log.=$text; + } else { + $rsp_log.="Error: $text\n"; + } + } + } + else { + if ($rsp->{NoErrorPrefix}) { + $rsp_log.= $rsp->{error}."\n"; + } else { + $rsp_log.= "Error: ".$rsp->{error}."\n"; + } + } + } + + if ($rsp->{warning}) { + if (ref($rsp->{warning}) eq 'ARRAY') { + foreach my $text (@{$rsp->{warning}}) { + if ($rsp->{NoWarnPrefix}) { + $rsp_log.= "$text\n"; + } else { + $rsp_log.= "Warning: $text\n"; + } + } + } + else { + if ($rsp->{NoWarnPrefix}) { + $rsp_log.= $rsp->{warning}."\n"; + } else { + $rsp_log.= "Warning: ".$rsp->{warning}."\n"; + } + } + } + + if ($rsp->{info}) { + if (ref($rsp->{info}) eq 'ARRAY') { + foreach my $text (@{$rsp->{info}}) { + $rsp_log.= "$text\n"; + } + }else{ + $rsp_log.= $rsp->{info}."\n"; + } + } + + if ($rsp->{sinfo}) { + if (ref($rsp->{sinfo}) eq 'ARRAY') { + foreach my $text (@{$rsp->{sinfo}}) { + $rsp_log.= "$text\r"; + } + }else{ + $rsp_log.= $rsp->{sinfo}."\r"; + } + } + + #Handle {node} structure + my $errflg=0; + my $nodes=($rsp->{node}); + unless (ref $nodes eq 'ARRAY') { + $nodes = [$nodes]; + } + if (scalar @{$nodes}) { + my $node; + foreach $node (@$nodes) { + my $desc; + if (ref($node->{name}) eq 'ARRAY') { + $desc=$node->{name}->[0]; + } else { + $desc=$node->{name}; + } + if ($node->{error}) { + $desc.=": Error: ".$node->{error}->[0]; + $errflg=1; + } + if ($node->{warning}) { + $desc.=": Warning: ".$node->{warning}->[0]; + $errflg=1; + } + if ($node->{data}) { + if (ref(\($node->{data})) eq 'SCALAR') { + $desc=$desc.": ".$node->{data}; + } elsif (ref($node->{data}) eq 'HASH') { + if ($node->{data}->{desc}) { + if (ref($node->{data}->{desc}) eq 'ARRAY') { + $desc=$desc.": ".$node->{data}->{desc}->[0]; + } else { + $desc=$desc.": ".$node->{data}->{desc}; + } + } + if ($node->{data}->{contents}) { + if (ref($node->{data}->{contents}) eq 'ARRAY') { + $desc="$desc: ".$node->{data}->{contents}->[0]; + }else{ + $desc="$desc: ".$node->{data}->{contents}; + } + } + }elsif (ref(\($node->{data}->[0])) eq 'SCALAR') { + $desc=$desc.": ".$node->{data}->[0]; + }else{ + if ($node->{data}->[0]->{desc}) { + $desc=$desc.": ".$node->{data}->[0]->{desc}->[0]; + } + if ($node->{data}->[0]->{contents}) { + $desc="$desc: ".$node->{data}->[0]->{contents}->[0]; + } + } + } + if ($desc) { + if ($errflg == 1) { + $rsp_log.= "$desc\n"; + }else{ + $rsp_log.= "$desc\n"; + } + } + } + } + + # Handle {data} structure with no nodes + foreach my $mykey ( keys %{$rsp} ) { + if ($mykey ne "data") {next;} + if ($rsp->{data}) { + my $data=($rsp->{data}); + my $data_entry; + foreach $data_entry (@$data) { + my $desc; + if (ref(\($data_entry)) eq 'SCALAR') { + $desc=$data_entry; + } else { + if ($data_entry->{desc}) { + $desc=$data_entry->{desc}->[0]; + } + if ($data_entry->{contents}) { + if ($desc) { + $desc="$desc: ".$data_entry->{contents}->[0]; + } else { + $desc=$data_entry->{contents}->[0]; + } + } + } + if ($desc) { + $rsp_log.= "$desc\n"; + } + } + } + } + } + $cmdlog_alllog .= $rsp_log; + return 0; +} + +#-------------------------------------------------------------------------------- +=head3 cmdlog_submitlog + + Used by recording command output feature. + After collecting all output for one specific command, using this subroutine to transfer output to 'Command log writer' process + + Arguments: + $cmdlog_alllog: this is a golbal attribute in a specific process which was forked for handle one specific command. + $cmdlog_alllog save the whole command output log, the format likes below: + ==================================================== + [Date] 2015-7-13 23:14:45 + [ClientType] cli + [Request] nodeset c910f02c02p30 osimage=rhels6.5-ppc64-install-compute + [Response] + c910f02c02p30: install rhels6.5-ppc64-compute + Returns: + 0 -> successful + 1 -> failed + + Note: + When connect with 'Command log writer' process by tcp, cmdlog_submitlog is only try 3 times. + If all 3 times are failed, cmdlog_submitlog will drop the command output log and issue a trace information to systemd to record this drop event. +=cut +#-------------------------------------------------------------------------------- +sub cmdlog_submitlog() { + my $tmpreq; + my $mysocket; + my $trytime=3; + my @tmplog=split(/\n/, $cmdlog_alllog); + foreach my $item (@tmplog) { + if($item =~ /\[Request\]/){ + $tmpreq = $item; + } + } + $tmpreq =~ s/\[Request\]\s+(.+)/$1/g; + if( $tmpreq =~ /getipmicons/) {return 1;} + + while ($trytime>0){ + $mysocket = IO::Socket::INET->new(PeerAddr => "127.0.0.1", + PeerPort => $cmdlog_port, + Proto => "tcp"); + if($mysocket) { + last; + }else{ + $trytime--; + sleep(0.05); + } + } + if($mysocket){ + print $mysocket $cmdlog_alllog; + close ($mysocket); + return 0; + }else{ + xCAT::MsgUtils->trace(0,"I","xcatd: Drop request '$tmpreq' output due to connection with 'Command log writer' process failed"); + return 1; + } +}