1362168 – Memory leak in several processes (mainly dynflow_executor) when (un)installing a package in loop

Red Hat Satellite engineering is moving the tracking of its product development work on Satellite to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "Satellite project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs will be migrated starting at the end of May. If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "Satellite project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/SAT-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1362168 - Memory leak in several processes (mainly dynflow_executor) when (un)installing a package in loop

Summary: Memory leak in several processes (mainly dynflow_executor) when (un)installin...

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Satellite
Classification:	Red Hat
Component:	Tasks Plugin
Sub Component:
Version:	6.2.0
Hardware:	x86_64
OS:	Linux
Priority:	high
Severity:	high
Target Milestone:	Unspecified
Assignee:	Shimon Shtein
QA Contact:
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2016-08-01 12:48 UTC by Pavel Moravec
Modified:	2024-03-25 14:56 UTC (History)
CC List:	21 users (show)
Fixed In Version:	foreman-tasks-0.9.2
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2018-02-21 16:54:37 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)
"ps aux" output taken every 30s during reproducer (186.09 KB, application/x-gzip) 2016-08-01 13:02 UTC, Pavel Moravec	no flags	Details
View All

Links
System	ID	Priority	Status	Summary	Last Updated
Foreman Issue Tracker	16487	High	Closed	Continuous memory leak while tasks are getting run	2020-10-26 15:58:33 UTC
Foreman Issue Tracker	17175	Normal	Closed	max_memory_per_executor support	2020-10-26 15:58:34 UTC
Red Hat Bugzilla	1352526	high	CLOSED	Concurrent contentview publish cause high memory usage of mongodb & Ruby	2021-04-06 18:00:03 UTC
Red Hat Bugzilla	1410735	medium	CLOSED	dynflow_executor memory increase triggered by capsule sync	2021-08-30 13:39:49 UTC

Internal Links: 1352526 1410735

Description Pavel Moravec 2016-08-01 12:48:13 UTC

Description of problem:
When installing and uninstalling a package in a loop, memory usage of several processes grow up. The biggest grows are:

dynflow_executor
Passenger RackApp: /usr/share/foreman


Version-Release number of selected component (if applicable):
Sat6.2 GA
foreman-1.11.0.49-1.el7sat.noarch
tfm-rubygem-dynflow-0.8.11-1.el7sat.noarch


How reproducible:
100%


Steps to Reproduce:
1. Have some Content Host(s).
2. Monitor ps usage e.g. via:

rm -f ps.txt
while true; do date; date >> ps.txt; ps aux >> ps.txt; sleep 30; done

3. In a loop, install and uninstall a package to a content host (you can run this in parallel to speedup reproducer, I think the leak is "scalable")

action=install
while true; do
  date
  hammer -u admin -p redhat host package ${action} --host pmoravec-rhel72.gsslab.brq.redhat.com --packages "sysstat"
  if [ $action = "install" ]; then
    action=remove
  else action=install
  fi
done


Actual results:
Both VSZ and RSS in ps output grows for several processes, mainly for dynflow_executor and each "Passenger RackApp: /usr/share/foreman" instance.


Expected results:
No VSZ/RSS increase (after some time).


Additional info:
ps.txt from my test to be attached

Comment 1 Pavel Moravec 2016-08-01 12:49:21 UTC

This can be a duplicate of https://bugzilla.redhat.com/show_bug.cgi?id=1352526 but using less intrusive and less memory-demanding reproducer.

Comment 2 Pavel Moravec 2016-08-01 13:02:02 UTC

Created attachment 1186426 [details]
"ps aux" output taken every 30s during reproducer

See these processes (everytime 1st and latest instance printed, to see the mem.increase):

foreman  24878  5.4  5.8 1978528 471164 ?      Sl   13:44   2:17 dynflow_executor
foreman  24878  6.1  6.5 2045092 525352 ?      Sl   13:44  10:58 dynflow_executor

foreman  24974  4.4  8.7 1557472 699412 ?      Sl   13:45   1:52 Passenger RackApp: /usr/share/foreman
foreman  24974  4.3  8.7 1557472 702252 ?      Sl   13:45   7:48 Passenger RackApp: /usr/share/foreman

foreman  24991  2.2  8.5 1492032 680884 ?      Sl   13:45   0:55 Passenger RackApp: /usr/share/foreman
foreman  24991  3.9  8.5 1492032 685592 ?      Sl   13:45   7:05 Passenger RackApp: /usr/share/foreman

foreman  25012  3.9  8.3 1492128 665052 ?      Sl   13:45   1:38 Passenger RackApp: /usr/share/foreman
foreman  25012  4.1  8.3 1492128 669492 ?      Sl   13:45   7:25 Passenger RackApp: /usr/share/foreman

(test run for approx. 2 hours, package (un)install task executed approx. 350 times)

Comment 4 Lukas Zapletal 2016-08-02 11:51:24 UTC

I enabled Ruby heap analyzer and Pavel reproduced the bug, we have a full heap dump. Initial analysis:

[root@pmoravec-sat62-rhel7 ~]# heapy read satellite-dump-after/systemd-private-c05c1b769a7e4432bc4b961381b83ec0-httpd.service-jjcs2Q/tmp/satellite-dump

Analyzing Heap
==============
Generation: nil object count: 383982
Generation:  45 object count: 3952
Generation:  46 object count: 22
Generation:  47 object count: 11947
Generation:  48 object count: 3290
Generation:  49 object count: 119
Generation:  50 object count: 195
Generation:  51 object count: 225
Generation:  52 object count: 4107
Generation:  53 object count: 1767
Generation:  54 object count: 2514
Generation:  55 object count: 4987
Generation:  56 object count: 8025
Generation:  57 object count: 264
Generation:  58 object count: 229
Generation:  59 object count: 2907
Generation:  60 object count: 39755
Generation:  61 object count: 16517
Generation:  62 object count: 17417
Generation:  63 object count: 9122
Generation:  64 object count: 8496
Generation:  65 object count: 4146
Generation:  66 object count: 10679
Generation:  67 object count: 37535
Generation:  68 object count: 22601
Generation:  69 object count: 18543
Generation:  70 object count: 15460
Generation:  71 object count: 13042
Generation:  72 object count: 11265
Generation:  73 object count: 6873
Generation:  74 object count: 17557
Generation:  75 object count: 11497
Generation:  76 object count: 7538
Generation:  77 object count: 9286
Generation:  78 object count: 8970
Generation:  79 object count: 22292
Generation:  80 object count: 19766
Generation:  81 object count: 188
Generation:  82 object count: 30630
Generation:  83 object count: 51191
Generation:  84 object count: 71584
Generation:  85 object count: 10100
Generation:  87 object count: 3266
Generation:  88 object count: 9854
Generation: 102 object count: 9562
Generation: 103 object count: 10708
Generation: 104 object count: 866
Generation: 105 object count: 10288
Generation: 106 object count: 7689
Generation: 107 object count: 12138
Generation: 108 object count: 9378
Generation: 109 object count: 4009
Generation: 110 object count: 10704
Generation: 111 object count: 19885
Generation: 112 object count: 837
Generation: 113 object count: 3501
Generation: 114 object count: 11059
Generation: 115 object count: 9571
Generation: 116 object count: 3379
Generation: 117 object count: 17487
Generation: 118 object count: 1132
Generation: 119 object count: 11160
Generation: 120 object count: 11699
Generation: 121 object count: 867
Generation: 122 object count: 9891
Generation: 123 object count: 1456
Generation: 124 object count: 11115
Generation: 125 object count: 870
Generation: 126 object count: 3459
Generation: 127 object count: 12515
Generation: 128 object count: 12245
Generation: 129 object count: 10826
Generation: 130 object count: 11048
Generation: 131 object count: 12584
Generation: 132 object count: 922280

[root@pmoravec-sat62-rhel7 ~]# heapy read satellite-dump-after/systemd-private-c05c1b769a7e4432bc4b961381b83ec0-httpd.service-jjcs2Q/tmp/satellite-dump all

Analyzing Heap (Generation: all)
-------------------------------

allocated by memory (244103625) (in bytes)
==============================
  39911024  /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:320
  29998917  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:155
  20790958  /opt/rh/rh-ruby22/root/usr/share/rubygems/rubygems/core_ext/kernel_require.rb:54
   4797568  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_controller/metal/strong_parameters.rb:349
   3992800  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/visitors.rb:64
   3954015  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/marshal.rb:6
   3480736  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/inflector/methods.rb:93
   3243896  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/hash_with_indifferent_access.rb:76
   3231868  /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/attribute_methods.rb:385
   2892269  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_controller/log_subscriber.rb:15
   2651432  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/http/parameter_filter.rb:49
   2428089  /usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/utils.rb:188
   2103593  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/path/pattern.rb:168
   1968208  /opt/rh/rh-ruby22/root/usr/share/ruby/set.rb:106
   1946256  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/class/attribute.rb:86
   1898343  /usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/utils/tee_input.rb:99
   1828168  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/object/json.rb:159
   1789718  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:223
   1555284  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/path/pattern.rb:95
   1409924  /usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/utils/unseekable_socket.rb:164
   1394551  poparser.ry:139
   1350618  /opt/rh/rh-ruby22/root/usr/share/ruby/openssl/buffering.rb:182
   1251808  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:86
   1209216  /opt/rh/rh-ror41/root/usr/share/gems/gems/tzinfo-1.2.2/lib/tzinfo/transition_data_timezone_info.rb:70
   1193174  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/routing/route_set.rb:482
   1095536  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/relation/delegation.rb:19
   1094770  poparser.ry:219
   1057784  /usr/share/foreman/config/initializers/routing_hash_for.rb:10
   1030816  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/result.rb:105
   1019461  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/vendor/mofile.rb:310
    979968  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/routing/mapper.rb:63
    944888  /opt/rh/rh-ruby22/root/usr/share/ruby/set.rb:81
    934329  /opt/theforeman/tfm/root/usr/share/gems/gems/pg-0.15.1/lib/pg/result.rb:9
    918320  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/parser.rb:140
    895080  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/hash_with_indifferent_access.rb:253
    824080  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/parser.rb:181
    808911  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/class/attribute.rb:78
    795728  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql_adapter.rb:515
    787552  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/po_file.rb:14
    787072  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/abstract_controller/helpers.rb:38
    755645  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/associations/builder/singular_association.rb:16
    712768  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/relation.rb:34
    708917  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/string/output_safety.rb:237
    673262  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:82
    667840  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/vendor/mofile.rb:57
    651216  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/translation.rb:120
    645635  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/associations/builder/association.rb:116
    639512  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/persistence.rb:51
    638622  /opt/rh/rh-ruby22/root/usr/share/ruby/uri/generic.rb:1503
    632112  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/associations/builder/association.rb:108

object count (1723928)
==============================
  183710  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:155
   53250  /opt/rh/rh-ruby22/root/usr/share/rubygems/rubygems/core_ext/kernel_require.rb:54
   50734  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/path/pattern.rb:168
   38416  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/visitors.rb:64
   35155  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/marshal.rb:6
   31446  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:223
   29261  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/object/json.rb:159
   24556  /usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/utils.rb:188
   22958  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/parser.rb:140
   22377  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/hash_with_indifferent_access.rb:253
   20602  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/parser.rb:181
   19420  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:86
   18660  /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/attribute_methods.rb:385
   17576  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/inflector/methods.rb:93
   16594  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/class/attribute.rb:86
   15902  /opt/theforeman/tfm/root/usr/share/gems/gems/pg-0.15.1/lib/pg/result.rb:9
   15310  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/abstract_controller/helpers.rb:38
   15307  poparser.ry:139
   15307  poparser.ry:219
   14759  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_controller/log_subscriber.rb:15
   14731  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:82
   14652  /opt/rh/rh-ruby22/root/usr/share/rubygems/rubygems/basic_specification.rb:62
   14645  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/vendor/mofile.rb:310
   13755  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/hash_with_indifferent_access.rb:76
   13515  /opt/rh/rh-ruby22/root/usr/share/ruby/uri/generic.rb:1503
   12912  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:56
   12632  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/object/json.rb:34
   12596  /opt/rh/rh-ror41/root/usr/share/gems/gems/tzinfo-1.2.2/lib/tzinfo/transition_data_timezone_info.rb:70
   11427  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/http/parameter_filter.rb:49
   11304  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_controller/metal/strong_parameters.rb:349
    9062  /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/type_check.rb:25
    8769  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/inflector/methods.rb:92
    8409  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/abstract_controller/base.rb:84
    8117  /opt/rh/rh-ruby22/root/usr/share/ruby/set.rb:290
    8070  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/result.rb:99
    8027  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/vendor/mofile.rb:161
    7987  /usr/share/foreman/config/initializers/routing_hash_for.rb:10
    7741  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql/database_statements.rb:145
    7703  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/formatter.rb:137
    7513  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/relation/calculations.rb:182
    6984  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/nodes/node.rb:33
    6816  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/string/output_safety.rb:237
    6795  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/array/wrap.rb:42
    6744  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/simple_package.rb:8
    6409  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/scanner.rb:50
    6409  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/parser.rb:186
    6250  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/scanner.rb:52
    6250  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/parser.rb:191
    6045  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/inflector/methods.rb:351
    6011  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/class/attribute.rb:84

High Ref Counts
==============================

  168751  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/abstract_controller/helpers.rb:38
  142939  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/hash_with_indifferent_access.rb:76
  138709  /opt/rh/rh-ruby22/root/usr/share/rubygems/rubygems/core_ext/kernel_require.rb:54
  125318  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/http/parameter_filter.rb:49
  124513  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_controller/metal/strong_parameters.rb:349
   81250  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/concern.rb:118
   71507  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/class/attribute.rb:86
   69469  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:155
   53091  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/object/json.rb:159
   51635  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:86
   45916  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/parser.rb:140
   45854  /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/attribute_methods.rb:385
   44894  /usr/share/foreman/config/initializers/routing_hash_for.rb:10
   38584  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/visitors.rb:64
   34855  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/marshal.rb:6
   32592  /usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/utils.rb:188
   30722  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/po_file.rb:14
   28299  /opt/rh/rh-ruby22/root/usr/share/ruby/set.rb:106
   25872  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/class/attribute.rb:78
   25378  /opt/rh/rh-ror41/root/usr/share/gems/gems/tzinfo-1.2.2/lib/tzinfo/transition_data_timezone_info.rb:70
   23315  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/abstract_controller/base.rb:84
   21660  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/translation.rb:120
   21001  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:223
   20531  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/parser.rb:181
   20129  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/result.rb:105
   19486  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/persistence.rb:51
   19186  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/parser.rb:186
   18063  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/vendor/mofile.rb:57
   17798  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/routes.rb:58
   17740  /opt/rh/rh-ruby22/root/usr/share/ruby/set.rb:81
   17443  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:340
   17115  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/hash_with_indifferent_access.rb:262
   16181  /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/param_description.rb:16
   14115  /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/callbacks.rb:138
   12596  /opt/rh/rh-ror41/root/usr/share/gems/gems/tzinfo-1.2.2/lib/tzinfo/transition_data_timezone_info.rb:17
   12447  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/parser.rb:191
   12246  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/routing/route_set.rb:450
   12234  /opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/type_check.rb:25
   12022  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/class/attribute.rb:84
   11799  /usr/share/foreman/config/initializers/routing_hash_for.rb:15
   11637  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/autosave_association.rb:151
   11307  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_controller/metal/strong_parameters.rb:343
   11307  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/http/parameter_filter.rb:57
   10785  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/relation/spawn_methods.rb:10
   10508  /usr/share/foreman/config/initializers/routing_hash_for.rb:6
   10010  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:505
    9966  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/routing/mapper.rb:63
    9601  /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/utils.rb:55
    9228  /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-4.20.0/lib/sequel/adapters/postgres.rb:655
    8638  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/relation/calculations.rb:182

Duplicate strings
==============================

 17483  "name"
 12682  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:155
  2274  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:223
  1130  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:82
   230  /opt/theforeman/tfm/root/usr/share/gems/gems/friendly_id-5.1.0/lib/friendly_id/configuration.rb:64
   211  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/result.rb:99
   202  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql/database_statements.rb:145
   126  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionview-4.1.5/lib/action_view/helpers/tag_helper.rb:144
   126  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionview-4.1.5/lib/action_view/helpers/tag_helper.rb:172
    65  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql/database_statements.rb:141
    57  /opt/rh/rh-ruby22/root/usr/share/ruby/set.rb:290
    48  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/model_schema.rb:223
    47  /opt/theforeman/tfm/root/usr/share/gems/gems/pg-0.15.1/lib/pg/result.rb:9
    43  /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/attribute_methods.rb:219
    38  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/relation/predicate_builder.rb:36
    38  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/relation/predicate_builder.rb:87
    24  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/schema_cache.rb:97
    24  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/attribute_methods/read.rb:110
    22  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/hash_with_indifferent_access.rb:67
    16  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/hash_with_indifferent_access.rb:95
    14  /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/attribute_methods.rb:385
    12  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/attribute_methods/read.rb:126
    10  poparser.ry:219
     6  /opt/theforeman/tfm/root/usr/share/gems/gems/safemode-1.2.3/lib/safemode/blankslate.rb:25
     6  /opt/theforeman/tfm/root/usr/share/gems/gems/deface-1.0.2/lib/deface/override.rb:178
     5  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/associations/join_dependency/join_part.rb:59
     4  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/hash/keys.rb:32
     4  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/core_ext/hash/keys.rb:11
     3  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/hash_with_indifferent_access.rb:133
     2  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/model_schema.rb:255
     2  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/vendor/string.rb:70
     2  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/hash_with_indifferent_access.rb:250
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/nodes/node.rb:33
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/arel-5.0.0/lib/arel/visitors/to_sql.rb:596
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/rpm.rb:6
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/rpm.rb:7
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/attribute_methods.rb:209
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/lib/katello/lazy_accessor.rb:37
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/controllers/katello/api/v2/activation_keys_controller.rb:53
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/controllers/katello/api/v2/organizations_controller.rb:72
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/controllers/katello/api/v2/activation_keys_controller.rb:32
     1  /usr/share/foreman/app/models/nic/managed.rb:53

 16357  "vendor"
 12424  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:155
  2248  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:223
  1124  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:82
   511  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/mo_file.rb:38
    14  /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/attribute_methods.rb:385
     7  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql/database_statements.rb:141
     7  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/result.rb:99
     7  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql/database_statements.rb:145
     3  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/model_schema.rb:223
     3  /opt/rh/rh-ruby22/root/usr/share/ruby/set.rb:290
     2  /opt/theforeman/tfm/root/usr/share/gems/gems/pg-0.15.1/lib/pg/result.rb:9
     2  /opt/theforeman/tfm/root/usr/share/gems/gems/fast_gettext-0.9.2/lib/fast_gettext/vendor/string.rb:70
     2  /opt/rh/rh-ror41/root/usr/share/gems/gems/thread_safe-0.3.4/lib/thread_safe/non_concurrent_cache_backend.rb:21
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/lib/katello/lazy_accessor.rb:37
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/attribute_methods.rb:27
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/schema_cache.rb:97

 15832  "release"
 12427  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:155
  2252  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:223
  1124  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:82
    15  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/gtg/simulator.rb:24
     5  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/controllers/katello/api/v2/root_controller.rb:56
     4  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/controllers/katello/api/v2/root_controller.rb:46
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/rpm.rb:6
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/rpm.rb:7
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/gtg/builder.rb:29
     1  /opt/rh/rh-ruby22/root/usr/share/rubygems/rubygems/core_ext/kernel_require.rb:54
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/scanner.rb:52

 15826  "version"
 12430  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:155
  2254  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:223
  1127  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:82
     2  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/scanner.rb:52
     2  /opt/rh/rh-ror41/root/usr/share/gems/gems/thread_safe-0.3.4/lib/thread_safe/non_concurrent_cache_backend.rb:21
     2  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/routing/mapper.rb:1476
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/rpm.rb:6
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-4.20.0/lib/sequel/core.rb:231
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/pg-0.15.1/lib/pg/result.rb:9
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/model_schema.rb:223
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/nodes/node.rb:33
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/actionpack-4.1.5/lib/action_dispatch/journey/gtg/builder.rb:29
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/attribute_methods.rb:27
     1  /opt/rh/rh-ruby22/root/usr/share/ruby/set.rb:290
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/rpm.rb:7

 15820  "arch"
 12430  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:155
  2254  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:223
  1127  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:82
     2  /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/attribute_methods.rb:209
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/rpm.rb:7
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/safemode-1.2.3/lib/safemode/blankslate.rb:25
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/rpm.rb:6
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/lib/katello/lazy_accessor.rb:37
     1  /opt/rh/rh-ruby22/root/usr/share/ruby/set.rb:290
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/pg-0.15.1/lib/pg/result.rb:9
     1  /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/model_schema.rb:223

 15801  "epoch"
 12427  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:155
  2248  /opt/rh/rh-ruby22/root/usr/share/gems/gems/json-1.8.1/lib/json/common.rb:223
  1124  /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/json/encoding.rb:82
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/rpm.rb:7
     1  /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/services/katello/pulp/rpm.rb:6

...

Looks like we do a LOT of logging on package upload:

2016-08-02 14:51:05 [app] [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#upload_package_profile as JSON
2016-08-02 14:51:05 [app] [I]   Parameters: {"_json"=>[{"vendor"=>"Red Hat, Inc.", "name"=>"python-isodate", "epoch"=>0, ...... HUGE AMOUNT OF DATA }}

This is INFO level log while this should DEFINITELY be only DEBUG level log and we need to make sure it does not get serialized (only when DEBUG is enabled).

Comment 5 Lukas Zapletal 2016-08-02 12:03:43 UTC

Looks like Rails does TON of stuff when dealing with incoming parameters - parsing, filtering, logging. We need to clean the upload_package_profile method to do minimum actions required to hand the request over to Candlepin:

- disable JSON parsing of incoming data (if that's possible - not sure if Katello just passes data over or does something with it)
- disable logging of Parameters for this method call (ideally switch it to DEBUG for whole application - INFO is annoying IMHO).

That should help a lot.

Comment 6 Lukas Zapletal 2016-08-02 12:19:13 UTC

Unfortunately, "Parameters" logging is hardcoded in Rails, I will try to file a PR to change that.

Comment 7 Lukas Zapletal 2016-08-02 12:20:58 UTC

And just for the record, the above measurements are from Rails app, I haven't tested dynflow at all.

Comment 8 Lukas Zapletal 2016-08-02 13:30:29 UTC

Looks like the measurements I made are all to do with extra logging we do in Rails app, but it has nothing to do with this particular report (it's obviously for dynflow/tasks). Ignore, I filed http://projects.theforeman.org/issues/13697 ticket for Katello team to improve logging and save some CPU cycles tho (and memory) tho.

Comment 10 Ivan Necas 2016-09-08 12:13:00 UTC

Created redmine issue http://projects.theforeman.org/issues/16487 from this bug

Comment 11 Pavel Moravec 2016-10-17 20:22:39 UTC

Another reproducer - not sure of the root cause is the same or not:

Run a REX / job invocation in a loop. The more hosts, the better. Probably if some job on some host fails (sometimes), the better for the leak.

I.e. try:

while true; do hammer -u admin -p redhat job-invocation create --job-template "Run Command - SSH Default" --inputs command="ls" --search-query "name ~ rhel"; sleep 5; done

and monitor dynflow_executor RSS.

Comment 18 Pavel Moravec 2016-12-04 20:56:47 UTC

FYI another reproducer showing the same: repeatedly create and delete a repo in a product. Copying particular steps from https://bugzilla.redhat.com/show_bug.cgi?id=1401331#c0 :


hammer product create --name=custom_product --organization-id=1 --label=custom_product

while true; do
	date
	sleep 2
	hammer repository create --content-type=yum --download-policy=immediate --label=custom_repo --name=custom_repo --organization-id=1 --product=custom_product
	hammer repository delete --name=custom_repo --organization-id=1 --product=custom_product
done


Wild guess theory:
- creating *any* task causes some memory increase happens, the task type does not matter
- wild speculation: cant overall memory consumption be in direct relationship with overall number of tasks (even successfully completed)? That would explain any fact I know about this BZ. Doesn't dynfow fetch _all_ tasks somewhere??

Comment 19 Bryan Kearney 2016-12-06 19:16:30 UTC

Moving this bug to POST for triage into Satellite 6 since the upstream issue http://projects.theforeman.org/issues/16487 has been resolved.

Comment 20 Ivan Necas 2016-12-06 21:02:42 UTC

We've spend a lot of time hunting the leaks in dynflow/foreman-tasks/katello code. And so far, we were not able to identify any source of long-referenced objects in memory, that would cause linear memory growth - and correct me if I'm wrong, but I don't think we have linear growth here over time.

From what we've seen, it seems like an issue with memory fragmentation (and the fact Ruby doesn't defragment) http://collectiveidea.com/blog/archives/2015/02/19/optimizing-rails-for-memory-usage-part-2-tuning-the-gc, which leads to the growth of the memory usage, especially at the beginning. From the testing so far, it also seems that, at the constant triggering of tasks, the memory consumption grow slows down and converges to some size eventually. The size depends on the type of tasks.

The only thing we were able to proceed with so far was ability to set top memory limit when we will restart the process to start from scratch.

Comment 21 Bryan Kearney 2016-12-06 21:16:36 UTC

Upstream bug assigned to sshtein

Comment 22 Bryan Kearney 2016-12-06 21:16:41 UTC

Upstream bug assigned to sshtein

Comment 23 Julio Entrena Perez 2016-12-07 09:37:50 UTC

(In reply to Ivan Necas from comment #20)
> From the testing so far, it also seems
> that, at the constant triggering of tasks, the memory consumption grow slows
> down and converges to some size eventually. The size depends on the type of
> tasks.

Memory consumption seems to grow until memory is exhausted in the Satellite:

Thu  3 Nov 02:00:02 GMT 2016
foreman   9372  1.4  2.8 3766116 1875464 ?     Sl   Nov02   8:35 dynflow_executor
Thu  3 Nov 03:00:01 GMT 2016
foreman   9372  3.1  3.0 3767144 1988484 ?     Sl   Nov02  20:54 dynflow_executor
Thu  3 Nov 04:00:01 GMT 2016
foreman   9372  3.4  3.2 3898216 2116100 ?     Sl   Nov02  24:58 dynflow_executor
Thu  3 Nov 05:00:01 GMT 2016
foreman   9372  3.2  3.0 3898216 2030112 ?     Sl   Nov02  25:11 dynflow_executor
Thu  3 Nov 06:00:01 GMT 2016
foreman   9372  3.0  3.2 4029288 2128260 ?     Sl   Nov02  25:24 dynflow_executor
Thu  3 Nov 07:00:01 GMT 2016
foreman   9372  2.8  3.2 3963752 2141008 ?     Sl   Nov02  25:37 dynflow_executor
Thu  3 Nov 08:00:01 GMT 2016
foreman   9372  2.6  3.3 3963752 2184288 ?     Sl   Nov02  25:49 dynflow_executor
Thu  3 Nov 09:00:01 GMT 2016
foreman   9372  2.5  3.4 3963752 2246696 ?     Sl   Nov02  26:01 dynflow_executor
Thu  3 Nov 10:00:01 GMT 2016
foreman   9372  2.5  3.4 4029288 2282420 ?     Sl   Nov02  27:18 dynflow_executor
Thu  3 Nov 11:00:01 GMT 2016
foreman   9372  2.7  3.9 4160360 2572304 ?     Sl   Nov02  31:13 dynflow_executor
Thu  3 Nov 12:00:01 GMT 2016
foreman   9372  2.6  3.9 4225896 2606920 ?     Sl   Nov02  31:42 dynflow_executor
Thu  3 Nov 13:00:02 GMT 2016
foreman   9372  2.6  4.4 4684648 2904032 ?     Sl   Nov02  33:47 dynflow_executor
Thu  3 Nov 14:00:01 GMT 2016
foreman   9372  2.5  4.5 4815720 2988368 ?     Sl   Nov02  33:59 dynflow_executor
Thu  3 Nov 15:00:02 GMT 2016
foreman   9372  2.4  4.5 4750184 3012948 ?     Sl   Nov02  34:32 dynflow_executor
Thu  3 Nov 16:00:01 GMT 2016
foreman   9372  2.4  4.6 4815720 3041548 ?     Sl   Nov02  34:47 dynflow_executor
Thu  3 Nov 17:00:01 GMT 2016
foreman   9372  2.3  4.6 4815720 3035972 ?     Sl   Nov02  35:01 dynflow_executor
Thu  3 Nov 18:00:01 GMT 2016
foreman   9372  2.3  5.3 5225080 3526112 ?     Sl   Nov02  36:25 dynflow_executor
Thu  3 Nov 19:00:01 GMT 2016
foreman   9372  2.4  5.3 5159544 3509704 ?     Sl   Nov02  39:43 dynflow_executor
Thu  3 Nov 20:00:02 GMT 2016
foreman   9372  2.4  5.3 5225080 3517584 ?     Sl   Nov02  40:33 dynflow_executor
Thu  3 Nov 21:00:01 GMT 2016
foreman   9372  2.3  5.3 5225080 3553480 ?     Sl   Nov02  40:47 dynflow_executor
Thu  3 Nov 22:00:01 GMT 2016
foreman   9372  2.2  5.4 5290616 3573540 ?     Sl   Nov02  40:59 dynflow_executor
Thu  3 Nov 23:00:01 GMT 2016
foreman   9372  2.2  5.4 5290616 3574744 ?     Sl   Nov02  41:11 dynflow_executor
Fri  4 Nov 00:00:01 GMT 2016
foreman   9372  2.1  5.4 5290616 3576148 ?     Sl   Nov02  41:23 dynflow_executor
Fri  4 Nov 01:00:01 GMT 2016
foreman   9372  2.0  5.4 5290616 3577028 ?     Sl   Nov02  41:36 dynflow_executor
Fri  4 Nov 02:00:01 GMT 2016
foreman   9372  2.5  5.6 5421688 3738580 ?     Sl   Nov02  51:47 dynflow_executor
Fri  4 Nov 03:00:01 GMT 2016
foreman   9372  3.0  6.3 5814904 4166068 ?     Sl   Nov02  64:14 dynflow_executor
Fri  4 Nov 04:00:01 GMT 2016
foreman   9372  3.5  6.3 5814904 4176124 ?     Sl   Nov02  76:17 dynflow_executor
Fri  4 Nov 05:00:01 GMT 2016
foreman   9372  3.9  6.4 5814904 4222716 ?     Sl   Nov02  88:29 dynflow_executor
Fri  4 Nov 06:00:01 GMT 2016
foreman   9372  4.4  6.4 5814904 4223828 ?     Sl   Nov02 101:58 dynflow_executor
Fri  4 Nov 07:00:01 GMT 2016
foreman   9372  4.7  6.4 5814904 4259208 ?     Sl   Nov02 111:10 dynflow_executor
Fri  4 Nov 08:00:01 GMT 2016
foreman   9372  4.7  6.4 5814904 4264004 ?     Sl   Nov02 113:11 dynflow_executor
Fri  4 Nov 09:00:01 GMT 2016
foreman   9372  4.5  6.5 5814904 4280900 ?     Sl   Nov02 113:24 dynflow_executor
Fri  4 Nov 10:00:01 GMT 2016
foreman   9372  4.4  6.5 5814904 4281956 ?     Sl   Nov02 113:39 dynflow_executor
Fri  4 Nov 11:00:01 GMT 2016
foreman   9372  4.4  6.5 5814904 4287672 ?     Sl   Nov02 115:28 dynflow_executor
Fri  4 Nov 12:00:02 GMT 2016
foreman   9372  4.4  6.5 5814904 4291108 ?     Sl   Nov02 118:41 dynflow_executor
Fri  4 Nov 13:00:01 GMT 2016
foreman   9372  4.4  6.6 5880440 4346008 ?     Sl   Nov02 120:11 dynflow_executor
Fri  4 Nov 14:00:01 GMT 2016
foreman   9372  4.4  6.6 5945976 4381616 ?     Sl   Nov02 122:43 dynflow_executor
Fri  4 Nov 15:00:02 GMT 2016
foreman   9372  4.3  6.6 6011512 4394916 ?     Sl   Nov02 123:05 dynflow_executor
Fri  4 Nov 16:00:01 GMT 2016
foreman   9372  4.3  6.6 5945976 4401240 ?     Sl   Nov02 125:08 dynflow_executor
Fri  4 Nov 17:00:01 GMT 2016
foreman   9372  4.3  6.7 5945976 4436372 ?     Sl   Nov02 127:50 dynflow_executor
Fri  4 Nov 18:00:01 GMT 2016
foreman   9372  5.0  6.8 5945976 4478744 ?     Sl   Nov02 152:15 dynflow_executor
Fri  4 Nov 19:00:01 GMT 2016
foreman   9372  5.8  6.8 5945976 4502804 ?     Sl   Nov02 178:38 dynflow_executor
Fri  4 Nov 20:00:01 GMT 2016
foreman   9372  6.5  6.8 5945976 4508344 ?     Sl   Nov02 203:42 dynflow_executor
Fri  4 Nov 21:00:01 GMT 2016
foreman   9372  6.7  7.0 6077048 4644864 ?     Sl   Nov02 214:31 dynflow_executor
Fri  4 Nov 22:00:01 GMT 2016
foreman   9372  6.6  7.0 6077048 4646620 ?     Sl   Nov02 214:44 dynflow_executor
Fri  4 Nov 23:00:01 GMT 2016
foreman   9372  6.5  7.0 6077048 4647412 ?     Sl   Nov02 214:56 dynflow_executor
Sat  5 Nov 00:00:01 GMT 2016
foreman   9372  6.3  7.0 6077048 4648468 ?     Sl   Nov02 215:08 dynflow_executor
Sat  5 Nov 01:00:01 GMT 2016
foreman   9372  6.2  7.1 6142584 4684320 ?     Sl   Nov02 215:20 dynflow_executor
Sat  5 Nov 02:00:01 GMT 2016
foreman   9372  6.4  7.7 6601336 5088120 ?     Sl   Nov02 225:42 dynflow_executor
Sat  5 Nov 03:00:01 GMT 2016
foreman   9372  6.7  7.7 6601336 5089176 ?     Sl   Nov02 238:17 dynflow_executor
Sat  5 Nov 04:00:01 GMT 2016
foreman   9372  6.6  7.7 6666872 5115456 ?     Sl   Nov02 238:33 dynflow_executor
Sat  5 Nov 05:00:01 GMT 2016
foreman   9372  6.5  7.7 6666872 5118864 ?     Sl   Nov02 238:45 dynflow_executor
Sat  5 Nov 06:00:01 GMT 2016
foreman   9372  6.4  7.8 6732408 5138840 ?     Sl   Nov02 238:57 dynflow_executor
Sat  5 Nov 07:00:01 GMT 2016
foreman   9372  6.3  7.8 6732408 5139664 ?     Sl   Nov02 239:09 dynflow_executor
Sat  5 Nov 08:00:01 GMT 2016
foreman   9372  6.2  7.8 6732408 5139724 ?     Sl   Nov02 239:21 dynflow_executor
Sat  5 Nov 09:00:01 GMT 2016
foreman   9372  6.1  7.8 6732408 5142480 ?     Sl   Nov02 239:34 dynflow_executor
Sat  5 Nov 10:00:01 GMT 2016
foreman   9372  6.0  7.8 6732408 5143500 ?     Sl   Nov02 239:45 dynflow_executor
Sat  5 Nov 11:00:01 GMT 2016
foreman   9372  5.9  7.8 6732408 5144580 ?     Sl   Nov02 239:57 dynflow_executor
Sat  5 Nov 12:00:01 GMT 2016
foreman   9372  5.8  7.8 6797944 5150024 ?     Sl   Nov02 240:09 dynflow_executor
Sat  5 Nov 13:00:01 GMT 2016
foreman   9372  5.7  7.8 6797944 5152164 ?     Sl   Nov02 240:21 dynflow_executor
Sat  5 Nov 14:00:01 GMT 2016
foreman   9372  5.7  7.8 6797944 5164676 ?     Sl   Nov02 240:33 dynflow_executor
Sat  5 Nov 15:00:01 GMT 2016
foreman   9372  5.6  7.8 6797944 5165748 ?     Sl   Nov02 240:45 dynflow_executor
Sat  5 Nov 16:00:01 GMT 2016
foreman   9372  5.5  7.8 6797944 5167652 ?     Sl   Nov02 240:57 dynflow_executor
Sat  5 Nov 17:00:02 GMT 2016
foreman   9372  5.4  7.8 6797944 5168448 ?     Sl   Nov02 241:09 dynflow_executor
Sat  5 Nov 18:00:01 GMT 2016
foreman   9372  5.4  7.8 6797944 5169504 ?     Sl   Nov02 241:21 dynflow_executor
Sat  5 Nov 19:00:01 GMT 2016
foreman   9372  5.3  7.8 6797944 5170560 ?     Sl   Nov02 241:33 dynflow_executor
Sat  5 Nov 20:00:01 GMT 2016
foreman   9372  5.2  7.8 6797944 5171352 ?     Sl   Nov02 241:45 dynflow_executor
Sat  5 Nov 21:00:01 GMT 2016
foreman   9372  5.2  7.8 6797944 5172672 ?     Sl   Nov02 241:58 dynflow_executor
Sat  5 Nov 22:00:01 GMT 2016
foreman   9372  5.1  7.8 6797944 5173464 ?     Sl   Nov02 242:10 dynflow_executor
Sat  5 Nov 23:00:02 GMT 2016
foreman   9372  5.1  7.8 6797944 5174564 ?     Sl   Nov02 242:22 dynflow_executor
Sun  6 Nov 00:00:01 GMT 2016
foreman   9372  5.0  7.8 6797944 5175620 ?     Sl   Nov02 242:34 dynflow_executor
Sun  6 Nov 01:00:01 GMT 2016
foreman   9372  4.9  7.8 6797944 5183272 ?     Sl   Nov02 242:46 dynflow_executor
Sun  6 Nov 02:00:01 GMT 2016
foreman   9372  4.9  7.9 6863480 5228900 ?     Sl   Nov02 246:14 dynflow_executor
Sun  6 Nov 03:00:02 GMT 2016
foreman   9372  4.9  7.9 6863480 5229520 ?     Sl   Nov02 248:23 dynflow_executor
Sun  6 Nov 04:00:01 GMT 2016
foreman   9372  4.9  7.9 6863480 5230912 ?     Sl   Nov02 248:34 dynflow_executor
Sun  6 Nov 05:00:02 GMT 2016
foreman   9372  4.8  7.9 6863480 5232384 ?     Sl   Nov02 248:46 dynflow_executor
Sun  6 Nov 06:00:01 GMT 2016
foreman   9372  4.8  7.9 6863480 5233380 ?     Sl   Nov02 248:59 dynflow_executor
Sun  6 Nov 07:00:01 GMT 2016
foreman   9372  4.7  7.9 6863480 5234460 ?     Sl   Nov02 249:11 dynflow_executor
Sun  6 Nov 08:00:01 GMT 2016
foreman   9372  4.7  7.9 6863480 5235516 ?     Sl   Nov02 249:23 dynflow_executor
Sun  6 Nov 09:00:01 GMT 2016
foreman   9372  4.6  7.9 6863480 5236572 ?     Sl   Nov02 249:35 dynflow_executor
Sun  6 Nov 10:00:01 GMT 2016
foreman   9372  4.6  7.9 6863480 5237628 ?     Sl   Nov02 249:48 dynflow_executor
Sun  6 Nov 11:00:01 GMT 2016
foreman   9372  4.5  7.9 6863480 5238420 ?     Sl   Nov02 250:00 dynflow_executor
Sun  6 Nov 12:00:01 GMT 2016
foreman   9372  4.5  7.9 6863480 5239476 ?     Sl   Nov02 250:12 dynflow_executor
Sun  6 Nov 13:00:01 GMT 2016
foreman   9372  4.4  7.9 6863480 5240268 ?     Sl   Nov02 250:25 dynflow_executor
Sun  6 Nov 14:00:01 GMT 2016
foreman   9372  4.4  7.9 6863480 5241324 ?     Sl   Nov02 250:37 dynflow_executor
Sun  6 Nov 15:00:01 GMT 2016
foreman   9372  4.3  7.9 6863480 5242380 ?     Sl   Nov02 250:48 dynflow_executor
Sun  6 Nov 16:00:02 GMT 2016
foreman   9372  4.3  7.9 6863480 5243172 ?     Sl   Nov02 251:01 dynflow_executor
Sun  6 Nov 17:00:01 GMT 2016
foreman   9372  4.3  7.9 6863480 5244228 ?     Sl   Nov02 251:13 dynflow_executor
Sun  6 Nov 18:00:01 GMT 2016
foreman   9372  4.2  7.9 6863480 5245284 ?     Sl   Nov02 251:25 dynflow_executor
Sun  6 Nov 19:00:01 GMT 2016
foreman   9372  4.2  7.9 6863480 5246340 ?     Sl   Nov02 251:37 dynflow_executor
Sun  6 Nov 20:00:01 GMT 2016
foreman   9372  4.1  7.9 6863480 5247132 ?     Sl   Nov02 251:50 dynflow_executor
Sun  6 Nov 21:00:01 GMT 2016
foreman   9372  4.1  7.9 6863480 5248188 ?     Sl   Nov02 252:02 dynflow_executor
Sun  6 Nov 22:00:01 GMT 2016
foreman   9372  4.1  7.9 6863480 5249244 ?     Sl   Nov02 252:14 dynflow_executor
Sun  6 Nov 23:00:01 GMT 2016
foreman   9372  4.0  7.9 6863480 5250036 ?     Sl   Nov02 252:26 dynflow_executor
Mon  7 Nov 00:00:01 GMT 2016
foreman   9372  4.0  7.9 6863480 5251092 ?     Sl   Nov02 252:39 dynflow_executor
Mon  7 Nov 01:00:01 GMT 2016
foreman   9372  4.0  7.9 6863480 5252148 ?     Sl   Nov02 252:50 dynflow_executor
Mon  7 Nov 02:00:01 GMT 2016
foreman   9372  4.0  8.2 7125624 5429464 ?     Sl   Nov02 258:06 dynflow_executor
Mon  7 Nov 03:00:01 GMT 2016
foreman   9372  4.0  8.2 7125624 5433552 ?     Sl   Nov02 263:07 dynflow_executor
Mon  7 Nov 04:00:01 GMT 2016
foreman   9372  4.0  8.2 7125624 5435396 ?     Sl   Nov02 263:19 dynflow_executor
Mon  7 Nov 05:00:01 GMT 2016
foreman   9372  4.0  8.2 7125624 5436188 ?     Sl   Nov02 263:31 dynflow_executor
Mon  7 Nov 06:00:01 GMT 2016
foreman   9372  3.9  8.2 7125624 5437352 ?     Sl   Nov02 263:43 dynflow_executor
Mon  7 Nov 07:00:01 GMT 2016
foreman   9372  3.9  8.2 7125624 5438408 ?     Sl   Nov02 263:56 dynflow_executor
Mon  7 Nov 08:00:01 GMT 2016
foreman   9372  3.9  8.2 7125624 5439464 ?     Sl   Nov02 264:07 dynflow_executor
Mon  7 Nov 09:00:01 GMT 2016
foreman   9372  3.8  8.2 7125624 5440256 ?     Sl   Nov02 264:20 dynflow_executor

It might eventually converge, the problem is memory that memory in the Satellite is exhausted way before such convergence is reached.
Customers need to restart the service twice a week to prevent memory exhaustion, which is not reasonable.

Comment 24 Pavel Moravec 2016-12-07 11:06:51 UTC

(In reply to Julio Entrena Perez from comment #23)
> (In reply to Ivan Necas from comment #20)
> > From the testing so far, it also seems
> > that, at the constant triggering of tasks, the memory consumption grow slows
> > down and converges to some size eventually. The size depends on the type of
> > tasks.
> 
> Memory consumption seems to grow until memory is exhausted in the Satellite:
> ..
> It might eventually converge, the problem is memory that memory in the
> Satellite is exhausted way before such convergence is reached.
> Customers need to restart the service twice a week to prevent memory
> exhaustion, which is not reasonable.

That is why http://projects.theforeman.org/issues/17175 is raised - if we suspect the problem is in ruby GC we cant such simply/directly fix, let recycle dynflow executors after consuming given amount of memory.

Comment 25 Ivan Necas 2016-12-07 14:49:03 UTC

Juan, I believe there are multiple issues that can lead to the growth, and no matter, how we tried, we were not able to get to the growth you mention just by running any tasks, and it usualy meant there are isuses in specific tasks that cause the growth. That's we we wrote [1], to provide info about possible known issues that can contribute to it and how to collect useful data for filing a BZ.

From what I've seen, I think it is higher change for this fast growth, there is an issue in specific task, rather than in dynflow/tasks. Please consult [1] and attached bugs there, and file a new bug with the collected data if not there.

[1] - https://access.redhat.com/solutions/2785811

Comment 30 Pavel Moravec 2017-01-06 09:48:46 UTC

FYI similar memory increase observed when synchronizing Capsule: https://bugzilla.redhat.com/show_bug.cgi?id=1410735

While repeatedly synchronizing a fully synced repo from CDN, memory utilization is really really flat.

Can't be the cause behind this BZ and bz1410735 the same? If:

- "package install to another machine" task causes the memory growth
- "capsule sync" task causes the growth
- "repo sync" task does not cause the growth

But I dont see anything what 1st and 2nd scenario has in common but 3rd doesnt have..

Comment 31 Ivan Necas 2017-01-06 14:02:18 UTC

What is also important IMO not the growth, but also the absolute numbers - at what memory values where the repo syncs monitored for memory growth?

Comment 35 Pavel Moravec 2017-01-10 13:14:03 UTC

Following original reproducer on 6.2.6, dynflow_executor memory consumption stayed flat over time - good work!

I would close the BZ but I see #c32 "unresolved" (though I would suggest dealing with it within a support case first). Leaving the closure decision on engineering.

Comment 46 Satellite Program 2017-05-22 16:16:29 UTC

Moving this bug to POST for triage into Satellite 6 since the upstream issue http://projects.theforeman.org/issues/17175 has been resolved.

Comment 48 Satellite Program 2018-02-21 16:54:37 UTC

Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA.
> > 
> > For information on the advisory, and where to find the updated files, follow the link below.
> > 
> > If the solution does not work for you, open a new bug report.
> > 
> > https://access.redhat.com/errata/RHSA-2018:0336

Note You need to log in before you can comment on or make changes to this bug.

aperotti
aruzicka
bbuckingham
bkearney
brubisch
daniele
dcaplan
egolov
inecas
jcallaha
jentrena
jorge_martinez
ktordeur
lzap
oshtaier
pdwyer
pmoravec
sauchter
unwosu
wfoster
xdmoon