[PUP-9956] Exec logs output of Sensitive unless and onlyif checks at debug Created: 2019/08/09  Updated: 2019/09/16  Resolved: 2019/09/06

Status: Resolved
Project: Puppet
Component/s: Types and Providers
Affects Version/s: PUP 6.7.2
Fix Version/s: PUP 5.5.17, PUP 6.4.4, PUP 6.9.0

Type: Bug Priority: Normal
Reporter: Steve Marlow Assignee: Kris Bosland
Resolution: Fixed Votes: 0
Labels: resolved-issue-added
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Template: PUP Bug Template
Team: Coremunity
Sprint: Platform Core KANBAN
Method Found: Needs Assessment
Release Notes: Bug Fix
Release Notes Summary: Exec onlyif and unless checks will now have their output redacted if they are marked sensitive.
QA Risk Assessment: Needs Assessment

 Description   

Puppet Version: 6.7.2
Puppet Server Version: N/A
OS Name/Version: macOS 10.14, Ubuntu 18.10

I have been working on implementing support for Sensitive in a module that contains many execs. When I use Sensitive in the command parameter it redacts the command and does not show any command output in debug mode. However, when I use Sensitive in the unless or onlyif parameters it redacts the command and logs the output at debug.

This is problematic for me because some of the commands being used in the unless statements are leaking passwords into reports when running in debug.

I would expect that if I mark a command as Sensitive that I wouldn't get logged output from the command as it would have a higher likelihood of containing sensitive information.

The following manifest can reproduce the issue:

# test.pp
exec { 'Sensitive command':
  command => Sensitive('/bin/echo "secret0"'),
}
 
exec { 'Sensitive unless':
  command => '/bin/echo Pass',
  unless  => Sensitive('/bin/echo "secret1"'),
}
 
exec { 'Sensitive onlyif':
  command => '/bin/echo Pass',
  onlyif  => Sensitive('/bin/echo "secret2'),
}

 

When I run puppet apply test.pp --debug I get the following output:

puppet apply test.pp --debug
Debug: Runtime environment: puppet_version=6.7.2, ruby_version=2.4.5, run_mode=user, default_encoding=UTF-8
...
Info: Applying configuration version '1565384722'
Debug: Exec[Sensitive command](provider=posix): Executing '[redacted]'
Debug: Executing: '[redacted]'
Notice: /Stage[main]/Main/Exec[Sensitive command]/returns: executed successfully
Debug: /Stage[main]/Main/Exec[Sensitive command]: The container Class[Main] will propagate my refresh event
Debug: Exec[Sensitive unless](provider=posix): Executing check '[redacted]'
Debug: Executing: '[redacted]'
Debug: /Stage[main]/Main/Exec[Sensitive unless]/unless: secret1
Debug: /Stage[main]/Main/Exec[Sensitive unless]: '[command redacted]' won't be executed because of failed check 'unless'
Debug: Exec[Sensitive onlyif](provider=posix): Executing check '[redacted]'
Debug: Executing: '[redacted]'
Debug: /Stage[main]/Main/Exec[Sensitive onlyif]/onlyif: secret2
Debug: Exec[Sensitive onlyif](provider=posix): Executing '[redacted]'
Debug: Executing: '[redacted]'
Notice: /Stage[main]/Main/Exec[Sensitive onlyif]/returns: executed successfully
Debug: /Stage[main]/Main/Exec[Sensitive onlyif]: The container Class[Main] will propagate my refresh event
Debug: Class[Main]: The container Stage[main] will propagate my refresh event
Debug: Finishing transaction 70240057109900
Debug: Storing state
Debug: Pruned old state cache entries in 0.00 seconds
Debug: Stored state in 0.01 seconds
Notice: Applied catalog in 0.07 seconds

It's a bit verbose, but you can see secret1 and secret2 leaked above on the following lines:

Debug: /Stage[main]/Main/Exec[Sensitive unless]/unless: secret1
Debug: /Stage[main]/Main/Exec[Sensitive onlyif]/onlyif: secret2

It's worth noting that logoutput does not affect this particular behavior:

# logoutput.pp
exec { 'Sensitive unless':
  command => '/bin/true',
  logoutput  => false,
  unless => Sensitive('/bin/echo secret1')
}
 
puppet apply --debug logoutput.pp
...
Info: Applying configuration version '1565385531'
Debug: Exec[Sensitive unless](provider=posix): Executing check '[redacted]'
Debug: Executing: '[redacted]'
Debug: /Stage[main]/Main/Exec[Sensitive unless]/unless: secret1
Debug: /Stage[main]/Main/Exec[Sensitive unless]: '[command redacted]' won't be executed because of failed check 'unless'
Debug: Finishing transaction 70187444945900
Debug: Storing state
Debug: Pruned old state cache entries in 0.00 seconds
Debug: Stored state in 0.01 seconds
Notice: Applied catalog in 0.02 seconds

Desired Behavior: When I run code in debug that contains an exec with Sensitive unless/onlyif commands the output of that command should be redacted or not logged.

Actual Behavior: Sensitive unless/onlyif checks log their output at debug.

Some minor digging shows the following code in the check methods for unless (in lib/puppet/type/exec.rb):

      # Return true if the command does not return 0.
      def check(value)
        begin
          output, status = provider.run(value, true)
        rescue Timeout::Error
          err _("Check %{value} exceeded timeout") % { value: value.inspect }
          return false
        end
 
        output.split(/\n/).each { |line|
          self.debug(line)
        }
 
        status.exitstatus != 0
      end
    end

The code for onlyif is quite similar. I suspect that this is the code responsible for logging the output in debug mode. A quick git blame shows that the output.split blocks in those methods haven't been touched in a long time and probably got missed in previous passes for Sensitive.



 Comments   
Comment by Josh Cooper [ 2019/08/09 ]

Looks related to PUP-8399

Comment by Josh Cooper [ 2019/08/30 ]

Merged to 5.5.x in https://github.com/puppetlabs/puppet/commit/b91e0bfc8f631177edd708fbdffc4181ceb34d6a

Comment by Kris Bosland [ 2019/09/06 ]

Passed CI in b91e0bfc8f631177edd708fbdffc4181ceb34d6a.

Comment by Kris Bosland [ 2019/09/06 ]

Tested in 5.5.x:

kris.bosland@kris:puppet % cat ../tmp/pup-9956/apply.pp                                                                                                                           ±[remotes/upstream/5.5.x]
# test.pp
exec { 'Non-sensitive command':
  command => '/bin/echo Pass',
}exec { 'Sensitive command':
  command => Sensitive('/bin/echo "secret0"'),
}exec { 'Sensitive unless':
  command => '/bin/echo Pass',
  unless  => Sensitive('/bin/echo "secret1"'),
}exec { 'Sensitive onlyif':
  command => '/bin/echo Pass',
  onlyif  => Sensitive('/bin/echo "secret2"'),
}
kris.bosland@kris:puppet % bx puppet apply ../tmp/pup-9956/apply.pp --debug | grep -i secret                                                                                      ±[remotes/upstream/5.5.x] 

Generated at Thu Nov 21 03:57:52 PST 2019 using JIRA 7.7.1#77002-sha1:e75ca93d5574d9409c0630b81c894d9065296414.