Bug 1624024 - Pulp repo sync fails on RHEL 7.6
Summary: Pulp repo sync fails on RHEL 7.6
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Satellite
Classification: Red Hat
Component: Pulp
Version: Unspecified
Hardware: Unspecified
OS: Linux
unspecified
high
Target Milestone: Unspecified
Assignee: satellite6-bugs
QA Contact: Peter Ondrejka
URL:
Whiteboard:
Depends On:
Blocks: 1646574
TreeView+ depends on / blocked
 
Reported: 2018-08-30 16:55 UTC by Mike McCune
Modified: 2019-06-13 21:26 UTC (History)
13 users (show)

Fixed In Version: pulp-2.13.4.14-1
Doc Type: If docs needed, set a value
Doc Text:
Clone Of: 1613992
: 1646574 (view as bug list)
Environment:
Last Closed: 2018-10-11 15:28:08 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2018:2914 0 None None None 2018-10-11 15:28:15 UTC

Description Mike McCune 2018-08-30 16:55:42 UTC
+++ This bug was initially created as a clone of Bug #1613992 +++

RHEL 7.6 will introduce a change to the implementation of SELinux permission checks on 'mmap' [0], causing Pulp repository syncs to fail at runtime. We need to update the SELinux policy to rectify.

[0] https://bugzilla.redhat.com/show_bug.cgi?id=1460322


+++ This bug was initially created as a clone of Bug #1607770 +++

Description of problem:
I can't sync a Red Hat repo in RHUI:

Jul 24 08:30:30 rhua pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (1515-99360) (13, 'Permission denied')
Jul 24 08:30:30 rhua pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (1515-99360) Traceback (most recent call last):
Jul 24 08:30:30 rhua pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (1515-99360)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 213, in run
Jul 24 08:30:30 rhua pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (1515-99360)     metadata_files = self.get_metadata(metadata_files)
Jul 24 08:30:30 rhua pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (1515-99360)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 367, in get_metadata
Jul 24 08:30:30 rhua pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (1515-99360)     metadata_files.generate_dbs()
Jul 24 08:30:30 rhua pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (1515-99360)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/repomd/metadata.py", line 294, in generate_dbs
Jul 24 08:30:30 rhua pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (1515-99360)     with contextlib.closing(gdbm.open(db_filename, 'nf')) as db_file_handle:
Jul 24 08:30:30 rhua pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (1515-99360) error: (13, 'Permission denied')
Jul 24 08:30:30 rhua pulp: pulp.server.async.tasks:INFO: Task failed : [7d71bab1-742d-4519-81a6-4696a08b7ec6]

audit.log says:

type=AVC msg=audit(1532421030.541:6224): avc:  denied  { map } for  pid=1515 comm="celery" path="/var/cache/pulp/reserved_resource_worker-1.com/7d71bab1-742d-4519-81a6-4696a08b7ec6/tmpFD8xWX/filelists.db" dev="xvda2" ino=8528349 scontext=system_u:system_r:celery_t:s0 tcontext=system_u:object_r:pulp_var_cache_t:s0 tclass=file permissive=0
type=SYSCALL msg=audit(1532421030.541:6224): arch=c000003e syscall=9 success=no exit=-13 a0=0 a1=3000 a2=3 a3=1 items=0 ppid=1412 pid=1515 auid=4294967295 uid=48 gid=48 euid=48 suid=48 fsuid=48 egid=48 sgid=48 fsgid=48 tty=(none) ses=4294967295 comm="celery" exe="/usr/bin/python2.7" subj=system_u:system_r:celery_t:s0 key=(null)

audit2allow suggests:

allow celery_t pulp_var_cache_t:file map;

#!!!! WARNING: 'shell_exec_t' is a base type.
allow celery_t shell_exec_t:file map;

Version-Release number of selected component (if applicable):
selinux-policy-targeted-3.13.1-207.el7.noarch
pulp-rpm-plugins-2.8.3.6-1.el7ui.noarch

Worked well in 7.5.

(I can be OtherQA here as RHUI is pretty hard to set up for those who don't normally work with it. I've already verified that the sync works with a custom policy based on audit2allow's recommendation.)

--- Additional comment from Red Hat Bugzilla Rules Engine on 2018-07-24 04:50:21 EDT ---

This bug report has Keywords: Regression or TestBlocker.

Since no regressions or test blockers are allowed between releases, it is also being [proposed|marked] as a blocker for this release.

Please resolve ASAP.

--- Additional comment from Radek Bíba on 2018-07-24 04:53:29 EDT ---

Note: the shell exec thing might be related to these errors, which appear in the log repeatedly but before the actual sync:

type=AVC msg=audit(1532412101.934:2100): avc:  denied  { map } for  pid=17443 comm="sh" path="/usr/bin/bash" dev="xvda2" ino=12626950 scontext=system_u:system_r:celery_t:s0 tcontext=system_u:object_r:shell_exec_t:s0 tclass=file permissive=0
type=SYSCALL msg=audit(1532412101.934:2100): arch=c000003e syscall=59 success=no exit=-13 a0=7f7698ac0f89 a1=7ffe12015f90 a2=7ffe1201a0c8 a3=7f7699c0ca10 items=0 ppid=17428 pid=17443 auid=4294967295 uid=48 gid=48 euid=48 suid=48 fsuid=48 egid=48 sgid=48 fsgid=48 tty=(none) ses=4294967295 comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:celery_t:s0 key=(null)

--- Additional comment from Radek Bíba on 2018-07-24 04:56:24 EDT ---

Also:

type=ANOM_ABEND msg=audit(1532416433.298:3969): auid=4294967295 uid=48 gid=48 ses=4294967295 subj=system_u:system_r:celery_t:s0 pid=1494 comm="sh" reason="memory violation" sig=11

--- Additional comment from Lukas Vrabec on 2018-07-24 12:05:37 EDT ---

Radek, 

celery_t domain is not part of selinux-policy rpm package. Moving to celery, component. It's fine to allow these rules, I'm just not the right maintainer.

--- Additional comment from Radek Bíba on 2018-07-25 01:36:59 EDT ---

Ah, right. We'll need at least one more clone of this bug, though -- it's my understanding now that we're going to have to make this change in rh-rhua-selinux-policy, which is a special package with rules for services running on RHUI nodes. I'll clone this bug now.

--- Additional comment from Radek Bíba on 2018-07-26 08:58:34 EDT ---

One more thing. An attempt to sync the Atomic Trees repo fails this way:

Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360) Task pulp.server.managers.repo.sync.sync[d5dffb26-c32d-45bf-aea7-b84d00f4a787] raised unexpected: ValueError('Error invoking gpg: -11: ',)
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360) Traceback (most recent call last):
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     R = retval = fun(*args, **kwargs)
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 473, in __call__
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     return super(Task, self).__call__(*args, **kwargs)
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 103, in __call__
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     return super(PulpTask, self).__call__(*args, **kwargs)
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 437, in __protected_call__
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     return self.run(*args, **kwargs)
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py", line 760, in sync
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     sync_report = sync_repo(transfer_repo, conduit, call_config)
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 658, in wrap_f
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     return f(*args, **kwargs)
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp_ostree/plugins/importers/web.py", line 91, in sync_repo
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     report = step.process_lifecycle()
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 562, in process_lifecycle
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     super(PluginStep, self).process_lifecycle()
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 159, in process_lifecycle
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     step.process()
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 249, in process
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     self._process_block()
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp/plugins/util/publish_step.py", line 293, in _process_block
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     self.process_main()
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp_ostree/plugins/importers/steps.py", line 93, in process_main
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     remote.add()
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp_ostree/plugins/importers/steps.py", line 414, in add
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     path, key_ids = self.gpg_keys
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/pulp_ostree/plugins/importers/steps.py", line 385, in gpg_keys
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     gpg = GPG(gnupghome=home)
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)   File "/usr/lib/python2.7/site-packages/gnupg.py", line 685, in __init__
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360)     result.stderr))
Jul 26 12:47:19 rhua pulp: celery.worker.job:ERROR: (1412-99360) ValueError: Error invoking gpg: -11:

audit.log:

type=AVC msg=audit(1532609239.294:23205): avc:  denied  { map } for  pid=347 comm="gpg" path="/usr/bin/gpg2" dev="xvda2" ino=12911427 scontext=system_u:system_r:celery_t:s0 
tcontext=system_u:object_r:gpg_exec_t:s0 tclass=file permissive=0
type=SYSCALL msg=audit(1532609239.294:23205): arch=c000003e syscall=59 success=no exit=-13 a0=367c1d0 a1=367c1f0 a2=305e680 a3=0 items=0 ppid=1515 pid=347 auid=4294967295 ui
d=48 gid=48 euid=48 suid=48 fsuid=48 egid=48 sgid=48 fsgid=48 tty=(none) ses=4294967295 comm="gpg" exe="/usr/bin/gpg2" subj=system_u:system_r:celery_t:s0 key=(null)
type=PROCTITLE msg=audit(1532609239.294:23205): proctitle="(null)"
type=ANOM_ABEND msg=audit(1532609239.297:23206): auid=4294967295 uid=48 gid=48 ses=4294967295 subj=system_u:system_r:celery_t:s0 pid=347 comm="gpg" reason="memory violation"
 sig=11

audit2allow additionally recommends:

allow celery_t gpg_exec_t:file map;

--- Additional comment from Radek Bíba on 2018-07-26 10:29:36 EDT ---

Another issue appears after allowing the above-mentioned rule, restarting pulp_workers, and starting a new sync process:

Jul 26 14:09:58 rhua kernel: celery[3727]: segfault at 342 ip 00007fedeab8d000 sp 00007ffdc7e000a8 error 4 in libc-2.17.so[7fedeaa37000+1c2000]
Jul 26 14:09:58 rhua pulp: celery.worker.job:ERROR: (3669-84480) Task pulp.server.managers.repo.sync.sync[4c1b7463-e9c4-4ef8-bec4-cd8946337a45] raised unexpected: WorkerLost
Error('Worker exited prematurely: signal 11 (SIGSEGV).',)
Jul 26 14:09:58 rhua pulp: celery.worker.job:ERROR: (3669-84480) Traceback (most recent call last):
Jul 26 14:09:58 rhua celery: reserved_resource_worker-1.com ready.
Jul 26 14:09:58 rhua pulp: celery.worker.job:ERROR: (3669-84480)   File "/usr/lib64/python2.7/site-packages/billiard/pool.py", line 1169, in mark_as_worker_lost
Jul 26 14:09:58 rhua pulp: celery.worker.job:ERROR: (3669-84480)     human_status(exitcode)),
Jul 26 14:09:58 rhua pulp: celery.worker.job:ERROR: (3669-84480) WorkerLostError: Worker exited prematurely: signal 11 (SIGSEGV).

Likely related to:

type=AVC msg=audit(1532614198.905:23436): avc:  denied  { map } for  pid=3727 comm="celery" path="/var/lib/rhui/remote_share/content/shared/ostree/4bcde2efdbbc3a8fc2f63bbe32
5ddfb8f339d802e4649654893d52590b0c1c7d/content/tmp/15d2c4c15307c23d27ddd67776865258517da84554929a3f92fc6c9187312a8b" dev="0:41" ino=17013677 scontext=system_u:system_r:celer
y_t:s0 tcontext=system_u:object_r:nfs_t:s0 tclass=file permissive=0
type=SYSCALL msg=audit(1532614198.905:23436): arch=c000003e syscall=9 success=no exit=-13 a0=0 a1=345 a2=1 a3=2 items=0 ppid=3669 pid=3727 auid=4294967295 uid=48 gid=48 euid
=48 suid=48 fsuid=48 egid=48 sgid=48 fsgid=48 tty=(none) ses=4294967295 comm="celery" exe="/usr/bin/python2.7" subj=system_u:system_r:celery_t:s0 key=(null)

Suggestion:

allow celery_t nfs_t:file map;

--- Additional comment from Radek Bíba on 2018-07-27 05:37:05 EDT ---

Also noticed this:

/var/log/audit/audit.log:type=AVC msg=audit(1532674014.408:25095): avc:  denied  { map } for  pid=5659 comm="pool" path="/usr/share/mime/mime.cache" dev="xvda2" ino=4554242 scontext=system_u:system_r:celery_t:s0 tcontext=system_u:object_r:usr_t:s0 tclass=file permissive=0

This denial has appeared repeatedly, in four-hour intervals which match the Atomic Trees repo syncs. The syncs themselves have been successful, though.

Anyway, another suggestion, then:

allow celery_t usr_t:file map;

--- Additional comment from dalley on 20180808T18:55:05

As described in the issue, the root cause of the failure is missing SELinux permissions for the Celery processes.

--- Additional comment from rbiba on 20180809T06:13:48

FWIW, here are all the rules that we're adding to RHUI, in one place:

https://gitlab.sat.lab.tlv.redhat.com/mminar/cloude/commit/f8908bcfe6813e37cbcfb29203b263d1291a1b3f

--- Additional comment from pm-rhel on 20180809T18:01:48

This bug report has Keywords: Regression or TestBlocker.

Since no regressions or test blockers are allowed between releases,
it is also being identified as a blocker for this release.

Please resolve ASAP.

--- Additional comment from pm-rhel on 20180809T18:05:25

Since this issue was entered in Red Hat Bugzilla, the pm_ack has been
set to + automatically for the next planned release

--- Additional comment from egolov on 20180816T13:34:44

note for myself: https://github.com/pulp/pulp/pull/3598/commits/a6fc49d691373c0a7aeab37d34f6724890e5090a

--- Additional comment from sat6-jenkins on 20180817T12:54:41

build status: succeeded

brew:
 * pulp: closed - https://brewweb.engineering.redhat.com/brew/taskinfo?taskID=17929628
 * pulp: closed - https://brewweb.engineering.redhat.com/brew/taskinfo?taskID=17929630
 * pulp: closed - https://brewweb.engineering.redhat.com/brew/taskinfo?taskID=17929633

--- Additional comment from mmccune on 20180820T15:59:02

Proposing to 6.3.z, 6.2.z as well.

Comment 5 Peter Ondrejka 2018-09-13 10:20:05 UTC
Verified on RHEL-7.6-20180912 with selinux-policy noarch 3.13.1-225.el7, RH repositories are syncing as expected

Comment 7 errata-xmlrpc 2018-10-11 15:28:08 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-2018:2914


Note You need to log in before you can comment on or make changes to this bug.