Jira (PUP-9956) Exec logs output of Sensitive unless and onlyif checks at debug

17 views
Skip to first unread message

Steve Marlow (JIRA)

unread,
Aug 9, 2019, 5:25:03 PM8/9/19
to puppe...@googlegroups.com
Steve Marlow created an issue
 
Puppet / Bug PUP-9956
Exec logs output of Sensitive unless and onlyif checks at debug
Issue Type: Bug Bug
Affects Versions: PUP 6.7.2
Assignee: Unassigned
Components: Types and Providers
Created: 2019/08/09 2:24 PM
Priority: Normal Normal
Reporter: Steve Marlow

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 "secret3'),
}

 

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.

Add Comment Add Comment
 
This message was sent by Atlassian JIRA (v7.7.1#77002-sha1:e75ca93)
Atlassian logo

Steve Marlow (JIRA)

unread,
Aug 9, 2019, 5:45:03 PM8/9/19
to puppe...@googlegroups.com
Steve Marlow updated an issue
Change By: Steve Marlow
*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:
{code:puppet}# 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 " secret3 secret2 '),
}
{code}

 

When I run puppet apply test.pp --debug I get the following output:
{noformat}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
{noformat}

It's a bit verbose, but you can see secret1 and secret2 leaked above on the following lines:
{noformat}Debug: /Stage[main]/Main/Exec[Sensitive unless]/unless: secret1

Debug: /Stage[main]/Main/Exec[Sensitive onlyif]/onlyif: secret2
{noformat}

It's worth noting that logoutput does not affect this particular behavior:
{noformat}# 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
{noformat}
*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):
{code:ruby}      # 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
{code}

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.

Josh Cooper (JIRA)

unread,
Aug 10, 2019, 12:35:03 AM8/10/19
to puppe...@googlegroups.com

Jorie Tappa (JIRA)

unread,
Aug 12, 2019, 12:56:02 PM8/12/19
to puppe...@googlegroups.com

Kris Bosland (JIRA)

unread,
Aug 28, 2019, 12:21:02 PM8/28/19
to puppe...@googlegroups.com

Josh Cooper (JIRA)

unread,
Aug 29, 2019, 5:11:03 PM8/29/19
to puppe...@googlegroups.com
Josh Cooper updated an issue
Change By: Josh Cooper
Fix Version/s: PUP 6.9.0
Fix Version/s: PUP 6.4.4
Fix Version/s: PUP 6.0.11
Fix Version/s: PUP 5.5.17

Josh Cooper (JIRA)

unread,
Aug 29, 2019, 5:11:03 PM8/29/19
to puppe...@googlegroups.com

Kris Bosland (JIRA)

unread,
Aug 29, 2019, 5:16:03 PM8/29/19
to puppe...@googlegroups.com
Kris Bosland updated an issue
Change By: Kris Bosland
Release Notes Summary: Exec onlyif and unless checks will now have their output redacted if they are marked sensitive.
Release Notes: Bug Fix

Josh Cooper (JIRA)

unread,
Aug 30, 2019, 4:49:02 PM8/30/19
to puppe...@googlegroups.com

Kris Bosland (JIRA)

unread,
Sep 6, 2019, 1:40:02 PM9/6/19
to puppe...@googlegroups.com
Kris Bosland commented on Bug PUP-9956

Passed CI in b91e0bfc8f631177edd708fbdffc4181ceb34d6a.

Kris Bosland (JIRA)

unread,
Sep 6, 2019, 1:42:03 PM9/6/19
to puppe...@googlegroups.com
Kris Bosland commented on Bug PUP-9956

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] 

Josh Cooper (JIRA)

unread,
Sep 16, 2019, 2:58:03 PM9/16/19
to puppe...@googlegroups.com

Jean Bond (JIRA)

unread,
Sep 16, 2019, 3:20:03 PM9/16/19
to puppe...@googlegroups.com
Jean Bond updated an issue
Change By: Jean Bond
Labels: resolved-issue-added
Reply all
Reply to author
Forward
0 new messages