1172952 - Puppet agent errors - "Could not intern_multiple from text/pson"

Status: RESOLVED FIXED

(Infrastructure & Operations :: RelOps: Puppet, task)

Description

[Dustin J. Mitchell [:dustin] (he/him)]

The first:

 Jun 09 07:12:40 talos-linux64-ix-077 puppet-agent: (/File[/var/lib/puppet/facts.d]) Failed to generate additional resources using 'eval_generate': Could not intern_multiple from text/pson: Paths must be fully qualified 

and they repeat for what looks like every agent run since.  Seems unrelated to the agent system.

This coincides with some switch reboots, but it's hard to see how those would be related.

Comment 1

[Dustin J. Mitchell [:dustin] (he/him)]

Correction, it stopped 10 minutes later; last one is:

 Jun 09 07:21:40 t-snow-r4-0087 puppet-agent: (/File[/var/lib/puppet/facts.d]) Failed to generate additional resources using 'eval_generate': Could not intern_multiple from text/pson: Paths must be fully qualified

Comment 2

[Amy Rich [:arr] [:arich]]

I haven't seen more of these, so it may have been some temporary glitch related to the switch work. Very hard to tell.

Comment 3

[Amy Rich [:arr] [:arich]]

We just got another spate of these, after xionox confirmed that the switch upgrades were done.

Comment 4

[Amy Rich [:arr] [:arich]]

There seem to be three types of errors we're seeing all at once:

yosemite: 

Tue Jun 09 08:28:05 -0700 2015 Puppet (err): Could not retrieve catalog from remote server: Net::ReadTimeout
Tue Jun 09 08:28:05 -0700 2015 Puppet (err): Could not retrieve catalog; skipping run

Windows:

Tue Jun 09 08:36:08 -0700 2015 Puppet (err): Could not retrieve local facts: failed to parse display name of moniker `winmgmts:{impersonationLevel=impersonate}!//./root/cimv2'
    HRESULT error code:0x8007045b
      A system shutdown is in progress.
Tue Jun 09 08:36:08 -0700 2015 Puppet (err): Failed to apply catalog: Could not retrieve local facts: failed to parse display name of moniker `winmgmts:{impersonationLevel=impersonate}!//./root/cimv2'
    HRESULT error code:0x8007045b
      A system shutdown is in progress.


Other OSes in scl3:

Tue Jun 09 08:31:06 -0700 2015 /File[/var/lib/puppet/facts.d] (err): Failed to generate additional resources using 'eval_generate': Could not intern_multiple from text/pson: Paths must be fully qualified
Tue Jun 09 08:31:26 -0700 2015 /File[/var/lib/puppet/facts.d] (err): Could not evaluate: Could not retrieve information from environment production source(s) puppet://releng-puppet1.srv.releng.scl3.mozilla.com/pluginfacts

(sometimes that's releng-puppet2 as well, so it's not just one puppet host).

Comment 5

[Dustin J. Mitchell [:dustin] (he/him)]

Only the third one worries me.  The "spate" was

 Jun 09 08:16:23 foopy63.p4.releng.scl3.mozilla.com puppet-agent: (/File[/var/lib/puppet/facts.d]) Could not evaluate: Could not retrieve information from environment production source(s) puppet://releng-puppet2.srv.releng.scl3.mozilla.com/pluginfacts
Jun 09 08:28:15 t-snow-r4-0014 puppet-agent: (/File[/var/lib/puppet/facts.d]) Could not evaluate: Could not retrieve information from environment production source(s) puppet://releng-puppet2.srv.releng.scl3.mozilla.com/pluginfacts
Jun 09 08:29:46 talos-linux64-ix-026 puppet-agent: (/File[/var/lib/puppet/facts.d]) Could not evaluate: Could not retrieve information from environment production source(s) puppet://releng-puppet2.srv.releng.scl3.mozilla.com/pluginfacts
Jun 09 08:30:21 foopy76.p6.releng.scl3.mozilla.com puppet-agent: (/File[/var/lib/puppet/facts.d]) Could not evaluate: Could not retrieve information from environment production source(s) puppet://releng-puppet1.srv.releng.scl3.mozilla.com/pluginfacts
Jun 09 08:30:22 t-snow-r4-0143 puppet-agent: (/File[/var/lib/puppet/facts.d]) Could not evaluate: Could not retrieve information from environment production source(s) puppet://releng-puppet1.srv.releng.scl3.mozilla.com/pluginfacts
Jun 09 08:30:22 t-snow-r4-0077 puppet-agent: (/File[/var/lib/puppet/facts.d]) Could not evaluate: Could not retrieve information from environment production source(s) puppet://releng-puppet1.srv.releng.scl3.mozilla.com/pluginfacts
Jun 09 08:31:02 talos-linux32-ix-025 puppet-agent: (/File[/var/lib/puppet/facts.d]) Could not evaluate: Could not retrieve information from environment production source(s) puppet://releng-puppet2.srv.releng.scl3.mozilla.com/pluginfacts
Jun 09 08:31:26 bld-lion-r5-091 puppet-agent: (/File[/var/lib/puppet/facts.d]) Could not evaluate: Could not retrieve information from environment production source(s) puppet://releng-puppet1.srv.releng.scl3.mozilla.com/pluginfacts 

interesting that it's limited to scl3.  I might suspect filesystem corruption due to filer failure, but I don't see any evidence of that in the kernel logs.

The "paths must be fully qualified" bit is the most mysterious.  It comes (no thanks to puppet for not giving this info) from lib/puppet/file_serving/base.rb:

 53   # Set our base path.
 54   attr_reader :path
 55   def path=(path)
 56     raise ArgumentError.new("Paths must be fully qualified") unless Puppet::FileServing::Base.absolute?(path)
 57     @path = path
 58   end

so somewhere, something is setting File{path: ..} to a partial path.  Something in the automatic fact synchronization code.

Comment 6

[Dustin J. Mitchell [:dustin] (he/him)]

I patched that method on releng-puppet2.srv.releng.scl3:


  # Set our base path.
  attr_reader :path
  def path=(path)
    raise ArgumentError.new("Paths must be fully qualified - got #{path} at #{caller.inspect}") unless Puppet::FileServing::Base.absolute?(path)
    @path = path
  end

let's see what we find.

Comment 7

[Dustin J. Mitchell [:dustin] (he/him)]

Nothing for a few hours now.. I'm guessing this was due to an EOF related to the switch work, and puppet is hiding the EOF through multiple layers of error handling.  I've reverted the code change (since I'm not totally sure it won't fail).