Bug 2224585
| Summary: | encountering selinux denial on ppc64le during attempted write by lscpu during rhsmcertd process | ||
|---|---|---|---|
| Product: | Red Hat Enterprise Linux 9 | Reporter: | John Sefler <jsefler> |
| Component: | selinux-policy | Assignee: | Nikola Knazekova <nknazeko> |
| Status: | CLOSED MIGRATED | QA Contact: | BaseOS QE Security Team <qe-baseos-security> |
| Severity: | medium | Docs Contact: | |
| Priority: | medium | ||
| Version: | 9.3 | CC: | kzak, lvrabec, mmalik, ptoscano, zpytela |
| Target Milestone: | rc | Keywords: | MigratedToJIRA, Triaged |
| Target Release: | --- | Flags: | pm-rhel:
mirror+
|
| Hardware: | ppc64le | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: |
Cause: lscpu uses O_RDONLY to read /dev/mem, but on ppc64 architecture it uses IBM's librtas.so that mmap /dev/mem using O_RDRW for open().
Consequence: SELinux denies write to raw memory devices
Fix: Do not audit attempts to write to raw memory devices
Result: Attempts to write to raw memory devices are dontaudited in the SELinux policy
|
Story Points: | --- |
| Clone Of: | Environment: | ||
| Last Closed: | 2023-08-21 18:01:54 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: | |||
Here are more details from audit.log (after setting "auditctl -w /etc/shadow -p w -k shadow-write")
type=AVC msg=audit(1689956926.198:12322): avc: denied { write } for pid=71996 comm="lscpu" name="mem" dev="devtmpfs" ino=3 scontext=system_u:system_r:rhsmcertd_t:s0 tcontext=system_u:object_r:memory_device_t:s0 tclass=chr_file permissive=0
type=SYSCALL msg=audit(1689956926.198:12322): arch=c0000015 syscall=286 success=no exit=-13 a0=ffffffffffffff9c a1=7fffa45e6ee0 a2=2 a3=0 items=1 ppid=71876 pid=71996 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="lscpu" exe="/usr/bin/lscpu" subj=system_u:system_r:rhsmcertd_t:s0 key=(null)^]ARCH=ppc64le SYSCALL=openat AUID="unset" UID="root" GID="root" EUID="root" SUID="root" FSUID="root" EGID="root" SGID="root" FSGID="root"
type=CWD msg=audit(1689956926.198:12322): cwd="/"
type=PATH msg=audit(1689956926.198:12322): item=0 name="/dev/mem" inode=3 dev=00:05 mode=020640 ouid=0 ogid=9 rdev=01:01 obj=system_u:object_r:memory_device_t:s0 nametype=NORMAL cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0^]OUID="root" OGID="kmem"
type=PROCTITLE msg=audit(1689956926.198:12322): proctitle=2F7573722F62696E2F6C73637075002D2D6A736F6E
All that subscription-manager & rhsmcertd do is invoking `lscpu` as part of the facts collection step; since it looks like lscpu is trying to write to /dev/mem, I'm reassigning this to util-linux (where lscpu belongs) for further investigation. lscpu uses /dev/mem to read information about hypervisors from DMI tables.
All this is done in read-only mode (open(O_RDONLY)), so I don't understand "avc: denied { write } ... SYSCALL=openat" from audit, but maybe it's audit system limitation that it's not able to differentiate between open() modes. Not sure.
Anyway, in this case, open() and read() are expected and wanted.
(In reply to Karel Zak from comment #3) > lscpu uses /dev/mem to read information about hypervisors from DMI tables. > > All this is done in read-only mode (open(O_RDONLY)), so I don't understand > "avc: denied { write } ... SYSCALL=openat" from audit, but maybe it's > audit system limitation that it's not able to differentiate between open() > modes. Not sure. In the SYSCALL line I can see O_RDWR: type=PROCTITLE msg=audit(07/21/2023 12:28:46.198:12322) : proctitle=/usr/bin/lscpu --json type=PATH msg=audit(07/21/2023 12:28:46.198:12322) : item=0 name=/dev/mem inode=3 dev=00:05 mode=character,640 ouid=root ogid=kmem rdev=01:01 obj=system_u:object_r:memory_device_t:s0 nametype=NORMAL cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0^]OUID="root" OGID="kmem" type=CWD msg=audit(07/21/2023 12:28:46.198:12322) : cwd=/ type=SYSCALL msg=audit(07/21/2023 12:28:46.198:12322) : arch=ppc64le syscall=openat success=no exit=EACCES(Permission denied) a0=AT_FDCWD a1=0x7fffa45e6ee0 a2=O_RDWR a3=0x0 items=1 ppid=71876 pid=71996 auid=unset uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=(none) ses=unset comm=lscpu exe=/usr/bin/lscpu subj=system_u:system_r:rhsmcertd_t:s0 key=(null) SYSCALL=openat AUID="unset" UID="root" GID="root" EUID="root" SUID="root" FSUID="root" EGID="root" SGID="root" FSGID="root" type=AVC msg=audit(07/21/2023 12:28:46.198:12322) : avc: denied { write } for pid=71996 comm=lscpu name=mem dev="devtmpfs" ino=3 scontext=system_u:system_r:rhsmcertd_t:s0 tcontext=system_u:object_r:memory_device_t:s0 tclass=chr_file permissive=0 Is it because it is called this way from lscpu? Or is it specific for this architecture? > > Anyway, in this case, open() and read() are expected and wanted. Thanks for the justification. I see where the problem is. lscpu reads /dev/mem (and it always uses O_RDONLY) in some situations, but it's not used in this case. On ppc64 lscpu uses IBM's librtas.so that mmap /dev/mem, and it really uses O_RDRW for open(). The code of the library: https://github.com/ibm-power-utilities/librtas/blob/next/librtas_src/syscall_rmo.c#L331C1-L345C1 It's probably because the RTAS syscalls use /dev/mem to return data to userspace. It's evident from strace (all are covered by private librtas lock): openat(AT_FDCWD, "/var/lock/LCK..librtas", O_RDWR|O_CREAT, 0600) = 5 getpid() = 41218 fcntl(5, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=2}) = 0 openat(AT_FDCWD, "/dev/mem", O_RDWR) = 6 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_SHARED, 6, 0xf6b0000) = 0x7fff802a0000 close(6) = 0 openat(AT_FDCWD, "/proc/device-tree/rtas/ibm,get-system-parameter", O_RDONLY) = 6 read(6, "\0\0\0002", 4096) = 4 close(6) = 0 rtas(0x7fffed497a00) = 0 geteuid() = 0 openat(AT_FDCWD, "/proc/ppc64/rtas/rmo_buffer", O_RDONLY) = 6 close(6) = 0 openat(AT_FDCWD, "/dev/mem", O_RDWR) = 6 munmap(0x7fff802a0000, 8192) = 0 close(6) = 0 getpid() = 41218 fcntl(5, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=2}) = 0 Conclusion: it's fine to assume that lscpu can open the file O_RDONLY and in O_RDWR on ppc64le. Issue migration from Bugzilla to Jira is in process at this time. This will be the last message in Jira copied from the Bugzilla bug. This BZ has been automatically migrated to the issues.redhat.com Red Hat Issue Tracker. All future work related to this report will be managed there. To find the migrated issue, look in the "Links" section for a direct link to the new issue location. The issue key will have an icon of 2 footprints next to it, and begin with "RHEL-" followed by an integer. You can also find this issue by visiting https://issues.redhat.com/issues/?jql= and searching the "Bugzilla Bug" field for this BZ's number, e.g. a search like: "Bugzilla Bug" = 1234567 In the event you have trouble locating or viewing this issue, you can file an issue by sending mail to rh-issues. |
Description of problem: During the course of automated testing of subscription-manager on ppc64le, the following selinux denials have been appearing regularly... Here is the denials in /var/log/audit.log... type=AVC msg=audit(1689950723.971:7026): avc: denied { write } for pid=47447 comm="lscpu" name="mem" dev="devtmpfs" ino=3 scontext=system_u:system_r:rhsmcertd_t:s0 tcontext=system_u:object_r:memory_device_t:s0 tclass=chr_file permissive=0 type=AVC msg=audit(1689950724.041:7027): avc: denied { write } for pid=47520 comm="lscpu" name="mem" dev="devtmpfs" ino=3 scontext=system_u:system_r:rhsmcertd_t:s0 tcontext=system_u:object_r:memory_device_t:s0 tclass=chr_file permissive=0 Here is the tail of /var/log/rhsm/rhsm.log corresponding to the time of the denials above... 2023-07-21 10:45:25,005 [DEBUG] rhsmcertd-worker:47327:MainThread @lock.py:226 - Unlocking file /run/rhsm/cert.pid 2023-07-21 10:45:25,005 [DEBUG] rhsmcertd-worker:47327:MainThread @base_action_client.py:82 - running lib: <subscription_manager.installedproductslib.InstalledProductsActionInvoker object at 0x7fffa0fc8340> 2023-07-21 10:45:25,005 [DEBUG] rhsmcertd-worker:47327:MainThread @lock.py:181 - Locking file: /run/rhsm/cert.pid 2023-07-21 10:45:25,005 [DEBUG] rhsmcertd-worker:47327:MainThread @cache.py:187 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json 2023-07-21 10:45:25,005 [DEBUG] rhsmcertd-worker:47327:MainThread @cache.py:205 - No changes. 2023-07-21 10:45:25,005 [DEBUG] rhsmcertd-worker:47327:MainThread @lock.py:226 - Unlocking file /run/rhsm/cert.pid 2023-07-21 10:45:25,006 [DEBUG] rhsmcertd-worker:47327:MainThread @base_action_client.py:82 - running lib: <subscription_manager.syspurposelib.SyspurposeSyncActionInvoker object at 0x7fffa0fc84c0> 2023-07-21 10:45:25,006 [DEBUG] rhsmcertd-worker:47327:MainThread @lock.py:181 - Locking file: /run/rhsm/cert.pid 2023-07-21 10:45:25,006 [DEBUG] rhsmcertd-worker:47327:MainThread @files.py:390 - Successfully read cached syspurpose contents. 2023-07-21 10:45:25,006 [DEBUG] rhsmcertd-worker:47327:MainThread @files.py:290 - Attempting to sync syspurpose content... 2023-07-21 10:45:25,006 [DEBUG] rhsmcertd-worker:47327:MainThread @connection.py:1116 - Making request: GET /subscription/consumers/d2154a89-29e9-47d8-8f6b-574523b30679 2023-07-21 10:45:25,007 [DEBUG] rhsmcertd-worker:47327:MainThread @connection.py:755 - Creating new connection 2023-07-21 10:45:25,009 [DEBUG] rhsmcertd-worker:47327:MainThread @connection.py:725 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem 2023-07-21 10:45:25,047 [DEBUG] rhsmcertd-worker:47327:MainThread @connection.py:820 - Created connection: <ssl.SSLSocket fd=5, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.0.2.181', 52774), raddr=('10.2.77.208', 443)> 2023-07-21 10:45:25,121 [DEBUG] rhsmcertd-worker:47327:MainThread @connection.py:1196 - Response time: 0.000141143798828125, Smoothed response time: 0.00016839908719062805 2023-07-21 10:45:25,121 [DEBUG] rhsmcertd-worker:47327:MainThread @connection.py:1150 - Response: status=200, requestUuid=613990c5-3f32-4144-bb8b-775981c3eb6e, request="GET /subscription/consumers/d2154a89-29e9-47d8-8f6b-574523b30679" 2023-07-21 10:45:25,121 [DEBUG] rhsmcertd-worker:47327:MainThread @connection.py:1156 - Server wants to close connection. Closing HTTP connection 2023-07-21 10:45:25,122 [DEBUG] rhsmcertd-worker:47327:MainThread @files.py:379 - Successfully read remote syspurpose from server. 2023-07-21 10:45:25,122 [DEBUG] rhsmcertd-worker:47327:MainThread @files.py:390 - Successfully read cached syspurpose contents. 2023-07-21 10:45:25,122 [DEBUG] rhsmcertd-worker:47327:MainThread @files.py:699 - Attempting a three-way merge... 2023-07-21 10:45:25,123 [DEBUG] rhsmcertd-worker:47327:MainThread @files.py:651 - Successfully updated syspurpose values at '/etc/rhsm/syspurpose/syspurpose.json'. 2023-07-21 10:45:25,123 [DEBUG] rhsmcertd-worker:47327:MainThread @files.py:652 - Failed to update syspurpose values at '/etc/rhsm/syspurpose/syspurpose.json'. 2023-07-21 10:45:25,123 [DEBUG] rhsmcertd-worker:47327:MainThread @files.py:651 - Successfully updated syspurpose values at '/var/lib/rhsm/cache/syspurpose.json'. 2023-07-21 10:45:25,123 [DEBUG] rhsmcertd-worker:47327:MainThread @files.py:652 - Failed to update syspurpose values at '/var/lib/rhsm/cache/syspurpose.json'. 2023-07-21 10:45:25,123 [DEBUG] rhsmcertd-worker:47327:MainThread @files.py:316 - Successfully synced system purpose. 2023-07-21 10:45:25,123 [DEBUG] rhsmcertd-worker:47327:MainThread @syspurposelib.py:282 - Syspurpose updated: Syspurpose Sync status: None updates: exceptions: 2023-07-21 10:45:25,123 [DEBUG] rhsmcertd-worker:47327:MainThread @lock.py:226 - Unlocking file /run/rhsm/cert.pid 2023-07-21 10:45:25,124 [DEBUG] rhsmcertd-worker:47327:MainThread @lock.py:226 - Unlocking file /run/rhsm/cert.pid 2023-07-21 10:45:25,473 [DEBUG] rhsmcertd-worker:47592:MainThread @rhsmcertd_worker.py:179 - X-Correlation-ID: 41195c07196a4d62bd7f0c17943f0b33 2023-07-21 10:45:25,473 [DEBUG] rhsmcertd-worker:47592:MainThread @rhsmcertd_worker.py:183 - check for rhsmcertd disable 2023-07-21 10:45:25,475 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:238 - Environment variable NO_PROXY= will be used 2023-07-21 10:45:25,475 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:622 - Creating new BaseRestLib instance 2023-07-21 10:45:25,475 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:364 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False 2023-07-21 10:45:25,475 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1116 - Making request: GET /subscription/ 2023-07-21 10:45:25,475 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:755 - Creating new connection 2023-07-21 10:45:25,479 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:725 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem 2023-07-21 10:45:25,517 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:820 - Created connection: <ssl.SSLSocket fd=5, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.0.2.181', 52782), raddr=('10.2.77.208', 443)> 2023-07-21 10:45:25,542 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1196 - Response time: 0.000118255615234375, Smoothed response time: 0.000118255615234375 2023-07-21 10:45:25,542 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1150 - Response: status=200, requestUuid=5366aa11-2447-44a7-86c0-702c76bc82fc, request="GET /subscription/" 2023-07-21 10:45:25,542 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1156 - Server wants to close connection. Closing HTTP connection 2023-07-21 10:45:25,543 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1405 - Server supports the following resources: {'entitlements': '/entitlements', '': '', 'subscriptions': '/subscriptions', 'roles': '/roles', 'jobs': '/jobs', 'activation_keys': '/activation_keys', 'admin': '/admin', 'pools': '/pools', 'rules': '/rules', 'owners': '/owners', 'cdn': '/cdn', 'content_overrides': '/consumers/{consumer_uuid}/content_overrides', '{owner}': '/hypervisors/{owner}', 'users': '/users', 'content': '/content', 'products': '/products', 'consumertypes': '/consumertypes', 'consumers': '/consumers', 'deleted_consumers': '/deleted_consumers', 'distributor_versions': '/distributor_versions', 'crl': '/crl', '{id}': '/serials/{id}', 'status': '/status', 'packages': '/consumers/{consumer_uuid}/packages'} 2023-07-21 10:45:25,543 [DEBUG] rhsmcertd-worker:47592:MainThread @lock.py:181 - Locking file: /run/rhsm/cert.pid 2023-07-21 10:45:25,543 [DEBUG] rhsmcertd-worker:47592:MainThread @base_action_client.py:82 - running lib: <subscription_manager.installedproductslib.InstalledProductsActionInvoker object at 0x7fffac398130> 2023-07-21 10:45:25,543 [DEBUG] rhsmcertd-worker:47592:MainThread @lock.py:181 - Locking file: /run/rhsm/cert.pid 2023-07-21 10:45:25,545 [DEBUG] rhsmcertd-worker:47592:MainThread @identity.py:142 - Loading consumer info from identity certificates. 2023-07-21 10:45:25,546 [DEBUG] rhsmcertd-worker:47592:MainThread @cache.py:187 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json 2023-07-21 10:45:25,546 [DEBUG] rhsmcertd-worker:47592:MainThread @cache.py:205 - No changes. 2023-07-21 10:45:25,546 [DEBUG] rhsmcertd-worker:47592:MainThread @lock.py:226 - Unlocking file /run/rhsm/cert.pid 2023-07-21 10:45:25,546 [DEBUG] rhsmcertd-worker:47592:MainThread @base_action_client.py:82 - running lib: <subscription_manager.syspurposelib.SyspurposeSyncActionInvoker object at 0x7fffac3985e0> 2023-07-21 10:45:25,546 [DEBUG] rhsmcertd-worker:47592:MainThread @lock.py:181 - Locking file: /run/rhsm/cert.pid 2023-07-21 10:45:25,546 [DEBUG] rhsmcertd-worker:47592:MainThread @files.py:390 - Successfully read cached syspurpose contents. 2023-07-21 10:45:25,546 [DEBUG] rhsmcertd-worker:47592:MainThread @files.py:290 - Attempting to sync syspurpose content... 2023-07-21 10:45:25,547 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1116 - Making request: GET /subscription/status 2023-07-21 10:45:25,547 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:755 - Creating new connection 2023-07-21 10:45:25,549 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:725 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem 2023-07-21 10:45:25,589 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:820 - Created connection: <ssl.SSLSocket fd=5, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.0.2.181', 52788), raddr=('10.2.77.208', 443)> 2023-07-21 10:45:25,615 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1196 - Response time: 0.00011038780212402344, Smoothed response time: 0.00011746883392333985 2023-07-21 10:45:25,615 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1150 - Response: status=200, requestUuid=069bfd1f-647f-45e9-90b4-2c3f35fa7230, request="GET /subscription/status" 2023-07-21 10:45:25,615 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1156 - Server wants to close connection. Closing HTTP connection 2023-07-21 10:45:25,615 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1449 - Server has the following capabilities: ['keycloak_auth', 'cloud_registration', 'instance_multiplier', 'derived_product', 'vcpu', 'cert_v3', 'hypervisors_heartbeat', 'remove_by_pool_id', 'syspurpose', 'storage_band', 'device_auth', 'cores', 'ssl_verify_status', 'multi_environment', 'hypervisors_async', 'org_level_content_access', 'guest_limit', 'ram', 'batch_bind', 'combined_reporting'] 2023-07-21 10:45:25,616 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1116 - Making request: GET /subscription/consumers/d2154a89-29e9-47d8-8f6b-574523b30679 2023-07-21 10:45:25,616 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:755 - Creating new connection 2023-07-21 10:45:25,618 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:725 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem 2023-07-21 10:45:25,657 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:820 - Created connection: <ssl.SSLSocket fd=5, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.0.2.181', 52794), raddr=('10.2.77.208', 443)> 2023-07-21 10:45:25,727 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1196 - Response time: 0.000110626220703125, Smoothed response time: 0.00011678457260131837 2023-07-21 10:45:25,728 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1150 - Response: status=200, requestUuid=fa8164d3-d4b1-4e86-b710-74fd1c28c28f, request="GET /subscription/consumers/d2154a89-29e9-47d8-8f6b-574523b30679" 2023-07-21 10:45:25,728 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1156 - Server wants to close connection. Closing HTTP connection 2023-07-21 10:45:25,728 [DEBUG] rhsmcertd-worker:47592:MainThread @files.py:379 - Successfully read remote syspurpose from server. 2023-07-21 10:45:25,728 [DEBUG] rhsmcertd-worker:47592:MainThread @files.py:390 - Successfully read cached syspurpose contents. 2023-07-21 10:45:25,728 [DEBUG] rhsmcertd-worker:47592:MainThread @files.py:699 - Attempting a three-way merge... 2023-07-21 10:45:25,729 [DEBUG] rhsmcertd-worker:47592:MainThread @files.py:651 - Successfully updated syspurpose values at '/etc/rhsm/syspurpose/syspurpose.json'. 2023-07-21 10:45:25,729 [DEBUG] rhsmcertd-worker:47592:MainThread @files.py:652 - Failed to update syspurpose values at '/etc/rhsm/syspurpose/syspurpose.json'. 2023-07-21 10:45:25,729 [DEBUG] rhsmcertd-worker:47592:MainThread @files.py:651 - Successfully updated syspurpose values at '/var/lib/rhsm/cache/syspurpose.json'. 2023-07-21 10:45:25,729 [DEBUG] rhsmcertd-worker:47592:MainThread @files.py:652 - Failed to update syspurpose values at '/var/lib/rhsm/cache/syspurpose.json'. 2023-07-21 10:45:25,729 [DEBUG] rhsmcertd-worker:47592:MainThread @files.py:316 - Successfully synced system purpose. 2023-07-21 10:45:25,729 [DEBUG] rhsmcertd-worker:47592:MainThread @syspurposelib.py:282 - Syspurpose updated: Syspurpose Sync status: None updates: exceptions: 2023-07-21 10:45:25,729 [DEBUG] rhsmcertd-worker:47592:MainThread @lock.py:226 - Unlocking file /run/rhsm/cert.pid 2023-07-21 10:45:25,730 [DEBUG] rhsmcertd-worker:47592:MainThread @base_action_client.py:82 - running lib: <subscription_manager.healinglib.HealingActionInvoker object at 0x7fffac3982e0> 2023-07-21 10:45:25,730 [DEBUG] rhsmcertd-worker:47592:MainThread @lock.py:181 - Locking file: /run/rhsm/cert.pid 2023-07-21 10:45:25,730 [DEBUG] rhsmcertd-worker:47592:MainThread @plugins.py:592 - loaded plugin modules: [] 2023-07-21 10:45:25,730 [DEBUG] rhsmcertd-worker:47592:MainThread @plugins.py:593 - loaded plugins: {} 2023-07-21 10:45:25,730 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1116 - Making request: GET /subscription/consumers/d2154a89-29e9-47d8-8f6b-574523b30679 2023-07-21 10:45:25,731 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:755 - Creating new connection 2023-07-21 10:45:25,733 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:725 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem 2023-07-21 10:45:25,772 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:820 - Created connection: <ssl.SSLSocket fd=5, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.0.2.181', 52808), raddr=('10.2.77.208', 443)> 2023-07-21 10:45:25,850 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1196 - Response time: 0.00012302398681640625, Smoothed response time: 0.00011740851402282715 2023-07-21 10:45:25,850 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1150 - Response: status=200, requestUuid=acf90f1d-29f9-44d9-a669-229a71fb35ad, request="GET /subscription/consumers/d2154a89-29e9-47d8-8f6b-574523b30679" 2023-07-21 10:45:25,850 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1156 - Server wants to close connection. Closing HTTP connection 2023-07-21 10:45:25,851 [WARNING] rhsmcertd-worker:47592:MainThread @healinglib.py:86 - Auto-heal disabled on server, skipping. 2023-07-21 10:45:25,851 [DEBUG] rhsmcertd-worker:47592:MainThread @lock.py:226 - Unlocking file /run/rhsm/cert.pid 2023-07-21 10:45:25,851 [DEBUG] rhsmcertd-worker:47592:MainThread @base_action_client.py:82 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x7fffac400f10> 2023-07-21 10:45:25,851 [DEBUG] rhsmcertd-worker:47592:MainThread @lock.py:181 - Locking file: /run/rhsm/cert.pid 2023-07-21 10:45:25,852 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1116 - Making request: GET /subscription/consumers/d2154a89-29e9-47d8-8f6b-574523b30679/certificates/serials 2023-07-21 10:45:25,852 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:755 - Creating new connection 2023-07-21 10:45:25,854 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:725 - Loaded CA certificates from /etc/rhsm/ca/: redhat-entitlement-authority.pem, redhat-uep.pem 2023-07-21 10:45:25,891 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:820 - Created connection: <ssl.SSLSocket fd=5, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.0.2.181', 52814), raddr=('10.2.77.208', 443)> 2023-07-21 10:45:25,953 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1196 - Response time: 0.00012183189392089844, Smoothed response time: 0.00011785085201263428 2023-07-21 10:45:25,953 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1150 - Response: status=200, requestUuid=5a3481c3-64c5-4e4f-8775-42fa507a8fb2, request="GET /subscription/consumers/d2154a89-29e9-47d8-8f6b-574523b30679/certificates/serials" 2023-07-21 10:45:25,953 [DEBUG] rhsmcertd-worker:47592:MainThread @connection.py:1156 - Server wants to close connection. Closing HTTP connection 2023-07-21 10:45:25,953 [INFO] rhsmcertd-worker:47592:MainThread @entcertlib.py:107 - certs updated: Total updates: 0 Found (local) serial# [] Expected (UEP) serial# [] Added (new) <NONE> Deleted (rogue): <NONE> 2023-07-21 10:45:25,954 [DEBUG] rhsmcertd-worker:47592:MainThread @lock.py:226 - Unlocking file /run/rhsm/cert.pid 2023-07-21 10:45:25,954 [DEBUG] rhsmcertd-worker:47592:MainThread @lock.py:226 - Unlocking file /run/rhsm/cert.pid Here is the tail of /var/log/rhsm/rhsmcertd.log corresponding to the time of the denials above... Fri Jul 21 10:45:23 2023 [DEBUG] (Cert check) executing: /usr/libexec/rhsmcertd-worker Fri Jul 21 10:45:25 2023 [INFO] (Cert Check) Certificates updated. Fri Jul 21 10:45:25 2023 [DEBUG] (Auto-attach) executing: /usr/libexec/rhsmcertd-worker --autoheal Fri Jul 21 10:45:25 2023 [INFO] (Auto-attach) Certificates updated. Version-Release number of selected component (if applicable): [root@ibm-p9z-25-lp6 ~]# rpm -q subscription-manager selinux-policy subscription-manager-1.29.35-1.el9.ppc64le selinux-policy-38.1.17-1.el9.noarch How reproducible: Steps to Reproduce: The automated IdentityTests.testIdentityIsBackedUpWhenConsumerIsDeletedServerSide(...) repeatedly produces this selinux denial. Actual results: selinux denials above Expected results: no selinux denials Additional info: