Bug 1191487 - repo sync finished with warning on UI and production throws: PLP0000: Importer indicated a failed response (Katello::Errors::PulpError)
Summary: repo sync finished with warning on UI and production throws: PLP0000: Importe...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Satellite
Classification: Red Hat
Component: Repositories
Version: 6.1.0
Hardware: Unspecified
OS: Unspecified
high
medium
Target Milestone: Unspecified
Assignee: Justin Sherrill
QA Contact: Sachin Ghai
URL: http://projects.theforeman.org/issues...
Whiteboard:
: 1193072 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-02-11 11:42 UTC by Sachin Ghai
Modified: 2019-12-16 04:39 UTC (History)
8 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-07-27 11:36:13 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
sync_backtrace under dynflow task status (106.51 KB, image/png)
2015-02-11 11:42 UTC, Sachin Ghai
no flags Details
complete backtrace from production.log (23.60 KB, text/plain)
2015-02-11 11:44 UTC, Sachin Ghai
no flags Details
for rhel65 and rhel66 sync status shows sync incomplete and details sections shows 'Not Found' but at same time sync for fedora is running (33.65 KB, image/png)
2015-02-11 12:42 UTC, Sachin Ghai
no flags Details
sync status says "sync complete' and details says 'yum meta not found' (9.48 KB, image/png)
2015-05-18 12:33 UTC, Sachin Ghai
no flags Details
UI shows sync_incomplete as sync status (31.29 KB, image/png)
2016-05-18 11:29 UTC, Sachin Ghai
no flags Details
sync tasks clearly state error: Error retrieving metadata: Not found (41.26 KB, image/png)
2016-05-18 11:30 UTC, Sachin Ghai
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Foreman Issue Tracker 10396 0 Normal Closed Better display metadata sync issues (404/403) to users 2020-10-30 20:17:07 UTC

Description Sachin Ghai 2015-02-11 11:42:18 UTC
Created attachment 990426 [details]
sync_backtrace under dynflow task status

Description of problem:
I installed sat6.1.0 beta snap2 and synced a custom repo of rhel65. Sync completed on UI with warning message.

production.log filled with long traceback:


Processing by Katello::Api::V2::RepositoriesController#sync_complete as JSON
  Parameters: {"call_report"=>"[FILTERED]", "event_type"=>"repo.sync.finish", "payload"=>{"importer_id"=>"yum_importer", "exception"=>nil, "repo_id"=>"Default_Organization-RHEL6-RHEL65_x86_64", "traceback"=>nil, "started"=>"2015-02-11T05:50:58Z", "_ns"=>"repo_sync_results", "completed"=>"2015-02-11T05:50:59Z", "importer_type_id"=>"yum_importer", "error_message"=>nil, "summary"=>{"content"=>{"state"=>"NOT_STARTED"}, "comps"=>{"state"=>"NOT_STARTED"}, "distribution"=>{"state"=>"NOT_STARTED"}, "errata"=>{"state"=>"NOT_STARTED"}, "metadata"=>{"state"=>"FAILED"}}, "added_count"=>0, "result"=>"failed", "updated_count"=>0, "details"=>{"content"=>{"size_total"=>0, "items_left"=>0, "items_total"=>0, "state"=>"NOT_STARTED", "size_left"=>0, "details"=>{"rpm_total"=>0, "rpm_done"=>0, "drpm_total"=>0, "drpm_done"=>0}, "error_details"=>[]}, "comps"=>{"state"=>"NOT_STARTED"}, "distribution"=>{"items_total"=>0, "state"=>"NOT_STARTED", "error_details"=>[], "items_left"=>0}, "errata"=>{"state"=>"NOT_STARTED"}, "metadata"=>{"state"=>"FAILED", "error"=>"Not Found"}}, "id"=>"54daedc3fc7c820384dd02a5", "removed_count"=>0}, "token"=>"", "api_version"=>"v2", "repository"=>{}}
Sync_complete called for RHEL65_x86_64, running after_sync.
Completed 200 OK in 192ms (Views: 0.3ms | ActiveRecord: 1.2ms)
Polling failed, attempt no. 1, retrying in 0.5
PLP0000: Importer indicated a failed response (Katello::Errors::PulpError)
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0/app/lib/actions/pulp/abstract_async_task.rb:100:in `block in external_task='
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0/app/lib/actions/pulp/abstract_async_task.rb:98:in `each'
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0/app/lib/actions/pulp/abstract_async_task.rb:98:in `external_task='
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action/polling.rb:86:in `poll_external_task_with_rescue'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action/polling.rb:15:in `run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action/cancellable.rb:9:in `run'
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0/app/lib/actions/pulp/abstract_async_task.rb:57:in `run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:443:in `block (3 levels) in execute_run'

Version-Release number of selected component (if applicable):
Satellite-6.1.0-RHEL-6-20150210.0
Sat6.1.0 beta snap2

How reproducible:
always

Steps to Reproduce:
1.
2.
3.

Actual results:
sync failed with long traceback in production.log and UI finished it with 'sync incomplete'

Expected results:
sync should be finished successfully

Additional info:

Comment 1 Sachin Ghai 2015-02-11 11:44:27 UTC
Created attachment 990427 [details]
complete backtrace from production.log

Comment 3 Sachin Ghai 2015-02-11 12:17:11 UTC
Sync for RedHat repo via manifest works fine.
--
Processing by Katello::Api::V2::RepositoriesController#sync_complete as JSON
  Parameters: {"call_report"=>"[FILTERED]", "event_type"=>"repo.sync.finish", "payload"=>{"importer_id"=>"yum_importer", "exception"=>nil, "repo_id"=>"Default_Organization-Red_Hat_Enterprise_Linux_Workstation-Red_Hat_Enterprise_Virtualization_Agents_for_RHEL_6_Workstation_RPMs_x86_64_6Workstation", "traceback"=>nil, "started"=>"2015-02-11T06:32:25Z", "_ns"=>"repo_sync_results", "completed"=>"2015-02-11T06:32:46Z", "importer_type_id"=>"yum_importer", "error_message"=>nil, "summary"=>{"content"=>{"state"=>"FINISHED"}, "comps"=>{"state"=>"FINISHED"}, "distribution"=>{"state"=>"FINISHED"}, "errata"=>{"state"=>"FINISHED"}, "metadata"=>{"state"=>"FINISHED"}}, "added_count"=>76, "result"=>"success", "updated_count"=>0, "details"=>{"content"=>{"size_total"=>3060396, "items_left"=>0, "items_total"=>55, "state"=>"FINISHED", "size_left"=>0, "details"=>{"rpm_total"=>55, "rpm_done"=>55, "drpm_total"=>0, "drpm_done"=>0}, "error_details"=>[]}, "comps"=>{"state"=>"FINISHED"}, "distribution"=>{"items_total"=>0, "state"=>"FINISHED", "error_details"=>[], "items_left"=>0}, "errata"=>{"state"=>"FINISHED"}, "metadata"=>{"state"=>"FINISHED"}}, "id"=>"54daf78efc7c820331acf790", "removed_count"=>0}, "token"=>"", "api_version"=>"v2", "repository"=>{}}
Sync_complete called for Red Hat Enterprise Virtualization Agents for RHEL 6 Workstation RPMs x86_64 6Workstation, running after_sync.
Completed 200 OK in 40ms (Views: 0.2ms | ActiveRecord: 1.3ms)
--

Comment 5 Sachin Ghai 2015-02-11 12:42:53 UTC
Created attachment 990433 [details]
for rhel65 and rhel66 sync status shows sync incomplete and details sections shows 'Not Found' but at same time sync for fedora is running

Comment 7 Mike McCune 2015-02-17 17:34:50 UTC
*** Bug 1193072 has been marked as a duplicate of this bug. ***

Comment 11 Justin Sherrill 2015-03-03 20:27:25 UTC
Sachin,

I am unable to reproduce this on katello nightly upstream nor on a satellite 6.1 build.  Are you able to reproduce?

Comment 12 Justin Sherrill 2015-03-03 20:32:09 UTC
anytime i try to sync a repo that doesn't have a valid repomd.xml file, the task always shows:

Not Found


and i see a proper error in the tasks page showing the details.  Although possibly this is what you are experiencing?

Comment 13 Justin Sherrill 2015-03-03 20:40:25 UTC

Sachin, it would help to know why the sync failed, i can only imagine it was some issue on the repo at the time.


Vagner,  I see now.  I think that the issue was just related to some issues on the cdn at the time.  We occasionally see these and contact the rcm people to fix the issue.

Comment 15 Sachin Ghai 2015-04-20 11:15:55 UTC
@Justin, sorry for replying a bit late.  but I'm not 100% sure about exact steps.. I'll see if I can reproduce this..

Comment 16 Justin Sherrill 2015-05-06 15:28:05 UTC
Connecting redmine issue http://projects.theforeman.org/issues/10396 from this bug

Comment 17 Justin Sherrill 2015-05-06 15:28:55 UTC
I am going to repurpose this bug to better display metadata issues.  Now it will say:

Yum Metadata: Not Found
or
Yum Metadata: Forbidden

Its difficult to specifically call out 'repomd.xml' as pulp doesn't provide that information, but i think specifying 'Yum Metadata' would at least point the person in the right direction.

Comment 18 Bryan Kearney 2015-05-07 14:04:50 UTC
Moving to POST since upstream bug http://projects.theforeman.org/issues/10396 has been closed
-------------
Justin Sherrill
Applied in changeset commit:katello|61d1d1d3770f699d491d47b9cb948b4c4ae3172e.

Comment 21 Sachin Ghai 2015-05-18 12:31:12 UTC
I verified this issue with sat6.1 GA snap4 compose2.

Here are few observations:

1) I tried to reproduce the original issue with an incorrect URL and on syncing with that, I got following error in production.log:

--
2015-05-18 16:51:43 [W] Polling failed, attempt no. 1, retrying in 0.5
2015-05-18 16:51:43 [W] PLP0000: Importer indicated a failed response (Katello::Errors::PulpError)
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.40/app/lib/actions/pulp/abstract_async_task.rb:100:in `block in external_task='
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.40/app/lib/actions/pulp/abstract_async_task.rb:98:in `each'
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.40/app/lib/actions/pulp/abstract_async_task.rb:98:in `external_task='
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.5/lib/dynflow/action/polling.rb:89:in `poll_external_task_with_rescue'
---

2) UI says under sync_status page under 'Details': "Yum Metadata: Not Found and result is: Sync Complete'. Please see the screenshot


I see that error message is improved in webUI but production.log still throws the same error as mentioned in original bug description. Is is expected ?

Also, when UI says "Yum Meatadata: Not found" then I think sync status shouldn't be 'Sync complete'. Its misleading I think.

Please suggest what is expected here ?

Comment 22 Sachin Ghai 2015-05-18 12:33:33 UTC
Created attachment 1026687 [details]
sync status says "sync complete' and details says 'yum meta not found'

Comment 24 jnikolak 2015-05-27 04:57:22 UTC
I verified this issue by noticing that another member disabled dns. in /etc/resolv.conf
I then also verified that shortname was disabled in /etc/hosts

Then once i enabled everything ran a few tests

ping $(hostname -f)
ping $(hostname -d)
ping $(hostname -s)

than re-ran the synchronisation and the error didn't appear.

Comment 25 Justin Sherrill 2015-05-28 20:36:26 UTC
Sachin,

That is the result of the structure of the tasking system and I think we should try to overcome it, however I would say lets open another bz for that.  

Are you okay with that?

Comment 26 Sachin Ghai 2015-06-08 11:55:14 UTC
@Justin: yeah. I filed this bz for incorrect status:

https://bugzilla.redhat.com/show_bug.cgi?id=1229290

However, I still believe that error message in production.log should be improved:

currently, its throwing error:

2015-06-08 07:48:39 [W] Polling failed, attempt no. 1, retrying in 0.5
2015-06-08 07:48:39 [W] PLP0000: Importer indicated a failed response (Katello::Errors::PulpError)
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.45/app/lib/actions/pulp/abstract_async_task.rb:100:in `block in external_task='
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.45/app/lib/actions/pulp/abstract_async_task.rb:98:in `each'

However, it should throw same error that we are showing in webUI i.e.

Yum Metadata: Not Found

Comment 28 Bryan Kearney 2015-07-10 15:33:34 UTC
Based on comment 26, the bug is now improving the error message. I am reducing to medium, and pushing out.

Comment 30 Thom Carlin 2015-11-25 23:35:17 UTC
Also occurs for katello-disconnected.

Comment 31 Bryan Kearney 2016-02-02 11:11:12 UTC
Upstream bug assigned to jsherril

Comment 32 Bryan Kearney 2016-02-02 11:11:16 UTC
Upstream bug component is WebUI

Comment 33 Bryan Kearney 2016-02-05 19:10:47 UTC
Upstream bug component is WebUI

Comment 34 Justin Sherrill 2016-03-16 19:16:16 UTC
Pulp is now returning 'Error retrieving metadata: Not found ' which gets logged to /var/log/messages and /var/log/foreman/production.log

In addition the sync now shows as 'Sync Incomplete' and the sync task is in a warning state. 

Moving to ON_QA

Comment 35 Sachin Ghai 2016-05-18 11:27:56 UTC
Verified with sat62 GA snap11

Now error is improved. I'm getting: 'Error retrieving metadata: Not found ' with sync tasks and sync status on webUI shows as 'Sync Incomplete'. Please see screenshot for verification.

Comment 36 Sachin Ghai 2016-05-18 11:28:49 UTC
also production.log throws proper error too:

2016-05-18 07:25:55 [app] [I] Started GET "/katello/sync_management/sync_status?repoids%5B%5D=39&_=1463570749203" for 10.65.223.218 at 2016-05-18 07:25:55 -0400
2016-05-18 07:25:55 [app] [I] Processing by Katello::SyncManagementController#sync_status as JSON
2016-05-18 07:25:55 [app] [I]   Parameters: {"repoids"=>["39"], "_"=>"1463570749203"}
2016-05-18 07:25:55 [app] [I] Completed 200 OK in 36ms (Views: 0.1ms | ActiveRecord: 4.1ms)
2016-05-18 07:25:56 [foreman-tasks/action] [E] RPM1004: Error retrieving metadata: Not found (Katello::Errors::PulpError)
 |

Comment 37 Sachin Ghai 2016-05-18 11:29:29 UTC
Created attachment 1158732 [details]
UI shows sync_incomplete as sync status

Comment 38 Sachin Ghai 2016-05-18 11:30:39 UTC
Created attachment 1158733 [details]
sync tasks clearly state error: Error retrieving metadata: Not found

Comment 39 Sachin Ghai 2016-05-18 11:31:13 UTC
Thanks Justin for fix.

Moving this to verified.

Comment 40 Bryan Kearney 2016-07-27 11:36:13 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-2016:1501


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