Uploaded image for project: 'Puppet'
  1. Puppet
  2. PUP-7198

Puppet Server uses facts from the previous run (n-1) after agent switches masters

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: PUP 4.9.0
    • Fix Version/s: PUP 5.0.0
    • Component/s: None
    • Environment:
    • Template:
    • Acceptance Criteria:
      Hide

      Regardless of facts terminus, PuppetServer/Master MUST always use actual set of facts received from the agent.

      Show
      Regardless of facts terminus, PuppetServer/Master MUST always use actual set of facts received from the agent.
    • Team:
      Agent
    • Story Points:
      8
    • Sprint:
      Agent 2017-04-19, Agent 2017-05-03, Agent 2017-05-31, Agent 2017-06-14, Agent 2017-06-28
    • Release Notes:
      Bug Fix
    • QA Risk Assessment:
      Manual

      Description

      I couldn't believe that, but I could finally reliably reproduce the problem in minimal sample. I've observed that episodically and believe this is a long standing issue - the reason I do not put Critical to this.

      Ruby fact plugin:

      Facter.add('fact_cache_issue') do
          setcode do
              begin
                  File.read('/etc/fact_cache_issue')
              rescue
              end
          end
      end
      

      Puppet code:

      class factcacheissue {
          $value = $::facts['fact_cache_issue'] ? {
              undef   => generate('/usr/bin/openssl', 'rand', '-hex', '8'),
              default => $::facts['fact_cache_issue']
          }
          
          file { '/etc/fact_cache_issue':
              content => $value,
          }
      }
      node cacheissue.example.com {
          include factcacheissue
          file {'/etc/puppetlabs/puppet/puppet.conf':
              mode    => '0644',
              content => '
      [main]
      client = false
      certname = cacheissue.example.com
      server = puppetback.example.com
      ca_server = puppet.example.com
      environment = production
      srv_domain = example.com
      use_srv_records = false
      ',
          }
      }
      

      1. Setup puppet-agent 1.9.0 package
      2. Run against CA server puppet.example.com
      3. During the first initialization, openssl generator is called and puppet server is changed to secondary master (puppetback.example.com)
      4. Second run goes to secondary master. Master stores facts PuppetDB, but Master does not see new facts during catalog compilations => calls openssl generator again.
      5. Each next run uses fact set from run #n-1 - that's very weird, and produces resource value switch to previous run.
      6. If puppet server is not switched then everything is correct.

      Command line output:

      Setting up puppet-agent (1.9.0-1jessie) ...
       
      Configuration file '/etc/puppetlabs/puppet/puppet.conf'
       ==> File on system created by you or by a script.
       ==> File also in package provided by package maintainer.
       ==> Using current old file as you requested.
      Created symlink from /etc/systemd/system/multi-user.target.wants/puppet.service to /lib/systemd/system/puppet.service.
      Created symlink from /etc/systemd/system/multi-user.target.wants/mcollective.service to /lib/systemd/system/mcollective.service.
      Created symlink from /etc/systemd/system/multi-user.target.wants/pxp-agent.service to /lib/systemd/system/pxp-agent.service.
      Removed symlink /etc/systemd/system/multi-user.target.wants/pxp-agent.service.
      + PUPPET=/opt/puppetlabs/bin/puppet
      + /opt/puppetlabs/bin/puppet resource service puppet ensure=false enable=false provider=systemd
      Notice: /Service[puppet]/enable: enable changed 'true' to 'false'
      service { 'puppet':
        ensure => 'stopped',
        enable => 'false',
      }
      + systemctl mask puppet
      Created symlink from /etc/systemd/system/puppet.service to /dev/null.
      + host maint.example.com
      + /opt/puppetlabs/bin/puppet agent --test --trace
      Info: Creating a new SSL key for cacheissue.example.com
      Info: Caching certificate for ca
      Info: csr_attributes file loading from /etc/puppetlabs/puppet/csr_attributes.yaml
      Info: Creating a new SSL certificate request for cacheissue.example.com
      Info: Certificate Request fingerprint (SHA256): DA:8A:E9:2C:01:A4:2B:B4:DA:28:66:89:8D:91:9B:4F:76:DF:62:4F:EA:A5:28:68:03:0B:20:92:03:01:70:01
      Info: Caching certificate for cacheissue.example.com
      Info: Caching certificate_revocation_list for ca
      Info: Caching certificate for ca
      Info: Using configured environment 'production'
      Info: Retrieving pluginfacts
      Info: Retrieving plugin
      < output removed >
      Notice: /File[/opt/puppetlabs/puppet/cache/lib/facter/factcacheissue.rb]/ensure: defined content as '{md5}7f09896f9c273cf29c2bb4d0cf21df27'
      < output removed >
      Info: Loading facts
      Info: Caching catalog for cacheissue.example.com
      Info: Applying configuration version '1486637068'
      Notice: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]/ensure: defined content as '{md5}c3623b026f1e4ffaad7bc5f31dce5ddf'
      Notice: /Stage[main]/Main/Node[cacheissue.example.com]/File[/etc/puppetlabs/puppet/puppet.conf]/content: 
      --- /etc/puppetlabs/puppet/puppet.conf  2017-02-09 10:44:08.044000000 +0000
      +++ /tmp/puppet-file20170209-954-g8w0cf 2017-02-09 10:44:28.616000000 +0000
      @@ -1,6 +1,9 @@
      +
       [main]
       client = false
       certname = cacheissue.example.com
      -server = puppet.example.com
      +server = puppetback.example.com
       ca_server = puppet.example.com
       environment = production
      +srv_domain = example.com
      +use_srv_records = false
       
      Info: Computing checksum on file /etc/puppetlabs/puppet/puppet.conf
      Info: /Stage[main]/Main/Node[cacheissue.example.com]/File[/etc/puppetlabs/puppet/puppet.conf]: Filebucketed /etc/puppetlabs/puppet/puppet.conf to puppet with sum 3f658fe9074501624c1ec8025cc03016
      Notice: /Stage[main]/Main/Node[cacheissue.example.com]/File[/etc/puppetlabs/puppet/puppet.conf]/content: content changed '{md5}3f658fe9074501624c1ec8025cc03016' to '{md5}f48d1f4f1bfcb3d2b2a0678d7433fa04'
      Notice: /Stage[main]/Main/Node[cacheissue.example.com]/Service[mcollective]/enable: enable changed 'true' to 'false'
      Notice: Applied catalog in 0.12 seconds
      + echo 'Please go to puppetserver and exec the following command when we wait for key'
      Please go to puppetserver and exec the following command when we wait for key
      + echo '> puppet cert sign cacheissue.example.com'
      > puppet cert sign cacheissue.example.com
      + echo 'Use CTRL+C to stop cycle, if fails due to different reasons'
      Use CTRL+C to stop cycle, if fails due to different reasons
      + sleep 5
      + test -n 1
      + exit 0
      Connection to 127.0.0.1 closed.
      + echo 'Provisioning DB VMs'
      Provisioning DB VMs
      ++ seq 1 2
      + for i in '$(seq 1 2)'
      + for h in cacheissue
      + puppet_deploy cacheissue
      + local vm=cacheissue
      + vagrant ssh cacheissue -- sudo /opt/puppetlabs/bin/puppet agent --test --trace
      sudo: unable to resolve host cacheissue.example.com
      Info: Using configured environment 'production'
      Info: Retrieving pluginfacts
      Info: Retrieving plugin
      Info: Loading facts
      Info: Caching catalog for cacheissue.example.com
      Info: Applying configuration version '1486636987'
      Notice: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]/content: 
      --- /etc/fact_cache_issue       2017-02-09 10:44:28.612000000 +0000
      +++ /tmp/puppet-file20170209-1058-3b631e        2017-02-09 10:44:40.932000000 +0000
      @@ -1 +1 @@
      -3069036cea991cba
      +f4956d526f3ea4b7
       
      Info: Computing checksum on file /etc/fact_cache_issue
      Info: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]: Filebucketed /etc/fact_cache_issue to puppet with sum c3623b026f1e4ffaad7bc5f31dce5ddf
      Notice: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]/content: content changed '{md5}c3623b026f1e4ffaad7bc5f31dce5ddf' to '{md5}965e17e84e855e7355c3145ce89af6aa'
      Notice: Applied catalog in 0.10 seconds
      + test 1 = 1
      + for i in '$(seq 1 2)'
      + for h in cacheissue
      + puppet_deploy cacheissue
      + local vm=cacheissue
      + vagrant ssh cacheissue -- sudo /opt/puppetlabs/bin/puppet agent --test --trace
      sudo: unable to resolve host cacheissue.example.com
      Info: Using configured environment 'production'
      Info: Retrieving pluginfacts
      Info: Retrieving plugin
      Info: Loading facts
      Info: Caching catalog for cacheissue.example.com
      Info: Applying configuration version '1486636987'
      Notice: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]/content: 
      --- /etc/fact_cache_issue       2017-02-09 10:44:40.980000000 +0000
      +++ /tmp/puppet-file20170209-1138-10kh2da       2017-02-09 10:44:46.904000000 +0000
      @@ -1 +1 @@
      -f4956d526f3ea4b7
      +3069036cea991cba
       
      Info: Computing checksum on file /etc/fact_cache_issue
      Info: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]: Filebucketed /etc/fact_cache_issue to puppet with sum 965e17e84e855e7355c3145ce89af6aa
      Notice: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]/content: content changed '{md5}965e17e84e855e7355c3145ce89af6aa' to '{md5}c3623b026f1e4ffaad7bc5f31dce5ddf'
      Notice: Applied catalog in 0.10 seconds
       
      root@cacheissue:~# puppet agent -t
      Info: Using configured environment 'production'
      Info: Retrieving pluginfacts
      Info: Retrieving plugin
      Info: Loading facts
      Info: Caching catalog for cacheissue.example.com
      Info: Applying configuration version '1486636987'
      Notice: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]/content: 
      --- /etc/fact_cache_issue       2017-02-09 10:44:46.948000000 +0000
      +++ /tmp/puppet-file20170209-1243-snbll1        2017-02-09 10:45:34.544000000 +0000
      @@ -1 +1 @@
      -3069036cea991cba
      +f4956d526f3ea4b7
       
      Info: Computing checksum on file /etc/fact_cache_issue
      Info: FileBucket got a duplicate file {md5}c3623b026f1e4ffaad7bc5f31dce5ddf
      Info: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]: Filebucketed /etc/fact_cache_issue to puppet with sum c3623b026f1e4ffaad7bc5f31dce5ddf
      Notice: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]/content: content changed '{md5}c3623b026f1e4ffaad7bc5f31dce5ddf' to '{md5}965e17e84e855e7355c3145ce89af6aa'
      Notice: Applied catalog in 0.09 seconds
      root@cacheissue:~# puppet agent -t
      Info: Using configured environment 'production'
      Info: Retrieving pluginfacts
      Info: Retrieving plugin
      Info: Loading facts
      Info: Caching catalog for cacheissue.example.com
      Info: Applying configuration version '1486636987'
      Notice: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]/content: 
      --- /etc/fact_cache_issue       2017-02-09 10:45:34.580000000 +0000
      +++ /tmp/puppet-file20170209-1312-20p13j        2017-02-09 10:45:46.756000000 +0000
      @@ -1 +1 @@
      -f4956d526f3ea4b7
      +3069036cea991cba
       
      Info: Computing checksum on file /etc/fact_cache_issue
      Info: FileBucket got a duplicate file {md5}965e17e84e855e7355c3145ce89af6aa
      Info: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]: Filebucketed /etc/fact_cache_issue to puppet with sum 965e17e84e855e7355c3145ce89af6aa
      Notice: /Stage[main]/Factcacheissue/File[/etc/fact_cache_issue]/content: content changed '{md5}965e17e84e855e7355c3145ce89af6aa' to '{md5}c3623b026f1e4ffaad7bc5f31dce5ddf'
      Notice: Applied catalog in 0.09 seconds
      
      

      PuppetServer log:

      2017-02-09 10:43:04,412 INFO  [qtp1584394027-67] [puppetserver] Puppet Caching node for cacheissue.example.com
      2017-02-09 10:43:07,118 INFO  [qtp1584394027-64] [puppetserver] Puppet 'replace_facts' command for cacheissue.example.com submitted to PuppetDB with UUID 319bb70e-ef88-4c9b-82ee-1ed9828b107c
      2017-02-09 10:43:07,390 INFO  [qtp1584394027-64] [puppetserver] Puppet Caching node for cacheissue.example.com
      2017-02-09 10:43:08,167 INFO  [qtp1584394027-64] [puppetserver] Puppet Compiled catalog for cacheissue.example.com in environment production in 0.74 seconds
      2017-02-09 10:43:08,167 INFO  [qtp1584394027-64] [puppetserver] Puppet Caching catalog for cacheissue.example.com
      2017-02-09 10:43:08,197 INFO  [qtp1584394027-64] [puppetserver] Puppet 'replace_catalog' command for cacheissue.example.com submitted to PuppetDB with UUID b4d21d85-04ce-4c73-828c-348fab7869a5
      2017-02-09 10:43:08,415 INFO  [qtp1584394027-65] [puppetserver] Puppet 'store_report' command for cacheissue.example.com submitted to PuppetDB with UUID 6a80a4fc-e692-418a-8564-bbafe5eed76e
      2017-02-09 10:44:38,593 INFO  [qtp1584394027-69] [puppetserver] Puppet Caching node for cacheissue.example.com
      2017-02-09 10:44:41,399 INFO  [qtp1584394027-66] [puppetserver] Puppet 'replace_facts' command for cacheissue.example.com submitted to PuppetDB with UUID c412c520-aa29-49f8-b91c-f97382f6ac09
      2017-02-09 10:44:41,602 INFO  [qtp1584394027-66] [puppetserver] Puppet Caching node for cacheissue.example.com
      2017-02-09 10:44:41,688 WARN  [qtp1584394027-66] [puppetserver] Puppet Class 'settings' is already defined; cannot redefine at :
      2017-02-09 10:44:41,728 WARN  [qtp1584394027-66] [c.p.p.ShellUtils] Executed an external process which logged to STDERR: f4956d526f3ea4b7
       
      2017-02-09 10:44:41,773 INFO  [qtp1584394027-66] [puppetserver] Puppet Compiled catalog for cacheissue.example.com in environment production in 0.09 seconds
      2017-02-09 10:44:41,774 INFO  [qtp1584394027-66] [puppetserver] Puppet Caching catalog for cacheissue.example.com
      2017-02-09 10:44:41,856 INFO  [qtp1584394027-66] [puppetserver] Puppet 'replace_catalog' command for cacheissue.example.com submitted to PuppetDB with UUID 4bbea8ed-b9ed-442e-90a4-289aaf27c991
      2017-02-09 10:44:42,087 INFO  [qtp1584394027-67] [puppetserver] Puppet 'store_report' command for cacheissue.example.com submitted to PuppetDB with UUID 981f4e68-c97a-4c21-8c58-ad629ddf5ad0
      2017-02-09 10:44:45,460 INFO  [qtp1584394027-65] [puppetserver] Puppet Caching node for cacheissue.example.com
      2017-02-09 10:44:47,539 INFO  [qtp1584394027-68] [puppetserver] Puppet 'replace_facts' command for cacheissue.example.com submitted to PuppetDB with UUID dd30a8f1-cb79-4a5e-9bad-4b6fbb0286e9
      2017-02-09 10:44:47,692 INFO  [qtp1584394027-68] [puppetserver] Puppet Caching node for cacheissue.example.com
      2017-02-09 10:44:47,739 WARN  [qtp1584394027-68] [puppetserver] Puppet Class 'settings' is already defined; cannot redefine at :
      2017-02-09 10:44:47,790 INFO  [qtp1584394027-68] [puppetserver] Puppet Compiled catalog for cacheissue.example.com in environment production in 0.05 seconds
      2017-02-09 10:44:47,790 INFO  [qtp1584394027-68] [puppetserver] Puppet Caching catalog for cacheissue.example.com
      2017-02-09 10:44:47,825 INFO  [qtp1584394027-68] [puppetserver] Puppet 'replace_catalog' command for cacheissue.example.com submitted to PuppetDB with UUID 29abc7d5-738a-4da2-a452-3f94a39491f2
      2017-02-09 10:44:48,717 INFO  [qtp1584394027-69] [puppetserver] Puppet 'store_report' command for cacheissue.example.com submitted to PuppetDB with UUID 12cfc770-3e6f-47ff-bf19-909687ca0a1e
      2017-02-09 10:45:32,811 INFO  [qtp1584394027-67] [puppetserver] Puppet Caching node for cacheissue.example.com
      2017-02-09 10:45:35,168 INFO  [qtp1584394027-64] [puppetserver] Puppet 'replace_facts' command for cacheissue.example.com submitted to PuppetDB with UUID 9b0fbc3f-4c9a-48b3-a9ec-46717c332139
      2017-02-09 10:45:35,351 INFO  [qtp1584394027-64] [puppetserver] Puppet Caching node for cacheissue.example.com
      2017-02-09 10:45:35,398 WARN  [qtp1584394027-64] [puppetserver] Puppet Class 'settings' is already defined; cannot redefine at :
      2017-02-09 10:45:35,434 INFO  [qtp1584394027-64] [puppetserver] Puppet Compiled catalog for cacheissue.example.com in environment production in 0.04 seconds
      2017-02-09 10:45:35,435 INFO  [qtp1584394027-64] [puppetserver] Puppet Caching catalog for cacheissue.example.com
      2017-02-09 10:45:35,464 INFO  [qtp1584394027-64] [puppetserver] Puppet 'replace_catalog' command for cacheissue.example.com submitted to PuppetDB with UUID a73829e8-750a-4d97-ae3a-b4e4f9a6e358
      2017-02-09 10:45:35,687 INFO  [qtp1584394027-65] [puppetserver] Puppet 'store_report' command for cacheissue.example.com submitted to PuppetDB with UUID 45b2d1e3-a077-4f43-8ce0-73f26873f18b
      2017-02-09 10:45:45,053 INFO  [qtp1584394027-69] [puppetserver] Puppet Caching node for cacheissue.example.com
      2017-02-09 10:45:47,384 INFO  [qtp1584394027-66] [puppetserver] Puppet 'replace_facts' command for cacheissue.example.com submitted to PuppetDB with UUID 6c60b22b-86df-4850-85c2-555d898833b1
      2017-02-09 10:45:47,567 INFO  [qtp1584394027-66] [puppetserver] Puppet Caching node for cacheissue.example.com
      2017-02-09 10:45:47,619 WARN  [qtp1584394027-66] [puppetserver] Puppet Class 'settings' is already defined; cannot redefine at :
      2017-02-09 10:45:47,660 INFO  [qtp1584394027-66] [puppetserver] Puppet Compiled catalog for cacheissue.example.com in environment production in 0.04 seconds
      2017-02-09 10:45:47,660 INFO  [qtp1584394027-66] [puppetserver] Puppet Caching catalog for cacheissue.example.com
      2017-02-09 10:45:47,684 INFO  [qtp1584394027-66] [puppetserver] Puppet 'replace_catalog' command for cacheissue.example.com submitted to PuppetDB with UUID 35a46c71-b074-421a-99b6-405d1a718f65
      2017-02-09 10:45:47,950 INFO  [qtp1584394027-67] [puppetserver] Puppet 'store_report' command for cacheissue.example.com submitted to PuppetDB with UUID f7c2cb6a-5968-4c97-93bf-85d530cbb5f9
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                andvgal Andrey Galkin
              • Votes:
                1 Vote for this issue
                Watchers:
                14 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Zendesk Support