Puppet: System Administration Automated

Support

Ticket #1147 (closed defect: fixed)

Opened 10 months ago

Last modified 9 months ago

facts gets unset

Reported by: emerose Assigned to: community
Priority: high Milestone: 0.24.4
Component: server Version: 0.24.3
Severity: normal Keywords:
Cc: marthag@mit.edu Triage Stage: Accepted
Attached Patches: None Complexity: Unknown

Description

I have a manifest like this: 

class apt {
  notice("lsbdistcodename is ${lsbdistcodename}.")
#...
  case "${lsbdistid}" {
    "Ubuntu": {
      package { "ubuntu-keyring": ensure => latest }
    }
  }

  file { "/etc/apt/sources.list":
    content => template("apt/${lsbdistcodename}-sources.list.erb"),
    tag => preboot,
  }
#...
}

When I include that code in a remote node, the puppetmaster reports: 

notice: Scope(Class[apt]): lsbdistcodename is .
debug: No true answers and no default
debug: Scope(Class[apt]): Retrieving template apt/-sources.list.erb
/usr/lib/ruby/1.8/puppet/parser/templatewrapper.rb:13:in `initialize'
/usr/lib/ruby/1.8/puppet/parser/functions.rb:215:in `new'
/usr/lib/ruby/1.8/puppet/parser/functions.rb:215:in `function_template'
/usr/lib/ruby/1.8/puppet/parser/functions.rb:211:in `collect'
/usr/lib/ruby/1.8/puppet/parser/functions.rb:211:in `function_template'
/usr/lib/ruby/1.8/puppet/parser/ast/function.rb:14:in `send'
/usr/lib/ruby/1.8/puppet/parser/ast/function.rb:14:in `evaluate'
/usr/lib/ruby/1.8/puppet/parser/ast.rb:54:in `safeevaluate'
/usr/lib/ruby/1.8/puppet/parser/ast/resourceparam.rb:16:in `evaluate'
/usr/lib/ruby/1.8/puppet/parser/ast.rb:54:in `safeevaluate'
/usr/lib/ruby/1.8/puppet/parser/ast/resource.rb:15:in `evaluate'
/usr/lib/ruby/1.8/erb.rb:739:in `collect'
/usr/lib/ruby/1.8/puppet/parser/ast/branch.rb:16:in `each'
/usr/lib/ruby/1.8/puppet/parser/ast/branch.rb:15:in `each'
/usr/lib/ruby/1.8/puppet/parser/ast/resource.rb:14:in `collect'
/usr/lib/ruby/1.8/puppet/parser/ast/resource.rb:14:in `evaluate'
/usr/lib/ruby/1.8/puppet/parser/ast.rb:54:in `safeevaluate'
/usr/lib/ruby/1.8/puppet/parser/ast/astarray.rb:35:in `evaluate'
/usr/lib/ruby/1.8/puppet/parser/ast/astarray.rb:34:in `collect'
/usr/lib/ruby/1.8/puppet/parser/ast/astarray.rb:34:in `evaluate'
/usr/lib/ruby/1.8/puppet/parser/ast.rb:54:in `safeevaluate'
/usr/lib/ruby/1.8/puppet/parser/ast/hostclass.rb:74:in `evaluate_code'
/usr/lib/ruby/1.8/puppet/parser/resource.rb:61:in `evaluate'
/usr/lib/ruby/1.8/puppet/parser/compiler.rb:145:in `evaluate_classes'
/usr/lib/ruby/1.8/puppet/parser/compiler.rb:136:in `each'
/usr/lib/ruby/1.8/puppet/parser/compiler.rb:136:in `evaluate_classes'
/usr/lib/ruby/1.8/puppet/parser/functions.rb:114:in `function_include'
/usr/lib/ruby/1.8/puppet/parser/ast/function.rb:14:in `send'
/usr/lib/ruby/1.8/puppet/parser/ast/function.rb:14:in `evaluate'
/usr/lib/ruby/1.8/puppet/parser/ast.rb:54:in `safeevaluate'
/usr/lib/ruby/1.8/puppet/parser/ast/astarray.rb:35:in `evaluate'
/usr/lib/ruby/1.8/puppet/parser/ast/astarray.rb:34:in `collect'
/usr/lib/ruby/1.8/puppet/parser/ast/astarray.rb:34:in `evaluate'
/usr/lib/ruby/1.8/puppet/parser/ast.rb:54:in `safeevaluate'
/usr/lib/ruby/1.8/puppet/parser/ast/hostclass.rb:74:in `evaluate_code'
/usr/lib/ruby/1.8/puppet/parser/ast/hostclass.rb:51:in `evaluate_code'
/usr/lib/ruby/1.8/puppet/parser/resource.rb:61:in `evaluate'
/usr/lib/ruby/1.8/puppet/parser/compiler.rb:238:in `evaluate_ast_node'
/usr/lib/ruby/1.8/puppet/parser/compiler.rb:88:in `compile'
/usr/lib/ruby/1.8/puppet/parser/interpreter.rb:29:in `compile'
/usr/lib/ruby/1.8/puppet/network/handler/configuration.rb:107:in `compile'
/usr/lib/ruby/1.8/puppet/util.rb:217:in `benchmark'
/usr/lib/ruby/1.8/puppet/network/handler/configuration.rb:105:in `compile'
/usr/lib/ruby/1.8/puppet/network/handler/configuration.rb:40:in `configuration'
/usr/lib/ruby/1.8/puppet/network/handler/master.rb:69:in `getconfig'
/usr/lib/ruby/1.8/puppet/util.rb:212:in `benchmark'
/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/usr/lib/ruby/1.8/puppet/util.rb:211:in `benchmark'
/usr/lib/ruby/1.8/puppet/network/handler/master.rb:68:in `getconfig'
/usr/share/rails/activerecord/lib/../../activesupport/lib/active_support/inflector.rb:250:in `to_proc'
/usr/lib/ruby/1.8/puppet/network/xmlrpc/processor.rb:52:in `call'
/usr/lib/ruby/1.8/puppet/network/xmlrpc/processor.rb:52:in `protect_service'
/usr/lib/ruby/1.8/puppet/network/xmlrpc/processor.rb:85:in `setup_processor'
/usr/lib/ruby/1.8/xmlrpc/server.rb:336:in `call'
/usr/lib/ruby/1.8/xmlrpc/server.rb:336:in `dispatch'
/usr/lib/ruby/1.8/xmlrpc/server.rb:323:in `each'
/usr/lib/ruby/1.8/xmlrpc/server.rb:323:in `dispatch'
/usr/lib/ruby/1.8/xmlrpc/server.rb:366:in `call_method'
/usr/lib/ruby/1.8/xmlrpc/server.rb:378:in `handle'
/usr/lib/ruby/1.8/puppet/network/xmlrpc/processor.rb:44:in `process'
/usr/lib/ruby/1.8/puppet/network/xmlrpc/webrick_servlet.rb:68:in `service'
/usr/lib/ruby/1.8/webrick/httpserver.rb:104:in `service'
/usr/lib/ruby/1.8/webrick/httpserver.rb:65:in `run'
/usr/lib/ruby/1.8/webrick/server.rb:173:in `start_thread'
/usr/lib/ruby/1.8/webrick/server.rb:162:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:162:in `start_thread'
/usr/lib/ruby/1.8/webrick/server.rb:95:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:92:in `each'
/usr/lib/ruby/1.8/webrick/server.rb:92:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:23:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:82:in `start'
/usr/lib/ruby/1.8/puppet.rb:336:in `start'
/usr/lib/ruby/1.8/puppet.rb:187:in `newthread'
/usr/lib/ruby/1.8/puppet.rb:186:in `initialize'
/usr/lib/ruby/1.8/puppet.rb:186:in `new'
/usr/lib/ruby/1.8/puppet.rb:186:in `newthread'
/usr/lib/ruby/1.8/puppet.rb:334:in `start'
/usr/lib/ruby/1.8/puppet.rb:333:in `each'
/usr/lib/ruby/1.8/puppet.rb:333:in `start'
/usr/sbin/puppetmasterd:281
/usr/lib/ruby/1.8/puppet/parser/interpreter.rb:32:in `compile'
/usr/lib/ruby/1.8/puppet/network/handler/configuration.rb:107:in `compile'
/usr/lib/ruby/1.8/puppet/util.rb:217:in `benchmark'
/usr/lib/ruby/1.8/puppet/network/handler/configuration.rb:105:in `compile'
/usr/lib/ruby/1.8/puppet/network/handler/configuration.rb:40:in `configuration'
/usr/lib/ruby/1.8/puppet/network/handler/master.rb:69:in `getconfig'
/usr/lib/ruby/1.8/puppet/util.rb:212:in `benchmark'
/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/usr/lib/ruby/1.8/puppet/util.rb:211:in `benchmark'
/usr/lib/ruby/1.8/puppet/network/handler/master.rb:68:in `getconfig'
/usr/share/rails/activerecord/lib/../../activesupport/lib/active_support/inflector.rb:250:in `to_proc'
/usr/lib/ruby/1.8/puppet/network/xmlrpc/processor.rb:52:in `call'
/usr/lib/ruby/1.8/puppet/network/xmlrpc/processor.rb:52:in `protect_service'
/usr/lib/ruby/1.8/puppet/network/xmlrpc/processor.rb:85:in `setup_processor'
/usr/lib/ruby/1.8/xmlrpc/server.rb:336:in `call'
/usr/lib/ruby/1.8/xmlrpc/server.rb:336:in `dispatch'
/usr/lib/ruby/1.8/xmlrpc/server.rb:323:in `each'
/usr/lib/ruby/1.8/xmlrpc/server.rb:323:in `dispatch'
/usr/lib/ruby/1.8/xmlrpc/server.rb:366:in `call_method'
/usr/lib/ruby/1.8/xmlrpc/server.rb:378:in `handle'
/usr/lib/ruby/1.8/puppet/network/xmlrpc/processor.rb:44:in `process'
/usr/lib/ruby/1.8/puppet/network/xmlrpc/webrick_servlet.rb:68:in `service'
/usr/lib/ruby/1.8/webrick/httpserver.rb:104:in `service'
/usr/lib/ruby/1.8/webrick/httpserver.rb:65:in `run'
/usr/lib/ruby/1.8/webrick/server.rb:173:in `start_thread'
/usr/lib/ruby/1.8/webrick/server.rb:162:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:162:in `start_thread'
/usr/lib/ruby/1.8/webrick/server.rb:95:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:92:in `each'
/usr/lib/ruby/1.8/webrick/server.rb:92:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:23:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:82:in `start'
/usr/lib/ruby/1.8/puppet.rb:336:in `start'
/usr/lib/ruby/1.8/puppet.rb:187:in `newthread'
/usr/lib/ruby/1.8/puppet.rb:186:in `initialize'
/usr/lib/ruby/1.8/puppet.rb:186:in `new'
/usr/lib/ruby/1.8/puppet.rb:186:in `newthread'
/usr/lib/ruby/1.8/puppet.rb:334:in `start'
/usr/lib/ruby/1.8/puppet.rb:333:in `each'
/usr/lib/ruby/1.8/puppet.rb:333:in `start'
/usr/sbin/puppetmasterd:281
err: Could not find template apt/-sources.list.erb at /etc/puppet/modules/apt/manifests/init.pp:23 on node node.mycorp.com

Facter, run on that node, does know about the lsbdistcodename fact: 

$ facter | grep lsb
lsbdistcodename => gutsy
lsbdistdescription => Ubuntu 7.10
lsbdistid => Ubuntu
lsbdistrelease => 7.10

The fact is also set correctly in the :configuration section of state.yaml on the client, as well as in the yaml/facts/node.mycorp.com.yaml file on the server.

I've tried completely fresh installs on the server, including blowing away the full /var/lib/puppet dir and the mysql database, but to no success. The server version is 0.24.3, and the problem exhibits itself on nodes running version 0.24.1 and 0.24.3; all the servers are ubuntu gutsy, and the puppet installs are those from packages.debian.org.

Possibly relevant is the fact that I also got bit by #1137; see that ticket for the patch I used to get around that problem.

Attachments

1147-debug-messages.patch (2.0 kB) - added by ctrlaltdel on 03/27/08 09:50:14.

Change History

03/20/08 03:10:33 changed by emerose

Actually, it seems like something much weirder is going on -- if I change the top of that manifest to: 

  notice("lsbdistcodename is ${lsbdistcodename}.")
  notice("lsbdistid is ${lsbdistid}.")
  notice("ipaddress is ${ipaddress}.")
  notice("fqdn is ${fqdn}.")

the corresponding messages on the puppetmaster are: 

notice: Scope(Class[apt]): lsbdistcodename is .
notice: Scope(Class[apt]): lsbdistid is .
notice: Scope(Class[apt]): ipaddress is .
notice: Scope(Class[apt]): fqdn is .

From the trace, it looks like the apt module is the first to be loaded, so this is probably not specific to any particular fact....

03/20/08 03:16:55 changed by emerose

  • summary changed from lsbdistcodename gets unset to facts gets unset.

03/21/08 04:16:25 changed by emerose

So, adding the following code to puppet/indirector/node/plain.rb solves the problem. I'm not entirely sure why yet, though -- when I do, I'll provide tests and a patch.... 

    def version(name)
        Puppet::Node::Facts.version(name)
    end

03/21/08 04:21:35 changed by luke

  • stage changed from Unreviewed to Accepted.
  • milestone set to 0.24.4.

The problem here is that you somehow got a cached node with no facts, and once the cache was there, Puppet always used it.

This method basically says to consider the version of the node facts (which is just the timestamp of the yaml file) as the version of the node, which means that if the node's facts change, then the cached node will get discarded and a new one will get generated, using those new facts.

I'm guessing that the originally invalid node cache is the result of needing node information at a time when fact data wasn't available, such as during certificate signing or something similar.

This method fixes the bug, and it should be easy to copy the test from spec/unit/indirector/node/exec.rb.

03/21/08 05:27:38 changed by luke

  • status changed from new to closed.
  • resolution set to fixed.

Fixed in [4f400d4].

03/26/08 20:08:28 changed by luke

Marking #1159 as a duplicate.

03/27/08 09:49:50 changed by ctrlaltdel

Well, I'm still experiencing the same bug with 0.24.4 (commit [3a8053a]).

I added some debug messages (see 1147-debug-messages.patch).

  • Puppet::Node::Plain.version (coming from [4f400d4]) is not called
  • vers is nil when has_most_recent? is called 
notice: Starting Puppet server version 0.24.4
yaml fresh: true (1206606844.0 vs 0.0)
info: terminus: #<Puppet::Node::Plain:0xb73d28ec>, terminus_name: plain
info: Using cached node dole.wrk.lsn.camptocamp.com
yaml fresh: true (1206606844.0 vs 0.0)
info: terminus: #<Puppet::Node::Plain:0xb73d28ec>, terminus_name: plain
info: Using cached node dole.wrk.lsn.camptocamp.com
yaml fresh: true (1206606844.0 vs 0.0)
info: terminus: #<Puppet::Node::Plain:0xb73d28ec>, terminus_name: plain
info: Using cached node dole.wrk.lsn.camptocamp.com

03/27/08 09:50:14 changed by ctrlaltdel

  • attachment 1147-debug-messages.patch added.

03/27/08 15:37:42 changed by luke

  • status changed from closed to reopened.
  • resolution deleted.

03/27/08 15:37:53 changed by luke

  • priority changed from normal to high.

04/03/08 18:38:07 changed by marthag

  • cc set to marthag@mit.edu.

04/09/08 06:56:30 changed by luke

  • status changed from reopened to closed.
  • resolution set to fixed.

I'm pretty sure the problem that ctraltdel is experiencing is a mismatch between the node name and the fact name, because the facts don't use a canonical node name as they should (#1178).

At this point, I'm assuming that the only problem left is that ticket, so I'm closing this in favor of that one.