The Puppet Labs Issue Tracker has Moved: https://tickets.puppetlabs.com
https://tickets.puppetlabs.com
. See the following page for information on filing tickets with JIRA:
Bug #22944
External facts are evaluated many times
Status: | Closed | Start date: | ||
---|---|---|---|---|
Priority: | Normal | Due date: | ||
Assignee: | - | % Done: | 0% | |
Category: | - | |||
Target version: | 1.7.4 | |||
Keywords: | Affected Facter version: | 1.7.3 | ||
Branch: | https://github.com/puppetlabs/facter/pull/570 | |||
We've Moved!Ticket tracking is now hosted in JIRA: https://tickets.puppetlabs.com This ticket is now tracked at: https://tickets.puppetlabs.com/browse/FACT-90 |
Description
Reproduction
- Drop script /etc/facter/facts.d/test.sh:
#!/bin/bash echo "SCRIPT CALLED" >&2 echo "test=value"
- Make script executeable
chmod +x /etc/facter/facts.d/test.sh
- Call ‘facter’, the following output is shown:
root@puppet:~# facter SCRIPT CALLED SCRIPT CALLED SCRIPT CALLED SCRIPT CALLED SCRIPT CALLED SCRIPT CALLED ... Regular facter output ...
I don’t see a reason why the script is called 6 times.
System information
- Ubuntu 12.04.3
- Facter 1.7.3
Related issues
History
#1
Updated by Josh Cooper over 2 years ago
- Description updated (diff)
- Status changed from Unreviewed to Accepted
#2
Updated by Josh Cooper over 2 years ago
- Subject changed from External fact is called 6 times to External facts are evaluated many times
- Target version set to 1.7.4
When you run facter
it will start by trying to load all facts, e.g. Facter::Util::Collection.load_all
. This walks facter’s search path, calling Kernel.load(file)
on each *.rb
file. When facter loads simple facts of the form:
Facter.add(:factname) do ... end
it registers a Facter::Util::Fact
object, and appends to its list of resolutions for that fact. In other words, we don’t actually try to evaluate the fact.
However, some facts resolve other facts outside of their add
block. For example, in ec2.rb
, we effectively do:
if !!(Facter.value(:macaddress) =~ %r{^[dD]0:0[dD]:}) Facter.add(:ec2) do ... end
The key issue here, is that we try to resolve the macaddress
fact before we’ve loaded the macaddress.rb
file and registered a Facter::Util::Fact
for it (because ec2.rb comes before macaddress.rb).
As a result, in Facter::Util::Collection.load(name)
, we call:
# Try to load the fact if necessary load(name) unless @facts[name]
where load(name)
causes all external facts to be evaluated:
def load(name) internal_loader.load(name) external_loader.load(self) # <---- HERE
But the fun doesn’t stop there. The :macaddress
fact has multiple resolutions, some confined by :osfamily
, others :operatingsystem
, each of which triggers all external facts to be evaluated. And actually :osfamily
depends on :operatingsystem
, so that adds another round of evaluating external facts.
The same issue also occurs when evaluating blockdevices.rb
as that depends on the :kernel
fact:
if Facter.value(:kernel) == 'Linux' ... Facter.add(:blockdevices) do
In the short-term, we should ensure we only load external facts once.
#3
Updated by Glenn Poston over 2 years ago
I think that the title of this ticket undermines it’s serverity, so I just wanted to add some research that I did.
I have an external fact (script) that takes 5s to evaluate. This causes my puppet runs to take 2x longer than they do without the fact evaluation. This doubles our run time. We use puppet to provision new instances for auto-scaling purposes, so puppet run times are critical for us. Here’s some data:
I was curious how much of an effect the long running external fact was effecting the timing, so I updated the external fact script to simply echo the content (instead of fetching it from s3). The facts it produced were the same as if it had fetched the facts from S3.
I then introduced a ‘sleep x’ before the echo statement in the script. Now we see some compounding delays. I think this adds a bit of support to the theory that puppet is unnecessarily re-evaluating facts, but it appears that facter may have some compounding delays as well.
Bottom Line:
When the script resolves instantaneously (echo statment only) script takes .004s facter takes .754s puppet takes 1m
When the script takes 1s (sleep 1, then echo) script takes 1s facter takes 6s puppet takes 1m12s
When the script takes 5s (sleep 5, then echo) script takes 5s facter takes 30s puppet takes 2m38s
#4
Updated by Josh Cooper over 2 years ago
Puppet also runs facter twice, which is why you’re seeing 6s facter run causing 1m12s puppet runs.
#5
Updated by Josh Cooper over 2 years ago
- Status changed from Accepted to In Topic Branch Pending Review
- Branch set to https://github.com/puppetlabs/facter/pull/570
#6
Updated by Ethan Brown over 2 years ago
- Status changed from In Topic Branch Pending Review to Merged - Pending Release
- Merged to stable in e0bdf2873c8ade9d7a06878d66e6bca902417515
- Merged to master in 20b0ee56b1c35c9ca75b98c58d66c93ec61834fc
#7
Updated by Melissa Stone over 2 years ago
- Status changed from Merged - Pending Release to Closed
Release in Facter 1.7.4-rc1
#8
Updated by Charlie Sharpsteen over 2 years ago
Redmine Issue #22944 has been migrated to JIRA: