Actions
Issue #2326
closedPublishes fail
Status:
CLOSED - CURRENTRELEASE
Priority:
Urgent
Assignee:
-
Sprint/Milestone:
-
Start date:
Due date:
Estimated time:
Severity:
3. High
Version:
Master
Platform Release:
2.10.1
OS:
Triaged:
Yes
Groomed:
No
Sprint Candidate:
No
Tags:
Pulp 2
Sprint:
Quarter:
Description
TL;DR: Repository publishes fail when SELinux is enabled, but no SELinux denials are logged.
Let's say you create, sync and publish a repository on Pulp 2.11 (master). It'll fail:
$ getenforce
Enforcing
$ pulp-admin rpm repo create --repo-id foo --feed https://repos.fedorapeople.org/pulp/pulp/fixtures/rpm-unsigned/
Successfully created repository [foo]
$ pulp-admin rpm repo sync run --repo-id foo
+----------------------------------------------------------------------+
Synchronizing Repository [foo]
+----------------------------------------------------------------------+
This command may be exited via ctrl+c without affecting the request.
Downloading metadata...
[/]
... completed
Downloading repository content...
[==================================================] 100%
RPMs: 32/32 items
Delta RPMs: 0/0 items
... completed
Downloading distribution files...
[==================================================] 100%
Distributions: 0/0 items
... completed
Importing errata...
[\]
... completed
Importing package groups/categories...
[-]
... completed
Cleaning duplicate packages...
[-]
... completed
Task Succeeded
Task Failed
[Errno 13] Permission denied
$ pulp-admin rpm repo delete --repo-id foo
This command may be exited via ctrl+c without affecting the request.
[\]
Running...
Repository [foo] successfully deleted
This script will succeed when selinux is disabled, but no selinux denials are logged:
$ getenforce
Enforcing
$ setenforce 0
$ echo > /var/log/audit/audit.log
$ semodule -R
$ pulp-admin rpm repo create --repo-id foo --feed https://repos.fedorapeople.org/pulp/pulp/fixtures/rpm-unsigned/
Successfully created repository [foo]
$ pulp-admin rpm repo sync run --repo-id foo
+----------------------------------------------------------------------+
Synchronizing Repository [foo]
+----------------------------------------------------------------------+
This command may be exited via ctrl+c without affecting the request.
Downloading metadata...
[/]
... completed
Downloading repository content...
[-]
[==================================================] 100%
RPMs: 0/0 items
Delta RPMs: 0/0 items
... completed
Downloading distribution files...
[==================================================] 100%
Distributions: 0/0 items
... completed
Importing errata...
[-]
... completed
Importing package groups/categories...
[-]
... completed
Cleaning duplicate packages...
[-]
... completed
Task Succeeded
Initializing repo metadata
[-]
... completed
Publishing Distribution files
[-]
... completed
Publishing RPMs
[==================================================] 100%
32 of 32 items
... completed
Publishing Delta RPMs
... skipped
Publishing Errata
[==================================================] 100%
4 of 4 items
... completed
Publishing Comps file
[==================================================] 100%
4 of 4 items
... completed
Publishing Metadata.
[-]
... completed
Closing repo metadata
[-]
... completed
Generating sqlite files
... skipped
Generating HTML files
... skipped
Publishing files to web
[-]
... completed
Writing Listings File
[-]
... completed
Task Succeeded
$ audit2allow -al
$ audit2allow -Ral
could not open interface info [/var/lib/sepolgen/interface_info]
$ cat /var/log/audit/audit.log
type=MAC_POLICY_LOAD msg=audit(1475703173.477:2674): policy loaded auid=0 ses=4
The journal provides some useful information:
Oct 05 17:29:33 pulp.example.com pulp[19736]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[3c2f34d4-9818-4aff-a193-e4f6c9f3f75a]
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:INFO: Task pulp.server.managers.repo.sync.sync[f5b11431-5462-4543-8dc7-26c784495a7c] succeeded in 8.637352837s: <pulp.server.async.tasks.TaskResult object at 0x7f06558aea50>
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[95d901b9-ba3a-40b9-83c9-64831767cc20] succeeded in 0.00448494699958s: None
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.strategy:INFO: Received task: pulp.server.managers.repo.publish.publish[77b466b0-1398-4aa0-ac33-3a467f9f0f0b]
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._release_resource[4a5eeec0-f8c2-405b-a6bc-3af3109aa667]
Oct 05 17:29:33 pulp.example.com pulp[19736]: celery.worker.job:INFO: Task pulp.server.async.tasks._queue_reserved_task[3c2f34d4-9818-4aff-a193-e4f6c9f3f75a] succeeded in 0.0376377650009s: None
Oct 05 17:29:33 pulp.example.com python[19909]: /etc/selinux/targeted/contexts/files/file_contexts: invalid context system_u:object_r:httpd_sys_rw_content_t:s0
Oct 05 17:29:33 pulp.example.com python[19909]: /etc/selinux/targeted/contexts/files/file_contexts: invalid context system_u:object_r:httpd_sys_rw_content_t:s0
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) Exception caught from plugin during publish for repo [foo]
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) Traceback (most recent call last):
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) File "/usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py", line 1239, in _do_publish
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) publish_report = publish_repo(transfer_repo, conduit, call_config)
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 673, in wrap_f
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) return f(*args, **kwargs)
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/distributors/yum/distributor.py", line 174, in publish_repo
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) return self._publisher.process_lifecycle()
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 566, in process_lifecycle
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) super(PluginStep, self).process_lifecycle()
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 163, in process_lifecycle
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) step.process()
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 253, in process
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) self._process_block()
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 297, in _process_block
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) self.process_main()
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 905, in process_main
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) selinux.restorecon(timestamp_master_dir.encode('utf-8'), recursive=True)
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) File "/usr/lib64/python2.7/site-packages/selinux/__init__.py", line 110, in restorecon
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) status, context = matchpathcon(path, mode)
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.controllers.repository:ERROR: (19909-45280) OSError: [Errno 13] Permission denied
Oct 05 17:29:33 pulp.example.com pulp[19909]: pulp.server.async.tasks:INFO: Task failed : [77b466b0-1398-4aa0-ac33-3a467f9f0f0b]
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) Task pulp.server.managers.repo.publish.publish[77b466b0-1398-4aa0-ac33-3a467f9f0f0b] raised unexpected: OSError(13, 'Permission denied')
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) Traceback (most recent call last):
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) R = retval = fun(*args, **kwargs)
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 488, in __call__
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) return super(Task, self).__call__(*args, **kwargs)
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 103, in __call__
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) return super(PulpTask, self).__call__(*args, **kwargs)
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 437, in __protected_call__
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) return self.run(*args, **kwargs)
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py", line 1095, in publish
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) result = check_publish(repo_obj, dist_id, dist_inst, transfer_repo, conduit, call_config)
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py", line 1187, in check_publish
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) result = _do_publish(repo_obj, dist_id, dist_inst, transfer_repo, conduit, call_config)
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py", line 1239, in _do_publish
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) publish_report = publish_repo(transfer_repo, conduit, call_config)
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 673, in wrap_f
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) return f(*args, **kwargs)
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/distributors/yum/distributor.py", line 174, in publish_repo
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) return self._publisher.process_lifecycle()
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 566, in process_lifecycle
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) super(PluginStep, self).process_lifecycle()
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 163, in process_lifecycle
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) step.process()
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 253, in process
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) self._process_block()
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 297, in _process_block
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) self.process_main()
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 905, in process_main
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) selinux.restorecon(timestamp_master_dir.encode('utf-8'), recursive=True)
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) File "/usr/lib64/python2.7/site-packages/selinux/__init__.py", line 110, in restorecon
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) status, context = matchpathcon(path, mode)
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:ERROR: (19772-45280) OSError: [Errno 13] Permission denied
Oct 05 17:29:33 pulp.example.com pulp[19772]: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[4a5eeec0-f8c2-405b-a6bc-3af3109aa667] succeeded in 0.00451806199999s: None
Here's the system on which this issue is apparent:
$ ssh $hostname grep PRETTY /etc/os-release
PRETTY_NAME="Fedora 23 (Twenty Three)"
$ ssh $hostname rpm -qa | sort | grep -i pulp
pulp-admin-client-2.11.0-0.1.alpha.git.710.7290d2b.fc23.noarch
pulp-docker-admin-extensions-2.2.0-0.1.alpha.git.201.9911531.fc23.noarch
pulp-docker-plugins-2.2.0-0.1.alpha.git.201.9911531.fc23.noarch
pulp-ostree-admin-extensions-1.2.0-0.1.alpha.git.104.2f01508.fc23.noarch
pulp-ostree-plugins-1.2.0-0.1.alpha.git.104.2f01508.fc23.noarch
pulp-puppet-admin-extensions-2.11.0-0.1.alpha.git.187.e97c179.fc23.noarch
pulp-puppet-plugins-2.11.0-0.1.alpha.git.187.e97c179.fc23.noarch
pulp-python-admin-extensions-1.2.0-0.1.alpha.git.109.e59ba95.fc23.noarch
pulp-python-plugins-1.2.0-0.1.alpha.git.109.e59ba95.fc23.noarch
pulp-rpm-admin-extensions-2.11.0-0.1.alpha.git.543.4255a48.fc23.noarch
pulp-rpm-plugins-2.11.0-0.1.alpha.git.543.4255a48.fc23.noarch
pulp-selinux-2.11.0-0.1.alpha.git.710.7290d2b.fc23.noarch
pulp-server-2.11.0-0.1.alpha.git.710.7290d2b.fc23.noarch
python-kombu-3.0.33-6.pulp.fc23.noarch
python-pulp-bindings-2.11.0-0.1.alpha.git.710.7290d2b.fc23.noarch
python-pulp-client-lib-2.11.0-0.1.alpha.git.710.7290d2b.fc23.noarch
python-pulp-common-2.11.0-0.1.alpha.git.710.7290d2b.fc23.noarch
python-pulp-docker-common-2.2.0-0.1.alpha.git.201.9911531.fc23.noarch
python-pulp-oid_validation-2.11.0-0.1.alpha.git.710.7290d2b.fc23.noarch
python-pulp-ostree-common-1.2.0-0.1.alpha.git.104.2f01508.fc23.noarch
python-pulp-puppet-common-2.11.0-0.1.alpha.git.187.e97c179.fc23.noarch
python-pulp-python-common-1.2.0-0.1.alpha.git.109.e59ba95.fc23.noarch
python-pulp-repoauth-2.11.0-0.1.alpha.git.710.7290d2b.fc23.noarch
python-pulp-rpm-common-2.11.0-0.1.alpha.git.543.4255a48.fc23.noarch
python-pulp-streamer-2.11.0-0.1.alpha.git.710.7290d2b.fc23.noarch
Related issues
Actions
Fix AVC denials while restoring SELinux context as part of publishing. closes #2326, #2277