Add unit tests for execute_to_log.

Change-Id: I828f35d099c6cba5527c2f0d6240854ae9c39153

doc/source/configuration.rst

@@ -4,4 +4,7 @@
 Configuration
 =============
 
-todo...
+It is required that debug logging be configured for Turbo Hispter, as we use
+the python logging framework to capture log messages from the task plugin
+code. Configuration is as simple as setting the debug_log configuration
+setting in config.json.

tests/test_utils.py

@@ -0,0 +1,73 @@
+#!/usr/bin/python2
+#
+# Copyright 2014 Rackspace Australia
+#
+# Licensed under the Apache License, Version 2.0 (the "License"); you may
+# not use this file except in compliance with the License. You may obtain
+# a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+# License for the specific language governing permissions and limitations
+# under the License.
+
+
+import fixtures
+import logging
+import os
+import testtools
+
+from turbo_hipster.lib import utils
+
+
+class TestExecuteToLog(testtools.TestCase):
+    def test_makes_dir(self):
+        tempdir = self.useFixture(fixtures.TempDir()).path
+        self.assertFalse(os.path.exists(os.path.join(tempdir, 'foo')))
+        utils.execute_to_log('echo yay',
+                             os.path.join(tempdir, 'foo', 'banana.log'),
+                             watch_logs=[])
+        self.assertTrue(os.path.exists(os.path.join(tempdir, 'foo')))
+
+    def test_logging_works(self):
+        # Setup python logging to do what we need
+        logging.basicConfig(format='%(asctime)s %(name)s %(message)s',
+                            level=logging.DEBUG)
+
+        tempdir = self.useFixture(fixtures.TempDir()).path
+        log_path = os.path.join(tempdir, 'banana.log')
+
+        utils.execute_to_log('echo yay', log_path, watch_logs=[])
+        self.assertTrue(os.path.exists(log_path))
+
+        with open(log_path) as f:
+            d = f.read()
+            print d
+
+        self.assertNotEqual('', d)
+        self.assertEqual(3, len(d.split('\n')))
+        self.assertNotEqual(-1, d.find('yay'))
+        self.assertNotEqual(-1, d.find('[script exit code = 0]'))
+
+    def test_timeout(self):
+        # Setup python logging to do what we need
+        logging.basicConfig(format='%(asctime)s %(name)s %(message)s',
+                            level=logging.DEBUG)
+
+        tempdir = self.useFixture(fixtures.TempDir()).path
+        log_path = os.path.join(tempdir, 'banana.log')
+
+        utils.execute_to_log('/bin/sleep 30', log_path, watch_logs=[],
+                             timeout=0.1)
+        self.assertTrue(os.path.exists(log_path))
+
+        with open(log_path) as f:
+            d = f.read()
+            print d
+
+        self.assertNotEqual('', d)
+        self.assertNotEqual(-1, d.find('[timeout]'))
+        self.assertNotEqual(-1, d.find('[script exit code = -9]'))

turbo_hipster/worker_server.py

@@ -49,15 +49,15 @@ class Server(object):
         self.load_plugins()
 
     def setup_logging(self):
-        if self.debug_log:
-            if not os.path.isdir(os.path.dirname(self.debug_log)):
-                os.makedirs(os.path.dirname(self.debug_log))
-            logging.basicConfig(format='%(asctime)s %(name)s %(message)s',
-                                filename=self.debug_log, level=logging.DEBUG)
-        else:
-            logging.basicConfig(format='%(asctime)s %(name)s %(message)s',
-                                level=logging.WARN)
-        self.log.debug('Log pusher starting.')
+        if not self.debug_log:
+            raise Exception('Debug log not configured')
+
+        # NOTE(mikal): debug logging _must_ be enabled for the log writing
+        # in lib.utils.execute_to_log to work correctly.
+        if not os.path.isdir(os.path.dirname(self.debug_log)):
+            os.makedirs(os.path.dirname(self.debug_log))
+        logging.basicConfig(format='%(asctime)s %(name)s %(message)s',
+                            filename=self.debug_log, level=logging.DEBUG)
 
     def load_plugins(self):
         """ Load the available plugins from task_plugins """