Bug 1399605 - package listing broken
Summary: package listing broken
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Update Infrastructure for Cloud Providers
Classification: Red Hat
Component: Documentation
Version: 3.0.0
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: ---
: 3.0.0
Assignee: Les Williams
QA Contact: Radek Bíba
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-11-29 11:56 UTC by Peter J
Modified: 2019-05-27 20:51 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: Known Issue
Doc Text:
Cause: High memory usage on searching repositories with a large number of rpms Consequence: Out of memory exceptions on low-ram machines Workaround (if any): Provide enough ram to search larger repositories. Result:
Clone Of:
Environment:
Last Closed: 2017-03-01 22:14:21 UTC
Target Upstream Version:


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2017:0367 normal SHIPPED_LIVE Red Hat Update Infrastructure 3.0 Release 2017-03-02 03:05:22 UTC

Description Peter J 2016-11-29 11:56:56 UTC
Description of problem:
While trying to list packages in repositories with huge amount of packages
example: Red Hat Enterprise Linux 7 Server from RHUI (RPMs) (7Server-x86_64)
rhui-manager reports an error:
An unexpected error has occurred during the last operation.
More information can be found in /root/.rhui/rhui.log.

Version-Release number of selected component (if applicable):
RHUI 3 Beta - RHUI-3.0-RHEL-7-20161012.0-RHUI-x86_64-dvd1.iso
RHEL 7.2

How reproducible:


Steps to Reproduce:
expecting that repo is already added and synced
1. start rhui-manager
2. press 'r' for repository management
3. press 'p' for listing
4. choose repository
5. use any filter - I used 'javapackages' - or no filter

Actual results:
An unexpected error has occurred during the last operation.
More information can be found in /root/.rhui/rhui.log.

Expected results:
Proper outpu, like list of packages/count/no packages

Additional info:

Error in rhui.log

2016-11-29 12:31:01,271 - Unexpected error caught at the shell level
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/rhui/tools/shell.py", line 88, in safe_
listen
    self.listen(clear=first_run)
  File "/usr/lib/python2.7/site-packages/rhui/tools/shell.py", line 122, in list
en
    Shell.listen(self)
  File "/usr/lib/python2.7/site-packages/rhui/common/shell.py", line 186, in listen
    item.func(*args, **item.kwargs)
  File "/usr/lib/python2.7/site-packages/rhui/tools/screens/repo.py", line 702, in packages
    packages = self.pulp.packages(repo_id)
  File "/usr/lib/python2.7/site-packages/rhui/tools/pulp_api.py", line 906, in packages
    rtn = self.repo_unit_api.search(repo_id).response_body
  File "/usr/lib/python2.7/site-packages/pulp/bindings/repository.py", line 484, in search
    return self.server.POST(path, data)
  File "/usr/lib/python2.7/site-packages/pulp/bindings/server.py", line 100, in POST
    log_request_body=log_request_body, ignore_prefix=ignore_prefix)
  File "/usr/lib/python2.7/site-packages/pulp/bindings/server.py", line 166, in _request
    self._handle_exceptions(response_code, response_body)
  File "/usr/lib/python2.7/site-packages/pulp/bindings/server.py", line 202, in _handle_exceptions
    raise exceptions.ApacheServerException(response_body)
ApacheServerException

Comment 1 Peter J 2016-11-29 12:02:31 UTC
pulp-https_access_ssl.log:
IP - - [29/Nov/2016:12:27:41 +0100] "POST /pulp/api/v2/repositories/
rhel-7-server-rhui-rpms-7Server-x86_64/search/units/ HTTP/1.1" 200 795635839 "-" "-"

pulp-https_error_ssl.log:
[Tue Nov 29 12:31:01.119521 2016] [core:error] [pid 27139] [client IP:33802] End of script output before headers: webservices.wsgi

Comment 4 Irina Gulina 2016-12-01 14:09:36 UTC
Reproduced on iso 20161122

rhui (repo) => i

Select one or more repositories:

  Custom Repositories

  Red Hat Repositories
    -  1 : Red Hat Enterprise Linux Server 5 (RPMs) (5Server-x86_64)

Enter value (1-1) to toggle selection, 'c' to confirm selections, or '?' for more commands: a

Select one or more repositories:

  Custom Repositories

  Red Hat Repositories
    x  1 : Red Hat Enterprise Linux Server 5 (RPMs) (5Server-x86_64)

Enter value (1-1) to toggle selection, 'c' to confirm selections, or '?' for more commands: c


Name:                Red Hat Enterprise Linux Server 5 (RPMs) (5Server-x86_64)
Type:                Red Hat
Relative Path:       content/dist/rhel/rhui/server/5/5Server/x86_64/os
GPG Check:           Yes
Custom GPG Keys:     (None)
Red Hat GPG Key:     Yes
Package Count:       20523
Last Sync:           12-01-2016 08:06
Next Sync:           12-01-2016 12:22


------------------------------------------------------------------------------
rhui (repo) => p

Choose a repository:
  1  - Red Hat Enterprise Linux Server 5 (RPMs) (5Server-x86_64)
Enter value (1-1) or 'b' to abort: 1

Enter the first few characters (case insensitive) of an RPM to filter the results
(blank line for no filter):
a

Wait for very long:

An unexpected error has occurred during the last operation.
More information can be found in /root/.rhui/rhui.log..

2016-11-29 17:26:35,592 - Unexpected error caught at the shell level
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/rhui/tools/shell.py", line 88, in safe_listen
    self.listen(clear=first_run)
  File "/usr/lib/python2.7/site-packages/rhui/tools/shell.py", line 127, in listen
    Shell.listen(self)
  File "/usr/lib/python2.7/site-packages/rhui/common/shell.py", line 186, in listen
    item.func(*args, **item.kwargs)
  File "/usr/lib/python2.7/site-packages/rhui/tools/screens/repo.py", line 836, in packages
    packages = self.pulp.packages(repo_id)
  File "/usr/lib/python2.7/site-packages/rhui/tools/pulp_api.py", line 922, in packages
    rtn = self.repo_unit_api.search(repo_id).response_body
  File "/usr/lib/python2.7/site-packages/pulp/bindings/repository.py", line 484, in search
    return self.server.POST(path, data)
  File "/usr/lib/python2.7/site-packages/pulp/bindings/server.py", line 100, in POST
    log_request_body=log_request_body, ignore_prefix=ignore_prefix)
  File "/usr/lib/python2.7/site-packages/pulp/bindings/server.py", line 166, in _request
    self._handle_exceptions(response_code, response_body)
  File "/usr/lib/python2.7/site-packages/pulp/bindings/server.py", line 202, in _handle_exceptions
    raise exceptions.ApacheServerException(response_body)
ApacheServerException

Comment 5 Patrick Creech 2016-12-01 19:01:26 UTC
The issue here appears to be a ram limitation.  I was able to reproduce on a low ram/swap (1G/2G), but after giving the same machine 16G ram, the exception no longer happened.

With large repositories, there is a large memory spike in pulp during the searching.  Utilizing a more limiting filter and providing more ram to the machine should help alleviate the problem

Comment 6 Peter J 2016-12-02 09:49:58 UTC
I can confirm that.
There is huge memory usage during search.
For the RHEL7 I had to increase memory to 8GB, however that was not enough for RHEL6 repositories, and I had to go up to 12GB.

Ignoring the fact that a search feature requires 12GB of memory (good candidate for some optimization?), it would be a good idea to update Prerequisites
https://access.redhat.com/documentation/en/red-hat-update-infrastructure/3.0.beta.1/paged/system-administrator-guide/chapter-3-prerequisites
since 4GB is obviously not enough. 16GB minimum I would say. At least note it somewhere.

And there is no proper memory deallocation/trash collection after the search finishes.

1st search in RHEL6 server repo
Memory utilization before 1st search: ~1GB used
Memory utilization after 1st search: ~7GB used

2nd search in RHEL6 server repo,
2nd search failed hitting the memory limit.
Memory utilization after 2nd search: ~9GB used

The workaround is to quit rhui-manager after every search, otherwise the allocated memory from previous searches will not get freed up ever.
After 3 hours the pulp's apache still has over 7GB allocated from the 1st search.
# top
 PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 2950 apache    20   0 9023828 7.595g   1904 S   0.3 49.0   1:06.20 httpd

# ps -q 2950 --cols 400 -o comm,args
COMMAND         COMMAND
httpd           (wsgi:pulp)     -DFOREGROUND

Comment 7 Patrick Creech 2016-12-02 13:19:04 UTC
The unfortunate item here is that python doesn't return memory back to the OS after it has allocated it.  While the objects themselves have been cleared, python will hold this memory for future use until the interpreter process exits.

This explains why when you close rhui-manager the memory drops.  It's python process has ended.  If you restart httpd the python wsgi process will release it's memory back to the OS as well.

This is an unfortunate but well documented issue with long running python processes that require large amounts of memory for only a short period of time.

The good news is the memory won't continue to grow endlessly.  Once all python processes have consumed the ram, it will hit an equilibrium, and not consume any more.  We just have to set system requirements appropriately

Since we have identified this issue, I will work with the docs team to ensure this requirement is documented properly.

Comment 8 Peter J 2016-12-02 14:16:21 UTC
While the memory fragmentation is known, it was fixed in python3.3.
http://bugs.python.org/issue11849

For older versions of python (since it is well known) there are many possible workarounds to get around the python memory management.
The first step should be really changing the algorithm so searching for a package does not need 12GB of memory (seriously, what do you store in that 12GB???).
Second step would be to use child processes, so when the job is done the memory gets freed.

It really does not seem right, when I ran a second search, the memory allocation immediately starts to grow, if the memory would be marked as free (cached) in python memory management, it should reuse it and not allocating new one immediately.

I hope the code will get some improvements in time, so I don't have to set a cron job to reboot apache each night.

Comment 9 Patrick Creech 2016-12-05 14:18:00 UTC
The underlying issue here is not in any code that RHUI maintains, unfortunately.  

The issue is in the underlying Pulp software that RHUI utilizes to manage repositories.  With that being said, they are aware of the memory utilization problems.  They are already taking strides to ensure better performance in future versions, as well as going through a major technology refactoring right now.  Future versions of pulp will utilize newer version of the python interpreter and will have an improved database access layer.  We have addressed our concerns over memory management with them and will continue to follow up.

As far as the second search's memory growing as well, there is more than one Python wsgi process that you are hitting up.  Since this memory issue is on a per-process basis, memory usage will grow for each process until it hits an equilibrium.

We will document this issue for now, and will work with the Pulp team to hopefully provide a better memory footprint in future versions.

Comment 14 errata-xmlrpc 2017-03-01 22:14:21 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/RHBA-2017:0367


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