Bug 1994923
| Summary: | Internal server error when accessing kickstart repository over http or https (db connection already closed) | ||
|---|---|---|---|
| Product: | Red Hat Satellite | Reporter: | Kenny Tordeurs <ktordeur> |
| Component: | Pulp | Assignee: | satellite6-bugs <satellite6-bugs> |
| Status: | CLOSED ERRATA | QA Contact: | Lai <ltran> |
| Severity: | high | Docs Contact: | |
| Priority: | high | ||
| Version: | 6.10.0 | CC: | ahumbe, egolov, ggainey, inecas, jsherril, mdellweg, osousa, pcreech, rchan, sshtein, ttereshc |
| Target Milestone: | 6.10.0 | Keywords: | Regression, Triaged |
| Target Release: | Unused | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | python-pulpcore-3.14.5 | Doc Type: | If docs needed, set a value |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2021-11-16 14:13:21 UTC | Type: | Bug |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
|
Description
Kenny Tordeurs
2021-08-18 07:59:09 UTC
Traceback in logs during the request: Aug 18 09:42:49 ktordeur-testathon pulpcore-content: [2021-08-18 08:42:49 +0000] [27629] [ERROR] Error handling request Aug 18 09:42:49 ktordeur-testathon pulpcore-content: Traceback (most recent call last): Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/backends/base/base.py", line 235, in _cursor Aug 18 09:42:49 ktordeur-testathon pulpcore-content: return self._prepare_cursor(self.create_cursor(name)) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/backends/postgresql/base.py", line 223, in create_cursor Aug 18 09:42:49 ktordeur-testathon pulpcore-content: cursor = self.connection.cursor() Aug 18 09:42:49 ktordeur-testathon pulpcore-content: psycopg2.InterfaceError: connection already closed Aug 18 09:42:49 ktordeur-testathon pulpcore-content: The above exception was the direct cause of the following exception: Aug 18 09:42:49 ktordeur-testathon pulpcore-content: Traceback (most recent call last): Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib64/python3.6/site-packages/aiohttp/web_protocol.py", line 422, in _handle_request Aug 18 09:42:49 ktordeur-testathon pulpcore-content: resp = await self._request_handler(request) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib64/python3.6/site-packages/aiohttp/web_app.py", line 499, in _handle Aug 18 09:42:49 ktordeur-testathon pulpcore-content: resp = await handler(request) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/pulpcore/content/handler.py", line 212, in stream_content Aug 18 09:42:49 ktordeur-testathon pulpcore-content: return await self._match_and_stream(path, request) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/pulpcore/content/handler.py", line 443, in _match_and_stream Aug 18 09:42:49 ktordeur-testathon pulpcore-content: distro = await loop.run_in_executor(None, match_distribution_blocking) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib64/python3.6/concurrent/futures/thread.py", line 56, in run Aug 18 09:42:49 ktordeur-testathon pulpcore-content: result = self.fn(*self.args, **self.kwargs) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/pulpcore/content/handler.py", line 441, in match_distribution_blocking Aug 18 09:42:49 ktordeur-testathon pulpcore-content: return self._match_distribution(path) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/pulpcore/content/handler.py", line 256, in _match_distribution Aug 18 09:42:49 ktordeur-testathon pulpcore-content: .get(base_path__in=base_paths) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/models/query.py", line 402, in get Aug 18 09:42:49 ktordeur-testathon pulpcore-content: num = len(clone) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/models/query.py", line 256, in __len__ Aug 18 09:42:49 ktordeur-testathon pulpcore-content: self._fetch_all() Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/models/query.py", line 1242, in _fetch_all Aug 18 09:42:49 ktordeur-testathon pulpcore-content: self._result_cache = list(self._iterable_class(self)) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/models/query.py", line 55, in __iter__ Aug 18 09:42:49 ktordeur-testathon pulpcore-content: results = compiler.execute_sql(chunked_fetch=self.chunked_fetch, chunk_size=self.chunk_size) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/models/sql/compiler.py", line 1140, in execute_sql Aug 18 09:42:49 ktordeur-testathon pulpcore-content: cursor = self.connection.cursor() Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/backends/base/base.py", line 256, in cursor Aug 18 09:42:49 ktordeur-testathon pulpcore-content: return self._cursor() Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/backends/base/base.py", line 235, in _cursor Aug 18 09:42:49 ktordeur-testathon pulpcore-content: return self._prepare_cursor(self.create_cursor(name)) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/utils.py", line 89, in __exit__ Aug 18 09:42:49 ktordeur-testathon pulpcore-content: raise dj_exc_value.with_traceback(traceback) from exc_value Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/backends/base/base.py", line 235, in _cursor Aug 18 09:42:49 ktordeur-testathon pulpcore-content: return self._prepare_cursor(self.create_cursor(name)) Aug 18 09:42:49 ktordeur-testathon pulpcore-content: File "/usr/lib/python3.6/site-packages/django/db/backends/postgresql/base.py", line 223, in create_cursor Aug 18 09:42:49 ktordeur-testathon pulpcore-content: cursor = self.connection.cursor() Aug 18 09:42:49 ktordeur-testathon pulpcore-content: django.db.utils.InterfaceError: connection already closed Aug 18 09:42:49 ktordeur-testathon pulpcore-content: [18/Aug/2021:08:42:49 +0000] "GET /pulp/content/Default_Organization/Library/content/dist/rhel8/8.4/x86_64/appstream/kickstart/ HTTP/1.1" 500 334 "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.159 Safari/537.36" the interesting part is "connection already closed", so something decided to close the PSQL connection, and then it tried to re-use it. restarting the pulpcore-content app made it work (well, spew other errors) again, but it would be super interesting to know what triggered the closed connection Seems the issue got fixed by doing: # systemctl restart pulpcore-content However hammer ping and all other services seemed fine aside from the logs in `# journalctl -u pulpcore-content` observed in https://bugzilla.redhat.com/show_bug.cgi?id=1994923#c5 I was able to browse the ks afterwards and provision a new host. It would be good to see if this patch helps. I was not able to reproduce issue locally. https://patch-diff.githubusercontent.com/raw/pulp/pulpcore/pull/1567.patch The Pulp upstream bug status is at POST. Updating the external tracker on this bug. The Pulp upstream bug priority is at High. Updating the external tracker on this bug. The Pulp upstream bug status is at NEW. Updating the external tracker on this bug. The Pulp upstream bug priority is at High. Updating the external tracker on this bug. (In reply to Tanya Tereshchenko from comment #10) > It would be good to see if this patch helps. I was not able to reproduce > issue locally. > https://patch-diff.githubusercontent.com/raw/pulp/pulpcore/pull/1567.patch I will attempt the patch as soon as I encounter the issue again, I'm not sure which set of conditions triggered it The Pulp upstream bug status is at MODIFIED. Updating the external tracker on this bug. All upstream Pulp bugs are at MODIFIED+. Moving this bug to POST. The Pulp upstream bug status is at CLOSED - CURRENTRELEASE. Updating the external tracker on this bug. I followed what was in the description for testing. After syncing the kickstarter repo, I was able to access both http and https without getting any sort of error. Verified with python3-pulpcore-3.14.5-2.el7pc.noarch on 6.10_016 It's possible that the following issues are related to the issue that was encountered here: https://projects.theforeman.org/issues/33703 https://pulp.plan.io/issues/9515 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 (Moderate: Satellite 6.10 Release), 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-2021:4702 |