Project

Profile

Help

Issue #4130

Updated by kersom over 5 years ago

Upload of RPM packages are failing.    A few tests failed today, most them related to *upload* an RPM packge to Pulp 2. 

 *Steps to reproduce:* 

 <pre><code class="text"> 

 pulp-admin rpm repo create --repo-id=foo 
 wget https://repos.fedorapeople.org/pulp/pulp/fixtures/rpm-with-non-ascii/rpm-with-non-ascii-1-1.fc25.noarch.rpm 
 pulp-admin -vvv rpm repo uploads rpm --repo-id foo --file rpm-with-non-ascii-1-1.fc25.noarch.rpm  

 </code></pre> 

 *Output:* 

 <pre><code class="text"> 
 [root@r76 ~]# pulp-admin -vvv rpm repo uploads rpm --repo-id foo --file rpm-with-non-ascii-1-1.fc25.noarch.rpm  
 +----------------------------------------------------------------------+ 
                               Unit Upload 
 +----------------------------------------------------------------------+ 

 2018-11-06 16:02:17,025 - DEBUG - sending GET request to /pulp/api/v2/repositories/foo/ 
 2018-11-06 16:02:17,135 - INFO - GET request to /pulp/api/v2/repositories/foo/ with parameters None 
 2018-11-06 16:02:17,135 - INFO - Response status : 200  

 2018-11-06 16:02:17,136 - INFO - Response body : 
  { 
   "scratchpad": {},  
   "display_name": null,  
   "description": null,  
   "last_unit_added": null,  
   "notes": { 
     "_repo-type": "rpm-repo" 
   },  
   "last_unit_removed": null,  
   "content_unit_counts": {},  
   "_ns": "repos",  
   "_id": { 
     "$oid": "5be20134db5ee913bb0318be" 
   },  
   "id": "foo",  
   "_href": "/pulp/api/v2/repositories/foo/" 
 } 

 Extracting necessary metadata for each request... 
 [==================================================] 100% 
 Analyzing: rpm-with-non-ascii-1-1.fc25.noarch.rpm 
 ... completed 

 Creating upload requests on the server... 
 [==================================================] 100% 
 Initializing: rpm-with-non-ascii-1-1.fc25.noarch.rpm 
 2018-11-06 16:02:17,136 - DEBUG - sending POST request to /pulp/api/v2/content/uploads/ 
 2018-11-06 16:02:17,208 - INFO - POST request to /pulp/api/v2/content/uploads/ with parameters None 
 2018-11-06 16:02:17,208 - INFO - Response status : 201  

 2018-11-06 16:02:17,208 - INFO - Response body : 
  { 
   "upload_id": "2e2a69bd-fc0f-449b-b23d-8385f5b701ae",  
   "_href": "/pulp/api/v2/content/uploads/2e2a69bd-fc0f-449b-b23d-8385f5b701ae/" 
 } 

 ... completed 

 Starting upload of selected units. If this process is stopped through ctrl+c, 
 the uploads will be paused and may be resumed later using the resume command or 
 canceled entirely using the cancel command. 

 Uploading: rpm-with-non-ascii-1-1.fc25.noarch.rpm 
 2018-11-06 16:02:17,210 - DEBUG - sending PUT request to /pulp/api/v2/content/uploads/2e2a69bd-fc0f-449b-b23d-8385f5b701ae/0/ 
 2018-11-06 16:02:17,278 - INFO - PUT request to /pulp/api/v2/content/uploads/2e2a69bd-fc0f-449b-b23d-8385f5b701ae/0/ 
 2018-11-06 16:02:17,278 - INFO - Response status : 200  

 2018-11-06 16:02:17,278 - INFO - Response body : 
  null 

 [==================================================] 100% 
 6392/6392 bytes 
 ... completed 

 Importing into the repository... 
 2018-11-06 16:02:17,280 - DEBUG - sending POST request to /pulp/api/v2/repositories/foo/actions/import_upload/ 
 2018-11-06 16:02:17,405 - INFO - POST request to /pulp/api/v2/repositories/foo/actions/import_upload/ with parameters {"override_config": {}, "unit_type_id": "rpm", "upload_id": "2e2a69bd-fc0f-449b-b23d-8385f5b701ae", "unit_key": {}, "unit_metadata": {}} 
 2018-11-06 16:02:17,405 - INFO - Response status : 202  

 2018-11-06 16:02:17,405 - INFO - Response body : 
  { 
   "spawned_tasks": [ 
     { 
       "_href": "/pulp/api/v2/tasks/ded240b3-ddf7-418f-bafb-dd9976854514/",  
       "task_id": "ded240b3-ddf7-418f-bafb-dd9976854514" 
     } 
   ],  
   "result": null,  
   "error": null 
 } 

 This command may be exited via ctrl+c without affecting the request. 


 [-] 
 Running... 
 2018-11-06 16:02:18,407 - DEBUG - sending GET request to /pulp/api/v2/tasks/ded240b3-ddf7-418f-bafb-dd9976854514/ 
 2018-11-06 16:02:18,535 - INFO - GET request to /pulp/api/v2/tasks/ded240b3-ddf7-418f-bafb-dd9976854514/ with parameters None 
 2018-11-06 16:02:18,536 - INFO - Response status : 200  

 2018-11-06 16:02:18,536 - INFO - Response body : 
  { 
   "exception": null,  
   "task_type": "pulp.server.managers.content.upload.import_uploaded_unit",  
   "_href": "/pulp/api/v2/tasks/ded240b3-ddf7-418f-bafb-dd9976854514/",  
   "task_id": "ded240b3-ddf7-418f-bafb-dd9976854514",  
   "tags": [ 
     "pulp:repository:foo",  
     "pulp:action:import_upload" 
   ],  
   "finish_time": "2018-11-06T21:02:17Z",  
   "_ns": "task_status",  
   "start_time": "2018-11-06T21:02:17Z",  
   "traceback": "Traceback (most recent call last):\n    File \"/usr/lib/python2.7/site-packages/celery/app/trace.py\", line 367, in trace_task\n      R = retval = fun(*args, **kwargs)\n    File \"/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py\", line 529, in __call__\n      return super(Task, self).__call__(*args, **kwargs)\n    File \"/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py\", line 107, in __call__\n      return super(PulpTask, self).__call__(*args, **kwargs)\n    File \"/usr/lib/python2.7/site-packages/celery/app/trace.py\", line 622, in __protected_call__\n      return self.run(*args, **kwargs)\n    File \"/usr/lib/python2.7/site-packages/pulp/server/managers/content/upload.py\", line 218, in import_uploaded_unit\n      unit_metadata, file_path, conduit, call_config)\n    File \"/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/importer.py\", line 65, in upload_unit\n      return upload.upload(repo, type_id, unit_key, metadata, file_path, conduit, config)\n    File \"/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/upload.py\", line 123, in upload\n      handlers[type_id](repo, type_id, unit_key, metadata, file_path, conduit, config)\n    File \"/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/upload.py\", line 391, in _handle_package\n      raise PulpCodedException(error_codes.RPM1016)\nPulpCodedException: Uploaded file is not a valid RPM.\n",  
   "spawned_tasks": [],  
   "progress_report": {},  
   "queue": "reserved_resource_worker-0@r76.pulp.vm.dq2",  
   "state": "error",  
   "worker_name": "reserved_resource_worker-0@r76.pulp.vm",  
   "result": null,  
   "error": { 
     "code": "RPM1016",  
     "data": {},  
     "description": "Uploaded file is not a valid RPM.",  
     "sub_errors": [] 
   },  
   "_id": { 
     "$oid": "5be201591fb71554c0fcfebf" 
   },  
   "id": "5be201591fb71554c0fcfebf" 
 [\] 
 Running... 

 Task Failed 

 Uploaded file is not a valid RPM. 

 Deleting the upload request... 
 2018-11-06 16:02:18,536 - DEBUG - sending DELETE request to /pulp/api/v2/content/uploads/2e2a69bd-fc0f-449b-b23d-8385f5b701ae/ 
 2018-11-06 16:02:18,606 - INFO - DELETE request to /pulp/api/v2/content/uploads/2e2a69bd-fc0f-449b-b23d-8385f5b701ae/ with parameters None 
 2018-11-06 16:02:18,606 - INFO - Response status : 200  

 2018-11-06 16:02:18,606 - INFO - Response body : 
  null 

 ... completed 

 </code></pre> 

 *journalctl -n 30:* 

 <pre><code class="text"> 
 -- Logs begin at Tue 2018-11-06 13:44:35 EST, end at Tue 2018-11-06 14:21:47 EST. -- 
 Nov 06 14:13:18 r76.pulp.vm pulp[11060]: gofer.messaging.adapter.qpid.connection:INFO: opened: qpid+ssl://r76.pulp.vm:5671 
 Nov 06 14:13:18 r76.pulp.vm pulp[11060]: gofer.messaging.adapter.connect:INFO: connected: qpid+ssl://r76.pulp.vm:5671 
 Nov 06 14:16:07 r76.pulp.vm chronyd[4364]: Selected source 162.23.41.10 
 Nov 06 14:16:12 r76.pulp.vm chronyd[4364]: Can't synchronise: no selectable sources 
 Nov 06 14:17:25 r76.pulp.vm sshd[11401]: FIPS mode initialized 
 Nov 06 14:17:25 r76.pulp.vm sshd[11401]: Accepted publickey for root from 192.168.122.1 port 60870 ssh2: RSA SHA256:1/LIskjXx+3aNEUAP6iWb1lYknrbp2huYKqbuVPsvbs 
 Nov 06 14:17:25 r76.pulp.vm systemd-logind[4350]: New session 5 of user root. 
 Nov 06 14:17:25 r76.pulp.vm systemd[1]: Started Session 5 of user root. 
 Nov 06 14:17:25 r76.pulp.vm sshd[11401]: pam_unix(sshd:session): session opened for user root by (uid=0) 
 Nov 06 14:17:40 r76.pulp.vm yum[11418]: Installed: wget-1.14-18.el7.x86_64 
 Nov 06 14:20:21 r76.pulp.vm pulp[11061]: pulp.server.webservices.middleware.exception:INFO: Authentication with username None failed: invalid SSL certificate. 
 Nov 06 14:20:24 r76.pulp.vm chronyd[4364]: Source 44.190.6.254 replaced with 72.5.72.15 
 Nov 06 14:20:26 r76.pulp.vm chronyd[4364]: Selected source 216.230.228.242 
 Nov 06 14:20:26 r76.pulp.vm chronyd[4364]: System clock wrong by 2361.160983 seconds, adjustment started 
 Nov 06 14:20:54 r76.pulp.vm pulp[11060]: kombu.transport.qpid:INFO: Connected to qpid with SASL mechanism ANONYMOUS 
 Nov 06 14:20:54 r76.pulp.vm pulp[10967]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[c0594d78-f0e2-4c7b-9372-f9e75f78b8f3] 
 Nov 06 14:20:54 r76.pulp.vm pulp[11033]: py.warnings:WARNING: [c0594d78] (11033-50144) /usr/lib64/python2.7/site-packages/pymongo/topology.py:74: UserWarning: MongoClient opened before fork. Create MongoClient with connect=False, or create client after forking. See PyMongo's documentation for details: http://api.mongodb.org/python/current/faq.html#using-pymongo-with-multiprocessing> 
 Nov 06 14:20:54 r76.pulp.vm pulp[11033]: py.warnings:WARNING: [c0594d78] (11033-50144)     "MongoClient opened before fork. Create MongoClient " 
 Nov 06 14:20:54 r76.pulp.vm pulp[11033]: py.warnings:WARNING: [c0594d78] (11033-50144) 
 Nov 06 14:20:54 r76.pulp.vm pulp[11033]: kombu.transport.qpid:INFO: [c0594d78] Connected to qpid with SASL mechanism ANONYMOUS 
 Nov 06 14:20:54 r76.pulp.vm pulp[10835]: celery.worker.strategy:INFO: Received task: pulp.server.managers.content.upload.import_uploaded_unit[53955228-dc8e-4935-ab96-ef59c5504ad6] 
 Nov 06 14:20:54 r76.pulp.vm pulp[10938]: py.warnings:WARNING: [53955228] (10938-28736) /usr/lib64/python2.7/site-packages/pymongo/topology.py:74: UserWarning: MongoClient opened before fork. Create MongoClient with connect=False, or create client after forking. See PyMongo's documentation for details: http://api.mongodb.org/python/current/faq.html#using-pymongo-with-multiprocessing> 
 Nov 06 14:20:54 r76.pulp.vm pulp[10938]: py.warnings:WARNING: [53955228] (10938-28736)     "MongoClient opened before fork. Create MongoClient " 
 Nov 06 14:20:54 r76.pulp.vm pulp[10938]: py.warnings:WARNING: [53955228] (10938-28736) 
 Nov 06 14:20:54 r76.pulp.vm pulp[10835]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._release_resource[024d1a9e-c6d9-4d5f-b0c7-a4882e148592] 
 Nov 06 14:20:54 r76.pulp.vm pulp[11033]: celery.app.trace:INFO: [c0594d78] Task pulp.server.async.tasks._queue_reserved_task[c0594d78-f0e2-4c7b-9372-f9e75f78b8f3] succeeded in 0.119898567s: None 
 Nov 06 14:20:54 r76.pulp.vm pulp[10938]: pulp.server.async.tasks:INFO: [53955228] Task failed : [53955228-dc8e-4935-ab96-ef59c5504ad6] : Uploaded file is not a valid RPM. 
 Nov 06 14:20:54 r76.pulp.vm pulp[10938]: celery.app.trace:INFO: [53955228] Task pulp.server.managers.content.upload.import_uploaded_unit[53955228-dc8e-4935-ab96-ef59c5504ad6] raised expected: PulpCodedException() 
 Nov 06 14:20:54 r76.pulp.vm pulp[10938]: celery.app.trace:INFO: [024d1a9e] Task pulp.server.async.tasks._release_resource[024d1a9e-c6d9-4d5f-b0c7-a4882e148592] succeeded in 0.00247618999992s: None 
 Nov 06 14:21:47 r76.pulp.vm yum[11463]: Installed: fpaste-0.3.7.4.1-2.el7.noarch 


 </code></pre> 



 *Pulp Packages:* 

 <pre><code class="text"> 

 [root@r76 ~]# rpm -qa | grep pulp 
 python-pulp-repoauth-2.19.0-0.1.alpha.201811060516gita768094.el7.noarch 
 pulp-ostree-plugins-1.4.0-0.1.alpha.201811060506git53beed4.el7.noarch 
 pulp-puppet-plugins-2.19.0-0.1.alpha.201811060508gitc54a546.el7.noarch 
 python-pulp-bindings-2.19.0-0.1.alpha.201811060516gita768094.el7.noarch 
 pulp-ostree-admin-extensions-1.4.0-0.1.alpha.201811060506git53beed4.el7.noarch 
 pulp-docker-admin-extensions-3.4.0-0.1.alpha.201811060504gita762419.el7.noarch 
 python-pulp-streamer-2.19.0-0.1.alpha.201811060516gita768094.el7.noarch 
 python-pulp-puppet-common-2.19.0-0.1.alpha.201811060508gitc54a546.el7.noarch 
 python-pulp-rpm-common-2.19.0-0.1.alpha.201811060511git204f995.el7.noarch 
 pulp-selinux-2.19.0-0.1.alpha.201811060516gita768094.el7.noarch 
 python-isodate-0.5.0-4.pulp.el7.noarch 
 python-pulp-ostree-common-1.4.0-0.1.alpha.201811060506git53beed4.el7.noarch 
 python-pulp-docker-common-3.4.0-0.1.alpha.201811060504gita762419.el7.noarch 
 python-pulp-python-common-2.1.0-0.1.alpha.201811060502git5e2aa35.el7.noarch 
 python-pulp-oid_validation-2.19.0-0.1.alpha.201811060516gita768094.el7.noarch 
 pulp-server-2.19.0-0.1.alpha.201811060516gita768094.el7.noarch 
 pulp-docker-plugins-3.4.0-0.1.alpha.201811060504gita762419.el7.noarch 
 pulp-python-plugins-2.1.0-0.1.alpha.201811060502git5e2aa35.el7.noarch 
 pulp-rpm-plugins-2.19.0-0.1.alpha.201811060511git204f995.el7.noarch 
 pulp-puppet-tools-2.19.0-0.1.alpha.201811060508gitc54a546.el7.noarch 
 pulp-admin-client-2.19.0-0.1.alpha.201811060516gita768094.el7.noarch 
 pulp-python-admin-extensions-2.1.0-0.1.alpha.201811060502git5e2aa35.el7.noarch 
 pulp-rpm-admin-extensions-2.19.0-0.1.alpha.201811060511git204f995.el7.noarch 
 pulp-deb-admin-extensions-1.9.0-0.1.alpha.201811060524gitb5fc87b.el7.noarch 
 pulp-deb-plugins-1.9.0-0.1.alpha.201811060524gitb5fc87b.el7.noarch 
 python-pulp-client-lib-2.19.0-0.1.alpha.201811060516gita768094.el7.noarch 
 pulp-puppet-admin-extensions-2.19.0-0.1.alpha.201811060508gitc54a546.el7.noarch 
 python-pulp-common-2.19.0-0.1.alpha.201811060516gita768094.el7.noarch 
 python-pulp-deb-common-1.9.0-0.1.alpha.201811060524gitb5fc87b.el7.noarch 

 </code></pre> 

 *System:* 

 <pre><code class="text"> 

 [root@r76 ~]# cat /etc/redhat-release  
 Red Hat Enterprise Linux Server release 7.6 (Maipo 

 </code></pre>

Back