Switch file based logging to WatchedFileHandler for logrotate

Fixes lp:772397

FileHandler opens the logfile at startup, keeps the stream open and
continues to log to it forever.

If logrotate decides to rotate the file, it will rename the original
file and a new file is created with the same attributes as the original
file.

The problem is that the process is still writing to the original file,
not the newly created file. Traditionally, system daemons respond to
a SIGHUP by re-opening log files and logrotate can be configured to
deliver this signal on rotation.

However, python has an elegant solution. WatchedFileHandler monitors
the inode for the specified log file name and, if that ever changes,
it re-opens the stream.

Nova already uses WatchedFileHandler to good effect. See:

  https://code.launchpad.net/~soren/nova/logrotate/+merge/50292

Change-Id: I7f693f133d230d65d7c94ebf3a2ec0c8b362f993

Authors

@@ -16,6 +16,7 @@ Josh Kearney <josh@jk0.org>
 Justin Shepherd <jshepher@rackspace.com>
 Ken Pepple <ken.pepple@gmail.com>
 Kevin L. Mitchell <kevin.mitchell@rackspace.com>
+Mark McLoughlin <markmc@redhat.com>
 Matt Dietz <matt.dietz@rackspace.com>
 Monty Taylor <mordred@inaugust.com>
 Rick Clark <rick@openstack.org>

glance/common/config.py

@@ -173,7 +173,7 @@ def setup_logging(options, conf):
             logdir = conf.get('log_dir')
         if logdir:
             logfile = os.path.join(logdir, logfile)
-        handler = logging.FileHandler(logfile)
+        handler = logging.handlers.WatchedFileHandler(logfile)
     else:
         handler = logging.StreamHandler(sys.stdout)
 

glance/tests/functional/test_logging.py

@@ -17,7 +17,9 @@
 
 """Functional test case that tests logging output"""
 
+import httplib2
 import os
+import stat
 import unittest
 
 from glance.tests import functional
@@ -75,3 +77,26 @@ def test_no_verbose_no_debug(self):
         self.assertFalse('DEBUG [glance-registry]' in registry_log_out)
 
         self.stop_servers()
+
+    def assertNotEmptyFile(self, path):
+        self.assertTrue(os.path.exists(path))
+        self.assertNotEqual(os.stat(path)[stat.ST_SIZE], 0)
+
+    def test_logrotate(self):
+        """
+        Test that we notice when our log file has been rotated
+        """
+        self.cleanup()
+        self.start_servers()
+
+        self.assertNotEmptyFile(self.api_server.log_file)
+
+        os.rename(self.api_server.log_file, self.api_server.log_file + ".1")
+
+        path = "http://%s:%d/" % ("0.0.0.0", self.api_port)
+        response, content = httplib2.Http().request(path, 'GET')
+        self.assertEqual(response.status, 300)
+
+        self.assertNotEmptyFile(self.api_server.log_file)
+
+        self.stop_servers()