From 97ca01394d701f5bf44ddc45bdedd01ed4141609 Mon Sep 17 00:00:00 2001 From: XuWei Date: Mon, 23 Jan 2017 00:46:26 -0500 Subject: [PATCH 1/7] xcatprobe osdeploy performance --- xCAT-probe/lib/perl/probe_global_constant.pm | 16 +- xCAT-probe/lib/perl/probe_utils.pm | 48 +++++ xCAT-probe/subcmds/osdeploy | 207 ++++++++++++++++++- 3 files changed, 255 insertions(+), 16 deletions(-) diff --git a/xCAT-probe/lib/perl/probe_global_constant.pm b/xCAT-probe/lib/perl/probe_global_constant.pm index db83a833d..454d58f36 100644 --- a/xCAT-probe/lib/perl/probe_global_constant.pm +++ b/xCAT-probe/lib/perl/probe_global_constant.pm @@ -27,12 +27,14 @@ $::STATE_BOOTLODER = 4; $::STATE_KERNEL = 5; $::STATE_INITRD = 6; $::STATE_KICKSTART = 7; -$::STATE_INSTALLING = 8; -$::STATE_INSTALLRPM = 9; -$::STATE_POSTSCRIPT = 10; -$::STATE_BOOTING = 11; -$::STATE_POSTBOOTSCRIPT = 12; -$::STATE_COMPLETED = 13; +$::STATE_NETBOOTING = 8; +$::STATE_ROOTIMG = 9; +$::STATE_INSTALLING = 10; +$::STATE_INSTALLRPM = 11; +$::STATE_POSTSCRIPT = 12; +$::STATE_BOOTING = 13; +$::STATE_POSTBOOTSCRIPT = 14; +$::STATE_COMPLETED = 15; #The description of every important stage of provision process %::STATE_DESC = ( @@ -77,5 +79,7 @@ $::STATE_DISCOVER_COMPLETED = 10; $::STATE_DISCOVER_COMPLETED => "discovery_complete", ); +$::DISKFUL = 1; +$::DISKLESS = 2; 1; diff --git a/xCAT-probe/lib/perl/probe_utils.pm b/xCAT-probe/lib/perl/probe_utils.pm index 99b59e46b..2400212c2 100644 --- a/xCAT-probe/lib/perl/probe_utils.pm +++ b/xCAT-probe/lib/perl/probe_utils.pm @@ -550,4 +550,52 @@ sub is_ntp_ready{ return 0; } +#------------------------------------------ + +=head3 + Description: + Convert second to time + Arguments: + second_in : the time in seconds + Returns: + xx:xx:xx xx hours xx minutes xx seconds +=cut + +#------------------------------------------ +sub convert_second_to_time { + my $second_in = shift; + $second_in = shift if (($second_in) && ($second_in =~ /probe_utils/)); + my @time = (); + my $result; + + if ($second_in == 0) { + return "00:00:00"; + } + + my $count = 0; + while ($count < 3) { + my $tmp_second; + if ($count == 2) { + $tmp_second = $second_in % 100; + } else { + $tmp_second = $second_in % 60; + } + if ($tmp_second == 0) { + push @time, "00"; + } elsif ($tmp_second < 10) { + push @time, "0" . "$tmp_second"; + } else { + push @time, "$tmp_second"; + } + + $second_in = ($second_in - $tmp_second) / 60; + $count++; + } + + my @time_result = reverse @time; + $result = join(":", @time_result); + + return $result; +} + 1; diff --git a/xCAT-probe/subcmds/osdeploy b/xCAT-probe/subcmds/osdeploy index 16a33f75c..c04c3af27 100755 --- a/xCAT-probe/subcmds/osdeploy +++ b/xCAT-probe/subcmds/osdeploy @@ -47,8 +47,8 @@ my $debug = 0; my $program_name = basename("$0"); $::USAGE = "Usage: $program_name -h - $program_name -n [-t ] [-V] - $program_name -n -r [-V] + $program_name -n [-t ] [-p ] [-V] + $program_name -n -r [-p ] [-V] Description: Probe operating system provision process. Supports two modes - 'Realtime monitor' and 'Replay history'. @@ -65,6 +65,9 @@ Options: -r : Trigger 'Replay history' mode. Follow the duration of rolling back. Units are 'h' (hour) or 'm' (minute) Supported format examples: 3h30m (3 hours and 30 minutes ago), 2h (2 hours ago), 40m (40 minutes ago) and 3 (3 hours ago). If unit is not specified, hour will be used by default. + -p : Performance of provision for each node and all. + Supported level: 1 (show how much time spent for provision), + 2 (show how much time spent for DHCP, Download RPM packages, Run Postscripts, Run Postbootscripts). "; @@ -82,6 +85,7 @@ if ( !GetOptions("--help|h|?" => \$help, "T" => \$test, "V" => \$verbose, + "p=s" => \$performance, "t=s" => \$maxwaittime, "r=s" => \$rollforward_time_of_replay, "n=s" => \$noderange)) @@ -107,6 +111,11 @@ unless ($noderange) { exit 1; } +my $command_input = "xcatprobe -w $program_name"; +$command_input .= " -n $noderange" if ($noderange); +$command_input .= " -p $performance" if ($performance); +$command_input .= " -V" if ($verbose); + if ($rollforward_time_of_replay) { if (($rollforward_time_of_replay !~ /(\d+)h(\d+)m/i) && ($rollforward_time_of_replay !~ /^(\d+)h*$/i) && ($rollforward_time_of_replay !~ /^(\d+)m$/i)) { probe_utils->send_msg("stdout", "f", "Unsupported time format for option '-r'"); @@ -127,6 +136,10 @@ if ($debug) { #if failed to pass pre-check, exit directly exit $rst if ($rst); +# record every status's start time and end time for each node +# $node_status_time{$node}{$status}{start_time} = $start_time; +my %node_status_time = () if ($performance); +my $provision_type = $::DISKFUL; if ($rollforward_time_of_replay) { $monitor = 0; @@ -468,6 +481,7 @@ sub conclusion_report { my $start_rpower = 0; my $isntalling = 0; my $postbootscript = 0; + my $completed = 0; #calculate node provision result #the max value of all state is the final stop stage @@ -476,6 +490,7 @@ sub conclusion_report { $start_rpower = 1 if ($_ == $::STATE_POWER_ON); $isntalling = 1 if ($_ == $::STATE_INSTALLING); $postbootscript = 1 if ($_ == $::STATE_POSTBOOTSCRIPT); + $completed = 1 if ($_ == $::STATE_COMPLETED) } # Cover limited non-privision error @@ -484,16 +499,11 @@ sub conclusion_report { # 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) { - if (!$isntalling && $postbootscript) { - $failed_node{$node}{non_provision_prediction} = "Target node just reboot from disk"; - next; - } - } else { + unless ($monitor) { if (! $start_rpower) { $failed_node{$node}{non_provision_prediction} = "Without provision process during rollback time window"; next; - } elsif (!$isntalling && $postbootscript) { + } elsif (!$isntalling && $postbootscript && !$completed) { $failed_node{$node}{non_provision_prediction} = "Target node just reboot from disk"; next; } @@ -505,7 +515,9 @@ sub conclusion_report { } } + my $is_success = 1; if (%failed_node) { + $is_success = 0; my $failed_node_num = keys %failed_node; if ($failed_node_num > 1) { probe_utils->send_msg("stdout", "d", "There are $failed_node_num node provision failures"); @@ -538,11 +550,144 @@ sub conclusion_report { } else { probe_utils->send_msg("stdout", "o", "All nodes provisioned successfully"); } + + performance_calculation($is_success) if ($performance); + return 0; } #------------------------------------------ +=head3 + Description: + Calculate the performance of provision (for each node) + Arguments: + performance: 1: calculate how much time spent for provision + 2: calculate how much time spent for each status (DHCP, RPM, POSTSCRIPTS, POSTBOOTSCRIPTS) + 3: reserve for diskless and diskful's other status + Returns: +=cut + +#------------------------------------------ +sub performance_calculation { + my $is_success = shift; + #print Dumper(%node_status_time); + + return if ((keys %node_status_time == 1 and $node_status_time{all}) or !%node_status_time); + + probe_utils->send_msg("stdout", "", "-----------node provision performance-----------"); + + my %all_spend_time = (); + my @status_for_time = (); + my $warninfo; + my $isnull = 0; + + my $length_node = 20; + my $space = " " x ($length_node - 4); + + # print table's first line + # @status_for_time: the status that needed to calculate time + if ($provision_type == $::DISKFUL and $performance == 3) { + print "NODE $space DHCP BOOTLOADER KERNEL INITRD KICKSTART RPM POST POSTBOOT COMPLETED\n"; + @status_for_time = ($::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_KICKSTART, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); + } elsif ($provision_type == $::DISKFUL and $performance == 2) { + print "NODE $space DHCP RPM POST POSTBOOT COMPLETED\n"; + @status_for_time = ($::STATE_DHCP, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); + } elsif ($provision_type == $::DISKLESS and $performance == 3) { + print "NODE $space DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT COMPLETED\n"; + @status_for_time = ($::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_NETBOOTING, $::STATE_ROOTIMG, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); + } elsif ($performance == 1) { + print "NODE $space COMPLETED\n"; + @status_for_time = ($::STATE_COMPLETED); + } + + # calculate time for each node and status + foreach my $node (keys %node_status_time) { + next if ($node eq "all"); + + # if did not get start time of power on, use osdeploy start time and show warning info + if ((!$node_status_time{$node}{$::STATE_POWER_ON}{start_time}) and $node_status_time{all}) { + $node_status_time{$node}{$::STATE_POWER_ON}{start_time} = $node_status_time{all}; + $warninfo = "Did not get start time from log during running, use xcatprobe start time"; + } + + if ($all_spend_time{start_time}) { + $all_spend_time{start_time} = ($all_spend_time{start_time} <= $node_status_time{$node}{$::STATE_POWER_ON}{start_time}) ? $all_spend_time{start_time} : $node_status_time{$node}{$::STATE_POWER_ON}{start_time}; + } else { + $all_spend_time{start_time} = $node_status_time{$node}{$::STATE_POWER_ON}{start_time}; + } + + if ($node_status_time{$node}{$::STATE_COMPLETED}{start_time}) { + $all_spend_time{end_time} = ($all_spend_time{end_time} >= $node_status_time{$node}{$::STATE_COMPLETED}{start_time}) ? $all_spend_time{end_time} : $node_status_time{$node}{$::STATE_COMPLETED}{start_time}; + } + + @timeinfo = (); + foreach my $status (@status_for_time) { + my $tmp_status; + my $tmp_detail_status; + if ($performance == 2 and $provision_type == $::DISKFUL) { + $tmp_detail_status = $::STATE_DHCP; + } else { + $tmp_detail_status = $::STATE_COMPLETED; + } + + # for some status, use time of power on as status's start time + if ($status <= $tmp_detail_status or $status == $::STATE_COMPLETED) { + $tmp_status = $::STATE_POWER_ON; + if ($warninfo) { + push @timeinfo, "NULL* "; + $isnull = 1; + $all_spend_time{$status}{rst} = "NULL* "; + next; + } + } else { + $tmp_status = $status; + } + + my $tmp_end_time; + $tmp_end_time = $node_status_time{$node}{$status}{end_time} if ($node_status_time{$node}{$status}{end_time}); + $tmp_end_time = $node_status_time{$node}{$status}{start_time} if ($status != $::STATE_DHCP and $status != $::STATE_INSTALLRPM and $status != $::STATE_POSTSCRIPT and $status != $::STATE_POSTBOOTSCRIPT and $node_status_time{$node}{$status}{start_time}); + + if ($node_status_time{$node}{$tmp_status}{start_time} && $tmp_end_time) { + if ($all_spend_time{$status}{start_time}) { + $all_spend_time{$status}{start_time} = ($all_spend_time{$status}{start_time} <= $node_status_time{$node}{$tmp_status}{start_time}) ? $all_spend_time{$status}{start_time} : $node_status_time{$node}{$tmp_status}{start_time}; + } else { + $all_spend_time{$status}{start_time} = $node_status_time{$node}{$tmp_status}{start_time}; + } + $all_spend_time{$status}{end_time} = ($all_spend_time{$status}{end_time} >= $tmp_end_time) ? $all_spend_time{$status}{end_time} : $tmp_end_time; + push @timeinfo, probe_utils->convert_second_to_time($tmp_end_time - $node_status_time{$node}{$tmp_status}{start_time}); + } else { + push @timeinfo, "NULL* "; + $all_spend_time{$status}{rst} = "NULL* "; + $isnull = 1; + } + } + + my $time_str = join(" ", @timeinfo); + $space = " " x ($length_node - length($node)); + print "$node $space $time_str\n"; + } + + my @time_rst = (); + foreach my $status (@status_for_time) { + if ($all_spend_time{$status}{rst} eq "NULL* ") { + push @time_rst, $all_spend_time{$status}{rst}; + } else { + my $status_time = probe_utils->convert_second_to_time($all_spend_time{$status}{end_time} - $all_spend_time{$status}{start_time}); + push @time_rst, $status_time; + } + } + + my $time_str = join(" ", @time_rst); + $space = " " x ($length_node - 3); + print "ALL $space $time_str\n"; + probe_utils->send_msg("stdout", "", "------------------------------------------------"); + probe_utils->send_msg("stdout", "", "$warninfo") if ($warninfo); + probe_utils->send_msg("stdout", "", "* : Did not get correct time, please run '$command_input -r xxhxxm' to get correct time") if ($isnull and $is_success); +} + +#------------------------------------------ + =head3 Description: Implement the monitor feature @@ -573,6 +718,8 @@ Start capturing every message during OS provision process.... "; probe_utils->send_msg("stdout", "", "$startline"); + $node_status_time{all} = time(); + my @openfilepids; my @openfilefds; my %fd_filetype_map; @@ -766,7 +913,7 @@ sub handle_dhcp_msg { my $ip = $1; my $mac = $2; my $nic = $3; - + if (exists $macmap{$mac}) { my $node = $macmap{$mac}{"node"}; my $record = $log_ref->{msg}; @@ -793,6 +940,7 @@ sub handle_dhcp_msg { $ipnodemap{$ip} = $node; set_node_state($node_state_ref, $node, $::STATE_DHCP); + $node_status_time{$node}{$::STATE_DHCP}{end_time} = $log_ref->{time} if ($performance and !$node_status_time{$node}{$::STATE_DHCP}{end_time}); } } elsif ($log_ref->{msg} =~ /BOOTREQUEST\s+from\s+(.+)\s+via\s+([^:]+)(.*)/) { my $mac = $1; @@ -802,6 +950,7 @@ sub handle_dhcp_msg { my $record = "Receive BOOTREQUEST from $mac via $nic"; probe_utils->send_msg("stdout", "d", "[$node] $log_ref->{time_record} $record") if ($monitor); push(@{ $node_state_ref->{$node}{log} }, $log_ref->{msg}) if ($debug); + $node_status_time{$node}{$::STATE_DHCP}{start_time} = $log_ref->{time} if ($performance); } } elsif ($log_ref->{msg} =~ /BOOTREPLY\s+for\s+(.+)\s+to\s+.+(\w\w:\w\w:\w\w:\w\w:\w\w:\w\w).+via\s+(.+)/) { my $ip = $1; @@ -821,6 +970,7 @@ sub handle_dhcp_msg { $ipnodemap{$ip} = $node; set_node_state($node_state_ref, $node, $::STATE_DHCP); + $node_status_time{$node}{$::STATE_DHCP}{end_time} = $log_ref->{time} if ($performance); } } } @@ -852,10 +1002,13 @@ sub handle_tftp_msg { if ($file =~ /xcat\/xnba.*/i or $file =~ /\/boot\/grub2\/powerpc-ieee1275\//i or $file =~ /\/yb\/node\/yaboot\-/i) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_BOOTLODER); + $node_status_time{$ipnodemap{$ip}}{$::STATE_BOOTLODER}{start_time} = $log_ref->{time} if ($performance); } elsif ($file =~ /vmlinuz|inst64|linux/) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_KERNEL); + $node_status_time{$ipnodemap{$ip}}{$::STATE_KERNEL}{start_time} = $log_ref->{time} if ($performance); } elsif ($file =~ /initrd/i) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_INITRD); + $node_status_time{$ipnodemap{$ip}}{$::STATE_INITRD}{start_time} = $log_ref->{time} if ($performance); } } } @@ -892,16 +1045,29 @@ sub handle_http_msg { if ($file =~ /vmlinuz|inst64/i or ($file =~ /linux/i and $file =~ /osimage/i)) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_KERNEL); + $node_status_time{$ipnodemap{$ip}}{$::STATE_KERNEL}{start_time} = $log_ref->{time} if ($performance); push (@{ $node_state_ref->{ $ipnodemap{$ip} }{errors}{$::STATE_KERNEL} }, "$record failed with $http_code") if ($http_code >= 400); } elsif ($file =~ /initrd/i and $file =~ /osimage/i) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_INITRD); + $node_status_time{$ipnodemap{$ip}}{$::STATE_INITRD}{start_time} = $log_ref->{time} if ($performance); push (@{ $node_state_ref->{ $ipnodemap{$ip} }{errors}{$::STATE_INITRD} }, "$record failed with $http_code") if ($http_code >= 400); } elsif (($file =~ /^\/install\/autoinst\//i) and ($file !~ /getinstdisk$/i) and ($file !~ /\.pre$/i) and ($file !~ /\.post$/i)) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_KICKSTART); + $node_status_time{$ipnodemap{$ip}}{$::STATE_KICKSTART}{start_time} = $log_ref->{time} if ($performance); push (@{ $node_state_ref->{ $ipnodemap{$ip} }{errors}{$::STATE_KICKSTART} }, "$record failed with $http_code") if ($http_code >= 400); } elsif ($file =~ /\.deb$/i or $file =~ /\/Packages\/.+\.rpm$/ or $file =~ /\/suse\/noarch\/.+\.rpm$/i) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_INSTALLRPM); + if ($performance) { + if ($node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{start_time}) { + $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{end_time} = $log_ref->{time}; + } else { + $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{start_time} = $log_ref->{time}; + } + } push (@{ $node_state_ref->{ $ipnodemap{$ip} }{errors}{$::STATE_INSTALLRPM} }, "$record failed with $http_code") if ($http_code >= 400); + } elsif ($file =~ /rootimg/) { + set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_ROOTIMG); + $node_status_time{$ipnodemap{$ip}}{$::STATE_ROOTIMG}{start_time} = $log_ref->{time} if ($performance); } } } @@ -939,6 +1105,7 @@ sub handle_cluster_msg { probe_utils->send_msg("stdout", "d", "[$node] $log_ref->{time_record} Use command $command to reboot node $node") if ($monitor); push(@{ $node_state_ref->{$node}{log} }, $log_ref->{msg}) if ($debug); set_node_state($node_state_ref, $node, $::STATE_POWER_ON); + $node_status_time{$node}{$::STATE_POWER_ON}{start_time} = $log_ref->{time} if ($performance); } } } @@ -955,10 +1122,16 @@ sub handle_cluster_msg { if ($status eq "installing") { set_node_state($node_state_ref, $node, $::STATE_INSTALLING); + $node_status_time{$node}{$::STATE_INSTALLING}{start_time} = $log_ref->{time} if ($performance); } elsif ($status eq "powering-on") { set_node_state($node_state_ref, $node, $::STATE_POWERINGON); + $node_status_time{$node}{$::STATE_POWERINGON}{start_time} = $log_ref->{time} if ($performance); } elsif ($status eq "booting") { set_node_state($node_state_ref, $node, $::STATE_BOOTING); + $node_status_time{$node}{$::STATE_BOOTING}{start_time} = $log_ref->{time} if ($performance); + } elsif ($status eq "netbooting") { + set_node_state($node_state_ref, $node, $::STATE_NETBOOTING); + $node_status_time{$node}{$::STATE_NETBOOTING}{start_time} = $log_ref->{time} if ($performance); } elsif ($status eq "failed") { $node_state_ref->{$node}{done} = 1; } @@ -990,6 +1163,11 @@ sub handle_compute_msg { push(@{ $node_state_ref->{$node}{log} }, $log_ref->{msg}) if ($debug); if ($log_ref->{msg} =~ /Running postscript:/i) { set_node_state($node_state_ref, $node, $::STATE_POSTSCRIPT); + if ($performance) { + if (!$node_status_time{$node}{$::STATE_POSTSCRIPT}{start_time}) { + $node_status_time{$node}{$::STATE_POSTSCRIPT}{start_time} = $log_ref->{time}; + } + } } elsif ($log_ref->{msg} =~ /postscript (.+) return with (\d+)/) { my $script_name = $1; my $return_code = $2; @@ -1000,8 +1178,14 @@ sub handle_compute_msg { push @{ $node_state_ref->{$node}{errors}{$::STATE_POSTSCRIPT} }, $error_str; } } + $node_status_time{$node}{$::STATE_POSTSCRIPT}{end_time} = $log_ref->{time} if ($performance); } elsif ($log_ref->{msg} =~ /Running postbootscript:/i) { set_node_state($node_state_ref, $node, $::STATE_POSTBOOTSCRIPT); + if ($performance) { + if (!$node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{start_time}) { + $node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{start_time} = $log_ref->{time}; + } + } } elsif ($log_ref->{msg} =~ /postbootscript (.+) return with (\d+)/) { my $script_name = $1; my $return_code = $2; @@ -1012,10 +1196,12 @@ sub handle_compute_msg { push @{ $node_state_ref->{$node}{errors}{$::STATE_POSTBOOTSCRIPT} }, $error_str; } } + $node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{end_time} = $log_ref->{time} if ($performance); } elsif ($log_ref->{msg} =~ /provision completed/) { set_node_state($node_state_ref, $node, $::STATE_COMPLETED); $node_state_ref->{$node}{done} = 1; probe_utils->send_msg("stdout", "o", "[$node] $log_ref->{time_record} provision completed") if ($monitor); + $node_status_time{$node}{$::STATE_COMPLETED}{start_time} = $log_ref->{time}; } } } @@ -1078,6 +1264,7 @@ sub set_node_state { @{ $node_state_ref->{$node}{statehistory} } = (); %{ $node_state_ref->{$node}{errors} } = (); push @{ $node_state_ref->{$node}{statehistory} }, $newstate; + $node_status_time{$node} = (); } else { my $index = @{ $node_state_ref->{$node}{statehistory} } - 1; From 6fdf3bef665eea5fb899cdaded513cfc7ddb6c5b Mon Sep 17 00:00:00 2001 From: XuWei Date: Tue, 24 Jan 2017 20:36:19 -0500 Subject: [PATCH 2/7] modified depending on comments --- xCAT-probe/lib/perl/probe_utils.pm | 7 +++---- xCAT-probe/subcmds/osdeploy | 7 ++++--- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/xCAT-probe/lib/perl/probe_utils.pm b/xCAT-probe/lib/perl/probe_utils.pm index 2400212c2..e309def96 100644 --- a/xCAT-probe/lib/perl/probe_utils.pm +++ b/xCAT-probe/lib/perl/probe_utils.pm @@ -580,10 +580,9 @@ sub convert_second_to_time { } else { $tmp_second = $second_in % 60; } - if ($tmp_second == 0) { - push @time, "00"; - } elsif ($tmp_second < 10) { - push @time, "0" . "$tmp_second"; + + if ($tmp_second < 10) { + push @time, "0$tmp_second"; } else { push @time, "$tmp_second"; } diff --git a/xCAT-probe/subcmds/osdeploy b/xCAT-probe/subcmds/osdeploy index c04c3af27..6a92ecc1a 100755 --- a/xCAT-probe/subcmds/osdeploy +++ b/xCAT-probe/subcmds/osdeploy @@ -65,9 +65,10 @@ Options: -r : Trigger 'Replay history' mode. Follow the duration of rolling back. Units are 'h' (hour) or 'm' (minute) Supported format examples: 3h30m (3 hours and 30 minutes ago), 2h (2 hours ago), 40m (40 minutes ago) and 3 (3 hours ago). If unit is not specified, hour will be used by default. - -p : Performance of provision for each node and all. - Supported level: 1 (show how much time spent for provision), - 2 (show how much time spent for DHCP, Download RPM packages, Run Postscripts, Run Postbootscripts). + -p Show elapsed time of each stage during provision for each node + Support 2 output format: + 1 Elapsed time of each stage during provision + 2 Elapsed time from power on node to each stage starting "; From 7674577324209c2d5f05bb6bf7e113f1ab72afd4 Mon Sep 17 00:00:00 2001 From: XuWei Date: Mon, 6 Feb 2017 02:30:51 -0500 Subject: [PATCH 3/7] modified depending on comments --- xCAT-probe/subcmds/osdeploy | 86 ++++++++++++++++++++----------------- 1 file changed, 47 insertions(+), 39 deletions(-) diff --git a/xCAT-probe/subcmds/osdeploy b/xCAT-probe/subcmds/osdeploy index 6a92ecc1a..6bc76d930 100755 --- a/xCAT-probe/subcmds/osdeploy +++ b/xCAT-probe/subcmds/osdeploy @@ -67,8 +67,8 @@ Options: If unit is not specified, hour will be used by default. -p Show elapsed time of each stage during provision for each node Support 2 output format: - 1 Elapsed time of each stage during provision - 2 Elapsed time from power on node to each stage starting + 'compact': Elapsed time of provision for each node. + 'details': Elapsed time for DHCP, RPM, POSTSCRIPTS and POSTBOOTSCRIPTS stages, and time for whole provision. "; @@ -112,11 +112,6 @@ unless ($noderange) { exit 1; } -my $command_input = "xcatprobe -w $program_name"; -$command_input .= " -n $noderange" if ($noderange); -$command_input .= " -p $performance" if ($performance); -$command_input .= " -V" if ($verbose); - if ($rollforward_time_of_replay) { if (($rollforward_time_of_replay !~ /(\d+)h(\d+)m/i) && ($rollforward_time_of_replay !~ /^(\d+)h*$/i) && ($rollforward_time_of_replay !~ /^(\d+)m$/i)) { probe_utils->send_msg("stdout", "f", "Unsupported time format for option '-r'"); @@ -125,6 +120,14 @@ if ($rollforward_time_of_replay) { } } +if ($performance) { + if ($performance ne "compact" and $performance ne "details") { + probe_utils->send_msg("stdout", "f", "Unsupported parameter for option '-p'"); + probe_utils->send_msg("stdout", "", "$::USAGE"); + exit 1; + } +} + my $rst = do_pre_check($noderange); if ($debug) { print "Dumper macmap--------\n"; @@ -447,7 +450,7 @@ sub do_replay { sub conclusion_report { my $node_state_ref = shift; - probe_utils->send_msg("stdout", "", "==================osdeploy_probe_report================="); + probe_utils->send_msg("stdout", "", "====================== Summary ====================="); if ($debug) { print "---->the result of %node_state<------\n"; @@ -494,10 +497,10 @@ sub conclusion_report { $completed = 1 if ($_ == $::STATE_COMPLETED) } - # Cover limited non-privision error + # Cover limited non-privision error when replay # 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 - # 2 When replay, if there isn't reboot operation for target node during the rollback time window + # 2 if there isn't reboot operation for target node during the rollback time window # That means there isn't provision process happened unless ($monitor) { @@ -563,16 +566,16 @@ sub conclusion_report { Description: Calculate the performance of provision (for each node) Arguments: - performance: 1: calculate how much time spent for provision - 2: calculate how much time spent for each status (DHCP, RPM, POSTSCRIPTS, POSTBOOTSCRIPTS) - 3: reserve for diskless and diskful's other status + performance: compact: calculate how much time spent for provision + details: calculate how much time spent for each status (DHCP, RPM, POSTSCRIPTS, POSTBOOTSCRIPTS) + reserve: reserve for diskless Returns: =cut #------------------------------------------ sub performance_calculation { my $is_success = shift; - #print Dumper(%node_status_time); + print Dumper(%node_status_time); return if ((keys %node_status_time == 1 and $node_status_time{all}) or !%node_status_time); @@ -588,16 +591,16 @@ sub performance_calculation { # print table's first line # @status_for_time: the status that needed to calculate time - if ($provision_type == $::DISKFUL and $performance == 3) { + if ($provision_type == $::DISKFUL and $performance eq "reserve") { print "NODE $space DHCP BOOTLOADER KERNEL INITRD KICKSTART RPM POST POSTBOOT COMPLETED\n"; @status_for_time = ($::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_KICKSTART, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); - } elsif ($provision_type == $::DISKFUL and $performance == 2) { + } elsif ($provision_type == $::DISKFUL and $performance eq "details") { print "NODE $space DHCP RPM POST POSTBOOT COMPLETED\n"; @status_for_time = ($::STATE_DHCP, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); - } elsif ($provision_type == $::DISKLESS and $performance == 3) { + } elsif ($provision_type == $::DISKLESS and $performance eq "reserve") { print "NODE $space DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT COMPLETED\n"; @status_for_time = ($::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_NETBOOTING, $::STATE_ROOTIMG, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); - } elsif ($performance == 1) { + } elsif ($performance eq "compact") { print "NODE $space COMPLETED\n"; @status_for_time = ($::STATE_COMPLETED); } @@ -612,30 +615,34 @@ sub performance_calculation { $warninfo = "Did not get start time from log during running, use xcatprobe start time"; } + # get the start time of the first node if ($all_spend_time{start_time}) { - $all_spend_time{start_time} = ($all_spend_time{start_time} <= $node_status_time{$node}{$::STATE_POWER_ON}{start_time}) ? $all_spend_time{start_time} : $node_status_time{$node}{$::STATE_POWER_ON}{start_time}; + $all_spend_time{start_time} = $node_status_time{$node}{$::STATE_POWER_ON}{start_time} if ($all_spend_time{start_time} > $node_status_time{$node}{$::STATE_POWER_ON}{start_time}); } else { $all_spend_time{start_time} = $node_status_time{$node}{$::STATE_POWER_ON}{start_time}; } + # get the end time of the last node if ($node_status_time{$node}{$::STATE_COMPLETED}{start_time}) { - $all_spend_time{end_time} = ($all_spend_time{end_time} >= $node_status_time{$node}{$::STATE_COMPLETED}{start_time}) ? $all_spend_time{end_time} : $node_status_time{$node}{$::STATE_COMPLETED}{start_time}; + $all_spend_time{end_time} = $node_status_time{$node}{$::STATE_COMPLETED}{start_time} if ($all_spend_time{end_time} < $node_status_time{$node}{$::STATE_COMPLETED}{start_time}); } + # get the start time and end time for each step @timeinfo = (); foreach my $status (@status_for_time) { my $tmp_status; my $tmp_detail_status; - if ($performance == 2 and $provision_type == $::DISKFUL) { + if ($performance eq "details" and $provision_type == $::DISKFUL) { + # when details, if the status is DHCP, use power on time as it's start time $tmp_detail_status = $::STATE_DHCP; } else { + # if not details, power on time is the start time for each steps $tmp_detail_status = $::STATE_COMPLETED; } - # for some status, use time of power on as status's start time if ($status <= $tmp_detail_status or $status == $::STATE_COMPLETED) { $tmp_status = $::STATE_POWER_ON; - if ($warninfo) { + if ($warninfo and $status == $::STATE_DHCP) { push @timeinfo, "NULL* "; $isnull = 1; $all_spend_time{$status}{rst} = "NULL* "; @@ -651,11 +658,11 @@ sub performance_calculation { if ($node_status_time{$node}{$tmp_status}{start_time} && $tmp_end_time) { if ($all_spend_time{$status}{start_time}) { - $all_spend_time{$status}{start_time} = ($all_spend_time{$status}{start_time} <= $node_status_time{$node}{$tmp_status}{start_time}) ? $all_spend_time{$status}{start_time} : $node_status_time{$node}{$tmp_status}{start_time}; + $all_spend_time{$status}{start_time} = $node_status_time{$node}{$tmp_status}{start_time} if ($all_spend_time{$status}{start_time} > $node_status_time{$node}{$tmp_status}{start_time}); } else { $all_spend_time{$status}{start_time} = $node_status_time{$node}{$tmp_status}{start_time}; } - $all_spend_time{$status}{end_time} = ($all_spend_time{$status}{end_time} >= $tmp_end_time) ? $all_spend_time{$status}{end_time} : $tmp_end_time; + $all_spend_time{$status}{end_time} = $tmp_end_time if ($all_spend_time{$status}{end_time} < $tmp_end_time); push @timeinfo, probe_utils->convert_second_to_time($tmp_end_time - $node_status_time{$node}{$tmp_status}{start_time}); } else { push @timeinfo, "NULL* "; @@ -669,6 +676,7 @@ sub performance_calculation { print "$node $space $time_str\n"; } + # @time_rst is used to record time of ALL my @time_rst = (); foreach my $status (@status_for_time) { if ($all_spend_time{$status}{rst} eq "NULL* ") { @@ -684,7 +692,15 @@ sub performance_calculation { print "ALL $space $time_str\n"; probe_utils->send_msg("stdout", "", "------------------------------------------------"); probe_utils->send_msg("stdout", "", "$warninfo") if ($warninfo); - probe_utils->send_msg("stdout", "", "* : Did not get correct time, please run '$command_input -r xxhxxm' to get correct time") if ($isnull and $is_success); + + if ($isnull and $is_success) { + my $command_input = "xcatprobe -w $program_name"; + $command_input .= " -n $noderange" if ($noderange); + $command_input .= " -p $performance"; + $command_input .= " -V" if ($verbose); + $command_input .= " -r xxhxxm"; + probe_utils->send_msg("stdout", "", "Did not get correct time, please run '$command_input' to get correct time"); + } } #------------------------------------------ @@ -951,7 +967,6 @@ sub handle_dhcp_msg { my $record = "Receive BOOTREQUEST from $mac via $nic"; probe_utils->send_msg("stdout", "d", "[$node] $log_ref->{time_record} $record") if ($monitor); push(@{ $node_state_ref->{$node}{log} }, $log_ref->{msg}) if ($debug); - $node_status_time{$node}{$::STATE_DHCP}{start_time} = $log_ref->{time} if ($performance); } } elsif ($log_ref->{msg} =~ /BOOTREPLY\s+for\s+(.+)\s+to\s+.+(\w\w:\w\w:\w\w:\w\w:\w\w:\w\w).+via\s+(.+)/) { my $ip = $1; @@ -971,7 +986,7 @@ sub handle_dhcp_msg { $ipnodemap{$ip} = $node; set_node_state($node_state_ref, $node, $::STATE_DHCP); - $node_status_time{$node}{$::STATE_DHCP}{end_time} = $log_ref->{time} if ($performance); + $node_status_time{$node}{$::STATE_DHCP}{end_time} = $log_ref->{time} if ($performance and !$node_status_time{$node}{$::STATE_DHCP}{end_time}); } } } @@ -1059,11 +1074,8 @@ sub handle_http_msg { } elsif ($file =~ /\.deb$/i or $file =~ /\/Packages\/.+\.rpm$/ or $file =~ /\/suse\/noarch\/.+\.rpm$/i) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_INSTALLRPM); if ($performance) { - if ($node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{start_time}) { - $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{end_time} = $log_ref->{time}; - } else { - $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{start_time} = $log_ref->{time}; - } + $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{end_time} = $log_ref->{time}; + $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{start_time} = $log_ref->{time} unless ( $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{start_time} ); } push (@{ $node_state_ref->{ $ipnodemap{$ip} }{errors}{$::STATE_INSTALLRPM} }, "$record failed with $http_code") if ($http_code >= 400); } elsif ($file =~ /rootimg/) { @@ -1165,9 +1177,7 @@ sub handle_compute_msg { if ($log_ref->{msg} =~ /Running postscript:/i) { set_node_state($node_state_ref, $node, $::STATE_POSTSCRIPT); if ($performance) { - if (!$node_status_time{$node}{$::STATE_POSTSCRIPT}{start_time}) { - $node_status_time{$node}{$::STATE_POSTSCRIPT}{start_time} = $log_ref->{time}; - } + $node_status_time{$node}{$::STATE_POSTSCRIPT}{start_time} = $log_ref->{time} unless ($node_status_time{$node}{$::STATE_POSTSCRIPT}{start_time}); } } elsif ($log_ref->{msg} =~ /postscript (.+) return with (\d+)/) { my $script_name = $1; @@ -1183,9 +1193,7 @@ sub handle_compute_msg { } elsif ($log_ref->{msg} =~ /Running postbootscript:/i) { set_node_state($node_state_ref, $node, $::STATE_POSTBOOTSCRIPT); if ($performance) { - if (!$node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{start_time}) { - $node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{start_time} = $log_ref->{time}; - } + $node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{start_time} = $log_ref->{time} unless ($node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{start_time}); } } elsif ($log_ref->{msg} =~ /postbootscript (.+) return with (\d+)/) { my $script_name = $1; From 17800828bf364757298fdfa3ddad137ee80f8692 Mon Sep 17 00:00:00 2001 From: XuWei Date: Thu, 9 Feb 2017 01:51:09 -0500 Subject: [PATCH 4/7] modified depending on comments --- xCAT-probe/subcmds/osdeploy | 219 +++++++++++++++++++++--------------- 1 file changed, 130 insertions(+), 89 deletions(-) diff --git a/xCAT-probe/subcmds/osdeploy b/xCAT-probe/subcmds/osdeploy index 6bc76d930..4ef4d689f 100755 --- a/xCAT-probe/subcmds/osdeploy +++ b/xCAT-probe/subcmds/osdeploy @@ -68,7 +68,8 @@ Options: -p Show elapsed time of each stage during provision for each node Support 2 output format: 'compact': Elapsed time of provision for each node. - 'details': Elapsed time for DHCP, RPM, POSTSCRIPTS and POSTBOOTSCRIPTS stages, and time for whole provision. + 'phase' : Elapsed time for DHCP, RPM, POSTSCRIPTS and POSTBOOTSCRIPTS stages, and time for whole provision. + 'origin' : Show origin time of each stage. "; @@ -121,7 +122,7 @@ if ($rollforward_time_of_replay) { } if ($performance) { - if ($performance ne "compact" and $performance ne "details") { + if ($performance ne "compact" and $performance ne "phase" and $performance ne "origin") { probe_utils->send_msg("stdout", "f", "Unsupported parameter for option '-p'"); probe_utils->send_msg("stdout", "", "$::USAGE"); exit 1; @@ -143,7 +144,6 @@ exit $rst if ($rst); # record every status's start time and end time for each node # $node_status_time{$node}{$status}{start_time} = $start_time; my %node_status_time = () if ($performance); -my $provision_type = $::DISKFUL; if ($rollforward_time_of_replay) { $monitor = 0; @@ -567,23 +567,25 @@ sub conclusion_report { Calculate the performance of provision (for each node) Arguments: performance: compact: calculate how much time spent for provision - details: calculate how much time spent for each status (DHCP, RPM, POSTSCRIPTS, POSTBOOTSCRIPTS) - reserve: reserve for diskless + phase: calculate how much time spent for each status (DHCP, RPM, POSTSCRIPTS, POSTBOOTSCRIPTS) + origin : show time point for each status + reserve: reserve for other type Returns: =cut #------------------------------------------ sub performance_calculation { my $is_success = shift; - print Dumper(%node_status_time); + #print Dumper(%node_status_time); - return if ((keys %node_status_time == 1 and $node_status_time{all}) or !%node_status_time); + return if (!%node_status_time); probe_utils->send_msg("stdout", "", "-----------node provision performance-----------"); - my %all_spend_time = (); + # Currently, only diskful is supported + my $provision_type = $::DISKFUL; + my @status_for_time = (); - my $warninfo; my $isnull = 0; my $length_node = 20; @@ -591,40 +593,61 @@ sub performance_calculation { # print table's first line # @status_for_time: the status that needed to calculate time - if ($provision_type == $::DISKFUL and $performance eq "reserve") { - print "NODE $space DHCP BOOTLOADER KERNEL INITRD KICKSTART RPM POST POSTBOOT COMPLETED\n"; - @status_for_time = ($::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_KICKSTART, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); - } elsif ($provision_type == $::DISKFUL and $performance eq "details") { - print "NODE $space DHCP RPM POST POSTBOOT COMPLETED\n"; - @status_for_time = ($::STATE_DHCP, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); - } elsif ($provision_type == $::DISKLESS and $performance eq "reserve") { - print "NODE $space DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT COMPLETED\n"; - @status_for_time = ($::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_NETBOOTING, $::STATE_ROOTIMG, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); - } elsif ($performance eq "compact") { - print "NODE $space COMPLETED\n"; + + my @title_lines = ( + "NODE $space ELAPSED\n", + "NODE $space SVRBOOT RPM POST POSTBOOT ELAPSED\n", + "NODE $space RPOWER DHCP BOOTLOADER KERNEL INITRD RPM POST POSTBOOT COMPLETED\n", + "NODE $space RPOWER DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT COMPLETED\n", + "NODE $space DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT ELAPSED\n"); + + if ($performance eq "compact") { + print $title_lines[0]; @status_for_time = ($::STATE_COMPLETED); } + if ($performance eq "phase") { + print $title_lines[1]; + @status_for_time = ($::STATE_DHCP, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); + } + + if ($performance eq "origin") { + if ($provision_type == $::DISKFUL){ + print $title_lines[2]; + @status_for_time = ($::STATE_POWER_ON, $::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); + } else { # reserved for diskless + print $title_lines[3]; + @status_for_time = ($::STATE_POWER_ON, $::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_NETBOOTING, $::STATE_ROOTIMG, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); + } + } + + if ($performance eq "reserve") { + print $title_lines[4]; + @status_for_time = ($::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_NETBOOTING, $::STATE_ROOTIMG, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); + } + # calculate time for each node and status foreach my $node (keys %node_status_time) { - next if ($node eq "all"); - # if did not get start time of power on, use osdeploy start time and show warning info - if ((!$node_status_time{$node}{$::STATE_POWER_ON}{start_time}) and $node_status_time{all}) { - $node_status_time{$node}{$::STATE_POWER_ON}{start_time} = $node_status_time{all}; - $warninfo = "Did not get start time from log during running, use xcatprobe start time"; - } - - # get the start time of the first node - if ($all_spend_time{start_time}) { - $all_spend_time{start_time} = $node_status_time{$node}{$::STATE_POWER_ON}{start_time} if ($all_spend_time{start_time} > $node_status_time{$node}{$::STATE_POWER_ON}{start_time}); - } else { - $all_spend_time{start_time} = $node_status_time{$node}{$::STATE_POWER_ON}{start_time}; - } - - # get the end time of the last node - if ($node_status_time{$node}{$::STATE_COMPLETED}{start_time}) { - $all_spend_time{end_time} = $node_status_time{$node}{$::STATE_COMPLETED}{start_time} if ($all_spend_time{end_time} < $node_status_time{$node}{$::STATE_COMPLETED}{start_time}); + if ($performance eq "origin") { + my @time_origin = (); + foreach my $status (@status_for_time) { + if ($node_status_time{$node}{$status}{time_point}) { + if ($status == $::STATE_DHCP and $node_status_time{$node}{$::STATE_DHCP}{end_time} > $node_status_time{$node}{$::STATE_BOOTLODER}{start_time}){ + push @time_origin, "NULL* "; + $isnull = 1; + } else { + push @time_origin, $node_status_time{$node}{$status}{time_point}; + } + } else { + push @time_origin, "NULL* "; + $isnull = 1; + } + } + my $time_str = join(" ", @time_origin); + $space = " " x ($length_node - length($node)); + print "$node $space $time_str\n"; + next; } # get the start time and end time for each step @@ -632,41 +655,28 @@ sub performance_calculation { foreach my $status (@status_for_time) { my $tmp_status; my $tmp_detail_status; - if ($performance eq "details" and $provision_type == $::DISKFUL) { - # when details, if the status is DHCP, use power on time as it's start time + if ($performance eq "phase") { + # when phase, if the status is DHCP, use power on time as it's start time $tmp_detail_status = $::STATE_DHCP; } else { - # if not details, power on time is the start time for each steps + # if not phase, power on time is the start time for each steps $tmp_detail_status = $::STATE_COMPLETED; } if ($status <= $tmp_detail_status or $status == $::STATE_COMPLETED) { $tmp_status = $::STATE_POWER_ON; - if ($warninfo and $status == $::STATE_DHCP) { - push @timeinfo, "NULL* "; - $isnull = 1; - $all_spend_time{$status}{rst} = "NULL* "; - next; - } } else { $tmp_status = $status; } - my $tmp_end_time; - $tmp_end_time = $node_status_time{$node}{$status}{end_time} if ($node_status_time{$node}{$status}{end_time}); + my $tmp_start_time = $node_status_time{$node}{$tmp_status}{start_time}; + my $tmp_end_time = $node_status_time{$node}{$status}{end_time}; $tmp_end_time = $node_status_time{$node}{$status}{start_time} if ($status != $::STATE_DHCP and $status != $::STATE_INSTALLRPM and $status != $::STATE_POSTSCRIPT and $status != $::STATE_POSTBOOTSCRIPT and $node_status_time{$node}{$status}{start_time}); - if ($node_status_time{$node}{$tmp_status}{start_time} && $tmp_end_time) { - if ($all_spend_time{$status}{start_time}) { - $all_spend_time{$status}{start_time} = $node_status_time{$node}{$tmp_status}{start_time} if ($all_spend_time{$status}{start_time} > $node_status_time{$node}{$tmp_status}{start_time}); - } else { - $all_spend_time{$status}{start_time} = $node_status_time{$node}{$tmp_status}{start_time}; - } - $all_spend_time{$status}{end_time} = $tmp_end_time if ($all_spend_time{$status}{end_time} < $tmp_end_time); - push @timeinfo, probe_utils->convert_second_to_time($tmp_end_time - $node_status_time{$node}{$tmp_status}{start_time}); + if ($tmp_start_time && $tmp_end_time) { + push @timeinfo, probe_utils->convert_second_to_time($tmp_end_time - $tmp_start_time); } else { push @timeinfo, "NULL* "; - $all_spend_time{$status}{rst} = "NULL* "; $isnull = 1; } } @@ -676,22 +686,7 @@ sub performance_calculation { print "$node $space $time_str\n"; } - # @time_rst is used to record time of ALL - my @time_rst = (); - foreach my $status (@status_for_time) { - if ($all_spend_time{$status}{rst} eq "NULL* ") { - push @time_rst, $all_spend_time{$status}{rst}; - } else { - my $status_time = probe_utils->convert_second_to_time($all_spend_time{$status}{end_time} - $all_spend_time{$status}{start_time}); - push @time_rst, $status_time; - } - } - - my $time_str = join(" ", @time_rst); - $space = " " x ($length_node - 3); - print "ALL $space $time_str\n"; probe_utils->send_msg("stdout", "", "------------------------------------------------"); - probe_utils->send_msg("stdout", "", "$warninfo") if ($warninfo); if ($isnull and $is_success) { my $command_input = "xcatprobe -w $program_name"; @@ -735,8 +730,6 @@ Start capturing every message during OS provision process.... "; probe_utils->send_msg("stdout", "", "$startline"); - $node_status_time{all} = time(); - my @openfilepids; my @openfilefds; my %fd_filetype_map; @@ -957,7 +950,10 @@ sub handle_dhcp_msg { $ipnodemap{$ip} = $node; set_node_state($node_state_ref, $node, $::STATE_DHCP); - $node_status_time{$node}{$::STATE_DHCP}{end_time} = $log_ref->{time} if ($performance and !$node_status_time{$node}{$::STATE_DHCP}{end_time}); + if ($performance and !$node_status_time{$node}{$::STATE_DHCP}{end_time}) { + $node_status_time{$node}{$::STATE_DHCP}{time_point} = $log_ref->{time_record}; + $node_status_time{$node}{$::STATE_DHCP}{end_time} = $log_ref->{time}; + } } } elsif ($log_ref->{msg} =~ /BOOTREQUEST\s+from\s+(.+)\s+via\s+([^:]+)(.*)/) { my $mac = $1; @@ -986,7 +982,10 @@ sub handle_dhcp_msg { $ipnodemap{$ip} = $node; set_node_state($node_state_ref, $node, $::STATE_DHCP); - $node_status_time{$node}{$::STATE_DHCP}{end_time} = $log_ref->{time} if ($performance and !$node_status_time{$node}{$::STATE_DHCP}{end_time}); + if ($performance and !$node_status_time{$node}{$::STATE_DHCP}{end_time}) { + $node_status_time{$node}{$::STATE_DHCP}{end_time} = $log_ref->{time}; + $node_status_time{$node}{$::STATE_DHCP}{time_point} = $log_ref->{time_record}; + } } } } @@ -1018,13 +1017,22 @@ sub handle_tftp_msg { if ($file =~ /xcat\/xnba.*/i or $file =~ /\/boot\/grub2\/powerpc-ieee1275\//i or $file =~ /\/yb\/node\/yaboot\-/i) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_BOOTLODER); - $node_status_time{$ipnodemap{$ip}}{$::STATE_BOOTLODER}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$ipnodemap{$ip}}{$::STATE_BOOTLODER}{start_time} = $log_ref->{time}; + $node_status_time{$ipnodemap{$ip}}{$::STATE_BOOTLODER}{time_point} = $log_ref->{time_record}; + } } elsif ($file =~ /vmlinuz|inst64|linux/) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_KERNEL); - $node_status_time{$ipnodemap{$ip}}{$::STATE_KERNEL}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$ipnodemap{$ip}}{$::STATE_KERNEL}{start_time} = $log_ref->{time}; + $node_status_time{$ipnodemap{$ip}}{$::STATE_KERNEL}{time_point} = $log_ref->{time_record}; + } } elsif ($file =~ /initrd/i) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_INITRD); - $node_status_time{$ipnodemap{$ip}}{$::STATE_INITRD}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$ipnodemap{$ip}}{$::STATE_INITRD}{start_time} = $log_ref->{time}; + $node_status_time{$ipnodemap{$ip}}{$::STATE_INITRD}{time_point} = $log_ref->{time_record}; + } } } } @@ -1061,26 +1069,39 @@ sub handle_http_msg { if ($file =~ /vmlinuz|inst64/i or ($file =~ /linux/i and $file =~ /osimage/i)) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_KERNEL); - $node_status_time{$ipnodemap{$ip}}{$::STATE_KERNEL}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$ipnodemap{$ip}}{$::STATE_KERNEL}{start_time} = $log_ref->{time}; + $node_status_time{$ipnodemap{$ip}}{$::STATE_KERNEL}{time_point} = $log_ref->{time_record}; + } push (@{ $node_state_ref->{ $ipnodemap{$ip} }{errors}{$::STATE_KERNEL} }, "$record failed with $http_code") if ($http_code >= 400); } elsif ($file =~ /initrd/i and $file =~ /osimage/i) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_INITRD); - $node_status_time{$ipnodemap{$ip}}{$::STATE_INITRD}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$ipnodemap{$ip}}{$::STATE_INITRD}{start_time} = $log_ref->{time}; + $node_status_time{$ipnodemap{$ip}}{$::STATE_INITRD}{time_point} = $log_ref->{time_record}; + } push (@{ $node_state_ref->{ $ipnodemap{$ip} }{errors}{$::STATE_INITRD} }, "$record failed with $http_code") if ($http_code >= 400); } elsif (($file =~ /^\/install\/autoinst\//i) and ($file !~ /getinstdisk$/i) and ($file !~ /\.pre$/i) and ($file !~ /\.post$/i)) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_KICKSTART); - $node_status_time{$ipnodemap{$ip}}{$::STATE_KICKSTART}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$ipnodemap{$ip}}{$::STATE_KICKSTART}{start_time} = $log_ref->{time}; + $node_status_time{$ipnodemap{$ip}}{$::STATE_KICKSTART}{time_point} = $log_ref->{time_record}; + } push (@{ $node_state_ref->{ $ipnodemap{$ip} }{errors}{$::STATE_KICKSTART} }, "$record failed with $http_code") if ($http_code >= 400); } elsif ($file =~ /\.deb$/i or $file =~ /\/Packages\/.+\.rpm$/ or $file =~ /\/suse\/noarch\/.+\.rpm$/i) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_INSTALLRPM); if ($performance) { $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{end_time} = $log_ref->{time}; $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{start_time} = $log_ref->{time} unless ( $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{start_time} ); + $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{time_point} = $log_ref->{time_record} unless ( $node_status_time{$ipnodemap{$ip}}{$::STATE_INSTALLRPM}{time_point} ); } push (@{ $node_state_ref->{ $ipnodemap{$ip} }{errors}{$::STATE_INSTALLRPM} }, "$record failed with $http_code") if ($http_code >= 400); } elsif ($file =~ /rootimg/) { set_node_state($node_state_ref, $ipnodemap{$ip}, $::STATE_ROOTIMG); - $node_status_time{$ipnodemap{$ip}}{$::STATE_ROOTIMG}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$ipnodemap{$ip}}{$::STATE_ROOTIMG}{start_time} = $log_ref->{time}; + $node_status_time{$ipnodemap{$ip}}{$::STATE_ROOTIMG}{time_point} = $log_ref->{time_record}; + } } } } @@ -1118,7 +1139,10 @@ sub handle_cluster_msg { probe_utils->send_msg("stdout", "d", "[$node] $log_ref->{time_record} Use command $command to reboot node $node") if ($monitor); push(@{ $node_state_ref->{$node}{log} }, $log_ref->{msg}) if ($debug); set_node_state($node_state_ref, $node, $::STATE_POWER_ON); - $node_status_time{$node}{$::STATE_POWER_ON}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$node}{$::STATE_POWER_ON}{start_time} = $log_ref->{time}; + $node_status_time{$node}{$::STATE_POWER_ON}{time_point} = $log_ref->{time_record}; + } } } } @@ -1135,16 +1159,28 @@ sub handle_cluster_msg { if ($status eq "installing") { set_node_state($node_state_ref, $node, $::STATE_INSTALLING); - $node_status_time{$node}{$::STATE_INSTALLING}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$node}{$::STATE_INSTALLING}{start_time} = $log_ref->{time}; + $node_status_time{$node}{$::STATE_INSTALLING}{time_point} = $log_ref->{time_record}; + } } elsif ($status eq "powering-on") { set_node_state($node_state_ref, $node, $::STATE_POWERINGON); - $node_status_time{$node}{$::STATE_POWERINGON}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$node}{$::STATE_POWERINGON}{start_time} = $log_ref->{time}; + $node_status_time{$node}{$::STATE_POWERINGON}{time_point} = $log_ref->{time_record}; + } } elsif ($status eq "booting") { set_node_state($node_state_ref, $node, $::STATE_BOOTING); - $node_status_time{$node}{$::STATE_BOOTING}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$node}{$::STATE_BOOTING}{start_time} = $log_ref->{time}; + $node_status_time{$node}{$::STATE_BOOTING}{time_point} = $log_ref->{time_record}; + } } elsif ($status eq "netbooting") { set_node_state($node_state_ref, $node, $::STATE_NETBOOTING); - $node_status_time{$node}{$::STATE_NETBOOTING}{start_time} = $log_ref->{time} if ($performance); + if ($performance) { + $node_status_time{$node}{$::STATE_NETBOOTING}{start_time} = $log_ref->{time}; + $node_status_time{$node}{$::STATE_NETBOOTING}{time_point} = $log_ref->{time_record}; + } } elsif ($status eq "failed") { $node_state_ref->{$node}{done} = 1; } @@ -1178,6 +1214,7 @@ sub handle_compute_msg { set_node_state($node_state_ref, $node, $::STATE_POSTSCRIPT); if ($performance) { $node_status_time{$node}{$::STATE_POSTSCRIPT}{start_time} = $log_ref->{time} unless ($node_status_time{$node}{$::STATE_POSTSCRIPT}{start_time}); + $node_status_time{$node}{$::STATE_POSTSCRIPT}{time_point} = $log_ref->{time_record} unless ($node_status_time{$node}{$::STATE_POSTSCRIPT}{time_point}); } } elsif ($log_ref->{msg} =~ /postscript (.+) return with (\d+)/) { my $script_name = $1; @@ -1194,6 +1231,7 @@ sub handle_compute_msg { set_node_state($node_state_ref, $node, $::STATE_POSTBOOTSCRIPT); if ($performance) { $node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{start_time} = $log_ref->{time} unless ($node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{start_time}); + $node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{time_point} = $log_ref->{time_record} unless ($node_status_time{$node}{$::STATE_POSTBOOTSCRIPT}{time_point}); } } elsif ($log_ref->{msg} =~ /postbootscript (.+) return with (\d+)/) { my $script_name = $1; @@ -1210,7 +1248,10 @@ sub handle_compute_msg { set_node_state($node_state_ref, $node, $::STATE_COMPLETED); $node_state_ref->{$node}{done} = 1; probe_utils->send_msg("stdout", "o", "[$node] $log_ref->{time_record} provision completed") if ($monitor); - $node_status_time{$node}{$::STATE_COMPLETED}{start_time} = $log_ref->{time}; + if ($performance) { + $node_status_time{$node}{$::STATE_COMPLETED}{start_time} = $log_ref->{time}; + $node_status_time{$node}{$::STATE_COMPLETED}{time_point} = $log_ref->{time_record}; + } } } } From 64b926ce630e33cf0697bbca0d8f84ef591c508b Mon Sep 17 00:00:00 2001 From: XuWei Date: Fri, 10 Feb 2017 02:22:54 -0500 Subject: [PATCH 5/7] modified table format --- xCAT-probe/lib/perl/probe_utils.pm | 61 ++++++++++++++++++++++++++++++ xCAT-probe/subcmds/osdeploy | 53 +++++++++++--------------- 2 files changed, 84 insertions(+), 30 deletions(-) diff --git a/xCAT-probe/lib/perl/probe_utils.pm b/xCAT-probe/lib/perl/probe_utils.pm index e309def96..72bf63bf9 100644 --- a/xCAT-probe/lib/perl/probe_utils.pm +++ b/xCAT-probe/lib/perl/probe_utils.pm @@ -7,6 +7,7 @@ use File::Path; use File::Copy; use Time::Local; use Socket; +use List::Util qw/sum/; #----------------------------------------- @@ -597,4 +598,64 @@ sub convert_second_to_time { return $result; } +sub print_table { + my $content = shift; + $content = shift if (($content) && ($content =~ /probe_utils/)); + my $has_title = shift; + my $title; + + if ($has_title) { + $title = shift(@$content); + } + + my @length_array; + my $count_num = 0; + foreach my $row (@$content) { + $count_num = 0; + foreach my $element (@{$row}) { + $length_array[$count_num] = length($element) if ($length_array[$count_num] < length($element)); + $count_num++; + } + } + + my @content_new; + my @row_new; + my $row_line; + my $whole_length; + foreach my $row (@$content) { + $count_num = 0; + @row_new = (); + foreach my $element (@{$row}) { + push @row_new, $element. " " x ($length_array[$count_num] - length($element)); + $count_num++; + } + $row_line = "| " . join(" | ", @row_new) . " |"; + $whole_length = length($row_line); + push @content_new, $row_line; + } + + my $title_new; + my $title_length = length($title); + if ($has_title) { + if ($whole_length < $title_length) { + $title_new = $title; + } elsif ($whole_length - 2 == $title_length) { + $title_new = "|". $title. "|"; + } else { + $title_new = " " x (($whole_length - 2 - $title_length)/2) . "$title"; + $title_new .= " " x ($whole_length - 2 - length($title_new)); + $title_new = "|" . $title_new . "|"; + } + } + + my $format_line = "-" x $whole_length; + print $format_line . "\n"; + print $title_new . "\n" if ($has_title); + print $format_line . "\n"; + foreach (@content_new) { + print $_ . "\n"; + } + print $format_line . "\n"; +} + 1; diff --git a/xCAT-probe/subcmds/osdeploy b/xCAT-probe/subcmds/osdeploy index 4ef4d689f..51b252889 100755 --- a/xCAT-probe/subcmds/osdeploy +++ b/xCAT-probe/subcmds/osdeploy @@ -580,78 +580,74 @@ sub performance_calculation { return if (!%node_status_time); - probe_utils->send_msg("stdout", "", "-----------node provision performance-----------"); - # Currently, only diskful is supported my $provision_type = $::DISKFUL; my @status_for_time = (); my $isnull = 0; - - my $length_node = 20; - my $space = " " x ($length_node - 4); - + my @time_content; # print table's first line # @status_for_time: the status that needed to calculate time + + push @time_content, "node provision performance"; my @title_lines = ( - "NODE $space ELAPSED\n", - "NODE $space SVRBOOT RPM POST POSTBOOT ELAPSED\n", - "NODE $space RPOWER DHCP BOOTLOADER KERNEL INITRD RPM POST POSTBOOT COMPLETED\n", - "NODE $space RPOWER DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT COMPLETED\n", - "NODE $space DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT ELAPSED\n"); + [qw/NODE ELAPSED/], + [qw/NODE SVRBOOT RPM POST POSTBOOT ELAPSED/], + [qw/NODE RPOWER DHCP BOOTLOADER KERNEL INITRD RPM POST POSTBOOT COMPLETED/], + [qw/NODE RPOWER DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT COMPLETED/], + [qw/NODE DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT ELAPSED/]); if ($performance eq "compact") { - print $title_lines[0]; + push @time_content, $title_lines[0]; @status_for_time = ($::STATE_COMPLETED); } if ($performance eq "phase") { - print $title_lines[1]; + push @time_content, $title_lines[1]; @status_for_time = ($::STATE_DHCP, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); } if ($performance eq "origin") { if ($provision_type == $::DISKFUL){ - print $title_lines[2]; + push @time_content, $title_lines[2]; @status_for_time = ($::STATE_POWER_ON, $::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); } else { # reserved for diskless - print $title_lines[3]; + push @time_content, $title_lines[3]; @status_for_time = ($::STATE_POWER_ON, $::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_NETBOOTING, $::STATE_ROOTIMG, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); } } if ($performance eq "reserve") { - print $title_lines[4]; + push @time_content, $title_lines[4]; @status_for_time = ($::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_NETBOOTING, $::STATE_ROOTIMG, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); } # calculate time for each node and status foreach my $node (keys %node_status_time) { + my @timeinfo = (); + push @timeinfo, $node; + if ($performance eq "origin") { - my @time_origin = (); foreach my $status (@status_for_time) { if ($node_status_time{$node}{$status}{time_point}) { if ($status == $::STATE_DHCP and $node_status_time{$node}{$::STATE_DHCP}{end_time} > $node_status_time{$node}{$::STATE_BOOTLODER}{start_time}){ - push @time_origin, "NULL* "; + push @timeinfo, "NULL"; $isnull = 1; } else { - push @time_origin, $node_status_time{$node}{$status}{time_point}; + push @timeinfo, $node_status_time{$node}{$status}{time_point}; } } else { - push @time_origin, "NULL* "; + push @timeinfo, "NULL"; $isnull = 1; } } - my $time_str = join(" ", @time_origin); - $space = " " x ($length_node - length($node)); - print "$node $space $time_str\n"; + push @time_content, [ @timeinfo ]; next; } # get the start time and end time for each step - @timeinfo = (); foreach my $status (@status_for_time) { my $tmp_status; my $tmp_detail_status; @@ -676,17 +672,14 @@ sub performance_calculation { if ($tmp_start_time && $tmp_end_time) { push @timeinfo, probe_utils->convert_second_to_time($tmp_end_time - $tmp_start_time); } else { - push @timeinfo, "NULL* "; + push @timeinfo, "NULL"; $isnull = 1; } } - - my $time_str = join(" ", @timeinfo); - $space = " " x ($length_node - length($node)); - print "$node $space $time_str\n"; + push @time_content, [ @timeinfo ]; } - probe_utils->send_msg("stdout", "", "------------------------------------------------"); + probe_utils->print_table(\@time_content, 1); if ($isnull and $is_success) { my $command_input = "xcatprobe -w $program_name"; From c75ed21486c9e6160844f87a478280beea346b43 Mon Sep 17 00:00:00 2001 From: XuWei Date: Mon, 13 Feb 2017 03:17:53 -0500 Subject: [PATCH 6/7] modified output title --- xCAT-probe/subcmds/osdeploy | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/xCAT-probe/subcmds/osdeploy b/xCAT-probe/subcmds/osdeploy index 51b252889..80aff8f5a 100755 --- a/xCAT-probe/subcmds/osdeploy +++ b/xCAT-probe/subcmds/osdeploy @@ -69,7 +69,7 @@ Options: Support 2 output format: 'compact': Elapsed time of provision for each node. 'phase' : Elapsed time for DHCP, RPM, POSTSCRIPTS and POSTBOOTSCRIPTS stages, and time for whole provision. - 'origin' : Show origin time of each stage. + 'origin' : Show origin start time of each stage. "; @@ -589,8 +589,6 @@ sub performance_calculation { # print table's first line # @status_for_time: the status that needed to calculate time - - push @time_content, "node provision performance"; my @title_lines = ( [qw/NODE ELAPSED/], [qw/NODE SVRBOOT RPM POST POSTBOOT ELAPSED/], @@ -599,16 +597,19 @@ sub performance_calculation { [qw/NODE DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT ELAPSED/]); if ($performance eq "compact") { + push @time_content, "Provision Time"; push @time_content, $title_lines[0]; @status_for_time = ($::STATE_COMPLETED); } if ($performance eq "phase") { + push @time_content, "Time for Phases"; push @time_content, $title_lines[1]; @status_for_time = ($::STATE_DHCP, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); } if ($performance eq "origin") { + push @time_content, "Start Time for Stage"; if ($provision_type == $::DISKFUL){ push @time_content, $title_lines[2]; @status_for_time = ($::STATE_POWER_ON, $::STATE_DHCP, $::STATE_BOOTLODER, $::STATE_KERNEL, $::STATE_INITRD, $::STATE_INSTALLRPM, $::STATE_POSTSCRIPT, $::STATE_POSTBOOTSCRIPT, $::STATE_COMPLETED); From a162ca8420d9dcc20b4d13d0c168c96e79dc6698 Mon Sep 17 00:00:00 2001 From: XuWei Date: Mon, 13 Feb 2017 21:02:25 -0500 Subject: [PATCH 7/7] change RPM to INSTALL --- xCAT-probe/lib/perl/probe_utils.pm | 66 +++++++++++++++++++++++------- xCAT-probe/subcmds/osdeploy | 17 +++++--- 2 files changed, 64 insertions(+), 19 deletions(-) diff --git a/xCAT-probe/lib/perl/probe_utils.pm b/xCAT-probe/lib/perl/probe_utils.pm index 72bf63bf9..47034b700 100644 --- a/xCAT-probe/lib/perl/probe_utils.pm +++ b/xCAT-probe/lib/perl/probe_utils.pm @@ -598,6 +598,50 @@ sub convert_second_to_time { return $result; } +#------------------------------------------ + +=head3 + Description: + print table + Arguments: + content: double dimensional array + has_title: whether has title in content + + eg: @content = ($title, + @content1, + @content2, + ...... + ); + $has_title = 1; + print_table(\@content, $has_title); + + or @content = (@content1, + @content2, + ...... + ); + $has_title = 0; + print_table(\@content, $has_title); + + Ouput: + -------------------------- + | xxxxxxx | + -------------------------- + | xxx | xxxx | xx | xx | + -------------------------- + | xx | xxxx | xxxx | xx | + -------------------------- + + or + + -------------------------- + | xxx | xxxx | xx | xx | + -------------------------- + | xx | xxxx | xxxx | xx | + -------------------------- + +=cut + +#------------------------------------------ sub print_table { my $content = shift; $content = shift if (($content) && ($content =~ /probe_utils/)); @@ -609,12 +653,10 @@ sub print_table { } my @length_array; - my $count_num = 0; foreach my $row (@$content) { - $count_num = 0; - foreach my $element (@{$row}) { - $length_array[$count_num] = length($element) if ($length_array[$count_num] < length($element)); - $count_num++; + for (my $i = 0; $i < @{$row}; $i++) { + my $ele_length = length(${$row}[$i]); + $length_array[$i] = $ele_length if ($length_array[$i] < $ele_length); } } @@ -623,24 +665,20 @@ sub print_table { my $row_line; my $whole_length; foreach my $row (@$content) { - $count_num = 0; @row_new = (); - foreach my $element (@{$row}) { - push @row_new, $element. " " x ($length_array[$count_num] - length($element)); - $count_num++; + for (my $i = 0; $i < @{$row}; $i++) { + push @row_new, ${$row}[$i] . " " x ($length_array[$i] - length(${$row}[$i])); } $row_line = "| " . join(" | ", @row_new) . " |"; - $whole_length = length($row_line); push @content_new, $row_line; } + $whole_length = length($row_line); my $title_new; my $title_length = length($title); if ($has_title) { - if ($whole_length < $title_length) { + if ($whole_length - 1 <= $title_length) { $title_new = $title; - } elsif ($whole_length - 2 == $title_length) { - $title_new = "|". $title. "|"; } else { $title_new = " " x (($whole_length - 2 - $title_length)/2) . "$title"; $title_new .= " " x ($whole_length - 2 - length($title_new)); @@ -649,7 +687,7 @@ sub print_table { } my $format_line = "-" x $whole_length; - print $format_line . "\n"; + print $format_line . "\n" if ($has_title); print $title_new . "\n" if ($has_title); print $format_line . "\n"; foreach (@content_new) { diff --git a/xCAT-probe/subcmds/osdeploy b/xCAT-probe/subcmds/osdeploy index 80aff8f5a..b656afd7e 100755 --- a/xCAT-probe/subcmds/osdeploy +++ b/xCAT-probe/subcmds/osdeploy @@ -41,6 +41,8 @@ my $monitor = 1; #used by developer, to debug the detail information about function running my $debug = 0; +my $osdeploy_start_time; + #--------------------------------------------- # Command Usage #--------------------------------------------- @@ -68,7 +70,7 @@ Options: -p Show elapsed time of each stage during provision for each node Support 2 output format: 'compact': Elapsed time of provision for each node. - 'phase' : Elapsed time for DHCP, RPM, POSTSCRIPTS and POSTBOOTSCRIPTS stages, and time for whole provision. + 'phase' : Elapsed time for DHCP, INSTALL, POSTSCRIPTS and POSTBOOTSCRIPTS stages, and time for whole provision. 'origin' : Show origin start time of each stage. "; @@ -567,7 +569,7 @@ sub conclusion_report { Calculate the performance of provision (for each node) Arguments: performance: compact: calculate how much time spent for provision - phase: calculate how much time spent for each status (DHCP, RPM, POSTSCRIPTS, POSTBOOTSCRIPTS) + phase: calculate how much time spent for each status (DHCP, INSTALL, POSTSCRIPTS, POSTBOOTSCRIPTS) origin : show time point for each status reserve: reserve for other type Returns: @@ -591,8 +593,8 @@ sub performance_calculation { my @title_lines = ( [qw/NODE ELAPSED/], - [qw/NODE SVRBOOT RPM POST POSTBOOT ELAPSED/], - [qw/NODE RPOWER DHCP BOOTLOADER KERNEL INITRD RPM POST POSTBOOT COMPLETED/], + [qw/NODE SVRBOOT INSTALL POST POSTBOOT ELAPSED/], + [qw/NODE RPOWER DHCP BOOTLOADER KERNEL INITRD INSTALL POST POSTBOOT COMPLETED/], [qw/NODE RPOWER DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT COMPLETED/], [qw/NODE DHCP BOOTLOADER KERNEL INITRD NETBOOTING ROOTIMG POSTBOOT ELAPSED/]); @@ -687,7 +689,10 @@ sub performance_calculation { $command_input .= " -n $noderange" if ($noderange); $command_input .= " -p $performance"; $command_input .= " -V" if ($verbose); - $command_input .= " -r xxhxxm"; + my $osdeploy_end_time = time(); + my $time_for_replay = $osdeploy_end_time - $osdeploy_start_time; + my $time_hour = ($time_for_replay - $time_for_replay%3600) / 3600 + 1; + $command_input .= " -r $time_hour" . "h"; probe_utils->send_msg("stdout", "", "Did not get correct time, please run '$command_input' to get correct time"); } } @@ -713,6 +718,8 @@ sub do_monitor { my $rst = 0; my $terminal = 0; + $osdeploy_start_time = time() if ($performance); + $SIG{TERM} = $SIG{INT} = sub { $terminal = 1; };