Bug 2047485
| Summary: | syncing repo using proxy can generate misleading log entries when proxy deny access to the url requested | ||
|---|---|---|---|
| Product: | Red Hat Satellite | Reporter: | Joniel Pasqualetto <jpasqual> |
| Component: | Pulp | Assignee: | satellite6-bugs <satellite6-bugs> |
| Status: | CLOSED ERRATA | QA Contact: | Lai <ltran> |
| Severity: | high | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 6.10.1 | CC: | alsouza, dalley, dkliban, ggainey, pcreech, rchan |
| Target Milestone: | 6.11.0 | Keywords: | Triaged |
| Target Release: | Unused | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | pulpcore-3.16.8 | Doc Type: | If docs needed, set a value |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2022-07-05 14:32:26 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: | |||
It's not really misleading. The part that fails is the HTTP "CONNECT" call which initializes the proxy tunnel, and this is indeed the URL that the "CONNECT" call is sent to. The remote URL is completely irrelevant to the error itself because no requests have been sent there yet. Changing the URL would make it misleading in the opposite direction because it's really the proxy which is the issue, not the remote url. It might be reasonable to give the user more awareness of which Remote is involved so that they could possibly turn off the proxy, but even then it's a minor misdirection because any Remote using that proxy will likely fail in the same way. Passing this back to you Joniel, not sure what the best action to take is here. Hello dalley When a CONNECT is sent, it goes with a destination host (the relative path we're going to fetch is not part of it, but the host is). For example, curl does it like this: ~~~ # curl -v https://cdn.redhat.com -k * About to connect() to proxy squid.redhat.com port 3128 (#0) * Trying 10.5.30.88... * Connected to squid.redhat.com (10.5.30.88) port 3128 (#0) * Establish HTTP proxy tunnel to cdn.redhat.com:443 > CONNECT cdn.redhat.com:443 HTTP/1.1 <==================== destination is part of the connect request > Host: cdn.redhat.com:443 > User-Agent: curl/7.29.0 > Proxy-Connection: Keep-Alive > < HTTP/1.0 200 Connection established < ~~~ Not knowing what was the complete request that was blocked complicates the troubleshooting process. Also, when talking about a URL for a user perspective, the proxy is not part of it. What about we get a log that says something like "error trying to connect to <remote host from remote URL> via <proxy URL>. That'd be super clear! 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.11 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-2022:5498 |
Description of problem: The error message returned by pulp when a proxy used to sync returns a 403 is not clear and very misleading. Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: pulp [7b674fa5-dac2-4ca1-ac25-891cfe108f56]: backoff:ERROR: Giving up download_wrapper(...) after 1 tries (aiohttp.client_exceptions.ClientHttpProxyError: 403, message='Forbidden', url=URL('http://127.0.0.1:3128')) The URL shows the proxy address instead of the actual URL trying to be synced. Version-Release number of selected component (if applicable): How reproducible: Steps to Reproduce: 1. Configure the repository to use a proxy 2. Ensure the proxy won't allow pulp to access the URL and will return a 403 3. Launch the sync Actual results: Sync fails, with misleading error messages: ~~~ Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: Giving up download_wrapper(...) after 1 tries (aiohttp.client_exceptions.ClientHttpProxyError: 403, message='Forbidden', url=URL('http://127.0.0.1:3128')) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: pulp [7b674fa5-dac2-4ca1-ac25-891cfe108f56]: backoff:ERROR: Giving up download_wrapper(...) after 1 tries (aiohttp.client_exceptions.ClientHttpProxyError: 403, message='Forbidden', url=URL('http://127.0.0.1:3128')) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: pulp [7b674fa5-dac2-4ca1-ac25-891cfe108f56]: pulp_rpm.app.tasks.synchronizing:INFO: Attempting to resolve a true url from potential mirrolist url 'https://cdn.redhat.com/content/dist/rhel/server/7/7Server/x86_64/sat-tools/6.10/os' Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: Giving up download_wrapper(...) after 1 tries (aiohttp.client_exceptions.ClientHttpProxyError: 403, message='Forbidden', url=URL('http://127.0.0.1:3128')) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: pulp [7b674fa5-dac2-4ca1-ac25-891cfe108f56]: backoff:ERROR: Giving up download_wrapper(...) after 1 tries (aiohttp.client_exceptions.ClientHttpProxyError: 403, message='Forbidden', url=URL('http://127.0.0.1:3128')) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: pulp [7b674fa5-dac2-4ca1-ac25-891cfe108f56]: pulpcore.tasking.pulpcore_worker:INFO: Task bd7efea8-e60a-4b4a-8f6c-b82e44dbc579 failed (403, message='Forbidden', url=URL('http://127.0.0.1:3128')) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: pulp [7b674fa5-dac2-4ca1-ac25-891cfe108f56]: pulpcore.tasking.pulpcore_worker:INFO: File "/usr/lib/python3.6/site-packages/pulpcore/tasking/pulpcore_worker.py", line 317, in _perform_task Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: result = func(*args, **kwargs) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 425, in synchronize Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: remote_url = fetch_remote_url(remote) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 289, in fetch_remote_url Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: remote_url = fetch_mirror(remote) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 247, in fetch_mirror Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: result = downloader.fetch() Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib/python3.6/site-packages/pulpcore/download/base.py", line 177, in fetch Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: return done.pop().result() Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib/python3.6/site-packages/pulpcore/download/http.py", line 264, in run Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: return await download_wrapper() Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib/python3.6/site-packages/backoff/_async.py", line 133, in retry Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: ret = await target(*args, **kwargs) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib/python3.6/site-packages/pulpcore/download/http.py", line 260, in download_wrapper Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: return await self._run(extra_data=extra_data) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib/python3.6/site-packages/pulp_rpm/app/downloaders.py", line 105, in _run Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: self.url, proxy=self.proxy, proxy_auth=self.proxy_auth, auth=self.auth Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib64/python3.6/site-packages/aiohttp/client.py", line 1117, in __aenter__ Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: self._resp = await self._coro Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib64/python3.6/site-packages/aiohttp/client.py", line 521, in _request Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: req, traces=traces, timeout=real_timeout Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib64/python3.6/site-packages/aiohttp/connector.py", line 535, in connect Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: proto = await self._create_connection(req, traces, timeout) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib64/python3.6/site-packages/aiohttp/connector.py", line 890, in _create_connection Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: _, proto = await self._create_proxy_connection(req, traces, timeout) Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: File "/usr/lib64/python3.6/site-packages/aiohttp/connector.py", line 1129, in _create_proxy_connection Jan 27 16:47:29 import-export-sat.usersys.redhat.com pulpcore-worker-2[16394]: headers=resp.headers, ~~~ Expected results: Better handling of the error and clear error message indicating that the proxy returned an <HTTP ERRORCODE> when <REPO URL> was requested. Additional info: