diff --git a/xCAT-server/lib/perl/xCAT/CmdLog.pm b/xCAT-server/lib/perl/xCAT/CmdLog.pm new file mode 100644 index 000000000..b7481ad23 --- /dev/null +++ b/xCAT-server/lib/perl/xCAT/CmdLog.pm @@ -0,0 +1,236 @@ +#!/usr/bin/env perl +# IBM(c) 2007 EPL license http://www.eclipse.org/legal/epl-v10.html +package xCAT::CmdLog; + +use strict; +use warnings; + +use xCAT::xcatd; + +sub new { + my ($class) = @_; + return bless { + buffer => '', + sensitive => 0, + }, $class; +} + +sub start_response { + my ($self, $req, $req_redacted) = @_; + $self->{sensitive} = response_is_sensitive($req, $req_redacted); + return; +} + +sub collect { + my ($self, $response, $local_server) = @_; + $self->{buffer} .= format_response($response, $local_server); + return 0; +} + +sub finalize { + my ($self) = @_; + my $response = finalize_response($self->{buffer}, $self->{sensitive}); + $self->{buffer} = ''; + $self->{sensitive} = 0; + return $response; +} + +sub response_is_sensitive { + my ($req, $req_redacted) = @_; + return 1 if defined $req->{command}->[0] + and ($req->{command}->[0] eq 'getcredentials' or $req->{command}->[0] eq 'lsvm'); + return 1 if join(' ', @{ $req->{arg} || [] }) =~ /passw/i; + return 1 if xCAT::xcatd->secret_in_request($req->{command}->[0], $req->{arg}); + return 1 if $req_redacted; + return 0; +} + +sub finalize_response { + my ($buffer, $sensitive) = @_; + return "*REDACTED*\n" + if $sensitive or xCAT::xcatd->secret_in_response($buffer); + return $buffer; +} + +sub format_response { + my ($response, $local_server) = @_; + my $response_log = ""; + + if (exists($response->{xcatresponse}->[0]->{serverdone}) + && !exists($response->{xcatresponse}->[0]->{error})) { + return $response_log; + } + + my $responses; + if (exists($response->{xcatresponse})) { + $responses = $response->{xcatresponse}; + } else { + push @{$responses}, $response; + } + return $response_log if ref($responses) ne 'ARRAY' or scalar(@$responses) == 0; + + foreach my $item (@{$responses}) { + my $rsp = $item; + my $msgsource = ""; + $msgsource = $rsp->{xcatdsource}->[0] if $rsp->{xcatdsource}; + $msgsource = "" if $local_server eq $msgsource; + + if ($rsp->{error}) { + if (ref($rsp->{error}) eq 'ARRAY') { + foreach my $text (@{ $rsp->{error} }) { + my $desc = "$text"; + $desc = "[$msgsource]: $desc" if $desc && $msgsource; + $desc = "Error: $desc" unless $rsp->{NoErrorPrefix}; + $response_log .= "$desc\n"; + } + } elsif (defined($rsp->{error})) { + my $desc = $rsp->{error}; + $desc = "[$msgsource]: $desc" if $desc && $msgsource; + $desc = "Error: $desc" unless $rsp->{NoErrorPrefix}; + $response_log .= "$desc\n"; + } + } + + if ($rsp->{warning}) { + if (ref($rsp->{warning}) eq 'ARRAY') { + foreach my $text (@{ $rsp->{warning} }) { + my $desc = "$text"; + $desc = "[$msgsource]: $desc" if $desc && $msgsource; + $desc = "Warning: $desc" unless $rsp->{NoWarnPrefix}; + $response_log .= "$desc\n"; + } + } elsif (defined($rsp->{warning})) { + my $desc = $rsp->{warning}; + $desc = "[$msgsource]: $desc" if $desc && $msgsource; + $desc = "Warning: $desc" unless $rsp->{NoWarnPrefix}; + $response_log .= "$desc\n"; + } + } + + if ($rsp->{info}) { + if (ref($rsp->{info}) eq 'ARRAY') { + foreach my $text (@{ $rsp->{info} }) { + my $desc = "$text"; + $desc = "[$msgsource]: $desc" if $desc && $msgsource; + $response_log .= "$desc\n"; + } + } else { + my $desc = $rsp->{info}; + $desc = "[$msgsource]: $desc" if $desc && $msgsource; + $response_log .= "$desc\n"; + } + } + + if ($rsp->{sinfo}) { + if (ref($rsp->{sinfo}) eq 'ARRAY') { + foreach my $text (@{ $rsp->{sinfo} }) { + $response_log .= "$text " if defined $text; + } + } elsif (defined($rsp->{sinfo})) { + $response_log .= $rsp->{sinfo} . " "; + } + } + + my $nodes = $rsp->{node}; + $nodes = [$nodes] unless ref $nodes eq 'ARRAY'; + if (scalar @{$nodes}) { + foreach my $node (@$nodes) { + my $desc; + if (ref($node->{name}) eq 'ARRAY') { + $desc = $node->{name}->[0]; + } else { + $desc = $node->{name}; + } + if ($node->{error} && defined($node->{error}->[0])) { + if ($desc) { + $desc = "$desc: [$msgsource]" if $msgsource; + } else { + $desc = "[$msgsource]" if $msgsource; + } + $desc .= ": Error: " . $node->{error}->[0]; + } + if ($node->{warning} && defined($node->{warning}->[0])) { + if ($desc) { + $desc = "$desc: [$msgsource]" if $msgsource; + } else { + $desc = "[$msgsource]" if $msgsource; + } + $desc .= ": Warning: " . $node->{warning}->[0]; + } + if ($node->{data}) { + if ($desc) { + $desc = "$desc: [$msgsource]" if $msgsource; + } else { + $desc = "[$msgsource]" if $msgsource; + } + if (ref(\($node->{data})) eq 'SCALAR') { + $desc = $desc . ": " . $node->{data} if defined $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] + if defined $node->{data}->{desc}->[0]; + } else { + $desc = $desc . ": " . $node->{data}->{desc} + if defined $node->{data}->{desc}; + } + } + if ($node->{data}->{contents}) { + if (ref($node->{data}->{contents}) eq 'ARRAY') { + $desc = "$desc: " . $node->{data}->{contents}->[0] + if defined $node->{data}->{contents}->[0]; + } else { + $desc = "$desc: " . $node->{data}->{contents} + if defined $node->{data}->{contents}; + } + } + } elsif (ref(\($node->{data}->[0])) eq 'SCALAR') { + $desc = $desc . ": " . $node->{data}->[0] + if defined $node->{data}->[0]; + } else { + if ($node->{data}->[0]->{desc} + && defined($node->{data}->[0]->{desc}->[0])) { + $desc = $desc . ": " . $node->{data}->[0]->{desc}->[0]; + } + if ($node->{data}->[0]->{contents} + && defined($node->{data}->[0]->{contents}->[0])) { + $desc = "$desc: " . $node->{data}->[0]->{contents}->[0]; + } + } + } + $response_log .= "$desc\n" if $desc; + } + } + + foreach my $key (keys %{$rsp}) { + next if $key ne 'data'; + if ($rsp->{data}) { + if (ref($rsp->{data}) eq 'ARRAY') { + foreach my $data_entry (@{ $rsp->{data} }) { + my $desc; + if (ref(\($data_entry)) eq 'SCALAR') { + $desc = $data_entry; + } else { + $desc = $data_entry->{desc}->[0] if $data_entry->{desc}; + if ($data_entry->{contents}) { + if ($desc) { + $desc = "$desc: " . $data_entry->{contents}->[0] + if defined $data_entry->{contents}->[0]; + } else { + $desc = $data_entry->{contents}->[0]; + } + } + } + $response_log .= "$desc\n" if $desc; + } + } else { + $response_log .= $rsp->{data} . "\n"; + } + } + } + } + + return $response_log; +} + +1; diff --git a/xCAT-server/sbin/xcatd b/xCAT-server/sbin/xcatd index e1a5ff6c9..b8487f1b5 100755 --- a/xCAT-server/sbin/xcatd +++ b/xCAT-server/sbin/xcatd @@ -51,6 +51,7 @@ use xCAT::TableUtils; use xCAT::NetworkUtils; use xCAT::MsgUtils; use xCAT::xcatd; +use xCAT::CmdLog; use xCAT::State; my $os = xCAT::Utils->osver(); my $arch = `uname -p`; @@ -224,8 +225,7 @@ if ($tmp) { } my $cmdlog_alllog = "====================================================\n"; my $cmdlog_starttime=undef; -my $cmdlog_response_buffer = ""; -my $cmdlog_response_sensitive = 0; +my $cmdlog_response = xCAT::CmdLog->new(); # ----used for command log end--------- my $enable_perf = $sitetab->getAttribs({'key'=>'enableperf'},'value'); @@ -2892,7 +2892,7 @@ sub service_connection { $cmdlog_request = xCAT::xcatd->redact_password($cmdlog_request); $cmdlog_req_redacted = 1 if $cmdlog_request ne $cmdlog_before_redact; $cmdlog_alllog .= $cmdlog_request . "\n[Response]\n"; - $cmdlog_response_sensitive = cmdlog_response_is_sensitive($req, $cmdlog_req_redacted); + $cmdlog_response->start_response($req, $cmdlog_req_redacted); # ----used for command log end---------- @@ -3400,254 +3400,21 @@ sub disable_callingtrace { =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 + Collect one response fragment for the current command. + Response formatting and buffering are handled by xCAT::CmdLog. Returns: 0 -> successful - 1 -> failed =cut # -------------------------------------------------------------------------------- sub cmdlog_collectlog() { - my $rsponse = shift; - my $rsp_log = ""; - - if ((exists($rsponse->{xcatresponse}->[0]->{serverdone})) && (!exists($rsponse->{xcatresponse}->[0]->{error}))) { return 0; } - my $rsp; - if (exists($rsponse->{xcatresponse})) { - $rsp = $rsponse->{xcatresponse}; - } else { - push @{$rsp}, $rsponse; - } - if (ref($rsp) ne 'ARRAY') { return 0; } - if (scalar(@$rsp) == 0) { return 0; } - - foreach my $tmprsp (@{$rsp}) { - $rsp = $tmprsp; - - # handle response - my $msgsource = ""; - $msgsource = $rsp->{xcatdsource}->[0] if ($rsp->{xcatdsource}); - #Only show response source when it is from different service node - $msgsource = "" if ($MYXCATSERVER eq $msgsource); - - # Handle errors - if ($rsp->{error}) { - if (ref($rsp->{error}) eq 'ARRAY') { - foreach my $text (@{ $rsp->{error} }) { - my $desc = "$text"; - $desc = "[$msgsource]: $desc" if ($desc && $msgsource); - $desc = "Error: $desc" unless ($rsp->{NoErrorPrefix}); - $rsp_log .= "$desc\n"; - } - } - else { - if (defined($rsp->{error})) { - my $desc = $rsp->{error}; - $desc = "[$msgsource]: $desc" if ($desc && $msgsource); - $desc = "Error: $desc" unless ($rsp->{NoErrorPrefix}); - $rsp_log .= "$desc\n"; - } - } - } - - if ($rsp->{warning}) { - if (ref($rsp->{warning}) eq 'ARRAY') { - foreach my $text (@{ $rsp->{warning} }) { - my $desc = "$text"; - $desc = "[$msgsource]: $desc" if ($desc && $msgsource); - $desc = "Warning: $desc" unless ($rsp->{NoWarnPrefix}); - $rsp_log .= "$desc\n"; - } - } - else { - if (defined($rsp->{warning})) { - my $desc = $rsp->{warning}; - $desc = "[$msgsource]: $desc" if ($desc && $msgsource); - $desc = "Warning: $desc" unless ($rsp->{NoWarnPrefix}); - $rsp_log .= "$desc\n"; - } - } - } - - if ($rsp->{info}) { - if (ref($rsp->{info}) eq 'ARRAY') { - foreach my $text (@{ $rsp->{info} }) { - my $desc = "$text"; - $desc = "[$msgsource]: $desc" if ($desc && $msgsource); - $rsp_log .= "$desc\n"; - } - } else { - my $desc = $rsp->{info}; - $desc = "[$msgsource]: $desc" if ($desc && $msgsource); - $rsp_log .= "$desc\n"; - } - } - - if ($rsp->{sinfo}) { - if (ref($rsp->{sinfo}) eq 'ARRAY') { - foreach my $text (@{ $rsp->{sinfo} }) { - if (defined($text)) { - $rsp_log .= "$text "; - } - } - } else { - if (defined($rsp->{sinfo})) { - $rsp_log .= $rsp->{sinfo} . " "; - } - } - } - - # 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}) && defined($node->{error}->[0])) { - if ($desc) { - $desc = "$desc: [$msgsource]" if ($msgsource); - } else { - $desc = "[$msgsource]" if ($msgsource); - } - $desc .= ": Error: " . $node->{error}->[0]; - $errflg = 1; - } - if (($node->{warning}) && defined($node->{warning}->[0])){ - if ($desc) { - $desc = "$desc: [$msgsource]" if ($msgsource); - } else { - $desc = "[$msgsource]" if ($msgsource); - } - $desc .= ": Warning: " . $node->{warning}->[0]; - $errflg = 1; - } - if ($node->{data}) { - if ($desc) { - $desc = "$desc: [$msgsource]" if ($msgsource); - } else { - $desc = "[$msgsource]" if ($msgsource); - } - if (ref(\($node->{data})) eq 'SCALAR') { - if (defined($node->{data})) { - $desc = $desc . ": " . $node->{data}; - } - } elsif (ref($node->{data}) eq 'HASH') { - if ($node->{data}->{desc}) { - if (ref($node->{data}->{desc}) eq 'ARRAY') { - if (defined($node->{data}->{desc}->[0])) { - $desc = $desc . ": " . $node->{data}->{desc}->[0]; - } - } else { - if (defined($node->{data}->{desc})) { - $desc = $desc . ": " . $node->{data}->{desc}; - } - } - } - if ($node->{data}->{contents}) { - if (ref($node->{data}->{contents}) eq 'ARRAY') { - if (defined($node->{data}->{contents}->[0])) { - $desc = "$desc: " . $node->{data}->{contents}->[0]; - } - } else { - if (defined($node->{data}->{contents})) { - $desc = "$desc: " . $node->{data}->{contents}; - } - } - } - } elsif (ref(\($node->{data}->[0])) eq 'SCALAR') { - if (defined($node->{data}->[0])) { - $desc = $desc . ": " . $node->{data}->[0]; - } - } else { - if ($node->{data}->[0]->{desc}) { - if (defined($node->{data}->[0]->{desc}->[0])) { - $desc = $desc . ": " . $node->{data}->[0]->{desc}->[0]; - } - } - if ($node->{data}->[0]->{contents}) { - if (defined($node->{data}->[0]->{contents}->[0])) { - $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}) { - if (ref($rsp->{data}) eq 'ARRAY') { - 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) { - if (defined($data_entry->{contents}->[0])) { - $desc = "$desc: " . $data_entry->{contents}->[0]; - } - } else { - $desc = $data_entry->{contents}->[0]; - } - } - } - if ($desc) { - $rsp_log .= "$desc\n"; - } - } - } else { - $rsp_log .= $rsp->{data} . "\n"; - } - } - } - } - $cmdlog_response_buffer .= $rsp_log; - return 0; -} - -sub cmdlog_response_is_sensitive { - my ($req, $req_redacted) = @_; - return 1 if defined $req->{command}->[0] and ($req->{command}->[0] eq 'getcredentials' or $req->{command}->[0] eq 'lsvm'); - return 1 if join(' ', @{ $req->{arg} || [] }) =~ /passw/i; - return 1 if xCAT::xcatd->secret_in_request($req->{command}->[0], $req->{arg}); - return 1 if $req_redacted; - return 0; + my $response = shift; + return $cmdlog_response->collect($response, $MYXCATSERVER); } sub cmdlog_finalize_response { - if ($cmdlog_response_sensitive or xCAT::xcatd->secret_in_response($cmdlog_response_buffer)) { - $cmdlog_response_buffer = "*REDACTED*\n"; - } - $cmdlog_alllog .= $cmdlog_response_buffer; - $cmdlog_response_buffer = ""; - $cmdlog_response_sensitive = 0; + $cmdlog_alllog .= $cmdlog_response->finalize(); } # -------------------------------------------------------------------------------- diff --git a/xCAT-test/unit/cmdlog_response_redact.t b/xCAT-test/unit/cmdlog_response_redact.t index 4bcc7054e..1a4a40e28 100644 --- a/xCAT-test/unit/cmdlog_response_redact.t +++ b/xCAT-test/unit/cmdlog_response_redact.t @@ -3,116 +3,100 @@ use strict; use warnings; use FindBin; -use lib "$FindBin::Bin/../lib"; use lib "$FindBin::Bin/../../perl-xCAT"; use lib "$FindBin::Bin/../../xCAT-server/lib/perl"; use Test::More; +use xCAT::CmdLog; -use XCAT::Test::File qw(repo_path slurp_repo_file); -use xCAT::xcatd; - -my $xcatd = repo_path('xCAT-server/sbin/xcatd'); -plan skip_all => 'xcatd not found' unless -r $xcatd; - -my $src = slurp_repo_file('xCAT-server/sbin/xcatd'); - -# Extract the three command-log response subs and load them. xcatd is present, -# so a sub that cannot be extracted is a hard failure, not a skip. -my %sub; -for my $name (qw(cmdlog_response_is_sensitive cmdlog_finalize_response cmdlog_collectlog)) { - my ($body) = $src =~ /(^sub \Q$name\E\b.*?^\})/ms; - BAIL_OUT("could not extract $name from xcatd") unless $body; - $body =~ s/^sub \Q$name\E\(\)/sub $name/m; - $sub{$name} = $body; -} - -our $cmdlog_alllog; -our $cmdlog_response_buffer; -our $cmdlog_response_sensitive; -our $MYXCATSERVER = ""; -{ - no strict; - no warnings; - eval "$sub{cmdlog_response_is_sensitive}\n$sub{cmdlog_finalize_response}\n$sub{cmdlog_collectlog}"; -} -die "eval of command-log subs failed: $@" if $@; - -# Classification from the request. -ok(cmdlog_response_is_sensitive({ command => ['getcredentials'], arg => [] }, ''), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['getcredentials'], arg => [] }, ''), 'getcredentials is a sensitive-response command'); -ok(cmdlog_response_is_sensitive({ command => ['lsvm'], arg => [] }, 0), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['lsvm'], arg => [] }, 0), 'lsvm returns the directory entry with its passwords, so it is sensitive'); -ok(cmdlog_response_is_sensitive({ command => ['gettab'], arg => ['key=xcat', 'passwd.password'] }, ''), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['gettab'], arg => ['key=xcat', 'passwd.password'] }, ''), 'gettab of a passwd column is sensitive'); -ok(cmdlog_response_is_sensitive({ command => ['tabdump'], arg => ['passwd'] }, ''), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['tabdump'], arg => ['passwd'] }, ''), 'tabdump passwd is sensitive'); -ok(cmdlog_response_is_sensitive({ command => ['rspconfig'], arg => [] }, 1), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['rspconfig'], arg => [] }, 1), 'a redacted request is sensitive'); -ok(!cmdlog_response_is_sensitive({ command => ['rpower'], arg => ['n1', 'stat'] }, 0), +ok(!xCAT::CmdLog::response_is_sensitive( + { command => ['rpower'], arg => ['n1', 'stat'] }, 0), 'a benign request is not sensitive'); # A secret attribute with no "passw" in its name must classify through the # shared secret set, not the text heuristic. -ok(cmdlog_response_is_sensitive({ command => ['gettab'], arg => ['node=pdu01', 'pdu.authkey'] }, 0), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['gettab'], arg => ['node=pdu01', 'pdu.authkey'] }, 0), 'gettab of an authentication key is sensitive'); -ok(cmdlog_response_is_sensitive({ command => ['gettab'], arg => ['node=pdu01', 'pdu.privkey'] }, 0), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['gettab'], arg => ['node=pdu01', 'pdu.privkey'] }, 0), 'gettab of a privacy key is sensitive'); -ok(cmdlog_response_is_sensitive({ command => ['gettab'], arg => ['key=snmpc', 'site.value'] }, 0), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['gettab'], arg => ['key=snmpc', 'site.value'] }, 0), 'gettab of the snmpc site value is sensitive'); -ok(!cmdlog_response_is_sensitive({ command => ['gettab'], arg => ['key=domain', 'site.value'] }, 0), +ok(!xCAT::CmdLog::response_is_sensitive( + { command => ['gettab'], arg => ['key=domain', 'site.value'] }, 0), 'gettab of a plain site value is not sensitive'); # A dump of a whole table that owns a secret column returns the bare values. -ok(cmdlog_response_is_sensitive({ command => ['tabdump'], arg => ['token'] }, 0), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['tabdump'], arg => ['token'] }, 0), 'tabdump of the token table is sensitive'); -ok(cmdlog_response_is_sensitive({ command => ['tabdump'], arg => ['prodkey'] }, 0), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['tabdump'], arg => ['prodkey'] }, 0), 'tabdump of the prodkey table is sensitive'); -ok(cmdlog_response_is_sensitive({ command => ['tabdump'], arg => ['site'] }, 0), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['tabdump'], arg => ['site'] }, 0), 'tabdump of the site table is sensitive'); -ok(cmdlog_response_is_sensitive({ command => ['tabdump'], arg => ['-w', 'key==snmpc', 'site'] }, 0), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['tabdump'], arg => ['-w', 'key==snmpc', 'site'] }, 0), 'a filtered site dump is sensitive'); -ok(!cmdlog_response_is_sensitive({ command => ['tabdump'], arg => ['networks'] }, 0), +ok(!xCAT::CmdLog::response_is_sensitive( + { command => ['tabdump'], arg => ['networks'] }, 0), 'tabdump of the networks table is not sensitive'); -ok(cmdlog_response_is_sensitive({ command => ['nodels'], noderange => ['node01'], arg => ['prodkey'] }, 0), +ok(xCAT::CmdLog::response_is_sensitive( + { command => ['nodels'], noderange => ['node01'], arg => ['prodkey'] }, 0), 'nodels of a whole secret table is sensitive'); -ok(!cmdlog_response_is_sensitive({ command => ['nodels'], noderange => ['switches'], arg => [] }, 0), +ok(!xCAT::CmdLog::response_is_sensitive( + { command => ['nodels'], noderange => ['switches'], arg => [] }, 0), 'a group named like a secret table is not sensitive'); -ok(!cmdlog_response_is_sensitive({ command => ['nodels'], noderange => ['node01'], arg => ['nodetype'] }, 0), +ok(!xCAT::CmdLog::response_is_sensitive( + { command => ['nodels'], noderange => ['node01'], arg => ['nodetype'] }, 0), 'nodels of a benign table is not sensitive'); -# Drive collect(s) then finalize, returning what was appended to the log. sub run { my ($sensitive, @responses) = @_; - $cmdlog_alllog = ""; - $cmdlog_response_buffer = ""; - $cmdlog_response_sensitive = $sensitive; - cmdlog_collectlog({ xcatresponse => [ { data => [$_] } ] }) for @responses; - cmdlog_finalize_response(); - return $cmdlog_alllog; + my $cmdlog = xCAT::CmdLog->new(); + $cmdlog->start_response( + { command => ['rpower'], arg => ['node01', 'stat'] }, + $sensitive, + ); + $cmdlog->collect( + { xcatresponse => [ { data => [$_] } ] }, + '', + ) for @responses; + return $cmdlog->finalize(); } -# A bare passwd value (gettab passwd.password) has no "passw" in the response, -# so only the request classification catches it. -my $bare = run(1, "S3cr3tPW"); +my $bare = run(1, 'S3cr3tPW'); unlike($bare, qr/S3cr3tPW/, 'a bare passwd value is not logged'); like($bare, qr/\*REDACTED\*/, 'a sensitive response is redacted'); -# A secret split across callbacks is redacted regardless of order. -unlike(run(0, "password", "S3cr3tPW"), qr/S3cr3tPW/, +unlike(run(0, 'password', 'S3cr3tPW'), qr/S3cr3tPW/, 'multi-callback, passw first: the secret fragment is not logged'); -unlike(run(0, "S3cr3tPW", "password"), qr/S3cr3tPW/, +unlike(run(0, 'S3cr3tPW', 'password'), qr/S3cr3tPW/, 'multi-callback, secret first: the earlier fragment is redacted too'); - -# Fallback: a response mentioning a password is redacted even without request signal. -like(run(0, "invalid password for node"), qr/\*REDACTED\*/, +like(run(0, 'invalid password for node'), qr/\*REDACTED\*/, 'a response mentioning a password is redacted by the fallback'); -# A benign response is logged verbatim. -my $benign = run(0, "node01: on"); +my $benign = run(0, 'node01: on'); like($benign, qr/node01: on/, 'a benign response is logged verbatim'); unlike($benign, qr/\*REDACTED\*/, 'a benign response is not redacted'); -# A detailed object listing expands attributes the request never named. my $lsdef = run(0, 'Object name: pdu01', ' authkey=AUTH_SECRET', ' privkey=PRIV_SECRET'); unlike($lsdef, qr/AUTH_SECRET|PRIV_SECRET/, 'implicit lsdef secrets are not logged'); like($lsdef, qr/\*REDACTED\*/, 'lsdef response containing secret attributes is redacted'); @@ -121,19 +105,87 @@ unlike($colon, qr/AAAAA/, 'a colon separated secret column is redacted'); my $plain = run(0, 'Object name: node01', ' groups=compute', ' mgt=ipmi'); unlike($plain, qr/\*REDACTED\*/, 'a benign object listing is not redacted'); -# Two requests on one connection: the finalizer runs at the next command's -# start. The earlier response must be preserved (redacted), the flag reset, and -# the next benign response neither lost nor over-redacted. -$cmdlog_alllog = ""; -$cmdlog_response_buffer = ""; -$cmdlog_response_sensitive = 1; -cmdlog_collectlog({ xcatresponse => [ { data => ["SECRET_N"] } ] }); -cmdlog_finalize_response(); -is($cmdlog_response_sensitive, 0, 'finalize clears the sensitive flag'); -cmdlog_collectlog({ xcatresponse => [ { data => ["benign_np1"] } ] }); -cmdlog_finalize_response(); -like($cmdlog_alllog, qr/\*REDACTED\*/, 'the earlier sensitive response is preserved as redacted, not lost'); -like($cmdlog_alllog, qr/benign_np1/, 'the next benign response is logged, not over-redacted'); -unlike($cmdlog_alllog, qr/SECRET_N/, 'the earlier secret is not leaked'); +my $connection = xCAT::CmdLog->new(); +$connection->start_response( + { command => ['getcredentials'], arg => [] }, + 0, +); +is( + $connection->collect( + { xcatresponse => [ { data => ['SECRET_N'] } ] }, + '', + ), + 0, + 'collecting a command response succeeds', +); +my $first = $connection->finalize(); +is($connection->{sensitive}, 0, 'finalization resets response sensitivity'); +$connection->start_response( + { command => ['rpower'], arg => ['node01', 'stat'] }, + 0, +); +$connection->collect( + { xcatresponse => [ { data => ['benign_np1'] } ] }, + '', +); +my $second = $connection->finalize(); +like($first, qr/\*REDACTED\*/, 'a sensitive response is preserved as redacted'); +unlike($first, qr/SECRET_N/, 'the sensitive response does not leak'); +like($second, qr/benign_np1/, 'a benign response after a sensitive request is preserved'); +unlike($second, qr/\*REDACTED\*/, 'the benign response is not over-redacted'); +unlike($second, qr/SECRET_N/, 'the finalized secret is not replayed in the next response'); + +my $local_connection = xCAT::CmdLog->new(); +$local_connection->start_response( + { command => ['rpower'], arg => ['node01', 'stat'] }, + 0, +); +$local_connection->collect( + { + xcatresponse => [ { + xcatdsource => ['management'], + info => ['working'], + } ], + }, + 'management', +); +is( + $local_connection->finalize(), + "working\n", + 'collect forwards the local server identity to response formatting', +); + +is( + xCAT::CmdLog::format_response( + { xcatresponse => [ { serverdone => [1] } ] }, + 'management', + ), + '', + 'a terminal serverdone response does not add log text', +); + +is( + xCAT::CmdLog::format_response( + { + xcatresponse => [ { + xcatdsource => ['service'], + error => ['failed'], + warning => ['careful'], + info => ['working'], + sinfo => ['progress'], + node => [ { + name => ['node01'], + data => ['on'], + } ], + } ], + }, + 'management', + ), + "Error: [service]: failed\n" + . "Warning: [service]: careful\n" + . "[service]: working\n" + . "progress node01: [service]: on\n", + 'response formatting preserves source, severity, progress, and node data', +); done_testing();