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
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
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
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
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
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.
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.
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.
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