neutron-server and keystone start to write logs into wrong file

Bug #1499349 reported by Denis Klepikov
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Fuel for OpenStack
Invalid
Medium
Fuel Library (Deprecated)
6.0.x
Won't Fix
High
MOS Maintenance
6.1.x
Fix Released
Critical
Alexey Stupnikov
7.0.x
Invalid
High
Alexey Stupnikov
8.0.x
Invalid
Medium
Fuel Library (Deprecated)

Bug Description

Fuel 6.0, neutron+vlan, ceph, Ubuntu

neutron-server and keystone start to write logs into wrong file

When Customer try to free space on disk he erase some .log files from /var/log/upstart folder on controller nodes.

After it neutron-server, neutron-dhcp, keystone services start to write logs into neutron-server.log.1, keystone.log.1, etc. files

Due to absence of the .log files, fuel-logrotate does not rotate .log.1 files and Customer reach full disk problem - cluster become inoperable.

Workaround:

For any logs into /var/log/upstart folder check that *.log file exist and services put data into it.
If the file do not exist or not using by related service (service can write logs onto *.log.1 file) please make next steps:

1 ensure that you have enough free space for log rotation
2 create fake log file with size more than 100M (let it be 120M and for example glance-api.log into /var/log/upstart folder)
fallocate -l 120M /var/log/upstart/glance-api.log
3 wait untill fuel-logrotate will be triggered by crone and fake log file will be rotated (glance-api.log -> glance-api.log.1, and system 4 will create new glance-api.log and start to put data there)
4 remove rotated fake log to free disk space (for example rm -f /var/log/upstart/glance-api.log.1)
5 proceed with another log

Changed in fuel:
assignee: nobody → Fuel Library Team (fuel-library)
summary: - neutron-server and keystone start to wright logs into wrong file
+ neutron-server and keystone start to write logs into wrong file
description: updated
Changed in fuel:
milestone: none → 6.0-updates
importance: Undecided → Medium
Revision history for this message
Denis Klepikov (dklepikov) wrote :

High due to customer-found

Dmitry Pyzhov (dpyzhov)
tags: added: area-library
Revision history for this message
Vitaly Sedelnik (vsedelnik) wrote :

Won't Fix for 6.0-updates as there is no way to deliver Fuel fixes in maintenance updates for 6.0. If the issue is occured in customer deployment we will have to fix it using the workaround provided in the description.

Revision history for this message
Gregory Elkinbard (gelkinbard) wrote :

I am wondering why this issue is considered to be invalid?
We have a known issue with log files filling up. And a user may take a reasonable action of removing the log files if this happens.
And if removing the log files will eventually cause the cluster to stop like happen at the customer site, we clearly have a bug and it needs to be fixed.

Linux process may hold a handle to a deleted file and keep writting to it.
That is a bit simplistic but probably acceptable. Linux process that does not hold an open handle, and selects a rotated file for writing instead of recreating its named log file is clearly in error.

Expected behavior is that services recreate the log file if it is missing. This is not a fuel bug, it should be fixed in the openstack services.

I do not understand the comment that we have no way to deliver Fuel fixes in a MU. Please explain.

Revision history for this message
Andrey Epifanov (aepifanov) wrote :

This issues happened again, at least 2 times
We need to fix it and backport to all MOS versions

Changed in fuel:
status: Invalid → Confirmed
Roman Rufanov (rrufanov)
tags: added: ct1
Revision history for this message
Roman Rufanov (rrufanov) wrote :

Customer found on MOS 6.1, need back-port please.

Revision history for this message
Alexey Stupnikov (astupnikov) wrote :

I have doublechecked this issue for MOS 6.1 and got interesting results. It turns out that described issue (appearence of *log.1 files) is caused by incorrect configuration of logrotated.

Overview:
Upstart log files contain stdout output from started daemons. There are two logrotate cron jobs: fuel-logrotate in root's crontab and logrotate cron job. The first one runs every 30 minutes, second one -- daily. Both jobs are responsible for rotating Upstart's logs, second job doesn't do it properly: it renames existing log file to log.1 file, but openstack processes can't understand job's signal about changed log file and still writes logs to renamed files (bug #1297705). To solve this issue we need to exclude /var/log/upstart dir configuration from daily logrotate job's objects.

Patch for bug #1469176 limited the amount of output and from now on it is hard to get the big enough files to rotate. However it still can be an issue.

Steps-to-reproduce:
1. create large log file in upstart directory:
# fallocate -l 120M /var/log/upstart/glance-api.log

2. manually rotate logs:
# logrotate /etc/logrotate.conf

3. check the result:
# ls -lh /var/log/upstart/glance-api*

Expected result:
There are glance-api.log and glance-api.log.1 files.

Actual result:
There is only glance-api.log.1 file and no glance-api.log file.

Patch:
logrotate.conf 2016-05-05 09:44:39.830318228 +0000
@@ -11,7 +11,7 @@

 # create new (empty) log files after rotating old ones
 create
-tabooext + .nodaily
+tabooext + .nodaily upstart
 compress
 delaycompress
 minsize 10M

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to fuel-library (stable/6.1)

Fix proposed to branch: stable/6.1
Review: https://review.openstack.org/312884

Revision history for this message
Alexey Stupnikov (astupnikov) wrote :

This bug is not valid for MOS 7.0 with MU updates applied.

Revision history for this message
Alexey Stupnikov (astupnikov) wrote :

Diag for MOS 7.0:
root@node-5:~# grep -r upstart /etc/logrotate.*
/etc/logrotate.d/fuel.nodaily:"/var/log/upstart/*.log"

Revision history for this message
Alexey Stupnikov (astupnikov) wrote :

More detailed information about MOS 7.0.

In MOS 6.1 upstart logs can be rotated by two separate cron jobs, one of them (its configuration is marked below) is not configured properly:
root@node-1:~# grep -r upstart /etc/logrotate.*
/etc/logrotate.d/upstart:/var/log/upstart/*.log { <<<<<<<<<<<<<<<<<<<
/etc/logrotate.d/fuel.nodaily:"/var/log/upstart/*.log"

In MOS 7.0 there is only one job with correct configuration exists, so described issue will not be reproduced there:
root@node-5:~# grep -r upstart /etc/logrotate.*
/etc/logrotate.d/fuel.nodaily:"/var/log/upstart/*.log"

So, I closed this bug as Invalid for MOS 7.0.

Changed in fuel:
status: Confirmed → Invalid
Revision history for this message
Alexey Stupnikov (astupnikov) wrote :

It is possible to solve this issue in MOS6.0 using patch from comment https://bugs.launchpad.net/fuel/+bug/1499349/comments/6 above on all slave ubuntu nodes and cleaning up the incorrect *log.1 files. So there is a WA available.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to fuel-library (stable/6.1)

Reviewed: https://review.openstack.org/312884
Committed: https://git.openstack.org/cgit/openstack/fuel-library/commit/?id=85536fadc87dba0a22a001e516905e989daadae4
Submitter: Jenkins
Branch: stable/6.1

commit 85536fadc87dba0a22a001e516905e989daadae4
Author: Alexey Stupnikov <email address hidden>
Date: Thu May 5 13:04:26 2016 +0300

    Excluded upstart log files from OS logrotate job processing

    Upstart log files contain stdout output from started daemons.
    There are two logrotate cron jobs: fuel-logrotate in root's
    crontab and logrotate cron job. The first one runs every 30
    minutes, second one -- daily. Both jobs are responsible for
    rotating Upstart's logs, but second job doesn't rotate them
    properly. logrotate cron job renames existing .log file to
    .log.1 file, but some openstack processes doesn't understand
    signals about changed log file. They still write their logs
    to renamed files (bug #1297705).
    To solve this issue we need to exclude upstart dir
    configuration from daily logrotate job config.

    Change-Id: I813845c08617ecb7ac728ffe5665e2120e267cd3
    Closes-bug: #1499349

tags: added: on-verification
Revision history for this message
Ekaterina Shutova (eshutova) wrote :

Verified on MOS 6.1 + mu6 updates.

Used scenario described above.

Revision history for this message
Ekaterina Shutova (eshutova) wrote :

Small addition:

Expected result:
There are only glance-api.log file.
Actual result matches expected result.

tags: added: t1
removed: ct1 on-verification
Revision history for this message
Roman Rufanov (rrufanov) wrote :

Reopening for 6.0 - Please back-port to 6.0 and it will be delivered as patch or instruction with steps.

Revision history for this message
Alexey Stupnikov (astupnikov) wrote :

We no longer support MOS5.1, MOS6.0, MOS6.1
We deliver only Critical/Security fixes to MOS7.0, MOS8.0.
We deliver only High/Critical/Security fixes to MOS9.2.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.