Jira (FACT-2996) Performance regression gathering networking facts in facter 4.x

28 views
Skip to first unread message

André Keller

unread,
Mar 24, 2021, 4:37:02 PM3/24/21
to puppe...@googlegroups.com
André Keller created an issue
 
Facter / Bug FACT-2996
Performance regression gathering networking facts in facter 4.x
Issue Type: Bug Bug
Affects Versions: FACT 4.0.52
Assignee: Unassigned
Components: Facter 4
Created: 2021/03/24 1:36 PM
Priority: Normal Normal
Reporter: André Keller

Facter version: 4.0.52
OS Ubuntu Linux 20.04

For gathering the networking fact, facter reads in the whole routing table (ip route show, ip -6 route show).

In facter 3 this happended once, in facter 4.x this happens once for every interface.

For router deployments, this makes a huge difference, as these both have potentially a huge routing table (a router with a BGP full table can easily have over 1 million routes) and 20 interfaces.

Add Comment Add Comment
 
This message was sent by Atlassian Jira (v8.5.2#805002-sha1:a66f935)
Atlassian logo

Mihai Buzgau (Jira)

unread,
Mar 25, 2021, 2:58:03 AM3/25/21
to puppe...@googlegroups.com

Mihai Buzgau (Jira)

unread,
Mar 25, 2021, 4:24:03 AM3/25/21
to puppe...@googlegroups.com

Mihai Buzgau (Jira)

unread,
Mar 25, 2021, 4:25:03 AM3/25/21
to puppe...@googlegroups.com

Mihai Buzgau (Jira)

unread,
Mar 25, 2021, 4:25:03 AM3/25/21
to puppe...@googlegroups.com

Gabriel Nagy (Jira)

unread,
Mar 25, 2021, 9:41:03 AM3/25/21
to puppe...@googlegroups.com

Gabriel Nagy (Jira)

unread,
Mar 26, 2021, 6:12:03 AM3/26/21
to puppe...@googlegroups.com
Gabriel Nagy commented on Bug FACT-2996
 
Re: Performance regression gathering networking facts in facter 4.x

Hi André Keller,

This shouldn't happen normally. I have 9 interfaces and in my case the routing table is read twice (there is room for improvement here to only read it once).

It would help if you can provide us some debug logs with the affected Facter runs (such as facter networking --debug).

André Keller

unread,
Mar 26, 2021, 11:04:04 AM3/26/21
to puppe...@googlegroups.com

Hi Gabriel,

Is there a way I can share the debug log with you, without having to share it publicly here?

Having a closer look at the debug log it seems that it does not do it once per interface, but once per fact.

f.e.

[2021-03-26 15:59:16.664573 ] DEBUG Facter::Resolvers::Linux::Networking - Could not resolve dhcp, got undefined method `each' for nil:NilClass
[2021-03-26 15:59:43.926525 ] DEBUG Facter::Resolvers::Linux::Networking - Could not resolve netmask6, got undefined method `each' for nil:NilClass
[2021-03-26 16:00:11.381382 ] DEBUG Facter::Resolvers::Linux::Networking - Could not resolve network6, got undefined method `each' for nil:NilClass
[2021-03-26 16:00:38.451925 ] DEBUG Facter::Resolvers::Linux::Networking - Could not resolve ip, got undefined method `each' for nil:NilClass
...

After each of those occurances it goes over the whole interfaces again and at the end, it will do ip route show/ip -6 route show.

The debug log does not say what it is actually looking for in the routing table though. What I could imagine is, that it is searching for a default route and fails because there isn't any on this system.

I'm happy to provide the debug log, but I'd rather not sure it publicly here.

Regards
André

Gabriel Nagy (Jira)

unread,
Mar 26, 2021, 11:25:03 AM3/26/21
to puppe...@googlegroups.com
Gabriel Nagy commented on Bug FACT-2996

 What I could imagine is, that it is searching for a default route and fails because there isn't any on this system.

Hmm, that undefined method `each' for nil:NilClass error could be what you are saying.

You can email me the logs at gabriel.nagy [at] puppet.com. Just to be on the safe side, could you also provide logs for a Facter 3 debug run, and the outputs of ip route show and ip -6 route show (if applicable). I'm assuming ip route get default doesn't return anything on your system?

 

Thanks

Josh Cooper (Jira)

unread,
Mar 30, 2021, 12:04:03 PM3/30/21
to puppe...@googlegroups.com

Mihai Buzgau (Jira)

unread,
Mar 31, 2021, 5:31:04 AM3/31/21
to puppe...@googlegroups.com
Mihai Buzgau updated an issue
Change By: Mihai Buzgau
Sprint: NW - 2021-03-31 , NW - 2021-04-14

Ciprian Badescu (Jira)

unread,
Apr 6, 2021, 8:36:04 AM4/6/21
to puppe...@googlegroups.com
Ciprian Badescu commented on Bug FACT-2996
 
Re: Performance regression gathering networking facts in facter 4.x

André Keller, Could you temporarily do the bellow change and provide us a `got undefined method `each' for nil:NilClass` message containing the full backtrace:

 

diff --git a/lib/facter/resolvers/base_resolver.rb b/lib/facter/resolvers/base_resolver.rb
index a9d0cfd8c..6841f0ec3 100644
--- a/lib/facter/resolvers/base_resolver.rb
+++ b/lib/facter/resolvers/base_resolver.rb
@@ -28,10 +28,10 @@ module Facter
           cache_nil_for_unresolved_facts(fact_name)
         end
       rescue NoMethodError => e
-        log.debug("Could not resolve #{fact_name}, got #{e}")
+        log.debug("Could not resolve #{fact_name}, got #{e} at #{e.backtrace}")
         @fact_list[fact_name] = nil
       rescue LoadError, NameError => e
-        log.debug("resolving fact #{fact_name}, but #{e}")
+        log.debug("resolving fact #{fact_name}, but got #{e} at #{e.backtrace}")
         @fact_list[fact_name] = nil
       end

 

 

This message was sent by Atlassian Jira (v8.13.2#813002-sha1:c495a97)
Atlassian logo

André Keller

unread,
Apr 7, 2021, 5:02:03 AM4/7/21
to puppe...@googlegroups.com

Hi Gabriel Nagy & Ciprian Badescu

sorry I somehow did not get notified about your last comments. I'll gather the logs and send them to Gabrial asap.

I'm assuming ip route get default doesn't return anything on your system?

Yes, that assumption is correct.

André Keller

unread,
Apr 7, 2021, 1:31:03 PM4/7/21
to puppe...@googlegroups.com

Hi Ciprian Badescu,

as requested the log line with the full backtrace

[2021-04-07 18:49:53.150115 ] DEBUG Facter::Resolvers::Linux::Networking - Could not resolve ip, got undefined method `each' for nil:NilClass at ["/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/util/resolvers/networking/networking.rb:91:in `expand_primary_interface'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/util/resolvers/networking/networking.rb:39:in `expand_main_bindings'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/resolvers/linux/networking.rb:22:in `retrieve_network_info'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/resolvers/linux/networking.rb:13:in `block in post_resolve'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/resolvers/linux/networking.rb:13:in `fetch'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/resolvers/linux/networking.rb:13:in `post_resolve'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/resolvers/base_resolver.rb:26:in `block in resolve'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/resolvers/base_resolver.rb:24:in `synchronize'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/resolvers/base_resolver.rb:24:in `resolve'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/facts/linux/networking/ip.rb:11:in `call_the_resolver'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/fact/internal/core_fact.rb:16:in `block in create'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/benchmarking/timer.rb:18:in `measure'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/fact/internal/core_fact.rb:15:in `create'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/fact/internal/internal_fact_manager.rb:47:in `block in resolve_sequentially'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/fact/internal/internal_fact_manager.rb:44:in `each'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/fact/internal/internal_fact_manager.rb:44:in `resolve_sequentially'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/fact/internal/internal_fact_manager.rb:12:in `resolve_facts'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/core/fact_manager.rb:24:in `resolve_facts'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter.rb:507:in `resolve_facts_for_user_query'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter.rb:436:in `to_user_output'", "/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/facter/framework/cli/cli.rb:114:in `query'", "/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/thor-1.0.1/lib/thor/command.rb:27:in `run'", "/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/thor-1.0.1/lib/thor/invocation.rb:127:in `invoke_command'", "/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/thor-1.0.1/lib/thor.rb:392:in `dispatch'", "/opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/thor-1.0.1/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>'"]

All backtraces can be found in the logs I sent to Gabriel Nagy a few minutes ago.

Ciprian Badescu (Jira)

unread,
Apr 8, 2021, 8:36:04 AM4/8/21
to puppe...@googlegroups.com

André Keller,

Thank you for the logs.

Based on them we found an issue in facter code, the fix was merged and should be part of the next nightly build and next official release.

Ciprian Badescu (Jira)

unread,
Apr 9, 2021, 2:38:02 AM4/9/21
to puppe...@googlegroups.com
Ciprian Badescu updated an issue
 
Change By: Ciprian Badescu
Release Notes: Bug Fix
Release Notes Summary: fix primary interface detection when default route forwards to blackhole

Claire Cadman (Jira)

unread,
Apr 13, 2021, 9:22:01 AM4/13/21
to puppe...@googlegroups.com
Reply all
Reply to author
Forward
0 new messages