Jira (PUP-10097) Using Binary type as a File resource's contents works in puppet apply, but not in puppet agent

0 views
Skip to first unread message

Garrett Guillotte (JIRA)

unread,
Oct 9, 2019, 2:16:05 PM10/9/19
to puppe...@googlegroups.com
Garrett Guillotte created an issue
 
Puppet / Bug PUP-10097
Using Binary type as a File resource's contents works in puppet apply, but not in puppet agent
Issue Type: Bug Bug
Affects Versions: PUP 5.5.16
Assignee: Unassigned
Created: 2019/10/09 11:15 AM
Priority: Normal Normal
Reporter: Garrett Guillotte

Puppet Version: 5.5.16
Puppet Server Version: PE 2018.1.9
OS Name/Version: RHEL 7.6

Desired Behavior:

puppet agent can manage the contents of a file resource that uses a Binary type for its contents, with behavior consistent with puppet apply running the same manifest.

Actual Behavior:

Attempting to write binary file content represented in hex as c7 d1 fc 84, converted to base64 and passed as Binary('x9H8hA=='), editing /etc/puppetlabs/code/environments/production/manifests/site.pp:

[root@pe-201819-master manifests]# cat site.pp
## site.pp ##
 
# This file (/etc/puppetlabs/puppet/manifests/site.pp) is the main entry point
...
node default {
  # This is where you can declare classes for all nodes.
  # Example:
  #   class { 'my_class': }
  file { '/tmp/test':
    ensure  => present,
    content => Binary('x9H8hA=='),
  }
}
 
[root@pe-201819-master manifests]# puppet apply site.pp
Notice: Compiled catalog for pe-201819-master.puppetdebug.vlan in environment production in 0.02 seconds
Notice: /Stage[main]/Main/Node[default]/File[/tmp/test]/ensure: defined content as '{md5}387d16f3cb61048e6fb16cfd81367ce8'
Notice: Applied catalog in 0.20 seconds
 
[root@pe-201819-master manifests]# od -t x1 /tmp/test
0000000 c7 d1 fc 84
0000004

This is the expected result of applying the manifest. puppet apply works as expected.

Running as puppet agent fails:

[root@pe-201819-master manifests]# puppet agent --test
Info: Using configured environment 'production'
Info: Retrieving pluginfacts
Info: Retrieving plugin
Info: Retrieving locales
Info: Loading facts
Info: Caching catalog for pe-201819-master.puppetdebug.vlan
Info: Applying configuration version '1570644420'
Notice: /Stage[main]/Main/Node[default]/File[/tmp/test]/content: Received a Log attribute with invalid encoding:"\n--- /tmp/test\t2019-10-09 18:06:34.850138853 +0000\n+++ /tmp/puppet-file20191009-20057-12z3c2w\t2019-10-09 18:07:15.397076080 +0000\n@@ -1 +1 @@\n-\xC7\xD1\xFC\x84\n\\ No newline at end of file\n+x9H8hA==\n\\ No newline at end of file\n"\nBacktrace:
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:190:in `newmessage'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:313:in `initialize'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:88:in `new'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:88:in `create'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/logging.rb:11:in `send_log'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/logging.rb:20:in `block (2 levels) in <module:Logging>'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/data_sync.rb:45:in `block in checksum_insync?'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/data_sync.rb:19:in `write_temporarily'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/data_sync.rb:44:in `checksum_insync?'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/content.rb:104:in `insync?'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/property.rb:278:in `safe_insync?'
Notice: /Stage[main]/Main/Node[default]/File[/tmp/test]/content: content changed '{md5}387d16f3cb61048e6fb16cfd81367ce8' to '{md5}1567c6c4f10f34202b0f7578d8d44e43'
Notice: Applied catalog in 21.24 seconds

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

Garrett Guillotte (JIRA)

unread,
Oct 9, 2019, 2:17:05 PM10/9/19
to puppe...@googlegroups.com
Garrett Guillotte updated an issue
Change By: Garrett Guillotte
*Puppet Version:* 5.5.16
*Puppet Server Version:* PE 2018.1.9
*OS Name/Version:* RHEL 7.6

*Desired Behavior:*

{{puppet agent}} can manage the contents of a {{file}} resource that uses a {{Binary}} type for its contents, with behavior consistent with {{puppet apply}} running the same manifest.

*Actual Behavior:*

Attempting to write binary file content represented in hex as {{c7 d1 fc 84}}, converted to base64 and passed as {{Binary('x9H8hA==')}}, editing {{/etc/puppetlabs/code/environments/production/manifests/site.pp}}:

{code}

[root@pe-201819-master manifests]# cat site.pp
## site.pp ##

# This file (/etc/puppetlabs/puppet/manifests/site.pp) is the main entry point
...
node default {
  # This is where you can declare classes for all nodes.
  # Example:
  #   class { 'my_class': }
  file { '/tmp/test':
    ensure  => present,
    content => Binary('x9H8hA=='),
  }
}

[root@pe-201819-master manifests]# puppet apply site.pp
Notice: Compiled catalog for pe-201819-master.puppetdebug.vlan in environment production in 0.02 seconds
Notice: /Stage[main]/Main/Node[default]/File[/tmp/test]/ensure: defined content as '{md5}387d16f3cb61048e6fb16cfd81367ce8'
Notice: Applied catalog in 0.20 seconds

[root@pe-201819-master manifests]# od -t x1 /tmp/test
0000000 c7 d1 fc 84
0000004
{code}


This is the expected result of applying the manifest. {{puppet apply}} works as expected.

Running as {{puppet agent}} fails:

{code}

[root@pe-201819-master manifests]# puppet agent --test
Info: Using configured environment 'production'
Info: Retrieving pluginfacts
Info: Retrieving plugin
Info: Retrieving locales
Info: Loading facts
Info: Caching catalog for pe-201819-master.puppetdebug.vlan
Info: Applying configuration version '1570644420'
Notice: /Stage[main]/Main/Node[default]/File[/tmp/test]/content: Received a Log attribute with invalid encoding:"\n--- /tmp/test\t2019-10-09 18:06:34.850138853 +0000\n+++ /tmp/puppet-file20191009-20057-12z3c2w\t2019-10-09 18:07:15.397076080 +0000\n@@ -1 +1 @@\n-\xC7\xD1\xFC\x84\n\\ No newline at end of file\n+x9H8hA==\n\\ No newline at end of file\n"\nBacktrace:
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:190:in `newmessage'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:313:in `initialize'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:88:in `new'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:88:in `create'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/logging.rb:11:in `send_log'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/logging.rb:20:in `block (2 levels) in <module:Logging>'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/data_sync.rb:45:in `block in checksum_insync?'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/data_sync.rb:19:in `write_temporarily'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/data_sync.rb:44:in `checksum_insync?'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/content.rb:104:in `insync?'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/property.rb:278:in `safe_insync?'
Notice: /Stage[main]/Main/Node[default]/File[/tmp/test]/content: content changed '{md5}387d16f3cb61048e6fb16cfd81367ce8' to '{md5}1567c6c4f10f34202b0f7578d8d44e43'
Notice: Applied catalog in 21.24 seconds
{code}

The file is created, but with the base64 content written as a string:

{code}

[root@pe-201819-master manifests]# od -t x1 /tmp/test
0000000 78 39 48 38 68 41 3d 3d
0000010

[root@pe-201819-master manifests]# cat /tmp/test
x9H8hA==
{code}

Garrett Guillotte (JIRA)

unread,
Oct 9, 2019, 2:30:05 PM10/9/19
to puppe...@googlegroups.com
Excerpted with debug logging:

{code}
...
2019-10-09 18:25:28 +0000 Puppet (debug): Executing: 'diff -u /tmp/test /tmp/puppet-file20191009-29036-thyi2b'
2019-10-09 18:25:28 +0000 /Stage[main]/Main/Node[default]/File[/tmp/test]/content (notice): Received a Log attribute with invalid encoding:"\n--- /tmp/test\t2019-10-09 18:25:21.809153889 +0000\n+++ /tmp/puppet-file20191009-29036-thyi2b\t2019-10-09 18:25:28.063298027 +0000\n@@ -1 +1 @@\n-\xC7\xD1\xFC\x84\n\\ No newline at end of file\n+x9H8hA==\n\\ No newline at end of file\n"\nBacktrace:

/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:190:in `newmessage'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:313:in `initialize'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:88:in `new'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:88:in `create'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/logging.rb:11:in `send_log'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/logging.rb:20:in `block (2 levels) in <module:Logging>'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/data_sync.rb:45:in `block in checksum_insync?'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/data_sync.rb:19:in `write_temporarily'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/data_sync.rb:44:in `checksum_insync?'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/file/content.rb:104:in `insync?'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/property.rb:278:in `safe_insync?'
2019-10-09 18:25:28 +0000 Puppet (debug): Executing: 'diff -u /tmp/test /tmp/puppet-file20191009-29036-2dqm05'
2019-10-09 18:25:28 +0000 /Stage[main]/Main/Node[default]/File[/tmp/test]/content (notice):
2019-10-09 18:25:28 +0000 /Stage[main]/Main/Node[default]/File[/tmp/test]/content (notice): content changed '{md5}387d16f3cb61048e6fb16cfd81367ce8' to '{md5}1567c6c4f10f34202b0f7578d8d44e43' (corrective)
2019-10-09 18:25:28 +0000 /Stage[main]/Main/Node[default]/File[/tmp/test] (debug):
The container Node[default] will propagate my refresh event
...
{code}

The
file is created, but with the base64 content written as a string:


{code}
[root@pe-201819-master manifests]# od -t x1 /tmp/test
0000000 78 39 48 38 68 41 3d 3d
0000010

[root@pe-201819-master manifests]# cat /tmp/test
x9H8hA==
{code}


md5 of the incorrect content ends in {{4e43}}. md5 of the correct content ends in {{7ce8}}.

Garrett Guillotte (JIRA)

unread,
Oct 9, 2019, 2:41:02 PM10/9/19
to puppe...@googlegroups.com

Garrett Guillotte (JIRA)

unread,
Oct 9, 2019, 2:46:02 PM10/9/19
to puppe...@googlegroups.com
Garrett Guillotte commented on Bug PUP-10097
 
Re: Using Binary type as a File resource's contents works in puppet apply, but not in puppet agent

This might be a duplicate of PUP-9110 / PUP-3600. If so, the inability to handle Binary type data in catalogs should be noted as a known issue in Puppet 5.5 that is resolved in Puppet 6.

Garrett Guillotte (JIRA)

unread,
Oct 9, 2019, 2:54:03 PM10/9/19
to puppe...@googlegroups.com

Henrik Lindberg (JIRA)

unread,
Oct 9, 2019, 5:31:03 PM10/9/19
to puppe...@googlegroups.com

Before 6 you had to configure both the agent and master with "rich_data=true" setting IIRC, and I think there was other issues as well that were addressed in Puppet 6 where rich data catalog is now both the default and is negotiated between agent and master.

Vadym Chepkov (JIRA)

unread,
Oct 9, 2019, 6:21:02 PM10/9/19
to puppe...@googlegroups.com

I have enabled rich_data on both servers and agent, restarted puppetserver, receive new error:

Error: Could not retrieve catalog from remote server: Could not intern from application/json: Internal Error: Puppet Context ':loaders' missing
Warning: Not using cache on failed catalog
Error: Could not retrieve catalog; skipping run

Henrik Lindberg (JIRA)

unread,
Oct 10, 2019, 2:58:03 AM10/10/19
to puppe...@googlegroups.com

Sorry, Binary is pretty much not a working feature in catalogs/agents before Puppet 6.

I doubt we will be able to backport all required fixes to Puppet 5.

Vadym Chepkov (JIRA)

unread,
Oct 10, 2019, 9:54:02 AM10/10/19
to puppe...@googlegroups.com

Brett Gray (JIRA)

unread,
Oct 11, 2019, 2:03:03 AM10/11/19
to puppe...@googlegroups.com

Henrik Lindberg (JIRA)

unread,
Oct 11, 2019, 3:21:03 AM10/11/19
to puppe...@googlegroups.com

Brett Gray it cannot be the very same issue since this ticket is about Binary not working on Puppet 5 even after turning on the (then experimental) support for rich data in catalogs. Your problem must be something else as you are on Puppet 6. It would help If you can help us with a simple reproducer for your issue and file a separate ticket.

Brett Gray (JIRA)

unread,
Oct 11, 2019, 3:34:03 AM10/11/19
to puppe...@googlegroups.com

Mihai Buzgau (JIRA)

unread,
Oct 22, 2019, 5:17:07 AM10/22/19
to puppe...@googlegroups.com

Patrick Grant (JIRA)

unread,
Oct 22, 2019, 6:31:03 AM10/22/19
to puppe...@googlegroups.com

Josh Cooper (JIRA)

unread,
Oct 31, 2019, 4:57:03 PM10/31/19
to puppe...@googlegroups.com

Josh Cooper (JIRA)

unread,
Oct 31, 2019, 4:57:03 PM10/31/19
to puppe...@googlegroups.com
Josh Cooper assigned an issue to Unassigned

Josh Cooper (JIRA)

unread,
Oct 31, 2019, 5:35:05 PM10/31/19
to puppe...@googlegroups.com
Josh Cooper commented on Bug PUP-10097
 
Re: Using Binary type as a File resource's contents works in puppet apply, but not in puppet agent

So there are a few different things going on.

1. When using a puppet 5.x agent and 5.x/6.x server, the resulting file is the base64 encoded content (since rich_data is off on the agent). In other words, binary file content doesn't seem to work:

$ od -t c /tmp/test
0000000    x   9   H   8   h   A   =   =

2. Enabling rich data on both 5.x agent and 5.x/6.x server does not work, because we didn't make the loaders available agent side until puppet 6:

$ bundle exec puppet agent -t
Info: Using configured environment 'production'
Info: Retrieving pluginfacts
Info: Retrieving plugin
Info: Retrieving locales
Error: Could not retrieve catalog from remote server: Could not intern from application/json: Internal Error: Puppet Context ':loaders' missing

3. Puppet only displays diffs when it updates an existing file. It doesn't display a diff when creating a new file. So to reliably trigger this issue you have to create a mismatched file.

4. The show_diff setting is automatically enabled when running puppet agent -t, but not puppet apply. This issue is reproducible when using puppet apply --show_diff. So it's not specific to apply or agent:

rm /tmp/test && touch /tmp/test && bundle exec puppet apply --show_diff manifest.pp
Notice: Compiled catalog for localhost in environment production in 0.02 seconds
Notice: /Stage[main]/Main/File[/tmp/test]/content: Received a Log attribute with invalid encoding:"\n--- /tmp/test\t2019-10-31 14:21:21.000000000 -0700\n+++ /var/folders/8m/d6146zxd6bv_3h8y4ykvvxh40000gn/T/puppet-file20191031-99254-1g938g5\t2019-10-31 14:21:26.000000000 -0700\n@@ -0,0 +1 @@\n+\xC7\xD1\xFC\x84\n\\ No newline at end of file\n"\nBacktrace:
/Users/josh/work/puppet/lib/puppet/util/log.rb:190:in `newmessage'
/Users/josh/work/puppet/lib/puppet/util/log.rb:315:in `initialize'
/Users/josh/work/puppet/lib/puppet/util/log.rb:88:in `new'
/Users/josh/work/puppet/lib/puppet/util/log.rb:88:in `create'
/Users/josh/work/puppet/lib/puppet/util/logging.rb:11:in `send_log'
/Users/josh/work/puppet/lib/puppet/util/logging.rb:20:in `block (2 levels) in <module:Logging>'
/Users/josh/work/puppet/lib/puppet/type/file/data_sync.rb:45:in `block in checksum_insync?'
/Users/josh/work/puppet/lib/puppet/type/file/data_sync.rb:19:in `write_temporarily'
/Users/josh/work/puppet/lib/puppet/type/file/data_sync.rb:44:in `checksum_insync?'
/Users/josh/work/puppet/lib/puppet/type/file/content.rb:106:in `insync?'
Notice: /Stage[main]/Main/File[/tmp/test]/content: content changed '{md5}d41d8cd98f00b204e9800998ecf8427e' to '{md5}387d16f3cb61048e6fb16cfd81367ce8'

5. The error occurs because the diff command returns a UTF-8 string, but the encoding is not valid (the underlying bytes are not a valid UTF-8 sequence):

(byebug) diff(resource[:path], path).encoding
#<Encoding:UTF-8>
(byebug) diff(resource[:path], path).valid_encoding?
false
(byebug)

The same occurs when executing the diff command directly from ruby:

irb(main):003:0> %x(diff #{oldpath} #{newpath})
=> "0a1\n> \xC7\xD1\xFC\x84\n\\ No newline at end of file\n"
irb(main):004:0> %x(diff #{oldpath} #{newpath}).encoding
=> #<Encoding:UTF-8>
irb(main):005:0> %x(diff #{oldpath} #{newpath}).valid_encoding?
=> false

6. The error message occurs because our logging code protects against log messages with invalid encodings, see PUP-1441. So we log that the message we were asked to log is invalid along with the stack trace.

For this ticket, I think we should validate the string returned by the diff command. If the encoding is not valid or if the encoding is binary, then we should log a message that the diff cannot be displayed.

Reply all
Reply to author
Forward
0 new messages