diff --git a/xCAT-probe/lib/perl/LogParse.pm b/xCAT-probe/lib/perl/LogParse.pm index 026c1adfe..3161703ac 100644 --- a/xCAT-probe/lib/perl/LogParse.pm +++ b/xCAT-probe/lib/perl/LogParse.pm @@ -23,6 +23,7 @@ use File::Basename; Arguments: Public attributes: $self->{verbose}:scalar, Offer verbose information, used for handling feature logic + $self->{load_type}:scalar, $::MONITOR or $::REPLAY, used for distinguishing monitor and replay. private attributes: $self->{log_open_info}: reference of a hash, used to save the log file operating information. $self->{current_ref_year}: scalar, the year information of current time. such as 2016. Used for log time parsing @@ -50,6 +51,7 @@ sub new { my $self = {}; my $class = shift; $self->{verbose} = shift; + $self->{load_type} = shift; my %log_open_info; $self->{log_open_info} = \%log_open_info; @@ -249,7 +251,7 @@ sub obtain_one_second_logs { while (<$fd>) { chomp; $self->debuglogger("[$loglabel]read: $_"); - my $log_content_ref = $self->obtain_log_content($self->{log_open_info}->{$loglabel}{filetype}, $_, 0); + my $log_content_ref = $self->obtain_log_content($self->{log_open_info}->{$loglabel}{filetype}, $_); #if read the log whoes time bigger than target time, stop to read $self->debuglogger("\t$log_content_ref->{time} $the_time_to_load"); @@ -472,7 +474,6 @@ sub obtain_log_content { my $self = shift; my $log_type = shift; my $original_log = shift; - my $is_monitor = shift; my %log_content = (); my @split_line = split(/\s+/, $original_log); @@ -480,7 +481,7 @@ sub obtain_log_content { if ($log_type == $::LOGTYPE_RSYSLOG) { if ($split_line[0] =~ /(\d+)-(\d+)-(\d+)T(\d+):(\d+):(\d+)(.+)-(.+)/) { $log_content{time_record} = "$4:$5:$6"; - $log_content{time} = $self->convert_to_epoch_seconds($split_line[0], $is_monitor); + $log_content{time} = $self->convert_to_epoch_seconds($split_line[0]); if (!xCAT::NetworkUtils->isIpaddr($split_line[1])) { my @sender_tmp = split(/\./, $split_line[1]); $log_content{sender} = $sender_tmp[0]; @@ -508,7 +509,7 @@ sub obtain_log_content { } else { my $timestamp = join(" ", @split_line[ 0 .. 2 ]); $log_content{time_record} = $split_line[2]; - $log_content{time} = $self->convert_to_epoch_seconds($timestamp, $is_monitor); + $log_content{time} = $self->convert_to_epoch_seconds($timestamp); if (!xCAT::NetworkUtils->isIpaddr($split_line[3])) { my @sender_tmp = split(/\./, $split_line[3]); $log_content{sender} = $sender_tmp[0]; @@ -539,7 +540,7 @@ sub obtain_log_content { if ($split_line[3] =~ /(\d+)\/(\w+)\/(\d+):(\d+):(\d+):(\d+)/) { $log_content{time_record} = "$4:$5:$6"; } - $log_content{time} = $self->convert_to_epoch_seconds($split_line[3], $is_monitor); + $log_content{time} = $self->convert_to_epoch_seconds($split_line[3]); if (!xCAT::NetworkUtils->isIpaddr($split_line[0])) { my @sender_tmp = split(/\./, $split_line[0]); $log_content{sender} = $sender_tmp[0]; @@ -567,7 +568,6 @@ sub obtain_log_content { sub convert_to_epoch_seconds { my $self = shift; my $timestr = shift; - my $is_monitor = shift; my $yday; my $mday; @@ -588,7 +588,7 @@ sub convert_to_epoch_seconds { ($mday, $dday, $h, $m, $s) = ($1, $2, $3, $4, $5); $yday = $self->{current_ref_year}; $epoch_seconds = timelocal($s, $m, $h, $dday, $monthsmap{$mday}, $yday); - if ($is_monitor) { + if ($self->{load_type} == $::MONITOR) { if ($epoch_seconds < $self->{current_ref_time}) { ++$yday; $epoch_seconds = timelocal($s, $m, $h, $dday, $monthsmap{$mday}, $yday); diff --git a/xCAT-probe/lib/perl/probe_global_constant.pm b/xCAT-probe/lib/perl/probe_global_constant.pm index 44b683117..db83a833d 100644 --- a/xCAT-probe/lib/perl/probe_global_constant.pm +++ b/xCAT-probe/lib/perl/probe_global_constant.pm @@ -2,6 +2,10 @@ # IBM(c) 2007 EPL license http://www.eclipse.org/legal/epl-v10.html package probe_global_constant; +#The type of load log +$::MONITOR = 0; +$::REPLAY = 1; + #The type of log $::LOGTYPE_RSYSLOG = 0; #rsyslog $::LOGTYPE_HTTP = 1; #apache log diff --git a/xCAT-probe/subcmds/discovery b/xCAT-probe/subcmds/discovery index 080d10ce0..258ab9829 100755 --- a/xCAT-probe/subcmds/discovery +++ b/xCAT-probe/subcmds/discovery @@ -914,7 +914,7 @@ sub do_monitor { my %fd_filetype_map; { #a very important brace to hold a code block - my $log_parse = LogParse->new($verbose); + my $log_parse = LogParse->new($verbose, $::MONITOR); my $candidate_log_ref = $log_parse->obtain_log_file_list(); #open candidate log file to obtain realtime log @@ -1071,7 +1071,7 @@ sub do_replay { print Dumper \%node_state; } - my $log_parse = LogParse->new($verbose); + my $log_parse = LogParse->new($verbose, $::REPLAY); my @candidate_mn_hostname_in_log = $log_parse->obtain_candidate_mn_hostname_in_log(); while ($start_time_of_replay < $end_time_of_replay) { diff --git a/xCAT-probe/subcmds/osdeploy b/xCAT-probe/subcmds/osdeploy index 4b64f67cd..b41ca4e1b 100755 --- a/xCAT-probe/subcmds/osdeploy +++ b/xCAT-probe/subcmds/osdeploy @@ -375,7 +375,7 @@ sub do_replay { print Dumper \%node_state; } - my $log_parse = LogParse->new($verbose); + my $log_parse = LogParse->new($verbose, $::REPLAY); my @candidate_mn_hostname_in_log = $log_parse->obtain_candidate_mn_hostname_in_log(); while ($start_time_of_replay < $end_time_of_replay) { @@ -455,7 +455,6 @@ sub conclusion_report { my $stop_stage = 0; my $start_rpower = 0; - my $power_on = 0; my $isntalling = 0; my $postbootscript = 0; @@ -468,12 +467,10 @@ sub conclusion_report { $postbootscript = 1 if ($_ == $::STATE_POSTBOOTSCRIPT); } - # Cover limited non-privision error - # 1 if xcatd receive reboot command to do provision (such like rpower, rnetboot, rinstall...) but the node status didn't change to "powering-on" - # that means reboot target node failed. - # 2 if power on target node successfully and there is 'running postbootscript' in node state history, but without "installing" state, + # Cover limited non-privision error + # 1 if power on target node successfully and there is 'running postbootscript' in node state history, but without "installing" state, # It is very possible to just do reboot process - # 3 There isn't reboot operation for target node during the rollback time window + # 2 When replay, if there isn't reboot operation for target node during the rollback time window # That means there isn't provision process happened if ($monitor) { @@ -491,11 +488,8 @@ sub conclusion_report { } } - if ($stop_stage != $::STATE_COMPLETED) { - $failed_node{$node}{provision_stop_point} = $stop_stage; - } - - if (@{ $node_state_ref->{$node}{errors}{$::STATE_POSTSCRIPT} }) { + # if not completed or completed but with postscript error, add node to failed_node hash + if ($stop_stage != $::STATE_COMPLETED or @{ $node_state_ref->{$node}{errors}{$::STATE_POSTSCRIPT} }) { $failed_node{$node}{provision_stop_point} = $stop_stage; } } @@ -512,15 +506,19 @@ sub conclusion_report { if ($failed_node{$node}{non_provision_prediction}) { probe_utils->send_msg("stdout", "f", "$node : $failed_node{$node}{non_provision_prediction}"); } else { + my $node_length = length($node); + my $space_str = " " x ($length_node + 2); + # if stop at stage before postscript, means there is error at current stage, print error message probe_utils->send_msg("stdout", "f", "$node : stop at stage '$::STATE_DESC{$failed_node{$node}{provision_stop_point}}'"); if ($failed_node{$node}{provision_stop_point} < $::STATE_POSTSCRIPT) { foreach my $node_error (@{ $node_state_ref->{$node}{errors}{$failed_node{$node}{provision_stop_point}} }) { - probe_utils->send_msg("stdout", "d", "$node_error"); + probe_utils->send_msg("stdout", "d", "$space_str $node_error"); } } else { + # if stop at postscript or after postscript, check whether has error from postscript, if has print for (my $stage = $::STATE_POSTSCRIPT; $stage <= $::STATE_COMPLETED; $stage++) { foreach my $node_error (@{ $node_state_ref->{$node}{errors}{$stage} }) { - probe_utils->send_msg("stdout", "d", "$node_error"); + probe_utils->send_msg("stdout", "d", "$space_str $node_error"); } } } @@ -569,7 +567,7 @@ Start capturing every message during OS provision process.... my %fd_filetype_map; { #a very important brace to hold a code block - my $log_parse = LogParse->new($verbose); + my $log_parse = LogParse->new($verbose, $::MONITOR); my $candidate_log_ref = $log_parse->obtain_log_file_list(); #open candidate log file to obtain realtime log @@ -611,7 +609,7 @@ Start capturing every message during OS provision process.... foreach my $hdl (@hdls) { my $line = ""; chomp($line = <$hdl>); - my $log_content_ref = $log_parse->obtain_log_content($fd_filetype_map{$hdl}, $line, $monitor); + my $log_content_ref = $log_parse->obtain_log_content($fd_filetype_map{$hdl}, $line); dispatch_log_to_handler($log_content_ref, \@candidate_mn_hostname_in_log, \%node_state); } } @@ -986,6 +984,7 @@ sub handle_compute_msg { my $return_code = $2; if ($return_code != 0) { my $error_str = "postscript $script_name return with $return_code"; + # when monitor, will show 2 same messages, so filter to show only one unless (grep {$_ eq $error_str} @{ $node_state_ref->{$node}{errors}{$::STATE_POSTSCRIPT} }) { push @{ $node_state_ref->{$node}{errors}{$::STATE_POSTSCRIPT} }, $error_str; } @@ -997,6 +996,7 @@ sub handle_compute_msg { my $return_code = $2; if ($return_code != 0) { my $error_str = "postbootscript $script_name return with $return_code"; + # when monitor, will show 2 same messages, so filter to show only one unless (grep {$_ eq $error_str} @{ $node_state_ref->{$node}{errors}{$::STATE_POSTBOOTSCRIPT} }) { push @{ $node_state_ref->{$node}{errors}{$::STATE_POSTBOOTSCRIPT} }, $error_str; } diff --git a/xCAT-probe/xcatprobe b/xCAT-probe/xcatprobe index dae96b42a..ef7d0bef1 100755 --- a/xCAT-probe/xcatprobe +++ b/xCAT-probe/xcatprobe @@ -141,7 +141,10 @@ sub format_cmd_output { if ($flag) { my $leftspace = $maxlen - length($finalmsg[$i]); - my $spacenum = (($leftspace >= $flaglen) ? ($leftspace - $flaglen) : ($screenwidth - length($finalmsg[$i]) + $maxlen - $flaglen)); + my $spacenum = 0; + if($flag !~ /debug/i) { + $spacenum = (($leftspace >= $flaglen) ? ($leftspace - $flaglen) : ($screenwidth - length($finalmsg[$i]) + $maxlen - $flaglen)); + } my $spacestr = " " x $spacenum; print "$finalmsg[$i]$spacestr";