Bug 887340

Summary: Rectify suboptimal logrotate arrangement imposing server restarts
Product: Red Hat Enterprise Linux 6 Reporter: Jan Pokorný [poki] <jpokorny>
Component: luciAssignee: Jan Pokorný [poki] <jpokorny>
Status: CLOSED ERRATA QA Contact: cluster-qe <cluster-qe>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.4CC: cfeist, cluster-maint, fdinitto, rmccabe, rsteiger, slevine, tlavigne
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: luci-0.26.0-91.el6 Doc Type: Bug Fix
Doc Text:
Cause: Logrotate configuration for luci imposed restarting this web application so as to make it start logging to the new file (old one has just been rotated). Consequence: This interferes with the assumption luci will run without interruptions so that it can provide a smooth experience without intermittent issues or delays. Fix: Luci is now able to adapt to rotated file automatically, hence the directive imposing restart could have been removed from its logrotate configuration. Note, however, that if you are updating from a RHEL 6.8 version of luci or older, you need to drop the automatic RPM extension from /etc/logrotate.d/luci.rpmnew (or remove said directive on your own) to experience the new, desired behavior. Result: Luci now works smoothly even at the time of logrotate routine crossing its path.
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-03-21 11:38:23 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:

Description Jan Pokorný [poki] 2012-12-14 17:30:55 UTC
Recently, I've realized the possible issue arising from logrotate
mechanism (when in place and by default, it is [cron.daily]) when it
comes to fulfilling the recipe for luci (as provided by default).

Luci can be restarted in the middle of asynchronous request towards ricci,
which can cause user's inconvenience (e.g., told to wait until a popup
confirms the action, it will not show up or error in AJAX is reported)
or perhaps even some inconsistencies in the DB (IIRC, we do not hook
exit handlers or anything like this).

The expected solution:

a. change log handlers in luci.ini to use WatchedFileHandler [1]
   (suported in Python 2.6+)

b. change logrotate recipe not to restart luci as it should cope
   well with the changes "under the feets" after step a.


Testing the proper behavior after these changes should be easy.
Run luci, perform some activity so the log messages are emitted,
run /usr/sbin/logrotate with specially crafted recipe for luci
(or just prepare the boundary condition) and see if luci is restarted
(should not be after the fix), if log files are indeed rotated (both
before and after) and if the emitting log messages continues without
disruption (especially after the fix).

Optionally, overhead caused by watching the target file for change
can be measured.  Also the implementation of WatchedFileHandler should
be investigated and/or various target file systems should be considered
(due to differences in support of inotify and the like).


[1] http://docs.python.org/2/library/logging.handlers.html#watchedfilehandler

Comment 1 Jan Pokorný [poki] 2013-01-04 12:26:58 UTC
Actually, using "copytruncate" option in the logrotate config file
might be a better solution.

Comment 13 Jan Pokorný [poki] 2016-11-29 19:08:12 UTC
Reminder for possible heads up in release notes:

When the user performes update of luci to version in "Fixed in version"
field or higher, hence when updating manually can observe

> warning: /etc/logrotate.d/luci created as /etc/logrotate.d/luci.rpmnew

if some changes were made to /etc/logrotate.d/luci, she is suggested
to drop

>    postrotate
>        /sbin/service luci condrestart 2>/dev/null >/dev/null || :
>    endscript

from that file (or just "cp /etc/logrotate.d/luci{.rpmnew,}")
to avoid now spurious/unneeded restarts of luci when rotating the logs
kicks in.

(This because the file is marked %config(noreplace).)

Comment 14 Jan Pokorný [poki] 2016-11-29 19:16:10 UTC
I missed the "corner case" of initial luci setup:

# paster setup-app /var/lib/luci/etc/luci.ini --no-default-sysconfig
> Traceback (most recent call last):
>   File "/usr/bin/paster", line 9, in <module>
>     load_entry_point('PasteScript==1.7.3', 'console_scripts', 'paster')()
>   File "/usr/lib/python2.6/site-packages/paste/script/command.py", line 84, in run
>     invoke(command, command_name, options, args[1:])
>   File "/usr/lib/python2.6/site-packages/paste/script/command.py", line 123, in invoke
>     exit_code = runner.run(args)
>   File "/usr/lib/python2.6/site-packages/paste/script/appinstall.py", line 68, in run
>     return super(AbstractInstallCommand, self).run(new_args)
>   File "/usr/lib/python2.6/site-packages/paste/script/command.py", line 218, in run
>     result = self.command()
>   File "/usr/lib/python2.6/site-packages/paste/script/appinstall.py", line 446, in command
>     self.logging_file_config(config_file)
>   File "/usr/lib/python2.6/site-packages/paste/script/command.py", line 757, in logging_file_config
>     fileConfig(config_file)
>   File "/usr/lib64/python2.6/logging/config.py", line 84, in fileConfig
>     handlers = _install_handlers(cp, formatters)
>   File "/usr/lib64/python2.6/logging/config.py", line 161, in _install_handlers
>     args = eval(args, vars(logging))
>   File "<string>", line 1, in <module>
> AttributeError: 'file' object has no attribute 'filename'

Comment 15 Jan Pokorný [poki] 2016-11-30 13:25:55 UTC
There was yet another issue found with the new changes:

The problem occurs  when you install luci anew and set LOG_FILE to
a nondefault value, the proceed with "service luci start".
Some early setup tasks (not triggered upon subsequently start of luci)
have to -- by design -- resort to using default log file, but then
it's not precreated with correct owner (root instead) so it subsequently
fails on inability to write to that file.

This is now fixed and both custom + default log files are initially
pre-created with desired owner so this failure can no longer happen.

Comment 21 errata-xmlrpc 2017-03-21 11:38:23 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://rhn.redhat.com/errata/RHBA-2017-0766.html