Hide Forgot
Description of problem: On my OSP8 install, cinder-api and cinder-volume are writing to deleted log files. I suspect this is related to log rotation. Nova, ceilometer, keystone, and neutron do not appear to be doing this despite having logs rotated. Version-Release number of selected component (if applicable): python-cinder-7.0.1-5.el7ost.noarch openstack-cinder-7.0.1-5.el7ost.noarch How reproducible: Spotted on my environment once so far. (10.16.151.137) Steps to Reproduce: 1. Install Cinder w/ packstack 2. Leave running for more than a week 3. Look for logs Additional info: # service openstack-cinder-api status Redirecting to /bin/systemctl status openstack-cinder-api.service ● openstack-cinder-api.service - OpenStack Cinder API Server Loaded: loaded (/usr/lib/systemd/system/openstack-cinder-api.service; enabled; vendor preset: disabled) Active: active (running) since Fri 2016-01-22 15:28:21 EST; 1 weeks 4 days ago Main PID: 9722 (cinder-api) CGroup: /system.slice/openstack-cinder-api.service ├─9722 /usr/bin/python2 /usr/bin/cinder-api --config-file /usr/share/cinder/cinder-dist.conf --config-file /etc/cinder/cinder.conf --logfile /var/log/cinder/ap... ├─9733 /usr/bin/python2 /usr/bin/cinder-api --config-file /usr/share/cinder/cinder-dist.conf --config-file /etc/cinder/cinder.conf --logfile /var/log/cinder/ap... ├─9734 /usr/bin/python2 /usr/bin/cinder-api --config-file /usr/share/cinder/cinder-dist.conf --config-file /etc/cinder/cinder.conf --logfile /var/log/cinder/ap... ├─9735 /usr/bin/python2 /usr/bin/cinder-api --config-file /usr/share/cinder/cinder-dist.conf --config-file /etc/cinder/cinder.conf --logfile /var/log/cinder/ap... └─9736 /usr/bin/python2 /usr/bin/cinder-api --config-file /usr/share/cinder/cinder-dist.conf --config-file /etc/cinder/cinder.conf --logfile /var/log/cinder/ap... Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. [root@dhcp148-231 cinder]# rpm -qi openstack-cinder python-cinder Name : openstack-cinder Epoch : 1 Version : 7.0.1 Release : 5.el7ost Architecture: noarch Install Date: Fri 22 Jan 2016 11:45:10 AM EST Group : Unspecified Size : 141495 License : ASL 2.0 Signature : RSA/SHA256, Tue 19 Jan 2016 02:57:58 PM EST, Key ID 938a80caf21541eb Source RPM : openstack-cinder-7.0.1-5.el7ost.src.rpm Build Date : Thu 14 Jan 2016 03:58:26 AM EST Build Host : x86-036.build.eng.bos.redhat.com Relocations : (not relocatable) Packager : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla> Vendor : Red Hat, Inc. URL : http://www.openstack.org/software/openstack-storage/ Summary : OpenStack Volume service Description : OpenStack Volume (codename Cinder) provides services to manage and access block storage volumes for use by Virtual Machine instances. Name : python-cinder Epoch : 1 Version : 7.0.1 Release : 5.el7ost Architecture: noarch Install Date: Fri 22 Jan 2016 11:45:09 AM EST Group : Applications/System Size : 12824530 License : ASL 2.0 Signature : RSA/SHA256, Tue 19 Jan 2016 02:58:21 PM EST, Key ID 938a80caf21541eb Source RPM : openstack-cinder-7.0.1-5.el7ost.src.rpm Build Date : Thu 14 Jan 2016 03:58:26 AM EST Build Host : x86-036.build.eng.bos.redhat.com Relocations : (not relocatable) Packager : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla> Vendor : Red Hat, Inc. URL : http://www.openstack.org/software/openstack-storage/ Summary : OpenStack Volume Python libraries Description : OpenStack Volume (codename Cinder) provides services to manage and access block storage volumes for use by Virtual Machine instances. [root@dhcp148-231 cinder]# lsof -p 9722 | grep log cinder-ap 9722 cinder mem REG 253,1 11600 34004880 /usr/lib64/python2.7/lib-dynload/syslog.so cinder-ap 9722 cinder 3w REG 253,1 1044434 1129185 /var/log/cinder/api.log-20160124 (deleted) [root@dhcp148-231 cinder]# ls -l /var/log/cinder/api* -rw-r--r--. 1 cinder cinder 0 Jan 24 03:17 /var/log/cinder/api.log -rw-r--r--. 1 cinder cinder 73104 Jan 8 17:29 /var/log/cinder/api.log-20160110.gz -rw-r--r--. 1 cinder cinder 44116 Jan 21 11:46 /var/log/cinder/api.log-20160122.gz -rw-r--r--. 1 cinder cinder 88684 Jan 22 15:35 /var/log/cinder/api.log-20160124.gz [root@dhcp148-231 cinder]# cat /etc/logrotate.d/openstack-cinder compress /var/log/cinder/*.log { weekly rotate 4 missingok compress minsize 100k }
Note: I manually sent a SIGHUP to cinder-volume and it then opened a new log file. Possible cinder bug where SIGHUP is sometimes ignored/ineffective?
... which resulted in a worse problem. An LVM volume wipe was running, dd'ing the device. The SIGHUP reloaded the volume driver, which started the delete again, causing a second dd process to start to the same device. 2016-02-03 12:23:32.638 7467 INFO oslo_service.service [req-dcb674ab-972a-40f0-a9c5-eaa0e176833d - - - - -] Caught SIGHUP, stopping children 2016-02-03 12:23:32.643 7467 WARNING oslo_config.cfg [req-dcb674ab-972a-40f0-a9c5-eaa0e176833d - - - - -] Option "logdir" from group "DEFAULT" is deprecated. Use option "log-dir" from group "DEFAULT". 2016-02-03 12:23:32.653 7549 INFO oslo_service.service [req-dcb674ab-972a-40f0-a9c5-eaa0e176833d - - - - -] Child caught SIGHUP, exiting 2016-02-03 12:23:32.662 7549 WARNING oslo_config.cfg [req-dcb674ab-972a-40f0-a9c5-eaa0e176833d - - - - -] Option "logdir" from group "DEFAULT" is deprecated. Use option "log-dir" from group "DEFAULT". 2016-02-03 12:23:32.673 7549 INFO cinder.service [-] Starting cinder-volume node (version 7.0.1) 2016-02-03 12:23:32.674 7549 INFO cinder.volume.manager [req-3130f73d-f6fd-4d82-9fad-85891ec61b49 - - - - -] Starting volume driver LVMVolumeDriver (3.0.0) 2016-02-03 12:23:33.186 7549 WARNING oslo_config.cfg [req-3130f73d-f6fd-4d82-9fad-85891ec61b49 - - - - -] Option "lock_path" from group "DEFAULT" is deprecated. Use option "lock_path" from group "oslo_concurrency". 2016-02-03 12:23:33.369 7549 INFO cinder.volume.targets.iscsi [req-3130f73d-f6fd-4d82-9fad-85891ec61b49 - - - - -] Skipping remove_export. No iscsi_target is presently exported for volume: fb38e727-9ebc-4d7f-ac33-f398c3b67fd7 2016-02-03 12:23:33.626 7549 INFO cinder.volume.utils [req-3130f73d-f6fd-4d82-9fad-85891ec61b49 - - - - -] Performing secure delete on volume: /dev/mapper/cinder--volumes-volume--fb38e727--9ebc--4d7f--ac33--f398c3b67fd7 7467 ? Ss 164:57 /usr/bin/python2 /usr/bin/cinder-volume --config-file /usr/share/cinder/cinder-dist.conf --config-file /etc/cinder/cinder.conf --logfile /var/log/ 7549 ? S 0:03 \_ /usr/bin/python2 /usr/bin/cinder-volume --config-file /usr/share/cinder/cinder-dist.conf --config-file /etc/cinder/cinder.conf --logfile /var/ 7676 ? S 0:00 \_ sudo cinder-rootwrap /etc/cinder/rootwrap.conf cgexec -g blkio:cinder-volume-copy dd if=/dev/zero of=/dev/mapper/cinder--volumes-volume--f 7677 ? S 0:00 | \_ /usr/bin/python2 /usr/bin/cinder-rootwrap /etc/cinder/rootwrap.conf cgexec -g blkio:cinder-volume-copy dd if=/dev/zero of=/dev/mapper/ 7678 ? D 0:00 | \_ dd if=/dev/zero of=/dev/mapper/cinder--volumes-volume--fb38e727--9ebc--4d7f--ac33--f398c3b67fd7 count=1 bs=1M oflag=direct 19218 ? S 0:00 \_ sudo cinder-rootwrap /etc/cinder/rootwrap.conf cgexec -g blkio:cinder-volume-copy dd if=/dev/zero of=/dev/mapper/cinder--volumes-volume--f 19219 ? S 0:00 \_ /usr/bin/python2 /usr/bin/cinder-rootwrap /etc/cinder/rootwrap.conf cgexec -g blkio:cinder-volume-copy dd if=/dev/zero of=/dev/mapper/ 19220 ? D 0:00 \_ dd if=/dev/zero of=/dev/mapper/cinder--volumes-volume--fb38e727--9ebc--4d7f--ac33--f398c3b67fd7 count=1 bs=1M oflag=direct
Log issue is probably fixed by https://review.openstack.org/#/c/208366/. This upstream launchpad https://bugs.launchpad.net/oslo-incubator/+bug/1276694 is related to the SIGHUP issue described here.
It may be cleanest to fix the log issue by configuring logrotate to use the "copytruncate" method.
(In reply to Eric Harney from comment #5) > It may be cleanest to fix the log issue by configuring logrotate to use the > "copytruncate" method. Agree. Btw, that approach is already proposed in BZ#1299899
*** This bug has been marked as a duplicate of bug 1309387 ***