RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1443215 - unable to open ATI��US��1�H��` to write timestamp: Permission denied
Summary: unable to open ATI��US��1�H��` to write timestamp: Permission denied
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: subscription-manager
Version: 7.4
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: rc
: ---
Assignee: Jiri Hnidek
QA Contact: John Sefler
URL:
Whiteboard:
: 1444711 1445059 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-04-18 19:03 UTC by John Sefler
Modified: 2017-08-01 19:22 UTC (History)
6 users (show)

Fixed In Version: subscription-manager-1.19.10-1
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-08-01 19:22:43 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2017:2083 0 normal SHIPPED_LIVE python-rhsm and subscription-manager bug fix and enhancement update 2017-08-01 18:14:19 UTC

Description John Sefler 2017-04-18 19:03:03 UTC 
Description of problem:
When restarting the rhsmcertd, the following message is logged to /var/log/rhsmcertd

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


Version-Release number of selected component (if applicable):
[root@jsefler-rhel7 ~]# rpm -q subscription-manager python-rhsm selinux-policy
subscription-manager-1.19.8-1.el7.x86_64
python-rhsm-1.19.5-1.el7.x86_64
selinux-policy-3.13.1-101.el7.noarch


How reproducible:


Steps to Reproduce:
[root@jsefler-rhel7 ~]# subscription-manager config --rhsmcertd.certcheckinterval=3 --rhsmcertd.autoattachinterval=4
[root@jsefler-rhel7 ~]# systemctl restart rhsmcertd.service



[root@jsefler-rhel7 ~]# tail -f /var/log/rhsm/rhsmcertd.log
Tue Apr 18 14:53:33 2017 [INFO] rhsmcertd is shutting down...
Tue Apr 18 14:53:33 2017 [INFO] Starting rhsmcertd...
Tue Apr 18 14:53:33 2017 [INFO] Auto-attach interval: 4.0 minute(s) [240 second(s)]
Tue Apr 18 14:53:33 2017 [INFO] Cert check interval: 3.0 minute(s) [180 second(s)]
Tue Apr 18 14:53:33 2017 [INFO] Waiting 2.0 minute(s) plus 137 splay second(s) [257 seconds(s) totals] before performing first auto-attach.
Tue Apr 18 14:53:33 2017 [INFO] Waiting 2.0 minute(s) plus 156 splay second(s) [276 seconds(s) totals] before performing first cert check.
Tue Apr 18 14:56:33 2017 [WARN] unable to open ATI��US��1�H��` to write timestamp: Permission denied
Tue Apr 18 14:57:51 2017 [INFO] (Auto-attach) Certificates updated.
Tue Apr 18 14:58:10 2017 [INFO] (Cert Check) Certificates updated.



[root@jsefler-rhel7 ~]# tail -f /var/log/messages
Apr 18 14:53:33 jsefler-rhel7 systemd: Stopping Enable periodic update of entitlement certificates....
Apr 18 14:53:33 jsefler-rhel7 systemd: Starting Enable periodic update of entitlement certificates....
Apr 18 14:53:33 jsefler-rhel7 systemd: Started Enable periodic update of entitlement certificates..
Apr 18 14:54:01 jsefler-rhel7 systemd: Started Session 41303 of user root.
Apr 18 14:54:01 jsefler-rhel7 systemd: Starting Session 41303 of user root.
Apr 18 14:56:01 jsefler-rhel7 systemd: Started Session 41304 of user root.
Apr 18 14:56:01 jsefler-rhel7 systemd: Starting Session 41304 of user root.
Apr 18 14:58:01 jsefler-rhel7 systemd: Started Session 41305 of user root.
Apr 18 14:58:01 jsefler-rhel7 systemd: Starting Session 41305 of user root.
Apr 18 14:58:10 jsefler-rhel7 dbus[683]: [system] Activating service name='org.fedoraproject.Setroubleshootd' (using servicehelper)
Apr 18 14:58:10 jsefler-rhel7 dbus-daemon: dbus[683]: [system] Activating service name='org.fedoraproject.Setroubleshootd' (using servicehelper)
Apr 18 14:58:10 jsefler-rhel7 dbus[683]: [system] Successfully activated service 'org.fedoraproject.Setroubleshootd'
Apr 18 14:58:10 jsefler-rhel7 dbus-daemon: dbus[683]: [system] Successfully activated service 'org.fedoraproject.Setroubleshootd'
Apr 18 14:58:15 jsefler-rhel7 setroubleshoot: SELinux is preventing /usr/bin/python2.7 from execute access on the file /usr/bin/hostname. For complete SELinux messages. run sealert -l 5472ce31-8e46-4419-9023-92316d8ca873
Apr 18 14:58:15 jsefler-rhel7 python: SELinux is preventing /usr/bin/python2.7 from execute access on the file /usr/bin/hostname.#012#012*****  Plugin catchall (100. confidence) suggests   **************************#012#012If you believe that python2.7 should be allowed execute access on the hostname file by default.#012Then you should report this as a bug.#012You can generate a local policy module to allow this access.#012Do#012allow this access for now by executing:#012# ausearch -c 'rhsmcertd-worke' --raw | audit2allow -M my-rhsmcertdworke#012# semodule -i my-rhsmcertdworke.pp#012
Apr 18 14:58:18 jsefler-rhel7 setroubleshoot: SELinux is preventing /usr/bin/python2.7 from execute access on the file /usr/bin/hostname. For complete SELinux messages. run sealert -l 5472ce31-8e46-4419-9023-92316d8ca873
Apr 18 14:58:18 jsefler-rhel7 python: SELinux is preventing /usr/bin/python2.7 from execute access on the file /usr/bin/hostname.#012#012*****  Plugin catchall (100. confidence) suggests   **************************#012#012If you believe that python2.7 should be allowed execute access on the hostname file by default.#012Then you should report this as a bug.#012You can generate a local policy module to allow this access.#012Do#012allow this access for now by executing:#012# ausearch -c 'rhsmcertd-worke' --raw | audit2allow -M my-rhsmcertdworke#012# semodule -i my-rhsmcertdworke.pp#012



Actual results:
 above

Expected results:


Additional info:
Comment 2 John Sefler 2017-04-20 18:09:03 UTC 
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 
----
Comment 3 Jiri Hnidek 2017-04-21 12:22:31 UTC 
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
Comment 4 Jiri Hnidek 2017-04-21 12:55:05 UTC 
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.
Comment 5 Kevin Howell 2017-04-24 14:40:07 UTC 
*** Bug 1444711 has been marked as a duplicate of this bug. ***
Comment 6 Jiri Hnidek 2017-04-26 18:37:04 UTC 
*** Bug 1445059 has been marked as a duplicate of this bug. ***
Comment 8 Rehana 2017-05-03 11:08:23 UTC 
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!!
Comment 9 errata-xmlrpc 2017-08-01 19:22:43 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-2017:2083
Note You need to log in before you can comment on or make changes to this bug.