Bug #9016: Fact import code consumes lot of memory - Foreman

Actions

Copy link

Bug #9016

closed

Fact import code consumes lot of memory

Added by Ohad Levy about 9 years ago. Updated almost 6 years ago.

Status:

Closed

Priority:

Normal

Assignee:

Lukas Zapletal

Category:

Importers

Target version:

1.14.0

Difficulty:

Triaged:

Bugzilla link:

1440825

Pull request:

https://github.com/theforeman/foreman/pull/3667, https://github.com/theforeman/foreman/pull/3896

Fixed in Releases:

Found in Releases:

Red Hat JIRA:

Description

This was initially reported on discovery process, but I located performance bottleneck in fact importing.

When importing a large set of hosts, the avg response time is high:

Completed 201 Created in 8403.7ms (Views: 3.6ms | ActiveRecord: 0.0ms)
Completed 201 Created in 3546.0ms (Views: 27.6ms | ActiveRecord: 0.0ms)
Completed 201 Created in 3260.2ms (Views: 3.4ms | ActiveRecord: 0.0ms)
Completed 201 Created in 5449.5ms (Views: 3.1ms | ActiveRecord: 0.0ms)
Completed 201 Created in 5356.3ms (Views: 3.5ms | ActiveRecord: 0.1ms)
Completed 201 Created in 8333.2ms (Views: 3.7ms | ActiveRecord: 0.1ms)
Completed 201 Created in 5271.3ms (Views: 3.2ms | ActiveRecord: 0.1ms)
Completed 201 Created in 8462.4ms (Views: 3.2ms | ActiveRecord: 0.1ms)
Completed 201 Created in 4223.7ms (Views: 3.2ms | ActiveRecord: 0.2ms)
Completed 201 Created in 8827.6ms (Views: 3.9ms | ActiveRecord: 0.1ms)
Completed 201 Created in 4510.4ms (Views: 3.1ms | ActiveRecord: 0.1ms)
Completed 201 Created in 4038.9ms (Views: 2.9ms | ActiveRecord: 0.1ms)
Completed 201 Created in 4075.4ms (Views: 3.2ms | ActiveRecord: 0.1ms)
Completed 201 Created in 4007.8ms (Views: 4.5ms | ActiveRecord: 0.2ms)
Completed 201 Created in 3886.1ms (Views: 3.6ms | ActiveRecord: 0.1ms)
Completed 201 Created in 4845.1ms (Views: 3.5ms | ActiveRecord: 0.2ms)
Completed 201 Created in 4626.0ms (Views: 3.6ms | ActiveRecord: 0.1ms)
Completed 201 Created in 4751.8ms (Views: 3.7ms | ActiveRecord: 0.1ms)

Observation, the O(n) depends on amount of facts reported. These are performance tests on production installation of Satellite 6.2 RC1 (roughly Foreman 1.11) with five concurrent CURL processes in loop registering discovery hosts (it calls facts import basically):

With 10 facts:

2016-07-21 13:06:20 [app] [I] Completed 201 Created in 386ms (Views: 2.0ms | ActiveRecord: 66.4ms)
2016-07-21 13:06:20 [app] [I] Completed 201 Created in 353ms (Views: 1.9ms | ActiveRecord: 68.8ms)
2016-07-21 13:06:21 [app] [I] Completed 201 Created in 360ms (Views: 2.1ms | ActiveRecord: 72.6ms)
2016-07-21 13:06:21 [app] [I] Completed 201 Created in 316ms (Views: 1.7ms | ActiveRecord: 58.7ms)
2016-07-21 13:06:21 [app] [I] Completed 201 Created in 366ms (Views: 2.0ms | ActiveRecord: 68.5ms)
2016-07-21 13:06:21 [app] [I] Completed 201 Created in 331ms (Views: 1.7ms | ActiveRecord: 59.6ms)
2016-07-21 13:06:22 [app] [I] Completed 201 Created in 322ms (Views: 1.7ms | ActiveRecord: 58.8ms)
2016-07-21 13:06:22 [app] [I] Completed 201 Created in 380ms (Views: 1.9ms | ActiveRecord: 85.0ms)
2016-07-21 13:06:22 [app] [I] Completed 201 Created in 337ms (Views: 2.2ms | ActiveRecord: 61.8ms)
2016-07-21 13:06:22 [app] [I] Completed 201 Created in 385ms (Views: 2.4ms | ActiveRecord: 77.8ms)
2016-07-21 13:06:22 [app] [I] Completed 201 Created in 442ms (Views: 1.7ms | ActiveRecord: 70.3ms)
2016-07-21 13:06:22 [app] [I] Completed 201 Created in 388ms (Views: 1.9ms | ActiveRecord: 86.2ms)
2016-07-21 13:06:23 [app] [I] Completed 201 Created in 349ms (Views: 2.1ms | ActiveRecord: 66.0ms)
2016-07-21 13:06:23 [app] [I] Completed 201 Created in 346ms (Views: 1.7ms | ActiveRecord: 74.3ms)
2016-07-21 13:06:23 [app] [I] Completed 201 Created in 364ms (Views: 1.8ms | ActiveRecord: 61.6ms)
2016-07-21 13:06:23 [app] [I] Completed 201 Created in 488ms (Views: 2.4ms | ActiveRecord: 80.6ms)
2016-07-21 13:06:24 [app] [I] Completed 201 Created in 485ms (Views: 2.7ms | ActiveRecord: 74.3ms)
2016-07-21 13:06:24 [app] [I] Completed 201 Created in 577ms (Views: 2.8ms | ActiveRecord: 76.6ms)

With 500 facts:

2016-07-21 13:09:29 [app] [I] Completed 201 Created in 1666ms (Views: 1.8ms | ActiveRecord: 376.8ms)
2016-07-21 13:09:30 [app] [I] Completed 201 Created in 1688ms (Views: 1.8ms | ActiveRecord: 380.2ms)
2016-07-21 13:09:31 [app] [I] Completed 201 Created in 1775ms (Views: 1.8ms | ActiveRecord: 387.7ms)
2016-07-21 13:09:32 [app] [I] Completed 201 Created in 1732ms (Views: 1.8ms | ActiveRecord: 436.5ms)
2016-07-21 13:09:33 [app] [I] Completed 201 Created in 1767ms (Views: 1.8ms | ActiveRecord: 410.1ms)
2016-07-21 13:09:34 [app] [I] Completed 201 Created in 1749ms (Views: 1.9ms | ActiveRecord: 404.3ms)
2016-07-21 13:09:34 [app] [I] Completed 201 Created in 1777ms (Views: 1.9ms | ActiveRecord: 416.1ms)
2016-07-21 13:09:35 [app] [I] Completed 201 Created in 1702ms (Views: 1.7ms | ActiveRecord: 398.9ms)
2016-07-21 13:09:36 [app] [I] Completed 201 Created in 1650ms (Views: 1.8ms | ActiveRecord: 358.3ms)
2016-07-21 13:09:37 [app] [I] Completed 201 Created in 1647ms (Views: 1.8ms | ActiveRecord: 330.7ms)
2016-07-21 13:09:38 [app] [I] Completed 201 Created in 1761ms (Views: 1.8ms | ActiveRecord: 404.6ms)
2016-07-21 13:09:39 [app] [I] Completed 201 Created in 1629ms (Views: 1.8ms | ActiveRecord: 347.6ms)
2016-07-21 13:09:40 [app] [I] Completed 201 Created in 1735ms (Views: 1.8ms | ActiveRecord: 420.6ms)
2016-07-21 13:09:40 [app] [I] Completed 201 Created in 1616ms (Views: 2.1ms | ActiveRecord: 329.6ms)
2016-07-21 13:09:41 [app] [I] Completed 201 Created in 1792ms (Views: 2.0ms | ActiveRecord: 418.4ms)
2016-07-21 13:09:42 [app] [I] Completed 201 Created in 1794ms (Views: 1.8ms | ActiveRecord: 454.0ms)
2016-07-21 13:09:43 [app] [I] Completed 201 Created in 1779ms (Views: 2.5ms | ActiveRecord: 424.4ms)
2016-07-21 13:09:44 [app] [I] Completed 201 Created in 1735ms (Views: 1.8ms | ActiveRecord: 411.7ms)
2016-07-21 13:09:45 [app] [I] Completed 201 Created in 1912ms (Views: 1.9ms | ActiveRecord: 461.2ms)
2016-07-21 13:09:46 [app] [I] Completed 201 Created in 1781ms (Views: 1.9ms | ActiveRecord: 463.5ms)
2016-07-21 13:09:47 [app] [I] Completed 201 Created in 1682ms (Views: 1.7ms | ActiveRecord: 377.2ms)
2016-07-21 13:09:47 [app] [I] Completed 201 Created in 1645ms (Views: 2.2ms | ActiveRecord: 336.1ms)
2016-07-21 13:09:49 [app] [I] Completed 201 Created in 1843ms (Views: 2.0ms | ActiveRecord: 435.9ms)
2016-07-21 13:09:49 [app] [I] Completed 201 Created in 1900ms (Views: 2.3ms | ActiveRecord: 470.4ms)
2016-07-21 13:09:51 [app] [I] Completed 201 Created in 1841ms (Views: 1.7ms | ActiveRecord: 406.0ms)
2016-07-21 13:09:51 [app] [I] Completed 201 Created in 1949ms (Views: 2.5ms | ActiveRecord: 443.3ms)
2016-07-21 13:09:52 [app] [I] Completed 201 Created in 1773ms (Views: 1.8ms | ActiveRecord: 453.9ms)

And with 1000 facts reported in each call:

2016-07-21 13:11:12 [app] [I] Completed 201 Created in 3104ms (Views: 1.8ms | ActiveRecord: 764.2ms)
2016-07-21 13:11:14 [app] [I] Completed 201 Created in 3133ms (Views: 1.9ms | ActiveRecord: 667.6ms)
2016-07-21 13:11:15 [app] [I] Completed 201 Created in 3113ms (Views: 2.0ms | ActiveRecord: 732.8ms)
2016-07-21 13:11:17 [app] [I] Completed 201 Created in 3139ms (Views: 1.8ms | ActiveRecord: 752.2ms)
2016-07-21 13:11:18 [app] [I] Completed 201 Created in 3015ms (Views: 2.2ms | ActiveRecord: 730.2ms)
2016-07-21 13:11:20 [app] [I] Completed 201 Created in 3139ms (Views: 1.9ms | ActiveRecord: 646.0ms)
2016-07-21 13:11:21 [app] [I] Completed 201 Created in 2877ms (Views: 1.8ms | ActiveRecord: 620.0ms)
2016-07-21 13:11:23 [app] [I] Completed 201 Created in 3011ms (Views: 2.4ms | ActiveRecord: 611.1ms)
2016-07-21 13:11:24 [app] [I] Completed 201 Created in 3007ms (Views: 1.8ms | ActiveRecord: 614.2ms)
2016-07-21 13:11:26 [app] [I] Completed 201 Created in 3163ms (Views: 1.9ms | ActiveRecord: 661.9ms)
2016-07-21 13:11:27 [app] [I] Completed 201 Created in 2923ms (Views: 1.8ms | ActiveRecord: 641.7ms)
2016-07-21 13:11:29 [app] [I] Completed 201 Created in 2982ms (Views: 2.1ms | ActiveRecord: 657.7ms)
2016-07-21 13:11:30 [app] [I] Completed 201 Created in 3018ms (Views: 1.8ms | ActiveRecord: 706.9ms)
2016-07-21 13:11:32 [app] [I] Completed 201 Created in 3212ms (Views: 1.8ms | ActiveRecord: 726.9ms)
2016-07-21 13:11:33 [app] [I] Completed 201 Created in 2931ms (Views: 2.1ms | ActiveRecord: 602.9ms)
2016-07-21 13:11:35 [app] [I] Completed 201 Created in 2991ms (Views: 2.5ms | ActiveRecord: 638.4ms)
2016-07-21 13:11:36 [app] [I] Completed 201 Created in 3016ms (Views: 1.8ms | ActiveRecord: 728.8ms)
2016-07-21 13:11:39 [app] [I] Completed 201 Created in 3170ms (Views: 1.7ms | ActiveRecord: 744.1ms)
2016-07-21 13:11:40 [app] [I] Completed 201 Created in 3312ms (Views: 1.9ms | ActiveRecord: 823.8ms)
2016-07-21 13:11:42 [app] [I] Completed 201 Created in 3198ms (Views: 1.7ms | ActiveRecord: 820.9ms)

Width of fact name or value does not matter, what's the bottleneck is our code that does fact importing. It does this in a loop over all facts merging them with database. We need to optimize that.

Related issues 4 (0 open — 4 closed)

Actions

Copy link

Updated by Lukas Zapletal about 8 years ago

Category set to Discovery plugin
Priority changed from Normal to High
Target version set to Discovery Plugin 6.0

Actions

Copy link

Updated by Lukas Zapletal almost 8 years ago

Subject changed from bulk discovery fact reporting should be async to Discovery fact reporting is slow

I'd rather investigate why this is slow than making it async.

Actions

Copy link

Updated by Lukas Zapletal over 7 years ago

Project changed from Discovery to Foreman
Subject changed from Discovery fact reporting is slow to Fact import code is O(n^2)
Description updated (diff)
Category deleted (~~Discovery plugin~~)
Priority changed from High to Normal
Target version deleted (~~Discovery Plugin 6.0~~)

Switching from Discovery to Core.

Actions

Copy link

Updated by Lukas Zapletal over 7 years ago

I got same results with both one and two passenger worker processes.

Actions

Copy link

Updated by Dominic Cleal over 7 years ago

Category set to Importers

Actions

Copy link

Updated by Lukas Zapletal over 7 years ago

I tried to add FactImporter#import! method into SQL transaction and there was no measurable difference.

I think the problem is that facts are stored in normal form, which is in this case sub-optimal. Most fact names are short enough to be able to create string index though them, I'd simply store them in denormalized table:

id, host_id, name, value

Actions

Copy link

Updated by Ohad Levy over 7 years ago

Lukas Zapletal wrote:

I think the problem is that facts are stored in normal form, which is in this case sub-optimal. Most fact names are short enough to be able to create string index though them, I'd simply store them in denormalized table:

id, host_id, name, value

Are you suggesting to searlize the values? in that case that would break search.

Actions

Copy link

Updated by Lukas Zapletal over 7 years ago

Are you suggesting to searlize the values? in that case that would break search.

Well that's just an idea. If there's no way of integrating this with scoped_search, I think we should be able to optimize some portions using plain SQL batch inserts:

https://joinhandshake.com/engineering/2016/01/26/quickly-inserting-thousands-of-records-in-rails.html

I am not sure how folks like plain SQL in our codebase.

Actions

Copy link

Updated by Lukas Zapletal over 7 years ago

Another idea is to provide a separate stored procedure for PostgreSQL that will do the same thing but faster by order of magnitude. And an optional flag (opt-in) to use the procedure instead normal selects+inserts.

Actions

Copy link

#10

Updated by Lukas Zapletal over 7 years ago

And third option is to use https://github.com/zdennis/activerecord-import gem which will allow bulk INSERTs for all our supported database using a simple DSL. It's a new dependency and it won't be as fast as the stored procedure as we need to iterate in Ruby, search for existing objects and add results into insert/update array, but will will be able to do insert/update in one DB call. Delete can be done via one call today already.

Actions

Copy link

#11

Updated by Marek Hulán over 7 years ago

(Edit: I apologize, I accidentally edited instead replied, now fixed -- lzap)

I don't. It's easy to introduce some MySQL vs PostgreSQL vs sqlite incompatibility.

I'm also not sure whether this is the bottleneck, there are not that many values in facter output. But I admit I did zero research. Why are you against background processing? I know it would have to be optional since there are potentially users that rely on facts in matchers so it influences the ENC output but I think it would solve performance issues for most of users. Don't get me wrong, I don't object optimization, it's just that I'd like to see facts being optionally imported on background too.

Actions

Copy link

#12

Updated by The Foreman Bot over 7 years ago

Status changed from New to Ready For Testing
Assignee set to Lukas Zapletal
Pull request https://github.com/theforeman/foreman/pull/3667 added

Actions

Copy link

#13

Updated by Lukas Zapletal over 7 years ago

Marek Hulán wrote:

I'm also not sure whether this is the bottleneck, there are not that many values in facter >output.

Let me surprise you, DELL PowerEdge R810 is a standard server and it provides 260 facts. The more CPU cores you have the more facts (each core reports several values).

Why are you against background processing?

Because I prefer to write clean code than making workarounds around this. A web server must handle a JSON request of 1000 keys within milliseconds and not 2 seconds (my measurements from today). Without any workarounds.

Anyway, I slightly improved the area in the patch, it's not ideal, we could go further perhaps. Ohad, the initial paste you sent - was it PostgreSQL or MySQL instance?

Actions

Copy link

#14

Updated by Marek Hulán over 7 years ago

All I'm saying is that we should perhaps combine both. And if we can't optimize further without pure SQL I think that would justify it, I'd just like to avoid it until really necessary.

Actions

Copy link

#15

Updated by Daniel Lobato Garcia over 7 years ago

Target version set to 1.7.1

Actions

Copy link

#16

Updated by Daniel Lobato Garcia over 7 years ago

Target version changed from 1.7.1 to 1.6.2

Actions

Copy link

#17

Updated by Jon McKenzie over 7 years ago

Just chiming in here. The current fact importer (we use 1.10, but it seems similar in 1.11 and 1.12) creates a huge performance penalty in one of our environments, which has thousands of EC2 hosts. In EC2, as you may know, Facter creates lots of dynamic facts with names such as "ec2_network_interfaces_macs_00:00:00:00:00:00_device_number" (where the MAC address changes for each instance) -- it has lots of these types of dynamic facts. In the current implementation, when a host runs an import, the importer builds up a list of all unique fact names (cf https://github.com/theforeman/foreman/blob/c696f740e9b8551e0acbf9db9ec390294ee71560/app/services/fact_importer.rb#L73). In an EC2 environment, this means iterating through hundreds of thousands of rows and loading that data into memory for each new fact import. When you have 100-200 hosts checking in in any given 5 minutes period, this basically brings Foreman to a crawl. If I log into Postgres and look at the active queries in our environment, 9 times out of 10 all of the active connections are these select queries building up lists of fact names.

So, that being said.. can I help in any way? Or are there any mitigation suggestions?

I thought about simply disabling fact imports in the node.rb script as a temporary measure, but our ENC data uses smart parameters which rely on fact data.

Actions

Copy link

#18

Updated by Jon McKenzie over 7 years ago

We ended up having to patch the fact importer code on all of our Foreman app servers. This could probably be a bit more concise, and is developed against 1.10.1, but here's our patch:

https://github.com/jcmcken/foreman/commit/efff5947167a2c58e46c91d345667f632ee07cda

Actions

Copy link

#19

Updated by Lukas Zapletal over 7 years ago

We are almost done with our patch to solve this problem. Testing with production data would be very valuable for us. Could you please patch your instance and show us some numbers:

https://github.com/theforeman/foreman/pull/3667/files

Actions

Copy link

#20

Updated by Jon McKenzie over 7 years ago

Hi Lukas,

I can tell by reading this code that this isn't going to solve our issue, or at the very least will cause different types of problems. Specifically this line is problematic, because it's still loading every fact name into memory (even fact names that the host doing the importing doesn't even have). We have 1,000,000+ distinct fact names in our fact_names table. Loading a hash of that size into memory for every host import (when we have 100-200 hosts checking in every 5 minutes) is very resource intensive.

Actions

Copy link

#21

Updated by Jon McKenzie over 7 years ago

Changing this on L.81 in your referenced PR...

fact_names = fact_name_class.where(:type => fact_name_class).index_by(&:name)

...to this...

fact_names = fact_name_class.where(:type => fact_name_class, :name => facts_to_create).index_by(&:name)

...would I think solve our issue vis the large numbers of fact names.

Actions

Copy link

#22

Updated by Lukas Zapletal over 7 years ago

Changing this on L.81 in your referenced PR...

Actually, I completely removed the list. I see no point in keeping this list in memory at all. We can just create fact names as we go. See the updated PR.

Actions

Copy link

#23

Updated by Lukas Zapletal over 7 years ago

Subject changed from Fact import code is O(n^2) to Fact import code consumes lot of memory

I am changing the title because the patch does not solve complexity of our code (lots of Rails allocations because the logic is stored in Rails). We are able to rewrite some portions to consume less memory, but if we want to achieve better throughput, we'd need to change the design of our importers significantly.

Actions

Copy link

#24

Updated by Jon McKenzie over 7 years ago

Lukas Zapletal wrote:

Changing this on L.81 in your referenced PR...

Actually, I completely removed the list. I see no point in keeping this list in memory at all. We can just create fact names as we go. See the updated PR.

Works for me. Thanks for this!

Actions

Copy link

#25