Bug 1443215

Additional Info:
The failure goes away when selinux is disabled (setenforce 0).


Here's a trace from the audit.log...
----
type=SYSCALL msg=audit(04/20/2017 14:03:08.981:661364) : arch=x86_64 syscall=execve success=no exit=EACCES(Permission denied) a0=0x15ce770 a1=0x15c6ad0 a2=0x7ffdd5588b88 a3=0x7ffdd5585fa0 items=0 ppid=26616 pid=26628 auid=unset uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=(none) ses=unset comm=rhsmcertd-worke exe=/usr/bin/python2.7 subj=system_u:system_r:rhsmcertd_t:s0 key=(null) 
type=AVC msg=audit(04/20/2017 14:03:08.981:661364) : avc:  denied  { execute } for  pid=26628 comm=rhsmcertd-worke name=hostname dev="dm-0" ino=8973142 scontext=system_u:system_r:rhsmcertd_t:s0 tcontext=system_u:object_r:hostname_exec_t:s0 tclass=file 
----
type=SYSCALL msg=audit(04/20/2017 14:03:09.045:661365) : arch=x86_64 syscall=execve success=no exit=EACCES(Permission denied) a0=0x15c6ad0 a1=0x1687ff0 a2=0x7ffdd5588b88 a3=0x7ffdd5586110 items=0 ppid=26616 pid=26663 auid=unset uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=(none) ses=unset comm=rhsmcertd-worke exe=/usr/bin/python2.7 subj=system_u:system_r:rhsmcertd_t:s0 key=(null) 
type=AVC msg=audit(04/20/2017 14:03:09.045:661365) : avc:  denied  { execute } for  pid=26663 comm=rhsmcertd-worke name=hostname dev="dm-0" ino=8973142 scontext=system_u:system_r:rhsmcertd_t:s0 tcontext=system_u:object_r:hostname_exec_t:s0 tclass=file 
----

I can't reproduce this bug in master. I'm trying version subscription-manager-1.19.8-1. It is strange, it prints following error:

unable to open ATI��US��1�H��` to write timestamp: Permission denied

I can confirm that I able to reproduce it at 1.19.8-1. This happens during second and next cert check / auto-attach. I will test in master too.

*** Bug 1444711 has been marked as a duplicate of this bug. ***

*** Bug 1445059 has been marked as a duplicate of this bug. ***

Reproducing the failure on :
============================
# subscription-manager  version
server type: This system is currently not registered.
subscription management server: 0.9.51.21-1
subscription management rules: 5.15.1
subscription-manager: 1.19.8-1.el7
python-rhsm: 1.19.5-1.el7

Selinux in enforcing mode 

[root@bkr-hv01-guest24 ~]# sestatus 
SELinux status:                 enabled
SELinuxfs mount:                /sys/fs/selinux
SELinux root directory:         /etc/selinux
Loaded policy name:             targeted
Current mode:                   enforcing
Mode from config file:          enforcing
Policy MLS status:              enabled
Policy deny_unknown status:     allowed
Max kernel policy version:      28

[root@bkr-hv01-guest24 ~]# subscription-manager register
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
Username: stage_test_rhel74
Password: 
The system has been registered with ID: 6c392c89-f0dc-485d-87c4-43b0776a7801

 
[root@bkr-hv01-guest24 ~]# subscription-manager config --rhsmcertd.certcheckinterval=3 --rhsmcertd.autoattachinterval=4

[root@bkr-hv01-guest24 ~]# systemctl restart rhsmcertd.service

[root@bkr-hv01-guest24 ~]# tail -f /var/log/rhsm/rhsmcertd.log
Wed May  3 05:44:51 2017 [INFO] Auto-attach interval: 1440.0 minute(s) [86400 second(s)]
Wed May  3 05:44:51 2017 [INFO] Cert check interval: 240.0 minute(s) [14400 second(s)]
Wed May  3 05:44:51 2017 [INFO] Waiting 2.0 minute(s) plus 1787 splay second(s) [1907 seconds(s) totals] before performing first auto-attach.
Wed May  3 05:44:51 2017 [INFO] Waiting 2.0 minute(s) plus 9042 splay second(s) [9162 seconds(s) totals] before performing first cert check.
Wed May  3 06:09:26 2017 [INFO] rhsmcertd is shutting down...
Wed May  3 06:09:26 2017 [INFO] Starting rhsmcertd...
Wed May  3 06:09:26 2017 [INFO] Auto-attach interval: 4.0 minute(s) [240 second(s)]
Wed May  3 06:09:26 2017 [INFO] Cert check interval: 3.0 minute(s) [180 second(s)]
Wed May  3 06:09:26 2017 [INFO] Waiting 2.0 minute(s) plus 164 splay second(s) [284 seconds(s) totals] before performing first auto-attach.
Wed May  3 06:09:26 2017 [INFO] Waiting 2.0 minute(s) plus 2 splay second(s) [122 seconds(s) totals] before performing first cert check.
Wed May  3 06:11:34 2017 [INFO] (Cert Check) Certificates updated.
Wed May  3 06:12:26 2017 [WARN] unable to open ATI��US��1�H��` to write timestamp: Permission denied
Wed May  3 06:14:21 2017 [INFO] (Auto-attach) Certificates updated.

^^ reproduced the WARNING and avc denial 

Retesting with the latest subscription-manager :
=============================================
# subscription-manager version
server type: This system is currently not registered.
subscription management server: 0.9.51.21-1
subscription management rules: 5.15.1
subscription-manager: 1.19.12-1.el7
python-rhsm: 1.19.6-1.el7

selinux packages:
selinux-policy-3.13.1-145.el7.noarch
selinux-policy-targeted-3.13.1-145.el7.noarch

[root@ibm-x3650m4-01-vm-10 ~]# sestatus 
SELinux status:                 enabled
SELinuxfs mount:                /sys/fs/selinux
SELinux root directory:         /etc/selinux
Loaded policy name:             targeted
Current mode:                   enforcing
Mode from config file:          enforcing
Policy MLS status:              enabled
Policy deny_unknown status:     allowed
Max kernel policy version:      28


[root@ibm-x3650m4-01-vm-10 ~]# START_DATE_TIME=`date "+%m/%d/%Y %T"`
[root@ibm-x3650m4-01-vm-10 ~]#  ausearch -m AVC -m USER_AVC -m SELINUX_ERR -i -ts ${START_DATE_TIME}
<no matches>

[root@ibm-x3650m4-01-vm-10 ~]# subscription-manager config --rhsmcertd.certcheckinterval=3 --rhsmcertd.autoattachinterval=4

[root@ibm-x3650m4-01-vm-10 ~]# systemctl restart rhsmcertd.service

[root@ibm-x3650m4-01-vm-10 ~]#  tail -f /var/log/rhsm/rhsmcertd.log
Wed May  3 03:49:45 2017 [INFO] Cert check interval: 240.0 minutes [14400 seconds]
Wed May  3 03:49:45 2017 [INFO] Waiting 2.0 minutes plus 70529 splay seconds [70649 seconds total] before performing first auto-attach.
Wed May  3 03:49:45 2017 [INFO] Waiting 2.0 minutes plus 1115 splay seconds [1235 seconds total] before performing first cert check.
Wed May  3 04:10:49 2017 [INFO] (Cert Check) Certificates updated.
Wed May  3 06:20:26 2017 [INFO] rhsmcertd is shutting down...
Wed May  3 06:20:26 2017 [INFO] Starting rhsmcertd...
Wed May  3 06:20:26 2017 [INFO] Auto-attach interval: 4.0 minutes [240 seconds]
Wed May  3 06:20:26 2017 [INFO] Cert check interval: 3.0 minutes [180 seconds]
Wed May  3 06:20:26 2017 [INFO] Waiting 2.0 minutes plus 187 splay seconds [307 seconds total] before performing first auto-attach.
Wed May  3 06:20:26 2017 [INFO] Waiting 2.0 minutes plus 65 splay seconds [185 seconds total] before performing first cert check.
Wed May  3 06:23:47 2017 [INFO] (Cert Check) Certificates updated.
Wed May  3 06:25:49 2017 [INFO] (Auto-attach) Certificates updated.

No warnings have been observed in the rhsmcertd.log, but still AVC denials are reported in the log

----
#ausearch -m AVC -m USER_AVC -m SELINUX_ERR -i -ts ${START_DATE_TIME}
----
type=PROCTITLE msg=audit(05/03/2017 06:23:45.570:431) : proctitle=/usr/bin/python -Es /usr/libexec/rhsmcertd-worker
type=SYSCALL msg=audit(05/03/2017 06:23:45.570:431) : arch=x86_64 syscall=execve success=no exit=EACCES(Permission denied) a0=0x2a85740 a1=0x2a89e60 a2=0x7fff7ad1a738 a3=0x7fff7ad17ae0 items=0 ppid=10134 pid=10143 auid=unset uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=(none) ses=unset comm=rhsmcertd-worke exe=/usr/bin/python2.7 subj=system_u:system_r:rhsmcertd_t:s0 key=(null)
type=AVC msg=audit(05/03/2017 06:23:45.570:431) : avc:  denied  { execute } for  pid=10143 comm=rhsmcertd-worke name=hostname dev="dm-0" ino=100767763 scontext=system_u:system_r:rhsmcertd_t:s0 tcontext=system_u:object_r:hostname_exec_t:s0 tclass=file
----
type=PROCTITLE msg=audit(05/03/2017 06:23:45.657:432) : proctitle=/usr/bin/python -Es /usr/libexec/rhsmcertd-worker
type=SYSCALL msg=audit(05/03/2017 06:23:45.657:432) : arch=x86_64 syscall=execve success=no exit=EACCES(Permission denied) a0=0x2aa7930 a1=0x2a98800 a2=0x7fff7ad1a738 a3=0x7fff7ad17c50 items=0 ppid=10134 pid=10178 auid=unset uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=(none) ses=unset comm=rhsmcertd-worke exe=/usr/bin/python2.7 subj=system_u:system_r:rhsmcertd_t:s0 key=(null)
type=AVC msg=audit(05/03/2017 06:23:45.657:432) : avc:  denied  { execute } for  pid=10178 comm=rhsmcertd-worke name=hostname dev="dm-0" ino=100767763 scontext=system_u:system_r:rhsmcertd_t:s0 tcontext=system_u:object_r:hostname_exec_t:s0 tclass=file
----

Discussed with Selinux qe (mmalik) ,he informed that with the latest selinux package from brew avc denials no longer appear.

Updating selinux-policy 

#rpm -Uvh http://download.eng.bos.redhat.com/brewroot/packages/selinux-policy/3.13.1/147.el7/noarch/selinux-policy-3.13.1-147.el7.noarch.rpm http://download.eng.bos.redhat.com/brewroot/packages/selinux-policy/3.13.1/147.el7/noarch/selinux-policy-targeted-3.13.1-147.el7.noarch.rpm

#  rpm -qa selinux*
selinux-policy-targeted-3.13.1-147.el7.noarch
selinux-policy-3.13.1-147.el7.noarch

AVC Denials no longer appear after rhsmcertd restart 

# systemctl restart rhsmcertd.service
#  tail -f /var/log/rhsm/rhsmcertd.log
Wed May  3 06:53:29 2017 [INFO] Cert check interval: 3.0 minutes [180 seconds]
Wed May  3 06:53:29 2017 [INFO] Waiting 2.0 minutes plus 220 splay seconds [340 seconds total] before performing first auto-attach.
Wed May  3 06:53:29 2017 [INFO] Waiting 2.0 minutes plus 43 splay seconds [163 seconds total] before performing first cert check.
Wed May  3 06:56:17 2017 [INFO] (Cert Check) Certificates updated.
Wed May  3 06:58:49 2017 [INFO] rhsmcertd is shutting down...
Wed May  3 06:58:49 2017 [INFO] Starting rhsmcertd...
Wed May  3 06:58:49 2017 [INFO] Auto-attach interval: 4.0 minutes [240 seconds]
Wed May  3 06:58:49 2017 [INFO] Cert check interval: 3.0 minutes [180 seconds]
Wed May  3 06:58:49 2017 [INFO] Waiting 2.0 minutes plus 137 splay seconds [257 seconds total] before performing first auto-attach.
Wed May  3 06:58:49 2017 [INFO] Waiting 2.0 minutes plus 92 splay seconds [212 seconds total] before performing first cert check.
Wed May  3 07:02:26 2017 [INFO] (Cert Check) Certificates updated.
Wed May  3 07:03:17 2017 [INFO] (Auto-attach) Certificates updated.

[root@ibm-x3650m4-01-vm-10 ~]#  ausearch -m AVC -m USER_AVC -m SELINUX_ERR -i -ts ${START_DATE_TIME}
<no matches>

following subscription was attached 

# subscription-manager list --consumed
+-------------------------------------------+
   Consumed Subscriptions
+-------------------------------------------+
Subscription Name:   Red Hat Enterprise Linux for Virtual Datacenters, Premium (DERIVED SKU)
Provides:            Oracle Java (for RHEL Server)
                     Red Hat Enterprise Linux High Performance Networking (for RHEL Server) - Extended Update Support
                     Red Hat Enterprise Linux Server - Extended Update Support
                     Red Hat Enterprise Linux Atomic Host
                     Red Hat Enterprise Linux Server
                     Oracle Java (for RHEL Workstation)
                     Red Hat EUCJP Support (for RHEL Server) - Extended Update Support
                     Red Hat Enterprise Linux Resilient Storage (for RHEL Server) - Extended Update Support
                     Oracle Java (for RHEL Server) - Extended Update Support
                     Red Hat Software Collections (for RHEL Server)
                     Red Hat Beta
                     dotNET on RHEL (for RHEL Server)
                     Red Hat Enterprise Linux High Availability (for RHEL Server) - Extended Update Support
                     Red Hat Developer Toolset (for RHEL Server)
                     Red Hat Enterprise Linux Atomic Host Beta
                     Red Hat Enterprise Linux Scalable File System (for RHEL Server) - Extended Update Support
                     Red Hat Enterprise Linux Load Balancer (for RHEL Server) - Extended Update Support
                     Red Hat Software Collections Beta (for RHEL Server)
                     Red Hat S-JIS Support (for RHEL Server) - Extended Update Support
SKU:                 RH00049
Contract:            11273884
Account:             5764711
Serial:              2059875420132685304
Pool ID:             8a99f9815b20573c015b3de396ce1dab
Provides Management: No
Active:              True
Quantity Used:       1
Service Level:       Premium
Service Type:        L1-L3
Status Details:      Guest has not been reported on any host and is using a temporary unmapped guest subscription.
Subscription Type:   Standard (Temporary)
Starts:              04/04/2017
Ends:                05/04/2017


Based on the above observations, marking the bug as Verified!!

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-2017:2083