Bug 767281

Summary:	Need better error handling for errors during sync
Product:	Red Hat Satellite	Reporter:	Mike McCune <mmccune>
Component:	WebUI	Assignee:	Jason E. Rist <jrist>
Status:	CLOSED CURRENTRELEASE	QA Contact:	Corey Welton <cwelton>
Severity:	high	Docs Contact:
Priority:	unspecified
Version:	6.0.1	CC:	cwelton, mmccune, sreichar
Target Milestone:	Unspecified	Keywords:	Triaged
Target Release:	Unused
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2012-08-22 18:13:36 UTC	Type:	---
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	747354, 767841

Description Mike McCune 2011-12-13 17:33:32 UTC

If a sync fails to fetch one or more of the packages during a sync we don't show these errors in the UI in any way and pulp gives up on the sync

An example would be we see here grinder got a bad package from the CDN:

grinder.log.2:2011-12-12 17:03:24,178 19902:139908981147392: grinder.ProgressTracker:WARNING: ProgressTracker:126 Modifying size information for <https://cdn.redhat.com/content/dist/rhel/server/6/6.1/x86_64/os/Packages/net-snmp-5.5-31.el6.x86_64.rpm>. original size = <305252>, new size = <419.0>, diff_in_size = <-304833.0>
grinder.log.2:2011-12-12 17:03:24,179 19902:139908981147392: grinder.BaseFetch:ERROR: activeobject:160 net-snmp-5.5-31.el6.x86_64.rpm size mismatch, read: 419 bytes, was expecting 305252 bytes
grinder.log.2:2011-12-12 17:03:24,179 19902:139908981147392: grinder.BaseFetch:WARNING: activeobject:160 Retrying fetch of: net-snmp-5.5-31.el6.x86_64.rpm with 1 retry attempts left.
grinder.log.2:2011-12-12 17:03:24,180 19902:139908981147392: grinder.BaseFetch:INFO: activeobject:160 Fetching 305252 bytes: net-snmp-5.5-31.el6.x86_64.rpm from https://cdn.redhat.com/content/dist/rhel/server/6/6.1/x86_64/os/Packages/net-snmp-5.5-31.el6.x86_64.rpm
grinder.log.2:2011-12-12 17:03:24,742 19902:139908981147392: grinder.BaseFetch:WARNING: activeobject:160 ERROR: Response = 403 fetching https://cdn.redhat.com/content/dist/rhel/server/6/6.1/x86_64/os/Packages/net-snmp-5.5-31.el6.x86_64.rpm.

we need Pulp to continue trying to sync the remainder of the repo and we need to report this error up to the user in Katello.

Comment 1 Jason E. Rist 2012-01-11 19:37:05 UTC

Had to create a repo to test this.  You need to remove an RPM in the middle so that the metadata for the repo doesn't match the RPM to test this.

repo creation:
1) grab a pile of RPMs from somewhere, rhel, fedora, whatever
2) put them in a directory
3) cd to that directory
4) run 'createrepo .'
6) move that dir  (plus subdir and all files) to a WWW accessible location where your katello server can get to it 

During sync rm one of the files.  You'll see the error in /var/lib/pulp/grinder.log and /var/lib/pulp/pulp.log

grinder:
2012-01-11 11:26:02,157 12074:139841626949376: grinder.ParallelFetch:INFO: ParallelFetch:361 Thread ending
2012-01-11 11:26:02,522 12074:139841610163968: grinder.BaseFetch:ERROR: activeobject:169 cow-2.2-3.noarch.rpm size mismatch, read: 344 bytes, was expecting 2249 bytes
2012-01-11 11:26:02,522 12074:139841610163968: grinder.BaseFetch:WARNING: activeobject:169 Retrying fetch of: cow-2.2-3.noarch.rpm with 1 retry attempts left.
2012-01-11 11:26:02,523 12074:139841610163968: grinder.BaseFetch:INFO: activeobject:169 Fetching 2249 bytes: cow-2.2-3.noarch.rpm from http://jrist.fedorapeople.org/ktrepo/cow-2.2-3.noarch.rpm
2012-01-11 11:26:02,905 12074:139841610163968: grinder.BaseFetch:ERROR: activeobject:169 cow-2.2-3.noarch.rpm size mismatch, read: 344 bytes, was expecting 2249 bytes
2012-01-11 11:26:02,905 12074:139841610163968: grinder.BaseFetch:WARNING: activeobject:169 Retrying fetch of: cow-2.2-3.noarch.rpm with 0 retry attempts left.
2012-01-11 11:26:02,906 12074:139841610163968: grinder.BaseFetch:INFO: activeobject:169 Fetching 2249 bytes: cow-2.2-3.noarch.rpm from http://jrist.fedorapeople.org/ktrepo/cow-2.2-3.noarch.rpm
2012-01-11 11:26:03,284 12074:139841610163968: grinder.BaseFetch:ERROR: activeobject:169 cow-2.2-3.noarch.rpm size mismatch, read: 344 bytes, was expecting 2249 bytes
2012-01-11 11:26:03,284 12074:139841610163968: grinder.BaseFetch:WARNING: activeobject:169 ERROR: Response = 404 fetching http://jrist.fedorapeople.org/ktrepo/cow-2.2-3.noarch.rpm.
2012-01-11 11:26:03,285 12074:139841610163968: grinder.ParallelFetch:INFO: ParallelFetch:165 1 threads are active. 1 items left to be fetched
2012-01-11 11:26:03,285 12074:139841610163968: grinder.ParallelFetch:INFO: ParallelFetch:346 WorkerThread deleting ActiveObject
2012-01-11 11:26:03,289 12074:139841610163968: grinder.ParallelFetch:INFO: ParallelFetch:361 Thread ending
2012-01-11 11:26:03,464 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:258 All threads have finished.
2012-01-11 11:26:03,465 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:277 ParallelFetch: 31 items successfully processed, 0 downloaded, 1 items had errors
2012-01-11 11:26:03,465 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:280 Transferred [72920] bytes of [rpm]
2012-01-11 11:26:03,465 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:281 Transferred [72920] total bytes in 6.56636500359 seconds
2012-01-11 11:26:03,465 12074:139841643734784: grinder.RepoFetch:INFO: RepoFetch:197 Finalizing metadata, moving /var/lib/pulp//repos/ACME_Corporation/Locker/custom/ktrepo2/ktrepo2//repodata.new to /var/lib/pulp//repos/ACME_Corporation/Locker/custom/ktrepo2/ktrepo2//repodata
2012-01-11 11:26:03,468 12074:139841643734784: grinder.RepoFetch:INFO: RepoFetch:151 Cleaning any orphaned packages..
2012-01-11 11:26:03,470 12074:139841643734784: grinder.RepoFetch:INFO: RepoFetch:156 Processed <32> items in [6] seconds. Report: 31 successes, 0 downloads, 1 errors
2012-01-11 11:26:03,470 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:227 Grinder stopping
2012-01-11 11:26:03,470 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:309 stop() invoked
2012-01-11 11:26:03,470 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:319 stop() completed
2012-01-11 11:26:03,470 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:231 Told thread <<WorkerThread(Thread-73, stopped daemon 139841610163968)>> to stop
2012-01-11 11:26:03,470 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:309 stop() invoked
2012-01-11 11:26:03,471 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:319 stop() completed
2012-01-11 11:26:03,471 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:231 Told thread <<WorkerThread(Thread-74, stopped daemon 139841626949376)>> to stop
2012-01-11 11:26:03,471 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:309 stop() invoked
2012-01-11 11:26:03,471 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:319 stop() completed
2012-01-11 11:26:03,471 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:231 Told thread <<WorkerThread(Thread-75, stopped daemon 139841635342080)>> to stop
2012-01-11 11:26:03,471 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:309 stop() invoked
2012-01-11 11:26:03,471 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:319 stop() completed
2012-01-11 11:26:03,471 12074:139841643734784: grinder.ParallelFetch:INFO: ParallelFetch:231 Told thread <<WorkerThread(Thread-76, stopped daemon 139841618556672)>> to stop

pulp:
2012-01-11 11:20:56,818 12074:139841643734784: pulp.server.api.synchronizers:INFO: synchronizers:640 YumSynchronizer reported 31 successes, 0 downloads, 1 errors

Fixed to bubble up the issue from grinder to katello.  Rails log, JSON returned from sync, and notice now show up in katello.

commit b0126457e03aa1b198cb8f20d0555cc1e7ba9e2e
Author: Jason E. Rist <jrist>
Date:   Wed Jan 11 11:58:27 2012 -0700

    Fixes to bubble up sync errors.

Comment 2 Mike McCune 2012-01-26 19:08:21 UTC

mass ON_QA move

Comment 3 Mike McCune 2012-01-26 23:36:24 UTC

*** Bug 751788 has been marked as a duplicate of this bug. ***

Comment 5 Corey Welton 2012-02-16 15:17:04 UTC

QA Verified - errors in sync (per the missing repos) bubble up to UI.

Comment 7 Mike McCune 2013-08-16 18:12:16 UTC

getting rid of 6.0.0 version since that doesn't exist