Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1071674

Summary: Packstack fails due to permission issues with /var/log/keystone/keystone.log
Product: Red Hat OpenStack Reporter: Nir Magnezi <nmagnezi>
Component: openstack-packstackAssignee: Martin Magr <mmagr>
Status: CLOSED ERRATA QA Contact: Udi Kalifon <ukalifon>
Severity: high Docs Contact:
Priority: unspecified    
Version: 4.0CC: aberezin, aortega, clasohm, ddomingo, derekh, fvollero, ichavero, lbezdick, mmagr, oblaut, openstack.redhat.com, psedlak, sclewis, social, srevivo, yeylon
Target Milestone: z4Keywords: UserExperience, ZStream
Target Release: 4.0   
Hardware: Unspecified   
OS: Linux   
Whiteboard:
Fixed In Version: openstack-packstack-2013.2.1-0.31.dev1018.el6ost Doc Type: Bug Fix
Doc Text:
Previously, it was possible for Packstack to incorrectly deploy the OpenStack Identity log file (namely, /var/log/keystone/keystone.log) with an ownership of 'root:root' (inteaed of 'keystone:keystone'). This release features the following changes in order to prevent this from occurring: * The cron job that runs every minute to flush tokens now explicitly runs as the correct user (namely, 'keystone:keystone'). * The OpenStack Identity DB user is now explicitly set to 'keystone_admin'. * A race condition was added to help ensure that db_sync and pki_setup runs before the OpenStack Identity log file is created.
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-05-29 19:58:26 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:
Attachments:
Description Flags
packstack answer file
none
keystone.pp.log with error from version 2013.2.1-0.30.dev1013
none
audit.log none

Description Nir Magnezi 2014-03-02 19:12:36 UTC
Created attachment 869678 [details]
packstack answer file

Description of problem:
=======================
packstack fails with an error, due to the fact that keystone.log is owned by root:root instead of keystone:keystone

Version-Release number of selected component (if applicable):
=============================================================
Havana 2014-02-28.3
openstack-packstack-2013.2.1-0.25.dev987.el6ost.noarch

How reproducible:
=================
2/2

Steps to Reproduce:
===================
1. Use packstack to install openstack (see answer file attached)

Actual results:
===============
Snipped from packstack log:

2014-03-02 20:11:07::DEBUG::sequences::48::root:: Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/packstack/installer/core/sequences.py", line 46, in run
    self.function(config)
  File "/usr/lib/python2.6/site-packages/packstack/plugins/puppet_950.py", line 187, in applyPuppetManifest
    waitforpuppet(currently_running)
  File "/usr/lib/python2.6/site-packages/packstack/plugins/puppet_950.py", line 167, in waitforpuppet
    validate_logfile(log)
  File "/usr/lib/python2.6/site-packages/packstack/modules/puppet.py", line 90, in validate_logfile
    raise PuppetError(message)
PuppetError: Error appeared during Puppet run: 192.168.160.29_keystone.pp
^[[mNotice: /Stage[main]/Keystone/Exec[keystone-manage db_sync]/returns: IOError: [Errno 13] Permission denied: '/var/log/keystone/keystone.log'^[[0m
You will find full trace in log /var/tmp/packstack/20140302-200328-EiK5ct/manifests/192.168.160.29_keystone.pp.log

2014-03-02 20:11:07::ERROR::run_setup::912::root:: Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/packstack/installer/run_setup.py", line 907, in main
    _main(confFile)
  File "/usr/lib/python2.6/site-packages/packstack/installer/run_setup.py", line 573, in _main
    runSequences()
  File "/usr/lib/python2.6/site-packages/packstack/installer/run_setup.py", line 552, in runSequences
    controller.runAllSequences()
  File "/usr/lib/python2.6/site-packages/packstack/installer/setup_controller.py", line 84, in runAllSequences
    sequence.run(self.CONF)
  File "/usr/lib/python2.6/site-packages/packstack/installer/core/sequences.py", line 105, in run
    step.run(config=config)
  File "/usr/lib/python2.6/site-packages/packstack/installer/core/sequences.py", line 52, in run
    raise SequenceError(str(ex))
SequenceError: Error appeared during Puppet run: 192.168.160.29_keystone.pp
^[[mNotice: /Stage[main]/Keystone/Exec[keystone-manage db_sync]/returns: IOError: [Errno 13] Permission denied: '/var/log/keystone/keystone.log'^[[0m
You will find full trace in log /var/tmp/packstack/20140302-200328-EiK5ct/manifests/192.168.160.29_keystone.pp.log

Expected results:
=================
as a workaround:
1. chown keystone:keystone /var/log/keystone/keystone.log
2. re-run packstack

Comment 1 Nir Magnezi 2014-03-02 19:13:51 UTC
Sorry, the workaround should have been under 'Additional Info'
The expected result is successful installation.

Comment 6 Alvaro Lopez Ortega 2014-03-11 19:30:42 UTC
Even though a patch was merged, there are still a few corners cases to take care of.

Comment 10 Udi Kalifon 2014-04-23 11:50:34 UTC
No problems using puddle 2014-04-15.5:
openstack-packstack-2013.2.1-0.30.dev1013.el6ost.noarch
openstack-packstack-puppet-2013.2.1-0.30.dev1013.el6ost.noarch

Comment 11 Pavel Sedlák 2014-04-28 17:34:45 UTC
This error:
> 192.168.1.8_keystone.pp:                          [ ERROR ]
> Applying Puppet manifests                         [ ERROR ]
> 
> ERROR : Error appeared during Puppet run: 192.168.1.8_keystone.pp
> Notice: /Stage[main]/Keystone::Db::Sync/Exec[keystone-manage db_sync]/returns: IOError: [Errno 13] Permission denied: '/var/log/keystone/keystone.log'
> You will find full trace in log /var/tmp/packstack/20140428-160128-93VPo9/manifests/192.168.1.8_keystone.pp.log

still happens with:
> openstack-packstack        noarch 2013.2.1-0.30.dev1013.el6ost
> openstack-packstack-puppet noarch 2013.2.1-0.30.dev1013.el6ost

See attached keystone.pp.log.

Comment 12 Pavel Sedlák 2014-04-28 17:36:01 UTC
Created attachment 890537 [details]
keystone.pp.log with error from version 2013.2.1-0.30.dev1013

Comment 14 Lukas Bezdicka 2014-04-29 14:24:08 UTC
Hi, can you please add audit logs from the machine? We need to know whether it was selinux or just standard unix permission.

Comment 15 Pavel Sedlák 2014-04-29 23:05:50 UTC
Created attachment 890967 [details]
audit.log

It seems as SELinux was not causing trouble here.

What I've missed to mention is, that this is not easily reproducible, it's flaky issue happening like once per few dozens (maybe 50-100?) of runs.

And just noticed ... https://github.com/stackforge/packstack/blob/master/packstack/puppet/templates/keystone.pp what if that cron entry can get deployed and actually executed before anything else creates/or fixes keystone.log?
Though probably almost all of the things require service running first, and that one needs db_sync etc to be done anyway - so i guess enforcing proper permissions should be done before that.

Comment 16 Lukas Bezdicka 2014-04-30 08:35:20 UTC
It definetly is the cron job, sorry for our blindness.

[root@localhost ~]# ps auxf | grep keystone
keystone   834  1.2  1.2 308072 50384 ?        Ss   10:28   0:00 /usr/bin/python /usr/bin/keystone-all
root      2917  0.0  0.0 112672   916 pts/0    S+   10:29   0:00          \_ grep --color=auto keystone
[root@localhost ~]# lsof | grep keystone.log
keystone-  834        keystone    3w      REG              253,0    556104      15799 /var/log/keystone/keystone.log
[root@localhost ~]# service openstack-keystone stop
Redirecting to /bin/systemctl stop  openstack-keystone.service
[root@localhost ~]# lsof | grep keystone.log
[root@localhost ~]# mv /var/log/keystone/keystone.log  ./
[root@localhost ~]# /usr/bin/keystone-manage token_flush
[root@localhost ~]# ls -lha /var/log/keystone
total 8.0K
drwxr-x---.  2 keystone keystone 4.0K Apr 30 10:30 .
drwxr-xr-x. 31 root     root     4.0K Apr 30 10:28 ..
-rw-r--r--.  1 root     root        0 Apr 30 10:30 keystone.log

Comment 17 Udi Kalifon 2014-05-15 13:33:06 UTC
This issue is random, so it's hard to say if it's really resolved. Marking it as VERIFIED since it didn't happen for a considerable time already to a few people who tried to reproduce it (psedlak, mpavlase and myself).

Comment 20 errata-xmlrpc 2014-05-29 19:58:26 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.

http://rhn.redhat.com/errata/RHBA-2014-0577.html

Comment 21 Ira Abramov 2014-06-09 11:23:25 UTC
Might need to be re-opened, this appears again in OSP5 beta on RHEL6.5