Bug 1201842

Summary: Uploading an rpm to selected repo raises Error notification in logs though rpm uploaded successfully
Product: Red Hat Satellite Reporter: Sachin Ghai <sghai>
Component: WebUIAssignee: Brad Buckingham <bbuckingham>
WebUI sub component: Katello QA Contact: Og Maciel <omaciel>
Status: CLOSED ERRATA Docs Contact:
Severity: medium    
Priority: unspecified CC: bbuckingham, omaciel
Version: 6.1.0Keywords: Triaged
Target Milestone: Unspecified   
Target Release: Unused   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-07-27 08:49:27 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:
Attachments:
Description Flags
rpm uploaded succssfully from UI
none
Satellite 6.1.1: Production Log for RPM upload none

Description Sachin Ghai 2015-03-13 15:34:45 UTC
Description of problem:
I created a product p1 and repo r1 of type yum and without URL. Later I uploaded an rpm to that repo. RPM was uploaded successfully but logs were generating error notification instead of info.


---
2015-03-13 15:31:53 [I] Processing by Katello::Api::V2::RepositoriesController#upload_content as HTML
2015-03-13 15:31:53 [I]   Parameters: {"content"=>[#<ActionDispatch::Http::UploadedFile:0x0000000fe148f8 @original_filename="syslinux-extlinux-nonlinux-4.02-16.el6_5.i686.rpm", @content_type="application/x-rpm", @headers="Content-Disposition: form-data; name=\"content[]\"; filename=\"syslinux-extlinux-nonlinux-4.02-16.el6_5.i686.rpm\"\r\nContent-Type: application/x-rpm\r\n", @tempfile=#<File:/tmp/RackMultipart20150313-2602-i6gmm5>>], "authenticity_token"=>"KNcpgscfcTQh6+ZC6QkCoNG4DjBLO3Wtg39I/WYzPEE=", "api_version"=>"v2", "id"=>"5"}
[ERROR 2015-03-13 15:31:54 pulp_rest  #2521] RestClient.put "https://dhcp201-163.englab.pnq.redhat.com/pulp/api/v2/content/uploads/5321e82e-307e-4a4a-a905-a70e8f76ec0e/0//", 310532 byte(s) length, "Accept"=>"*/*; q=0.5, application/xml", "Accept-Encoding"=>"gzip, deflate", "Authorization"=>"OAuth oauth_body_hash=\"2jmj7l5rSw0yVb%2FvlWAYkK%2FYBwk%3D\", oauth_consumer_key=\"katello\", oauth_nonce=\"wo2ECxwU1YltCXe2cJvwdchQxdoXo8bSOQizhff548\", oauth_signature=\"oIqJId9LDkI54R6QUTIi%2Bai7izA%3D\", oauth_signature_method=\"HMAC-SHA1\", oauth_timestamp=\"1426240914\", oauth_version=\"1.0\"", "Content-Length"=>"310532", "accept"=>"application/json", "content_type"=>"application/json", "pulp-user"=>"admin-dadc4c13"
 | \n# => 200 OK | application/json 24 bytes
 | 
[ERROR 2015-03-13 15:31:55 pulp_rest  #2521] RestClient.delete "https://dhcp201-163.englab.pnq.redhat.com/pulp/api/v2/content/uploads/5321e82e-307e-4a4a-a905-a70e8f76ec0e//", "Accept"=>"*/*; q=0.5, application/xml", "Accept-Encoding"=>"gzip, deflate", "Authorization"=>"OAuth oauth_consumer_key=\"katello\", oauth_nonce=\"qMUaZvD9gACGLvSd0d2wGqiXvDPFpv2YpPLAVOqUI\", oauth_signature=\"QQ1X4eJ31cbxXjyqyIARI53Ityw%3D\", oauth_signature_method=\"HMAC-SHA1\", oauth_timestamp=\"1426240915\", oauth_version=\"1.0\"", "accept"=>"application/json", "content_type"=>"application/json", "pulp-user"=>"admin-dadc4c13"
 | \n# => 200 OK | application/json 24 bytes
 | 
2015-03-13 15:31:56 [I] Completed 200 OK in 3150ms (Views: 0.3ms | ActiveRecord: 28.3ms)
-----


Version-Release number of selected component (if applicable):

sat6.1 beta snap6 compose2 (Satellite-6.1.0-RHEL-6-20150311.1).

How reproducible:
always

Steps to Reproduce:
1.
2.
3.

Actual results:
RPM was uploaded successfully but logs were generating error notification instead of info.

Expected results:
Instead of Error, it should be info notifications in logs

Additional info:

Comment 1 Sachin Ghai 2015-03-13 15:36:36 UTC
Created attachment 1001432 [details]
rpm uploaded succssfully from UI

Comment 3 Brad Buckingham 2015-09-02 18:09:47 UTC
I have tested this on a Satellite 6.1.1 GA install and am no longer observing
the behavior described.

RPMs:
ruby193-rubygem-katello-2.2.0.66-1.el7sat.noarch
foreman-1.7.2.34-1.el7sat.noarch

Attaching the production log output for the rpm upload.

Comment 4 Brad Buckingham 2015-09-02 18:11:30 UTC
Created attachment 1069563 [details]
Satellite 6.1.1: Production Log for RPM upload

Comment 5 Og Maciel 2016-03-24 15:57:42 UTC
Created a custom product and repo (yum-based) without a feed url. Then I manually uploaded an rpm from the web ui. The package was successfully imported and can be see in the web ui. Below you can see the logs generated in the process:


==> /var/log/messages <==
Mar 24 11:52:49 cloud-qe-10 pulp: kombu.transport.qpid:INFO: Connected to qpid with SASL mechanism ANONYMOUS

==> /var/log/foreman/production.log <==
2016-03-24 11:52:49 [app] [I] Started POST "/katello/api/v2/repositories/31/upload_content" for 10.10.62.185 at 2016-03-24 11:52:49 -0400
2016-03-24 11:52:49 [app] [I] Processing by Katello::Api::V2::RepositoriesController#upload_content as HTML
2016-03-24 11:52:49 [app] [I]   Parameters: {"content"=>[#<ActionDispatch::Http::UploadedFile:0x007fa60dfffa90 @tempfile=#<Tempfile:/tmp/RackMultipart20160324-6710-1dkgkyb>, @original_filename="Antelope-10.6.9-1.elfake.noarch.rpm", @content_type="application/octet-stream", @headers="Content-Disposition: form-data; name=\"content[]\"; filename=\"Antelope-10.6.9-1.elfake.noarch.rpm\"\r\nContent-Type: application/octet-stream\r\n">], "authenticity_token"=>"hYdhb2SHrPCjM+qoQydCdiBWlg4kwLIIN5icu/+pJZU=", "api_version"=>"v2", "id"=>"31"}

==> /var/log/httpd/foreman-ssl_access_ssl.log <==
10.16.96.105 - - [24/Mar/2016:11:52:49 -0400] "GET /pulp/api/v2//status/ HTTP/1.1" 200 256 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:49 -0400] "GET /pulp/api/v2/users/ HTTP/1.1" 200 140 "-" "Ruby"

==> /var/log/httpd/foreman-ssl_error_ssl.log <==
[Thu Mar 24 11:52:49.737045 2016] [ssl:warn] [pid 28415] [client 10.10.62.185:58239] AH02227: Failed to set r->user to 'SSL_CLIENT_S_DN_CN', referer: https://cloud-qe-10.idmqe.lab.eng.bos.redhat.com/products/16/repositories/31
[Thu Mar 24 11:52:49.876447 2016] [ssl:warn] [pid 25042] [client 10.16.96.105:48361] AH02227: Failed to set r->user to 'SSL_CLIENT_S_DN_CN'
[Thu Mar 24 11:52:49.876665 2016] [ssl:warn] [pid 25042] [client 10.16.96.105:48361] AH02227: Failed to set r->user to 'SSL_CLIENT_S_DN_CN'

==> /var/log/messages <==
Mar 24 11:52:50 cloud-qe-10 pulp: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[37b833ef-87b6-4fbf-9ad3-b222ad837921]
Mar 24 11:52:50 cloud-qe-10 pulp: celery.worker.strategy:INFO: Received task: pulp.server.managers.content.upload.import_uploaded_unit[6cdc39ec-7b34-4e0d-ac9f-42d8ab43059e]
Mar 24 11:52:50 cloud-qe-10 pulp: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._release_resource[76507d4b-0c33-4a05-8973-87daa0e19938]
Mar 24 11:52:50 cloud-qe-10 pulp: celery.worker.job:INFO: Task pulp.server.async.tasks._queue_reserved_task[37b833ef-87b6-4fbf-9ad3-b222ad837921] succeeded in 0.0353393479891s: None
Mar 24 11:52:50 cloud-qe-10 pulp: celery.worker.job:INFO: Task pulp.server.managers.content.upload.import_uploaded_unit[6cdc39ec-7b34-4e0d-ac9f-42d8ab43059e] succeeded in 0.151371250016s: {'details': {}, 'success_flag': True, 'summary': ''}
Mar 24 11:52:50 cloud-qe-10 pulp: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[76507d4b-0c33-4a05-8973-87daa0e19938] succeeded in 0.00396718701813s: None

==> /var/log/httpd/foreman-ssl_access_ssl.log <==
10.16.96.105 - admin [24/Mar/2016:11:52:50 -0400] "POST /pulp/api/v2/content/uploads/ HTTP/1.1" 201 132 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:50 -0400] "PUT /pulp/api/v2/content/uploads/077bb843-f2d3-4283-a448-2385f559bf84/0// HTTP/1.1" 200 4 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:50 -0400] "POST /pulp/api/v2/repositories/IBMORG-Zoo_Repo-African_Animals/actions/import_upload// HTTP/1.1" 202 172 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:50 -0400] "GET /pulp/api/v2/tasks/6cdc39ec-7b34-4e0d-ac9f-42d8ab43059e/ HTTP/1.1" 200 351 "-" "Ruby"

==> /var/log/messages <==
Mar 24 11:52:51 cloud-qe-10 pulp: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[3024e321-c78f-42dd-9b73-7cad86c5de54]
Mar 24 11:52:51 cloud-qe-10 pulp: celery.worker.strategy:INFO: Received task: pulp.server.managers.repo.publish.publish[1cfd0288-cb72-44c1-9852-20af6d553154]
Mar 24 11:52:51 cloud-qe-10 pulp: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._release_resource[4d2c2479-320d-42e8-aab6-9fb6d2579e91]
Mar 24 11:52:51 cloud-qe-10 pulp: celery.worker.job:INFO: Task pulp.server.async.tasks._queue_reserved_task[3024e321-c78f-42dd-9b73-7cad86c5de54] succeeded in 0.0335723189928s: None
Mar 24 11:52:51 cloud-qe-10 pulp: pulp.plugins.pulp_rpm.plugins.distributors.yum.metadata.metadata:WARNING: Overwriting existing metadata file [/var/cache/pulp/reserved_resource_worker-0.lab.eng.bos.redhat.com/1cfd0288-cb72-44c1-9852-20af6d553154/repodata/repomd.xml]
Mar 24 11:52:51 cloud-qe-10 pulp: celery.worker.job:INFO: Task pulp.server.managers.repo.publish.publish[1cfd0288-cb72-44c1-9852-20af6d553154] succeeded in 0.215144292015s: {'exception': None, 'repo_id': u'IBMORG-Zoo_Repo-African_Animals', 'traceback': None, 'started': '2016-03-24T15:52:51Z',...
Mar 24 11:52:51 cloud-qe-10 pulp: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[4d2c2479-320d-42e8-aab6-9fb6d2579e91] succeeded in 0.00404385701404s: None

==> /var/log/foreman/production.log <==
2016-03-24 11:52:51 [app] [I] Completed 200 OK in 2140ms (Views: 0.2ms | ActiveRecord: 36.6ms)

==> /var/log/httpd/foreman-ssl_access_ssl.log <==
10.16.96.105 - admin [24/Mar/2016:11:52:51 -0400] "GET /pulp/api/v2/tasks/6cdc39ec-7b34-4e0d-ac9f-42d8ab43059e/ HTTP/1.1" 200 439 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:51 -0400] "DELETE /pulp/api/v2/content/uploads/077bb843-f2d3-4283-a448-2385f559bf84// HTTP/1.1" 200 4 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:51 -0400] "GET /pulp/api/v2/repositories/IBMORG-Zoo_Repo-African_Animals/?details=true HTTP/1.1" 200 573 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:51 -0400] "POST /pulp/api/v2/repositories/IBMORG-Zoo_Repo-African_Animals/search/units/ HTTP/1.1" 200 1310 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:51 -0400] "POST /pulp/api/v2/repositories/IBMORG-Zoo_Repo-African_Animals/actions/publish/ HTTP/1.1" 202 172 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:51 -0400] "POST /pulp/api/v2/content/units/rpm/search/ HTTP/1.1" 200 301 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:51 -0400] "GET /pulp/api/v2/tasks/1cfd0288-cb72-44c1-9852-20af6d553154/ HTTP/1.1" 200 386 "-" "Ruby"
10.16.96.105 - admin [24/Mar/2016:11:52:51 -0400] "GET /pulp/api/v2/tasks/1cfd0288-cb72-44c1-9852-20af6d553154/ HTTP/1.1" 200 1277 "-" "Ruby"
10.10.62.185 - - [24/Mar/2016:11:52:49 -0400] "POST /katello/api/v2/repositories/31/upload_content HTTP/1.1" 200 20 "https://cloud-qe-10.idmqe.lab.eng.bos.redhat.com/products/16/repositories/31" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:38.0) Gecko/20100101 Firefox/38.0"

==> /var/log/foreman/production.log <==
2016-03-24 11:52:52 [app] [I] Started GET "/katello/api/v2/repositories/31?organization_id=3" for 10.10.62.185 at 2016-03-24 11:52:52 -0400
2016-03-24 11:52:52 [app] [I] Processing by Katello::Api::V2::RepositoriesController#show as JSON
2016-03-24 11:52:52 [app] [I]   Parameters: {"organization_id"=>"3", "api_version"=>"v2", "id"=>"31"}
2016-03-24 11:52:52 [app] [I]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.9/app/views/katello/api/v2/repositories/show.json.rabl within katello/api/v2/layouts/resource (30.9ms)
2016-03-24 11:52:52 [app] [I] Completed 200 OK in 35ms (Views: 16.9ms | ActiveRecord: 15.2ms)

==> /var/log/httpd/foreman-ssl_access_ssl.log <==
10.10.62.185 - - [24/Mar/2016:11:52:52 -0400] "GET /katello/api/v2/repositories/31?organization_id=3 HTTP/1.1" 200 593 "https://cloud-qe-10.idmqe.lab.eng.bos.redhat.com/products/16/repositories/31" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:38.0) Gecko/20100101 Firefox/38.0"

==> /var/log/httpd/foreman-ssl_error_ssl.log <==
[Thu Mar 24 11:52:52.061795 2016] [ssl:warn] [pid 28415] [client 10.10.62.185:58239] AH02227: Failed to set r->user to 'SSL_CLIENT_S_DN_CN', referer: https://cloud-qe-10.idmqe.lab.eng.bos.redhat.com/products/16/repositories/31

Comment 6 Og Maciel 2016-03-24 15:59:39 UTC
I was not able to reproduce the issue reported and therefore am marking this as VERIFIED on Satellite 6.2.0 SNAP 5.1

Comment 9 errata-xmlrpc 2016-07-27 08:49:27 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:1500