Issue #4130
Updated by kersom about 6 years ago
Upload of RPM packages are failing. A few tests failed today, most them related to *upload* an RPM packge to Pulp 2. Similar error happened when attempting to upload different types of RPMs. *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 -vvvvv -vvv rpm repo uploads rpm --repo-id foo --file rpm-with-non-ascii-1-1.fc25.noarch.rpm +----------------------------------------------------------------------+ Unit Upload +----------------------------------------------------------------------+ 2018-11-06 14:20:54,369 16:02:17,025 - DEBUG - sending GET request to /pulp/api/v2/repositories/foo/ 2018-11-06 14:20:54,443 16:02:17,135 - INFO - GET request to /pulp/api/v2/repositories/foo/ with parameters None 2018-11-06 14:20:54,443 16:02:17,135 - INFO - Response status : 200 2018-11-06 14:20:54,443 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": "5be1e983db5ee92b35299634" "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 14:20:54,444 16:02:17,136 - DEBUG - sending POST request to /pulp/api/v2/content/uploads/ 2018-11-06 14:20:54,519 16:02:17,208 - INFO - POST request to /pulp/api/v2/content/uploads/ with parameters None 2018-11-06 14:20:54,519 16:02:17,208 - INFO - Response status : 201 2018-11-06 14:20:54,519 16:02:17,208 - INFO - Response body : { "upload_id": "b77d8a04-cfb8-47c3-a188-9906736185b2", "2e2a69bd-fc0f-449b-b23d-8385f5b701ae", "_href": "/pulp/api/v2/content/uploads/b77d8a04-cfb8-47c3-a188-9906736185b2/" "/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 14:20:54,521 16:02:17,210 - DEBUG - sending PUT request to /pulp/api/v2/content/uploads/b77d8a04-cfb8-47c3-a188-9906736185b2/0/ /pulp/api/v2/content/uploads/2e2a69bd-fc0f-449b-b23d-8385f5b701ae/0/ 2018-11-06 14:20:54,615 16:02:17,278 - INFO - PUT request to /pulp/api/v2/content/uploads/b77d8a04-cfb8-47c3-a188-9906736185b2/0/ /pulp/api/v2/content/uploads/2e2a69bd-fc0f-449b-b23d-8385f5b701ae/0/ 2018-11-06 14:20:54,615 16:02:17,278 - INFO - Response status : 200 2018-11-06 14:20:54,615 16:02:17,278 - INFO - Response body : null [==================================================] 100% 6392/6392 bytes ... completed Importing into the repository... 2018-11-06 14:20:54,617 16:02:17,280 - DEBUG - sending POST request to /pulp/api/v2/repositories/foo/actions/import_upload/ 2018-11-06 14:20:54,774 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": "b77d8a04-cfb8-47c3-a188-9906736185b2", "2e2a69bd-fc0f-449b-b23d-8385f5b701ae", "unit_key": {}, "unit_metadata": {}} 2018-11-06 14:20:54,774 16:02:17,405 - INFO - Response status : 202 2018-11-06 14:20:54,774 16:02:17,405 - INFO - Response body : { "spawned_tasks": [ { "_href": "/pulp/api/v2/tasks/53955228-dc8e-4935-ab96-ef59c5504ad6/", "/pulp/api/v2/tasks/ded240b3-ddf7-418f-bafb-dd9976854514/", "task_id": "53955228-dc8e-4935-ab96-ef59c5504ad6" "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 14:20:55,777 16:02:18,407 - DEBUG - sending GET request to /pulp/api/v2/tasks/53955228-dc8e-4935-ab96-ef59c5504ad6/ /pulp/api/v2/tasks/ded240b3-ddf7-418f-bafb-dd9976854514/ 2018-11-06 14:20:55,891 16:02:18,535 - INFO - GET request to /pulp/api/v2/tasks/53955228-dc8e-4935-ab96-ef59c5504ad6/ /pulp/api/v2/tasks/ded240b3-ddf7-418f-bafb-dd9976854514/ with parameters None 2018-11-06 14:20:55,891 16:02:18,536 - INFO - Response status : 200 2018-11-06 14:20:55,891 16:02:18,536 - INFO - Response body : { "exception": null, "task_type": "pulp.server.managers.content.upload.import_uploaded_unit", "_href": "/pulp/api/v2/tasks/53955228-dc8e-4935-ab96-ef59c5504ad6/", "/pulp/api/v2/tasks/ded240b3-ddf7-418f-bafb-dd9976854514/", "task_id": "53955228-dc8e-4935-ab96-ef59c5504ad6", "ded240b3-ddf7-418f-bafb-dd9976854514", "tags": [ "pulp:repository:foo", "pulp:action:import_upload" ], "finish_time": "2018-11-06T19:20:54Z", "2018-11-06T21:02:17Z", "_ns": "task_status", "start_time": "2018-11-06T19:20:54Z", "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": "5be1e996f57913ba8b8f06d5" "5be201591fb71554c0fcfebf" }, "id": "5be1e996f57913ba8b8f06d5" "5be201591fb71554c0fcfebf" [\] Running... Task Failed Uploaded file is not a valid RPM. Deleting the upload request... 2018-11-06 14:20:55,892 16:02:18,536 - DEBUG - sending DELETE request to /pulp/api/v2/content/uploads/b77d8a04-cfb8-47c3-a188-9906736185b2/ /pulp/api/v2/content/uploads/2e2a69bd-fc0f-449b-b23d-8385f5b701ae/ 2018-11-06 14:20:55,967 16:02:18,606 - INFO - DELETE request to /pulp/api/v2/content/uploads/b77d8a04-cfb8-47c3-a188-9906736185b2/ /pulp/api/v2/content/uploads/2e2a69bd-fc0f-449b-b23d-8385f5b701ae/ with parameters None 2018-11-06 14:20:55,967 16:02:18,606 - INFO - Response status : 200 2018-11-06 14:20:55,967 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>
.