facter ignored and recalculates facts which should be cached if cache_groups contains spaces like 'desktop management interface'

[sharewax]

Describe the Bug

facter -d shows that "desktop management interface facts cache file expired, missing or is corrupt" even that it set to cache by settings.

/etc/puppetlabs/facter/facter.conf

facts : {
    blocklist : ["EC2","hypervisors"]
    ttls : [{"desktop management interface":"30 days"},{"virtualization":"30 days"},{"path":"30 days"},{"ssh":"30 days"},{"timezone":"30 days"},{"id":"30 days"},{"fips":"30 days"},{"augeas":"30 days"},{"Xen":"30 days"},{"EC2":"30 days"},{"GCE":"30 days"}]
}

facter -d dmi
[2024-05-07 09:29:00.081147 ] INFO Facter - executed with command line: -d dmi
[2024-05-07 09:29:00.081228 ] DEBUG Facter - Facter version: 4.5.1
[2024-05-07 09:29:00.081254 ] DEBUG Facter - blocking collection of EC2 hypervisors facts
[2024-05-07 09:29:00.081313 ] DEBUG Facter::ClassDiscoverer - There is no module named Centos
[2024-05-07 09:29:00.083404 ] DEBUG Facter::FactManager - Resolving facts sequentially
[2024-05-07 09:29:00.086731 ] DEBUG Facter::FactLoader - Loading all internal facts
[2024-05-07 09:29:00.098411 ] DEBUG Facter::FactLoader - Loading custom facts
[2024-05-07 09:29:00.099477 ] DEBUG Facter::FactLoader - Loading external facts
[2024-05-07 09:29:00.155169 ] DEBUG Facter::QueryParser - List of resolvable facts: [#<Facter::SearchedFact:0x0000000002176428 @name="dmi.product.name", @fact_class=Facts::Linux::Dmi::Product::Name, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x0000000002176018 @name="dmi.product.serial_number", @fact_class=Facts::Linux::Dmi::Product::SerialNumber, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x0000000002175898 @name="dmi.product.uuid", @fact_class=Facts::Linux::Dmi::Product::Uuid, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x0000000002174ec0 @name="dmi.board.product", @fact_class=Facts::Linux::Dmi::Board::Product, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x0000000002174560 @name="dmi.board.serial_number", @fact_class=Facts::Linux::Dmi::Board::SerialNumber, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x00000000023f2f08 @name="dmi.board.asset_tag", @fact_class=Facts::Linux::Dmi::Board::AssetTag, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x00000000023f2a80 @name="dmi.board.manufacturer", @fact_class=Facts::Linux::Dmi::Board::Manufacturer, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x00000000023f1c20 @name="dmi.chassis.asset_tag", @fact_class=Facts::Linux::Dmi::Chassis::AssetTag, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x00000000023f1180 @name="dmi.chassis.type", @fact_class=Facts::Linux::Dmi::Chassis::Type, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x00000000023e1ac8 @name="dmi.bios.version", @fact_class=Facts::Linux::Dmi::Bios::Version, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x00000000023e1050 @name="dmi.bios.vendor", @fact_class=Facts::Linux::Dmi::Bios::Vendor, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x00000000023e0830 @name="dmi.bios.release_date", @fact_class=Facts::Linux::Dmi::Bios::ReleaseDate, @user_query="dmi", @type=:core, @file=nil>, #<Facter::SearchedFact:0x00000000023e0218 @name="dmi.manufacturer", @fact_class=Facts::Linux::Dmi::Manufacturer, @user_query="dmi", @type=:core, @file=nil>]
[2024-05-07 09:29:00.155686 ] DEBUG Facter::CacheManager - desktop management interface facts cache file expired, missing or is corrupt
[2024-05-07 09:29:00.155743 ] DEBUG Facter::Util::FileHelper - File at: /opt/puppetlabs/facter/cache/cached_facts/desktop management interface is not accessible.
[2024-05-07 09:29:00.156122 ] DEBUG Facter::CacheManager - desktop management interface facts cache file expired, missing or is corrupt
[2024-05-07 09:29:00.156472 ] DEBUG Facter::CacheManager - desktop management interface facts cache file expired, missing or is corrupt
[2024-05-07 09:29:00.156901 ] DEBUG Facter::CacheManager - desktop management interface facts cache file expired, missing or is corrupt
[2024-05-07 09:29:00.157371 ] DEBUG Facter::CacheManager - desktop management interface facts cache file expired, missing or is corrupt
...

cat /opt/puppetlabs/facter/cache/cached_facts/desktop\ management\ interface
{
  "bios_version": "2.19.0",
  "bios_release_date": "12/12/2023",
  "serialnumber": "F5SX9Q2",
  "uuid": "4C4C4544-0035-5310-8058-C6C04F395132",
  "boardproductname": "02C2CP",
  "boardserialnumber": ".F5SX9Q2.CNIVC0082Q0694.",
  "chassistype": "Rack Mount Chassis",
  "dmi.bios.version": "2.19.0",
  "dmi.bios.release_date": "12/12/2023",
  "dmi.product.serial_number": "F5SX9Q2",
  "dmi.product.uuid": "4C4C4544-0035-5310-8058-C6C04F395132",
  "dmi.board.product": "02C2CP",
  "dmi.board.serial_number": ".F5SX9Q2.CNIVC0082Q0694.",
  "dmi.chassis.type": "Rack Mount Chassis",
  "cache_format_version": 1
}

Expected Behavior

dmi data should be cached properly and not rerun every run puppet/facter.

Steps to Reproduce

Steps to reproduce the behavior:
facter -d dmi

Environment

• Version [4.5.1], puppet version 7.27
• Platform [CentOS7, Oracle Linux 9]

Additional Context

ls -al /opt/puppetlabs/facter/cache/cached_facts/

-rw-r--r--. 1 root root   90 May  7 00:07 augeas
-rw-r--r--. 1 root root  608 May  7 10:07 desktop management interface
-rw-r--r--. 1 root root   56 May  7 00:07 fips
-rw-r--r--. 1 root root  192 May  7 00:07 id
-rw-r--r--. 1 root root  100 May  7 00:07 path
-rw-r--r--. 1 root root 3062 Nov  8 22:25 processor
-rw-r--r--. 1 root root 2509 May  7 00:07 ssh
-rw-r--r--. 1 root root   52 May  7 00:07 timezone
-rw-r--r--. 1 root root   79 May  7 10:07 virtualization

files virtualization and desktop management interface shouldn't changed every puppet run because it should be cached and renewed only one time in 30 days as it set in facter config.

Internal tracking ticket https://perforce.atlassian.net/browse/FACT-3209

[joshcooper]

The problem is because if facter attempts to resolve a fact like dmi.board.asset_tag, which could not be resolve previously, and so isn't in the cache, then facter deletes the cache(!) see

facter/lib/facter/framework/core/cache_manager.rb

Line 98 in 1d46692

delete_cache(fact_group) unless data.keys.grep(/#{searched_fact.name}/).any?

But that means the cache is effectively disabled if there happens to be one fact in the group that can never be resolved...

I think the behavior was introduced in 9b87395#diff-f0f24801215b37a96e44c08052ac98123c0b54de2e18c5a81836811934c438bbR103 to detect if a cached fact is missing after upgrading from puppet 3 to 4.

We also don't log anything if we fail to load the cache:

facter/lib/facter/framework/core/cache_manager.rb

Lines 202 to 203 in 1d46692

	rescue JSON::ParserError
	delete_cache(group_name)

[sharewax]

It seems that before removing in this case it's better to check - probably that string cache_format_version is present in cache file to detect that this cache is already fresh version.

[joshcooper]

[2024-09-26 18:06:31.397041 ] DEBUG Facter::CacheManager - loading cached values for dmi.board.serial_number facts
[2024-09-26 18:06:31.397744 ] DEBUG Facter::CacheManager - loading cached values for dmi.board.asset_tag facts
["/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/cache_manager.rb:219:in `check_ttls?'",
 "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/cache_manager.rb:73:in `resolve_fact'",
 "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/cache_manager.rb:17:in `block in resolve_facts'",
 "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/cache_manager.rb:16:in `delete_if'",
 "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/cache_manager.rb:16:in `resolve_facts'",
 "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/fact_manager.rb:22:in `resolve_facts'",
 "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter.rb:530:in `resolve_facts_for_user_query'",
 "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter.rb:461:in `to_user_output'",
 "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/cli/cli.rb:124:in `query'",
 "/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/thor-1.2.2/lib/thor/command.rb:27:in `run'",
 "/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/thor-1.2.2/lib/thor/invocation.rb:127:in `invoke_command'",
 "/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/thor-1.2.2/lib/thor.rb:392:in `dispatch'",
 "/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/thor-1.2.2/lib/thor/base.rb:485:in `start'",
 "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/cli/cli_launcher.rb:23:in `start'",
 "/opt/puppetlabs/puppet/bin/facter:10:in `<main>'"]