Puppet

It seems to me that for some reason the results from the puppet_node_classifier are being cached and not regenerated under at least some circumstances.

Versions:

CentOS release 5.4 ruby 1.8.5 (2006-08-25) [x86_64-linux] puppet-server-0.25.1-0.2.rc2.el5 puppet-0.25.1-0.2.rc2.el5 fastthread (1.0.7) passenger (2.2.5) rack (1.0.1) rake (0.8.7)

Here’s my entire site.pp:

exec {"debugger":
    command => "/bin/echo 'application = $application'; /bin/echo 'env = $env'",
    logoutput => true
}

I restarted apache (to kick passenger and clear everything out). I then ran puppet on a client like this:

/usr/sbin/puppetd --server=puppetmaster.host --test --report --ignorecache --trace --verbose

Here’s the first puppet_node_classifier output:

---
parameters:
  application: "mysql"
  env: "sand-07"
  hostname: "01.mysql.sand-07.nym1"

And the results from the puppet run:

info: Caching catalog for 01.mysql.sand-07.nym1
info: Applying configuration version '1258609070'
notice: //Exec[debugger]/returns: application = mysql
notice: //Exec[debugger]/returns: env = sand-07
notice: //Exec[debugger]/returns: hostname = 01.mysql.sand-07.nym1
notice: //Exec[debugger]/returns: executed successfully
notice: Finished catalog run in 0.39 seconds

Looks good so far. But here’s the next puppet_node_classifier:

---
parameters:
  application: "api"
  env: "sand-07"
  hostname: "03.api.sand-07.nym1"

And its corresponding puppet run:

info: Caching catalog for 03.api.sand-07.nym1
info: Applying configuration version '1258609070'
notice: //Exec[debugger]/returns: application = mysql
notice: //Exec[debugger]/returns: env = sand-07
notice: //Exec[debugger]/returns: hostname = 01.mysql.sand-07.nym1
notice: //Exec[debugger]/returns: executed successfully
notice: Finished catalog run in 0.41 seconds

Here is the debug output from the puppetmaster (generated by adding ARG << “—debug” to config.ru):

For the first run:

 (mount[files]) allowing * access
 Starting Puppet server version 0.25.1
 (access[^/catalog/([^/]+)$]) allowing 'method' find
 (access[^/catalog/([^/]+)$]) allowing * access
 (access[/certificate_revocation_list/ca]) allowing 'method' find
 (access[/certificate_revocation_list/ca]) allowing * access
 (access[/report]) allowing 'method' save
 (access[/report]) allowing * access
 (access[/file]) allowing * access
 (access[/certificate/ca]) adding authentication no
 (access[/certificate/ca]) allowing 'method' find
 (access[/certificate/ca]) allowing * access
 (access[/certificate/]) adding authentication no
 (access[/certificate/]) allowing 'method' find
 (access[/certificate/]) allowing * access
 (access[/certificate_request]) adding authentication no
 (access[/certificate_request]) allowing 'method' find
 (access[/certificate_request]) allowing 'method' save
 (access[/certificate_request]) allowing * access
 (access[/]) adding authentication any
 Expiring the node cache of 01.mysql.sand-07.nym1
 Not using expired node for 01.mysql.sand-07.nym1 from cache; expired at Thu Nov 19 05:49:35 +0000 2009
 Caching node for 01.mysql.sand-07.nym1
 Compiled catalog for 01.mysql.sand-07.nym1 in 0.01 seconds

For the second (bad) run all I get is this, which shows the expiration of the node cache for the proper node but then compiling the catalog for the wrong node:

 Expiring the node cache of 03.api.sand-07.nym1
 Compiled catalog for 01.mysql.sand-07.nym1 in 0.00 seconds

It seems that the results from the puppet_node_classifier are cached from the first puppet run, and used from then on.

When I switched back to the webrick, this problem went away.

Please let me know how I can help debug this issue, it was a PITA to track down, and I’m not sure if I’ve provided all the information that could prove useful.