<NME> test_logging.py
<BEF> #!/usr/bin/env python
# -*- coding: utf-8 -*-
#
# Copyright (C) 2012:
#    Hartmut Goebel <h.goebel@crazy-compilers.com>
#
# This file is part of Shinken.
#
# Shinken is free software: you can redistribute it and/or modify
# it under the terms of the GNU Affero General Public License as published by
# the Free Software Foundation, either version 3 of the License, or
# (at your option) any later version.
#
# Shinken is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
# GNU Affero General Public License for more details.
#
# You should have received a copy of the GNU Affero General Public License
# along with Shinken.  If not, see <http://www.gnu.org/licenses/>.

"""
Test shinken.logging
"""

import sys
import os
import time
import cPickle
from cStringIO import StringIO

from tempfile import NamedTemporaryFile

import __import_shinken
import logging
from logging import NOTSET, DEBUG, INFO, WARNING, ERROR, CRITICAL, StreamHandler
from shinken.log import logger as shinken_logger, naglog_result, Log, human_timestamp_log
from shinken.log import defaultFormatter, BrokHandler, ColorStreamHandler

shinken_logger.set_log = True

from shinken.brok import Brok
from shinken_test import *

# The logging module requires some object for collecting broks
class Dummy:
    """Dummy class for collecting broks"""
    def add(self, o):
        pass

class Collector:
    """Dummy class for collecting broks"""
    def __init__(self):
        self.list = []

    def add(self, o):
        self.list.append(o)



class NoSetup:
    def setUp(self):
        pass



#logger.load_obj(Dummy())



class TestLevels(NoSetup, ShinkenTest):

    def test_default_level(self):
        logger = Log(name=None, log_set=True)
        self.assertEqual(logger.level, logging.NOTSET)

    def test_setLevel(self):
        logger = Log(name=None, log_set=True)
        logger.setLevel(logging.WARNING)
        self.assertEqual(logger.level, min(WARNING, INFO))

    def test_setLevel_non_integer_raises(self):
        logger = Log(name=None, log_set=True)
        self.assertRaises(TypeError, logger.setLevel, 1.0)

    def test_load_obj_must_not_change_level(self):
        logger = Log(name=None, log_set=True)
        # argl, load_obj() unsets the level! save and restore it
        logger.setLevel(logging.CRITICAL)
        logger.load_obj(Dummy())
        self.assertEqual(logger.level, min(CRITICAL, INFO))


class TestBasics(NoSetup, ShinkenTest):

    def test_setting_and_unsetting_human_timestamp_format(self):
        # :hack: shinken.log.human_timestamp_log is a global variable
        self.assertEqual(shinken.log.human_timestamp_log, False)
        logger.set_human_format(True)
        self.assertEqual(shinken.log.human_timestamp_log, True)
        logger.set_human_format(False)
        self.assertEqual(shinken.log.human_timestamp_log, False)
        logger.set_human_format(True)
    def test_setting_and_unsetting_human_timestamp_format(self):
        # :hack: logging.human_timestamp_log is a global variable
        self.assertEqual(logging.human_timestamp_log, False)
        logger.set_human_format()
        self.assertEqual(logging.human_timestamp_log, True)
        logger.set_human_format(False)
        self.assertEqual(logging.human_timestamp_log, False)
        """
        Return the log messages stored as Broks into the collector.

        This also tests whether all objects collected by the collector
        are log entries.
        """
        for obj in collector.list:
            self.assertIsInstance(obj, Brok)
            self.assertEqual(obj.type, 'log')
            data = cPickle.loads(obj.data)
            self.assertEqual(data.keys(), ['log'])
            yield data['log']

    def _prepare_logging(self):
        self._collector = Collector()
        self._stdout = sys.stdout
        sys.stdout = StringIO()
        logger = Log(name=None, log_set=True)

        sh = StreamHandler(sys.stdout)
        sh.setFormatter(defaultFormatter)
        logger.addHandler(sh)
        logger.load_obj(self._collector)
        logger.pre_log_buffer = [] # reset the pre_log for several tests
        return logger


    def _get_logging_output(self):
        broklogs = list(self._get_brok_log_messages(self._collector))

        stdoutlogs = sys.stdout.getvalue().splitlines()
        sys.stdout = sys.__stdout__

        if hasattr(self, 'logfile_name'):
            f = open(self.logfile_name)
            filelogs = list(f.readlines())
            f.close()
            try:
                os.remove(self.logfile_name)
            except Exception: # On windows, the file is still lock. But should be close!?!
                pass
        else:
            filelogs = None
        return broklogs, stdoutlogs, filelogs


    def _put_log(self, log_method, *messages):
        #self._prepare_logging()
        try:
            for msg in messages:
                log_method(msg)
        finally:
            return self._get_logging_output()
        msgs, lines = self._put_log(logger.debug, 'Some log-message')
        self.assertEqual(len(msgs), 0)
        self.assertEqual(len(lines), 1)
        self.assertRegexpMatches(lines[0], r'^\[\d+\] Debug :\s+Some log-message$')

    def test_basic_logging_info(self):
        logger.set_level(logger.INFO)
        msgs, lines = self._put_log(logger.info, 'Some log-message')
        self.assertEqual(len(msgs), 1)
        self.assertEqual(len(lines), 1)
        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Info :\s+Some log-message\n$')
        self.assertRegexpMatches(lines[0], r'^\[\d+\] Info :\s+Some log-message$')

    def test_basic_logging_warning(self):
        logger.set_level(logger.WARNING)
        msgs, lines = self._put_log(logger.warning, 'Some log-message')
        self.assertEqual(len(msgs), 1)
        self.assertEqual(len(lines), 1)
        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Warning :\s+Some log-message\n$')
        self.assertRegexpMatches(lines[0], r'^\[\d+\] Warning :\s+Some log-message$')


    def test_basic_logging_error(self):
        shinken_logger.setLevel(DEBUG)
        msgs, lines = self._put_log(logger.error, 'Some log-message')
        self.assertEqual(len(msgs), 1)
        self.assertEqual(len(lines), 1)
        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Error :\s+Some log-message\n$')
        self.assertRegexpMatches(lines[0], r'^\[\d+\] Error :\s+Some log-message$')

    def test_basic_logging_critical(self):
        msgs, lines = self._put_log(logger.critical, 'Some log-message')
        self.assertEqual(len(msgs), 1)
        self.assertEqual(len(lines), 1)
        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Critical :\s+Some log-message\n$')
        self.assertRegexpMatches(lines[0], r'^\[\d+\] Critical :\s+Some log-message$')

    def test_level_is_higher_then_the_one_set(self):
        # just test two samples


    def test_basic_logging_warning(self):
        logger = self._prepare_logging()
        logger.setLevel(WARNING)
        self.generic_tst(logger.warning, 'Some log-message',
                         [1, 1], [r'^\[\d+\] WARNING:\s+Some log-message\n$', r'^\[\d+\] WARNING:\s+Some log-message$'])

    def test_basic_logging_error(self):
        logger = self._prepare_logging()
        logger.setLevel(ERROR)
        self.generic_tst(logger.error, 'Some log-message',
                         [1, 1], [r'^\[\d+\] ERROR:\s+Some log-message\n$', r'^\[\d+\] ERROR:\s+Some log-message$'])
        logger.set_human_format(True)
        msgs, lines = self._put_log(logger.info, 'Some ] log-message')
        self.assertRegexpMatches(msgs[0],
            r'^\[[^\]]+] Info :\s+Some \] log-message\n$')
        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
        self.assertRegexpMatches(lines[0],
            r'^\[[^\]]+] Info :\s+Some \] log-message$')
        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
        logger.set_human_format(False)

    def test_reset_human_timestamp_format(self):
        # just test two samples
        logger.setLevel(CRITICAL)
        self.generic_tst(logger.error, 'Some log-message',
                         [1, 0], [r'^\[\d+\] ERROR:\s+Some log-message\n$', ''])

        # need to prepare again to have stdout=StringIO()
        logger = self._prepare_logging()
        logger.setLevel(logging.INFO)
        self.generic_tst(logger.debug, 'Some log-message',
                         [0, 0], ['', ''])


    def test_human_timestamp_format(self):
        "test output using the human timestamp format"
        logger = self._prepare_logging()
        logger.setLevel(logging.INFO)
        logger.set_human_format(True)
        loglist = self.generic_tst(logger.info, 'Some ] log-message',
                         [1, 1], [r'^\[\d+\] INFO:\s+Some \] log-message\n$', r'^\[[^\]]+] INFO:\s+Some \] log-message$'])

        time.strptime(loglist[1][0].split(' INFO: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
        logger.set_human_format(False)

    def test_reset_human_timestamp_format(self):
        "test output after switching of the human timestamp format"
        # ensure the human timestamp format is set, ...
        self.test_human_timestamp_format()
        # ... then turn it off
        logger.set_human_format(False)
        # test whether the normal format is used again
        self.test_basic_logging_info()


class TestColorConsoleLogger(NoSetup, ShinkenTest, LogCollectMixin):

    def test_basic_logging_info_colored(self):
        shinken_logger.setLevel(INFO)
        self._collector = Collector()
        sys.stdout = StringIO()
        shinken_logger.handlers[0].stream = sys.stdout
        shinken_logger.load_obj(self._collector)
        if isinstance(shinken_logger.handlers[0], ColorStreamHandler):
            self.generic_tst(shinken_logger.info, 'Some log-message',
                             [1, 1],
                             [r'^\[.+?\] INFO: \[Shinken\] Some log-message$',
                              r'^\x1b\[95m\[.+?\] INFO: \[Shinken\] Some log-message\x1b\[0m$'])
        else:
        self.assertEqual(len(lines), 1)
        self.assertEqual(len(local_log), 1)
        self.assertRegexpMatches(local_log[0],
            r' \[\d+\] Debug :\s+Some log-message$')

    def test_basic_logging_info(self):
        logger.set_level(logger.INFO)
        shinken_logger.setLevel(INFO)
        self._collector = Collector()
        self.assertEqual(len(lines), 1)
        self.assertEqual(len(local_log), 1)
        self.assertRegexpMatches(local_log[0],
            r' \[\d+\] Info :\s+Some log-message\n$')

    def test_basic_logging_error(self):
        logger.set_level(logger.ERROR)
                             [r'^\[.+?\] INFO: \[Shinken\] Some log-message$',
                              r'^\x1b\[95m\[.+?\] INFO: \[Shinken\] Some log-message\x1b\[0m$'])
        else:
        self.assertEqual(len(local_log), 1)
        print >> sys.stderr, local_log[0]
        self.assertRegexpMatches(local_log[0],
            r' \[\d+\] Error :\s+Some log-message\n$')

    def test_basic_logging_critical(self):
        logger.set_level(logger.CRITICAL)
        _, time2 = times.rsplit('[', 1)
        time.strptime(time2.rsplit(']')[0], '%a %b %d %H:%M:%S %Y')
        self.assertEqual(len(lines), 1)
        self.assertEqual(len(local_log), 1)
        self.assertRegexpMatches(local_log[0],
            r' \[\d+\] Critical :\s+Some log-message\n$')

    def test_level_is_higher_then_the_one_set(self):
        # just test two samples
        # ... then turn it off
        logger.set_human_format(False)
        # test whether the normal format is used again
        self.test_basic_logging_info_colored()


class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):

    def _prepare_logging(self):
        logger = super(TestWithLocalLogging, self)._prepare_logging()
        # set up a temporary file for logging
        logfile = NamedTemporaryFile("w", delete=False)
        logfile.close()
        self.logfile_name = logfile.name
        logger.register_local_log(logfile.name, purge_buffer=False)
        return logger
        msgs, lines, local_log = self._put_log(logger.info, 'Some ] log-message')
        self.assertEqual(len(local_log), 1)
        self.assertRegexpMatches(local_log[0],
            r' \[[^\]]+] Info :\s+Some \] log-message\n$')
        # :fixme: Currently, the local log gets prefixed another
        # timestamp. As it is yet unclear, whether this intended or
        # not, we test it, too.
        times = local_log[0].split(' Info :    ', 1)[0]
        time1, time2 = times.rsplit('[', 1)
        time.strptime(time1.rsplit(',')[0], '%Y-%m-%d %H:%M:%S')
        time.strptime(time2, '%a %b %d %H:%M:%S %Y]')
        logfile.close()
        logfile_name = logfile.name
        logger.register_local_log(logfile_name, purge_buffer=False)
        self.assertEqual(logger.level, min(ERROR, INFO))


    def test_basic_logging_log(self):
        sys.stdout = StringIO()
        self._collector = Collector()
        sh = StreamHandler(sys.stdout)
        sh.setFormatter(defaultFormatter)
        shinken_logger.handlers = []
        shinken_logger.addHandler(sh)
        shinken_logger.load_obj(self._collector)
        shinken_logger.log_set = True
        logfile = NamedTemporaryFile("w", delete=False)
        logfile.close()
        self.logfile_name = logfile.name
        shinken_logger.register_local_log(logfile.name, purge_buffer=False)
        shinken_logger.setLevel(DEBUG)
        self.generic_tst(lambda x: naglog_result('info', x), 'Some log-message',
                         [1, 1, 1], ['', r'^\[\d+\] Some log-message$', r'^\[\d+\] Some log-message$'])


    def test_basic_logging_debug_does_not_send_broks(self):
        logger = self._prepare_logging()
        self.assertEqual(len(msgs), 1)
        self.assertEqual(len(lines), 1)
        self.assertRegexpMatches(msgs[0],
             r'^\[\d+\] Info :\s+\[Tiroler Schinken\] Some log-message\n$')
        self.assertRegexpMatches(lines[0],
             r'^\[\d+\] Info :\s+\[Tiroler Schinken\] Some log-message$')

    def test_human_timestamp_format(self):
        logger.set_level(logger.INFO)
        logger.set_human_format(True)
        msgs, lines = self._put_log(logger.info, 'Some ] log-message')
        self.assertRegexpMatches(msgs[0],
            r'^\[[^\]]+] Info :\s+\[Tiroler Schinken\] Some \] log-message\n$')
        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
        self.assertRegexpMatches(lines[0],
            r'^\[[^\]]+] Info :\s+\[Tiroler Schinken\] Some \] log-message$')
        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
        logger.set_human_format(False)

    def test_reset_human_timestamp_format(self):
                         [1, 1, 1], ['', '', r'\[\d+\] CRITICAL:\s+Some log-message\n$'])

    def test_level_is_higher_then_the_one_set(self):
        logger = self._prepare_logging()
        # just test two samples
        logger.setLevel(CRITICAL)
        self.generic_tst(logger.debug, 'Some log-message', [0, 0, 0], ['', '', ''])

        # need to prepare again to have stdout=StringIO() and a local log file
        logger = self._prepare_logging()
        logger.setLevel(INFO)
        self.generic_tst(logger.debug, 'Some log-message', [0, 0, 0], ['', '', ''])

    def test_human_timestamp_format(self):
        logger = self._prepare_logging()
        logger.setLevel(logging.INFO)
        logger.set_human_format(True)
        loglist = self.generic_tst(logger.info, 'Some log-message',
                         [1, 1, 1],
                         [r'', r'', r'\[[^\]]+] INFO:\s+Some log-message\n$'])

        # :fixme: Currently, the local log gets prefixed another
        # timestamp. As it is yet unclear, whether this intended or
        # not, we test it, too.
        times = loglist[2][0].split(' INFO:    ', 1)[0]
        _, time2 = times.rsplit('[', 1)
        time.strptime(time2.rsplit(']')[0], '%a %b %d %H:%M:%S %Y')
        logger.set_human_format(False)

    def test_reset_human_timestamp_format(self):
        "test output after switching of the human timestamp format"
        # ensure the human timestamp format is set, ...
        self.test_human_timestamp_format()
        # ... then turn it off
        logger.set_human_format(False)
        # test whether the normal format is used again
        self.test_basic_logging_info()


class TestNamedCollector(NoSetup, ShinkenTest, LogCollectMixin):

    # :todo: add a test for the local log file, too

    def _prepare_logging(self):
        self._collector = Collector()
        self._stdout = sys.stdout
        sys.stdout = StringIO()
        logger = Log(name=None, log_set=True)
        from shinken.log import defaultFormatter
        from logging import StreamHandler
        sh = StreamHandler(sys.stdout)
        sh.setFormatter(defaultFormatter)
        logger.addHandler(sh)
        logger.load_obj(self._collector, 'Tiroler Schinken')
        return logger

    def test_basic_logging_info(self):
        logger = self._prepare_logging()
        logger.setLevel(logging.INFO)
        self.generic_tst(logger.info, 'Some log-message',
                         [1, 1],
                         [r'^\[\d+\] INFO:\s+\[Tiroler Schinken\] Some log-message\n$',
                          r'^\[\d+\] INFO:\s+\[Tiroler Schinken\] Some log-message$'])

    def test_human_timestamp_format(self):
        logger = self._prepare_logging()
        logger.setLevel(logging.INFO)
        logger.set_human_format(True)
        loglist = self.generic_tst(logger.info, 'Some ] log-message',
                         [1, 1],
                         [r'^\[\d+\] INFO:\s+\[Tiroler Schinken\] Some \] log-message\n$',
                          r'^\[[^\]]+] INFO:\s+\[Tiroler Schinken\] Some \] log-message$'])
        # No TS for broker!
        time.strptime(loglist[1][0].split(' INFO: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
        logger.set_human_format(False)

    def test_reset_human_timestamp_format(self):
        # ensure human timestamp format is set and working
        self.test_human_timestamp_format()
        # turn of human timestamp format
        logger.set_human_format(False)
        # test for normal format
        self.test_basic_logging_info()


if __name__ == '__main__':
    unittest.main()

<MSG> Fix: typo error in logging test

<DFF> @@ -104,7 +104,7 @@ class TestBasics(unittest.TestCase):
     def test_setting_and_unsetting_human_timestamp_format(self):
         # :hack: logging.human_timestamp_log is a global variable
         self.assertEqual(logging.human_timestamp_log, False)
-        logger.set_human_format()
+        logger.set_human_format(True)
         self.assertEqual(logging.human_timestamp_log, True)
         logger.set_human_format(False)
         self.assertEqual(logging.human_timestamp_log, False)
@@ -164,23 +164,23 @@ class TestDefaultLoggingMethods(NoSetup, ShinkenTest, LogCollectMixin):
         msgs, lines = self._put_log(logger.debug, 'Some log-message')
         self.assertEqual(len(msgs), 0)
         self.assertEqual(len(lines), 1)
-        self.assertRegexpMatches(lines[0], r'^\[\d+\] Debug :\s+Some log-message$')
+        self.assertRegexpMatches(lines[0], r'^\[\d+\] Debug:\s+Some log-message$')
 
     def test_basic_logging_info(self):
         logger.set_level(logger.INFO)
         msgs, lines = self._put_log(logger.info, 'Some log-message')
         self.assertEqual(len(msgs), 1)
         self.assertEqual(len(lines), 1)
-        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Info :\s+Some log-message\n$')
-        self.assertRegexpMatches(lines[0], r'^\[\d+\] Info :\s+Some log-message$')
+        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Info:\s+Some log-message\n$')
+        self.assertRegexpMatches(lines[0], r'^\[\d+\] Info:\s+Some log-message$')
 
     def test_basic_logging_warning(self):
         logger.set_level(logger.WARNING)
         msgs, lines = self._put_log(logger.warning, 'Some log-message')
         self.assertEqual(len(msgs), 1)
         self.assertEqual(len(lines), 1)
-        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Warning :\s+Some log-message\n$')
-        self.assertRegexpMatches(lines[0], r'^\[\d+\] Warning :\s+Some log-message$')
+        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Warning:\s+Some log-message\n$')
+        self.assertRegexpMatches(lines[0], r'^\[\d+\] Warning:\s+Some log-message$')
 
 
     def test_basic_logging_error(self):
@@ -188,15 +188,15 @@ class TestDefaultLoggingMethods(NoSetup, ShinkenTest, LogCollectMixin):
         msgs, lines = self._put_log(logger.error, 'Some log-message')
         self.assertEqual(len(msgs), 1)
         self.assertEqual(len(lines), 1)
-        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Error :\s+Some log-message\n$')
-        self.assertRegexpMatches(lines[0], r'^\[\d+\] Error :\s+Some log-message$')
+        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Error:\s+Some log-message\n$')
+        self.assertRegexpMatches(lines[0], r'^\[\d+\] Error:\s+Some log-message$')
 
     def test_basic_logging_critical(self):
         msgs, lines = self._put_log(logger.critical, 'Some log-message')
         self.assertEqual(len(msgs), 1)
         self.assertEqual(len(lines), 1)
-        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Critical :\s+Some log-message\n$')
-        self.assertRegexpMatches(lines[0], r'^\[\d+\] Critical :\s+Some log-message$')
+        self.assertRegexpMatches(msgs[0], r'^\[\d+\] Critical:\s+Some log-message\n$')
+        self.assertRegexpMatches(lines[0], r'^\[\d+\] Critical:\s+Some log-message$')
 
     def test_level_is_higher_then_the_one_set(self):
         # just test two samples
@@ -216,11 +216,11 @@ class TestDefaultLoggingMethods(NoSetup, ShinkenTest, LogCollectMixin):
         logger.set_human_format(True)
         msgs, lines = self._put_log(logger.info, 'Some ] log-message')
         self.assertRegexpMatches(msgs[0],
-            r'^\[[^\]]+] Info :\s+Some \] log-message\n$')
-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
+            r'^\[[^\]]+] Info:\s+Some \] log-message\n$')
+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
         self.assertRegexpMatches(lines[0],
-            r'^\[[^\]]+] Info :\s+Some \] log-message$')
-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
+            r'^\[[^\]]+] Info:\s+Some \] log-message$')
+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
         logger.set_human_format(False)
 
     def test_reset_human_timestamp_format(self):
@@ -274,7 +274,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):
         self.assertEqual(len(lines), 1)
         self.assertEqual(len(local_log), 1)
         self.assertRegexpMatches(local_log[0],
-            r' \[\d+\] Debug :\s+Some log-message$')
+            r' \[\d+\] Debug:\s+Some log-message$')
 
     def test_basic_logging_info(self):
         logger.set_level(logger.INFO)
@@ -283,7 +283,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):
         self.assertEqual(len(lines), 1)
         self.assertEqual(len(local_log), 1)
         self.assertRegexpMatches(local_log[0],
-            r' \[\d+\] Info :\s+Some log-message\n$')
+            r' \[\d+\] Info:\s+Some log-message\n$')
 
     def test_basic_logging_error(self):
         logger.set_level(logger.ERROR)
@@ -293,7 +293,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):
         self.assertEqual(len(local_log), 1)
         print >> sys.stderr, local_log[0]
         self.assertRegexpMatches(local_log[0],
-            r' \[\d+\] Error :\s+Some log-message\n$')
+            r' \[\d+\] Error:\s+Some log-message\n$')
 
     def test_basic_logging_critical(self):
         logger.set_level(logger.CRITICAL)
@@ -302,7 +302,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):
         self.assertEqual(len(lines), 1)
         self.assertEqual(len(local_log), 1)
         self.assertRegexpMatches(local_log[0],
-            r' \[\d+\] Critical :\s+Some log-message\n$')
+            r' \[\d+\] Critical:\s+Some log-message\n$')
 
     def test_level_is_higher_then_the_one_set(self):
         # just test two samples
@@ -325,11 +325,11 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):
         msgs, lines, local_log = self._put_log(logger.info, 'Some ] log-message')
         self.assertEqual(len(local_log), 1)
         self.assertRegexpMatches(local_log[0],
-            r' \[[^\]]+] Info :\s+Some \] log-message\n$')
+            r' \[[^\]]+] Info:\s+Some \] log-message\n$')
         # :fixme: Currently, the local log gets prefixed another
         # timestamp. As it is yet unclear, whether this intended or
         # not, we test it, too.
-        times = local_log[0].split(' Info :    ', 1)[0]
+        times = local_log[0].split(' Info: ', 1)[0]
         time1, time2 = times.rsplit('[', 1)
         time.strptime(time1.rsplit(',')[0], '%Y-%m-%d %H:%M:%S')
         time.strptime(time2, '%a %b %d %H:%M:%S %Y]')
@@ -362,20 +362,20 @@ class TestNamedCollector(NoSetup, ShinkenTest, LogCollectMixin):
         self.assertEqual(len(msgs), 1)
         self.assertEqual(len(lines), 1)
         self.assertRegexpMatches(msgs[0],
-             r'^\[\d+\] Info :\s+\[Tiroler Schinken\] Some log-message\n$')
+             r'^\[\d+\] Info:\s+\[Tiroler Schinken\] Some log-message\n$')
         self.assertRegexpMatches(lines[0],
-             r'^\[\d+\] Info :\s+\[Tiroler Schinken\] Some log-message$')
+             r'^\[\d+\] Info:\s+\[Tiroler Schinken\] Some log-message$')
 
     def test_human_timestamp_format(self):
         logger.set_level(logger.INFO)
         logger.set_human_format(True)
         msgs, lines = self._put_log(logger.info, 'Some ] log-message')
         self.assertRegexpMatches(msgs[0],
-            r'^\[[^\]]+] Info :\s+\[Tiroler Schinken\] Some \] log-message\n$')
-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
+            r'^\[[^\]]+] Info:\s+\[Tiroler Schinken\] Some \] log-message\n$')
+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
         self.assertRegexpMatches(lines[0],
-            r'^\[[^\]]+] Info :\s+\[Tiroler Schinken\] Some \] log-message$')
-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
+            r'^\[[^\]]+] Info:\s+\[Tiroler Schinken\] Some \] log-message$')
+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')
         logger.set_human_format(False)
 
     def test_reset_human_timestamp_format(self):

{'commit': "diff --git a/test/test_logging.py b/test/test_logging.py\nindex 4d92b04e1..d19309876 100755\n--- a/test/test_logging.py\n+++ b/test/test_logging.py\n@@ -104,7 +104,7 @@ class TestBasics(unittest.TestCase):\n     def test_setting_and_unsetting_human_timestamp_format(self):\n         # :hack: logging.human_timestamp_log is a global variable\n         self.assertEqual(logging.human_timestamp_log, False)\n-        logger.set_human_format()\n+        logger.set_human_format(True)\n         self.assertEqual(logging.human_timestamp_log, True)\n         logger.set_human_format(False)\n         self.assertEqual(logging.human_timestamp_log, False)\n@@ -164,23 +164,23 @@ class TestDefaultLoggingMethods(NoSetup, ShinkenTest, LogCollectMixin):\n         msgs, lines = self._put_log(logger.debug, 'Some log-message')\n         self.assertEqual(len(msgs), 0)\n         self.assertEqual(len(lines), 1)\n-        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Debug :\\s+Some log-message$')\n+        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Debug:\\s+Some log-message$')\n \n     def test_basic_logging_info(self):\n         logger.set_level(logger.INFO)\n         msgs, lines = self._put_log(logger.info, 'Some log-message')\n         self.assertEqual(len(msgs), 1)\n         self.assertEqual(len(lines), 1)\n-        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Info :\\s+Some log-message\\n$')\n-        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Info :\\s+Some log-message$')\n+        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Info:\\s+Some log-message\\n$')\n+        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Info:\\s+Some log-message$')\n \n     def test_basic_logging_warning(self):\n         logger.set_level(logger.WARNING)\n         msgs, lines = self._put_log(logger.warning, 'Some log-message')\n         self.assertEqual(len(msgs), 1)\n         self.assertEqual(len(lines), 1)\n-        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Warning :\\s+Some log-message\\n$')\n-        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Warning :\\s+Some log-message$')\n+        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Warning:\\s+Some log-message\\n$')\n+        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Warning:\\s+Some log-message$')\n \n \n     def test_basic_logging_error(self):\n@@ -188,15 +188,15 @@ class TestDefaultLoggingMethods(NoSetup, ShinkenTest, LogCollectMixin):\n         msgs, lines = self._put_log(logger.error, 'Some log-message')\n         self.assertEqual(len(msgs), 1)\n         self.assertEqual(len(lines), 1)\n-        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Error :\\s+Some log-message\\n$')\n-        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Error :\\s+Some log-message$')\n+        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Error:\\s+Some log-message\\n$')\n+        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Error:\\s+Some log-message$')\n \n     def test_basic_logging_critical(self):\n         msgs, lines = self._put_log(logger.critical, 'Some log-message')\n         self.assertEqual(len(msgs), 1)\n         self.assertEqual(len(lines), 1)\n-        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Critical :\\s+Some log-message\\n$')\n-        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Critical :\\s+Some log-message$')\n+        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Critical:\\s+Some log-message\\n$')\n+        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Critical:\\s+Some log-message$')\n \n     def test_level_is_higher_then_the_one_set(self):\n         # just test two samples\n@@ -216,11 +216,11 @@ class TestDefaultLoggingMethods(NoSetup, ShinkenTest, LogCollectMixin):\n         logger.set_human_format(True)\n         msgs, lines = self._put_log(logger.info, 'Some ] log-message')\n         self.assertRegexpMatches(msgs[0],\n-            r'^\\[[^\\]]+] Info :\\s+Some \\] log-message\\n$')\n-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n+            r'^\\[[^\\]]+] Info:\\s+Some \\] log-message\\n$')\n+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n         self.assertRegexpMatches(lines[0],\n-            r'^\\[[^\\]]+] Info :\\s+Some \\] log-message$')\n-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n+            r'^\\[[^\\]]+] Info:\\s+Some \\] log-message$')\n+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n         logger.set_human_format(False)\n \n     def test_reset_human_timestamp_format(self):\n@@ -274,7 +274,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n         self.assertEqual(len(lines), 1)\n         self.assertEqual(len(local_log), 1)\n         self.assertRegexpMatches(local_log[0],\n-            r' \\[\\d+\\] Debug :\\s+Some log-message$')\n+            r' \\[\\d+\\] Debug:\\s+Some log-message$')\n \n     def test_basic_logging_info(self):\n         logger.set_level(logger.INFO)\n@@ -283,7 +283,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n         self.assertEqual(len(lines), 1)\n         self.assertEqual(len(local_log), 1)\n         self.assertRegexpMatches(local_log[0],\n-            r' \\[\\d+\\] Info :\\s+Some log-message\\n$')\n+            r' \\[\\d+\\] Info:\\s+Some log-message\\n$')\n \n     def test_basic_logging_error(self):\n         logger.set_level(logger.ERROR)\n@@ -293,7 +293,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n         self.assertEqual(len(local_log), 1)\n         print >> sys.stderr, local_log[0]\n         self.assertRegexpMatches(local_log[0],\n-            r' \\[\\d+\\] Error :\\s+Some log-message\\n$')\n+            r' \\[\\d+\\] Error:\\s+Some log-message\\n$')\n \n     def test_basic_logging_critical(self):\n         logger.set_level(logger.CRITICAL)\n@@ -302,7 +302,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n         self.assertEqual(len(lines), 1)\n         self.assertEqual(len(local_log), 1)\n         self.assertRegexpMatches(local_log[0],\n-            r' \\[\\d+\\] Critical :\\s+Some log-message\\n$')\n+            r' \\[\\d+\\] Critical:\\s+Some log-message\\n$')\n \n     def test_level_is_higher_then_the_one_set(self):\n         # just test two samples\n@@ -325,11 +325,11 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n         msgs, lines, local_log = self._put_log(logger.info, 'Some ] log-message')\n         self.assertEqual(len(local_log), 1)\n         self.assertRegexpMatches(local_log[0],\n-            r' \\[[^\\]]+] Info :\\s+Some \\] log-message\\n$')\n+            r' \\[[^\\]]+] Info:\\s+Some \\] log-message\\n$')\n         # :fixme: Currently, the local log gets prefixed another\n         # timestamp. As it is yet unclear, whether this intended or\n         # not, we test it, too.\n-        times = local_log[0].split(' Info :    ', 1)[0]\n+        times = local_log[0].split(' Info: ', 1)[0]\n         time1, time2 = times.rsplit('[', 1)\n         time.strptime(time1.rsplit(',')[0], '%Y-%m-%d %H:%M:%S')\n         time.strptime(time2, '%a %b %d %H:%M:%S %Y]')\n@@ -362,20 +362,20 @@ class TestNamedCollector(NoSetup, ShinkenTest, LogCollectMixin):\n         self.assertEqual(len(msgs), 1)\n         self.assertEqual(len(lines), 1)\n         self.assertRegexpMatches(msgs[0],\n-             r'^\\[\\d+\\] Info :\\s+\\[Tiroler Schinken\\] Some log-message\\n$')\n+             r'^\\[\\d+\\] Info:\\s+\\[Tiroler Schinken\\] Some log-message\\n$')\n         self.assertRegexpMatches(lines[0],\n-             r'^\\[\\d+\\] Info :\\s+\\[Tiroler Schinken\\] Some log-message$')\n+             r'^\\[\\d+\\] Info:\\s+\\[Tiroler Schinken\\] Some log-message$')\n \n     def test_human_timestamp_format(self):\n         logger.set_level(logger.INFO)\n         logger.set_human_format(True)\n         msgs, lines = self._put_log(logger.info, 'Some ] log-message')\n         self.assertRegexpMatches(msgs[0],\n-            r'^\\[[^\\]]+] Info :\\s+\\[Tiroler Schinken\\] Some \\] log-message\\n$')\n-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n+            r'^\\[[^\\]]+] Info:\\s+\\[Tiroler Schinken\\] Some \\] log-message\\n$')\n+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n         self.assertRegexpMatches(lines[0],\n-            r'^\\[[^\\]]+] Info :\\s+\\[Tiroler Schinken\\] Some \\] log-message$')\n-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n+            r'^\\[[^\\]]+] Info:\\s+\\[Tiroler Schinken\\] Some \\] log-message$')\n+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n         logger.set_human_format(False)\n \n     def test_reset_human_timestamp_format(self):\n", 'commit_subject': 'Fix: typo error in logging test', 'repo_name': 'naparuba/shinken', 'committer': {'name': 'FORLOT Romain', 'email': '56bbb5a961715324494f8cea4eeacde849fb8e10@yahoo.com', 'time_sec': '1347287150', 'tz_offset': '120', 'date': {'seconds': '1347287150'}}, 'commit_tree': '5e41af225207a0848395573295d5405df930e142', 'commit_message': 'Fix: typo error in logging test\n', 'language_name': 'Perl', 'license': 'agpl-3.0', 'hunks': "@@ -104,7 +104,7 @@ class TestBasics(unittest.TestCase):\n     def test_setting_and_unsetting_human_timestamp_format(self):\n         # :hack: logging.human_timestamp_log is a global variable\n         self.assertEqual(logging.human_timestamp_log, False)\n-        logger.set_human_format()\n+        logger.set_human_format(True)\n         self.assertEqual(logging.human_timestamp_log, True)\n         logger.set_human_format(False)\n         self.assertEqual(logging.human_timestamp_log, False)\n@@ -164,23 +164,23 @@ class TestDefaultLoggingMethods(NoSetup, ShinkenTest, LogCollectMixin):\n         msgs, lines = self._put_log(logger.debug, 'Some log-message')\n         self.assertEqual(len(msgs), 0)\n         self.assertEqual(len(lines), 1)\n-        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Debug :\\s+Some log-message$')\n+        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Debug:\\s+Some log-message$')\n \n     def test_basic_logging_info(self):\n         logger.set_level(logger.INFO)\n         msgs, lines = self._put_log(logger.info, 'Some log-message')\n         self.assertEqual(len(msgs), 1)\n         self.assertEqual(len(lines), 1)\n-        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Info :\\s+Some log-message\\n$')\n-        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Info :\\s+Some log-message$')\n+        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Info:\\s+Some log-message\\n$')\n+        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Info:\\s+Some log-message$')\n \n     def test_basic_logging_warning(self):\n         logger.set_level(logger.WARNING)\n         msgs, lines = self._put_log(logger.warning, 'Some log-message')\n         self.assertEqual(len(msgs), 1)\n         self.assertEqual(len(lines), 1)\n-        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Warning :\\s+Some log-message\\n$')\n-        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Warning :\\s+Some log-message$')\n+        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Warning:\\s+Some log-message\\n$')\n+        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Warning:\\s+Some log-message$')\n \n \n     def test_basic_logging_error(self):\n@@ -188,15 +188,15 @@ class TestDefaultLoggingMethods(NoSetup, ShinkenTest, LogCollectMixin):\n         msgs, lines = self._put_log(logger.error, 'Some log-message')\n         self.assertEqual(len(msgs), 1)\n         self.assertEqual(len(lines), 1)\n-        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Error :\\s+Some log-message\\n$')\n-        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Error :\\s+Some log-message$')\n+        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Error:\\s+Some log-message\\n$')\n+        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Error:\\s+Some log-message$')\n \n     def test_basic_logging_critical(self):\n         msgs, lines = self._put_log(logger.critical, 'Some log-message')\n         self.assertEqual(len(msgs), 1)\n         self.assertEqual(len(lines), 1)\n-        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Critical :\\s+Some log-message\\n$')\n-        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Critical :\\s+Some log-message$')\n+        self.assertRegexpMatches(msgs[0], r'^\\[\\d+\\] Critical:\\s+Some log-message\\n$')\n+        self.assertRegexpMatches(lines[0], r'^\\[\\d+\\] Critical:\\s+Some log-message$')\n \n     def test_level_is_higher_then_the_one_set(self):\n         # just test two samples\n@@ -216,11 +216,11 @@ class TestDefaultLoggingMethods(NoSetup, ShinkenTest, LogCollectMixin):\n         logger.set_human_format(True)\n         msgs, lines = self._put_log(logger.info, 'Some ] log-message')\n         self.assertRegexpMatches(msgs[0],\n-            r'^\\[[^\\]]+] Info :\\s+Some \\] log-message\\n$')\n-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n+            r'^\\[[^\\]]+] Info:\\s+Some \\] log-message\\n$')\n+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n         self.assertRegexpMatches(lines[0],\n-            r'^\\[[^\\]]+] Info :\\s+Some \\] log-message$')\n-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n+            r'^\\[[^\\]]+] Info:\\s+Some \\] log-message$')\n+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n         logger.set_human_format(False)\n \n     def test_reset_human_timestamp_format(self):\n@@ -274,7 +274,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n         self.assertEqual(len(lines), 1)\n         self.assertEqual(len(local_log), 1)\n         self.assertRegexpMatches(local_log[0],\n-            r' \\[\\d+\\] Debug :\\s+Some log-message$')\n+            r' \\[\\d+\\] Debug:\\s+Some log-message$')\n \n     def test_basic_logging_info(self):\n         logger.set_level(logger.INFO)\n@@ -283,7 +283,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n         self.assertEqual(len(lines), 1)\n         self.assertEqual(len(local_log), 1)\n         self.assertRegexpMatches(local_log[0],\n-            r' \\[\\d+\\] Info :\\s+Some log-message\\n$')\n+            r' \\[\\d+\\] Info:\\s+Some log-message\\n$')\n \n     def test_basic_logging_error(self):\n         logger.set_level(logger.ERROR)\n@@ -293,7 +293,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n         self.assertEqual(len(local_log), 1)\n         print >> sys.stderr, local_log[0]\n         self.assertRegexpMatches(local_log[0],\n-            r' \\[\\d+\\] Error :\\s+Some log-message\\n$')\n+            r' \\[\\d+\\] Error:\\s+Some log-message\\n$')\n \n     def test_basic_logging_critical(self):\n         logger.set_level(logger.CRITICAL)\n@@ -302,7 +302,7 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n         self.assertEqual(len(lines), 1)\n         self.assertEqual(len(local_log), 1)\n         self.assertRegexpMatches(local_log[0],\n-            r' \\[\\d+\\] Critical :\\s+Some log-message\\n$')\n+            r' \\[\\d+\\] Critical:\\s+Some log-message\\n$')\n \n     def test_level_is_higher_then_the_one_set(self):\n         # just test two samples\n@@ -325,11 +325,11 @@ class TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n         msgs, lines, local_log = self._put_log(logger.info, 'Some ] log-message')\n         self.assertEqual(len(local_log), 1)\n         self.assertRegexpMatches(local_log[0],\n-            r' \\[[^\\]]+] Info :\\s+Some \\] log-message\\n$')\n+            r' \\[[^\\]]+] Info:\\s+Some \\] log-message\\n$')\n         # :fixme: Currently, the local log gets prefixed another\n         # timestamp. As it is yet unclear, whether this intended or\n         # not, we test it, too.\n-        times = local_log[0].split(' Info :    ', 1)[0]\n+        times = local_log[0].split(' Info: ', 1)[0]\n         time1, time2 = times.rsplit('[', 1)\n         time.strptime(time1.rsplit(',')[0], '%Y-%m-%d %H:%M:%S')\n         time.strptime(time2, '%a %b %d %H:%M:%S %Y]')\n@@ -362,20 +362,20 @@ class TestNamedCollector(NoSetup, ShinkenTest, LogCollectMixin):\n         self.assertEqual(len(msgs), 1)\n         self.assertEqual(len(lines), 1)\n         self.assertRegexpMatches(msgs[0],\n-             r'^\\[\\d+\\] Info :\\s+\\[Tiroler Schinken\\] Some log-message\\n$')\n+             r'^\\[\\d+\\] Info:\\s+\\[Tiroler Schinken\\] Some log-message\\n$')\n         self.assertRegexpMatches(lines[0],\n-             r'^\\[\\d+\\] Info :\\s+\\[Tiroler Schinken\\] Some log-message$')\n+             r'^\\[\\d+\\] Info:\\s+\\[Tiroler Schinken\\] Some log-message$')\n \n     def test_human_timestamp_format(self):\n         logger.set_level(logger.INFO)\n         logger.set_human_format(True)\n         msgs, lines = self._put_log(logger.info, 'Some ] log-message')\n         self.assertRegexpMatches(msgs[0],\n-            r'^\\[[^\\]]+] Info :\\s+\\[Tiroler Schinken\\] Some \\] log-message\\n$')\n-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n+            r'^\\[[^\\]]+] Info:\\s+\\[Tiroler Schinken\\] Some \\] log-message\\n$')\n+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n         self.assertRegexpMatches(lines[0],\n-            r'^\\[[^\\]]+] Info :\\s+\\[Tiroler Schinken\\] Some \\] log-message$')\n-        time.strptime(msgs[0].split(' Info :    ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n+            r'^\\[[^\\]]+] Info:\\s+\\[Tiroler Schinken\\] Some \\] log-message$')\n+        time.strptime(msgs[0].split(' Info: ', 1)[0], '[%a %b %d %H:%M:%S %Y]')\n         logger.set_human_format(False)\n \n     def test_reset_human_timestamp_format(self):\n", 'addition_count': 26, 'deletion_count': 26, 'src_file': 'a/test/test_logging.py', 'tgt_file': 'b/test/test_logging.py', 'file_extension': '.py', 'before_file': '#!/usr/bin/env python\n# -*- coding: utf-8 -*-\n#\n# Copyright (C) 2012:\n#    Hartmut Goebel <h.goebel@crazy-compilers.com>\n#\n# This file is part of Shinken.\n#\n# Shinken is free software: you can redistribute it and/or modify\n# it under the terms of the GNU Affero General Public License as published by\n# the Free Software Foundation, either version 3 of the License, or\n# (at your option) any later version.\n#\n# Shinken is distributed in the hope that it will be useful,\n# but WITHOUT ANY WARRANTY; without even the implied warranty of\n# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the\n# GNU Affero General Public License for more details.\n#\n# You should have received a copy of the GNU Affero General Public License\n# along with Shinken.  If not, see <http://www.gnu.org/licenses/>.\n\n"""\nTest shinken.logging\n"""\n\nimport sys\nimport os\nimport time\nimport cPickle\nfrom cStringIO import StringIO\n\nfrom tempfile import NamedTemporaryFile\n\nimport __import_shinken\nimport logging\nfrom logging import NOTSET, DEBUG, INFO, WARNING, ERROR, CRITICAL, StreamHandler\nfrom shinken.log import logger as shinken_logger, naglog_result, Log, human_timestamp_log\nfrom shinken.log import defaultFormatter, BrokHandler, ColorStreamHandler\n\nshinken_logger.set_log = True\n\nfrom shinken.brok import Brok\nfrom shinken_test import *\n\n# The logging module requires some object for collecting broks\nclass Dummy:\n    """Dummy class for collecting broks"""\n    def add(self, o):\n        pass\n\nclass Collector:\n    """Dummy class for collecting broks"""\n    def __init__(self):\n        self.list = []\n\n    def add(self, o):\n        self.list.append(o)\n\n\n\nclass NoSetup:\n    def setUp(self):\n        pass\n\n\n\n#logger.load_obj(Dummy())\n\n\n\nclass TestLevels(NoSetup, ShinkenTest):\n\n    def test_default_level(self):\n        logger = Log(name=None, log_set=True)\n        self.assertEqual(logger.level, logging.NOTSET)\n\n    def test_setLevel(self):\n        logger = Log(name=None, log_set=True)\n        logger.setLevel(logging.WARNING)\n        self.assertEqual(logger.level, min(WARNING, INFO))\n\n    def test_setLevel_non_integer_raises(self):\n        logger = Log(name=None, log_set=True)\n        self.assertRaises(TypeError, logger.setLevel, 1.0)\n\n    def test_load_obj_must_not_change_level(self):\n        logger = Log(name=None, log_set=True)\n        # argl, load_obj() unsets the level! save and restore it\n        logger.setLevel(logging.CRITICAL)\n        logger.load_obj(Dummy())\n        self.assertEqual(logger.level, min(CRITICAL, INFO))\n\n\nclass TestBasics(NoSetup, ShinkenTest):\n\n    def test_setting_and_unsetting_human_timestamp_format(self):\n        # :hack: shinken.log.human_timestamp_log is a global variable\n        self.assertEqual(shinken.log.human_timestamp_log, False)\n        logger.set_human_format(True)\n        self.assertEqual(shinken.log.human_timestamp_log, True)\n        logger.set_human_format(False)\n        self.assertEqual(shinken.log.human_timestamp_log, False)\n        logger.set_human_format(True)\n    def test_setting_and_unsetting_human_timestamp_format(self):\n        # :hack: logging.human_timestamp_log is a global variable\n        self.assertEqual(logging.human_timestamp_log, False)\n        logger.set_human_format()\n        self.assertEqual(logging.human_timestamp_log, True)\n        logger.set_human_format(False)\n        self.assertEqual(logging.human_timestamp_log, False)\n        """\n        Return the log messages stored as Broks into the collector.\n\n        This also tests whether all objects collected by the collector\n        are log entries.\n        """\n        for obj in collector.list:\n            self.assertIsInstance(obj, Brok)\n            self.assertEqual(obj.type, \'log\')\n            data = cPickle.loads(obj.data)\n            self.assertEqual(data.keys(), [\'log\'])\n            yield data[\'log\']\n\n    def _prepare_logging(self):\n        self._collector = Collector()\n        self._stdout = sys.stdout\n        sys.stdout = StringIO()\n        logger = Log(name=None, log_set=True)\n\n        sh = StreamHandler(sys.stdout)\n        sh.setFormatter(defaultFormatter)\n        logger.addHandler(sh)\n        logger.load_obj(self._collector)\n        logger.pre_log_buffer = [] # reset the pre_log for several tests\n        return logger\n\n\n    def _get_logging_output(self):\n        broklogs = list(self._get_brok_log_messages(self._collector))\n\n        stdoutlogs = sys.stdout.getvalue().splitlines()\n        sys.stdout = sys.__stdout__\n\n        if hasattr(self, \'logfile_name\'):\n            f = open(self.logfile_name)\n            filelogs = list(f.readlines())\n            f.close()\n            try:\n                os.remove(self.logfile_name)\n            except Exception: # On windows, the file is still lock. But should be close!?!\n                pass\n        else:\n            filelogs = None\n        return broklogs, stdoutlogs, filelogs\n\n\n    def _put_log(self, log_method, *messages):\n        #self._prepare_logging()\n        try:\n            for msg in messages:\n                log_method(msg)\n        finally:\n            return self._get_logging_output()\n        msgs, lines = self._put_log(logger.debug, \'Some log-message\')\n        self.assertEqual(len(msgs), 0)\n        self.assertEqual(len(lines), 1)\n        self.assertRegexpMatches(lines[0], r\'^\\[\\d+\\] Debug :\\s+Some log-message$\')\n\n    def test_basic_logging_info(self):\n        logger.set_level(logger.INFO)\n        msgs, lines = self._put_log(logger.info, \'Some log-message\')\n        self.assertEqual(len(msgs), 1)\n        self.assertEqual(len(lines), 1)\n        self.assertRegexpMatches(msgs[0], r\'^\\[\\d+\\] Info :\\s+Some log-message\\n$\')\n        self.assertRegexpMatches(lines[0], r\'^\\[\\d+\\] Info :\\s+Some log-message$\')\n\n    def test_basic_logging_warning(self):\n        logger.set_level(logger.WARNING)\n        msgs, lines = self._put_log(logger.warning, \'Some log-message\')\n        self.assertEqual(len(msgs), 1)\n        self.assertEqual(len(lines), 1)\n        self.assertRegexpMatches(msgs[0], r\'^\\[\\d+\\] Warning :\\s+Some log-message\\n$\')\n        self.assertRegexpMatches(lines[0], r\'^\\[\\d+\\] Warning :\\s+Some log-message$\')\n\n\n    def test_basic_logging_error(self):\n        shinken_logger.setLevel(DEBUG)\n        msgs, lines = self._put_log(logger.error, \'Some log-message\')\n        self.assertEqual(len(msgs), 1)\n        self.assertEqual(len(lines), 1)\n        self.assertRegexpMatches(msgs[0], r\'^\\[\\d+\\] Error :\\s+Some log-message\\n$\')\n        self.assertRegexpMatches(lines[0], r\'^\\[\\d+\\] Error :\\s+Some log-message$\')\n\n    def test_basic_logging_critical(self):\n        msgs, lines = self._put_log(logger.critical, \'Some log-message\')\n        self.assertEqual(len(msgs), 1)\n        self.assertEqual(len(lines), 1)\n        self.assertRegexpMatches(msgs[0], r\'^\\[\\d+\\] Critical :\\s+Some log-message\\n$\')\n        self.assertRegexpMatches(lines[0], r\'^\\[\\d+\\] Critical :\\s+Some log-message$\')\n\n    def test_level_is_higher_then_the_one_set(self):\n        # just test two samples\n\n\n    def test_basic_logging_warning(self):\n        logger = self._prepare_logging()\n        logger.setLevel(WARNING)\n        self.generic_tst(logger.warning, \'Some log-message\',\n                         [1, 1], [r\'^\\[\\d+\\] WARNING:\\s+Some log-message\\n$\', r\'^\\[\\d+\\] WARNING:\\s+Some log-message$\'])\n\n    def test_basic_logging_error(self):\n        logger = self._prepare_logging()\n        logger.setLevel(ERROR)\n        self.generic_tst(logger.error, \'Some log-message\',\n                         [1, 1], [r\'^\\[\\d+\\] ERROR:\\s+Some log-message\\n$\', r\'^\\[\\d+\\] ERROR:\\s+Some log-message$\'])\n        logger.set_human_format(True)\n        msgs, lines = self._put_log(logger.info, \'Some ] log-message\')\n        self.assertRegexpMatches(msgs[0],\n            r\'^\\[[^\\]]+] Info :\\s+Some \\] log-message\\n$\')\n        time.strptime(msgs[0].split(\' Info :    \', 1)[0], \'[%a %b %d %H:%M:%S %Y]\')\n        self.assertRegexpMatches(lines[0],\n            r\'^\\[[^\\]]+] Info :\\s+Some \\] log-message$\')\n        time.strptime(msgs[0].split(\' Info :    \', 1)[0], \'[%a %b %d %H:%M:%S %Y]\')\n        logger.set_human_format(False)\n\n    def test_reset_human_timestamp_format(self):\n        # just test two samples\n        logger.setLevel(CRITICAL)\n        self.generic_tst(logger.error, \'Some log-message\',\n                         [1, 0], [r\'^\\[\\d+\\] ERROR:\\s+Some log-message\\n$\', \'\'])\n\n        # need to prepare again to have stdout=StringIO()\n        logger = self._prepare_logging()\n        logger.setLevel(logging.INFO)\n        self.generic_tst(logger.debug, \'Some log-message\',\n                         [0, 0], [\'\', \'\'])\n\n\n    def test_human_timestamp_format(self):\n        "test output using the human timestamp format"\n        logger = self._prepare_logging()\n        logger.setLevel(logging.INFO)\n        logger.set_human_format(True)\n        loglist = self.generic_tst(logger.info, \'Some ] log-message\',\n                         [1, 1], [r\'^\\[\\d+\\] INFO:\\s+Some \\] log-message\\n$\', r\'^\\[[^\\]]+] INFO:\\s+Some \\] log-message$\'])\n\n        time.strptime(loglist[1][0].split(\' INFO: \', 1)[0], \'[%a %b %d %H:%M:%S %Y]\')\n        logger.set_human_format(False)\n\n    def test_reset_human_timestamp_format(self):\n        "test output after switching of the human timestamp format"\n        # ensure the human timestamp format is set, ...\n        self.test_human_timestamp_format()\n        # ... then turn it off\n        logger.set_human_format(False)\n        # test whether the normal format is used again\n        self.test_basic_logging_info()\n\n\nclass TestColorConsoleLogger(NoSetup, ShinkenTest, LogCollectMixin):\n\n    def test_basic_logging_info_colored(self):\n        shinken_logger.setLevel(INFO)\n        self._collector = Collector()\n        sys.stdout = StringIO()\n        shinken_logger.handlers[0].stream = sys.stdout\n        shinken_logger.load_obj(self._collector)\n        if isinstance(shinken_logger.handlers[0], ColorStreamHandler):\n            self.generic_tst(shinken_logger.info, \'Some log-message\',\n                             [1, 1],\n                             [r\'^\\[.+?\\] INFO: \\[Shinken\\] Some log-message$\',\n                              r\'^\\x1b\\[95m\\[.+?\\] INFO: \\[Shinken\\] Some log-message\\x1b\\[0m$\'])\n        else:\n        self.assertEqual(len(lines), 1)\n        self.assertEqual(len(local_log), 1)\n        self.assertRegexpMatches(local_log[0],\n            r\' \\[\\d+\\] Debug :\\s+Some log-message$\')\n\n    def test_basic_logging_info(self):\n        logger.set_level(logger.INFO)\n        shinken_logger.setLevel(INFO)\n        self._collector = Collector()\n        self.assertEqual(len(lines), 1)\n        self.assertEqual(len(local_log), 1)\n        self.assertRegexpMatches(local_log[0],\n            r\' \\[\\d+\\] Info :\\s+Some log-message\\n$\')\n\n    def test_basic_logging_error(self):\n        logger.set_level(logger.ERROR)\n                             [r\'^\\[.+?\\] INFO: \\[Shinken\\] Some log-message$\',\n                              r\'^\\x1b\\[95m\\[.+?\\] INFO: \\[Shinken\\] Some log-message\\x1b\\[0m$\'])\n        else:\n        self.assertEqual(len(local_log), 1)\n        print >> sys.stderr, local_log[0]\n        self.assertRegexpMatches(local_log[0],\n            r\' \\[\\d+\\] Error :\\s+Some log-message\\n$\')\n\n    def test_basic_logging_critical(self):\n        logger.set_level(logger.CRITICAL)\n        _, time2 = times.rsplit(\'[\', 1)\n        time.strptime(time2.rsplit(\']\')[0], \'%a %b %d %H:%M:%S %Y\')\n        self.assertEqual(len(lines), 1)\n        self.assertEqual(len(local_log), 1)\n        self.assertRegexpMatches(local_log[0],\n            r\' \\[\\d+\\] Critical :\\s+Some log-message\\n$\')\n\n    def test_level_is_higher_then_the_one_set(self):\n        # just test two samples\n        # ... then turn it off\n        logger.set_human_format(False)\n        # test whether the normal format is used again\n        self.test_basic_logging_info_colored()\n\n\nclass TestWithLocalLogging(NoSetup, ShinkenTest, LogCollectMixin):\n\n    def _prepare_logging(self):\n        logger = super(TestWithLocalLogging, self)._prepare_logging()\n        # set up a temporary file for logging\n        logfile = NamedTemporaryFile("w", delete=False)\n        logfile.close()\n        self.logfile_name = logfile.name\n        logger.register_local_log(logfile.name, purge_buffer=False)\n        return logger\n        msgs, lines, local_log = self._put_log(logger.info, \'Some ] log-message\')\n        self.assertEqual(len(local_log), 1)\n        self.assertRegexpMatches(local_log[0],\n            r\' \\[[^\\]]+] Info :\\s+Some \\] log-message\\n$\')\n        # :fixme: Currently, the local log gets prefixed another\n        # timestamp. As it is yet unclear, whether this intended or\n        # not, we test it, too.\n        times = local_log[0].split(\' Info :    \', 1)[0]\n        time1, time2 = times.rsplit(\'[\', 1)\n        time.strptime(time1.rsplit(\',\')[0], \'%Y-%m-%d %H:%M:%S\')\n        time.strptime(time2, \'%a %b %d %H:%M:%S %Y]\')\n        logfile.close()\n        logfile_name = logfile.name\n        logger.register_local_log(logfile_name, purge_buffer=False)\n        self.assertEqual(logger.level, min(ERROR, INFO))\n\n\n    def test_basic_logging_log(self):\n        sys.stdout = StringIO()\n        self._collector = Collector()\n        sh = StreamHandler(sys.stdout)\n        sh.setFormatter(defaultFormatter)\n        shinken_logger.handlers = []\n        shinken_logger.addHandler(sh)\n        shinken_logger.load_obj(self._collector)\n        shinken_logger.log_set = True\n        logfile = NamedTemporaryFile("w", delete=False)\n        logfile.close()\n        self.logfile_name = logfile.name\n        shinken_logger.register_local_log(logfile.name, purge_buffer=False)\n        shinken_logger.setLevel(DEBUG)\n        self.generic_tst(lambda x: naglog_result(\'info\', x), \'Some log-message\',\n                         [1, 1, 1], [\'\', r\'^\\[\\d+\\] Some log-message$\', r\'^\\[\\d+\\] Some log-message$\'])\n\n\n    def test_basic_logging_debug_does_not_send_broks(self):\n        logger = self._prepare_logging()\n        self.assertEqual(len(msgs), 1)\n        self.assertEqual(len(lines), 1)\n        self.assertRegexpMatches(msgs[0],\n             r\'^\\[\\d+\\] Info :\\s+\\[Tiroler Schinken\\] Some log-message\\n$\')\n        self.assertRegexpMatches(lines[0],\n             r\'^\\[\\d+\\] Info :\\s+\\[Tiroler Schinken\\] Some log-message$\')\n\n    def test_human_timestamp_format(self):\n        logger.set_level(logger.INFO)\n        logger.set_human_format(True)\n        msgs, lines = self._put_log(logger.info, \'Some ] log-message\')\n        self.assertRegexpMatches(msgs[0],\n            r\'^\\[[^\\]]+] Info :\\s+\\[Tiroler Schinken\\] Some \\] log-message\\n$\')\n        time.strptime(msgs[0].split(\' Info :    \', 1)[0], \'[%a %b %d %H:%M:%S %Y]\')\n        self.assertRegexpMatches(lines[0],\n            r\'^\\[[^\\]]+] Info :\\s+\\[Tiroler Schinken\\] Some \\] log-message$\')\n        time.strptime(msgs[0].split(\' Info :    \', 1)[0], \'[%a %b %d %H:%M:%S %Y]\')\n        logger.set_human_format(False)\n\n    def test_reset_human_timestamp_format(self):\n                         [1, 1, 1], [\'\', \'\', r\'\\[\\d+\\] CRITICAL:\\s+Some log-message\\n$\'])\n\n    def test_level_is_higher_then_the_one_set(self):\n        logger = self._prepare_logging()\n        # just test two samples\n        logger.setLevel(CRITICAL)\n        self.generic_tst(logger.debug, \'Some log-message\', [0, 0, 0], [\'\', \'\', \'\'])\n\n        # need to prepare again to have stdout=StringIO() and a local log file\n        logger = self._prepare_logging()\n        logger.setLevel(INFO)\n        self.generic_tst(logger.debug, \'Some log-message\', [0, 0, 0], [\'\', \'\', \'\'])\n\n    def test_human_timestamp_format(self):\n        logger = self._prepare_logging()\n        logger.setLevel(logging.INFO)\n        logger.set_human_format(True)\n        loglist = self.generic_tst(logger.info, \'Some log-message\',\n                         [1, 1, 1],\n                         [r\'\', r\'\', r\'\\[[^\\]]+] INFO:\\s+Some log-message\\n$\'])\n\n        # :fixme: Currently, the local log gets prefixed another\n        # timestamp. As it is yet unclear, whether this intended or\n        # not, we test it, too.\n        times = loglist[2][0].split(\' INFO:    \', 1)[0]\n        _, time2 = times.rsplit(\'[\', 1)\n        time.strptime(time2.rsplit(\']\')[0], \'%a %b %d %H:%M:%S %Y\')\n        logger.set_human_format(False)\n\n    def test_reset_human_timestamp_format(self):\n        "test output after switching of the human timestamp format"\n        # ensure the human timestamp format is set, ...\n        self.test_human_timestamp_format()\n        # ... then turn it off\n        logger.set_human_format(False)\n        # test whether the normal format is used again\n        self.test_basic_logging_info()\n\n\nclass TestNamedCollector(NoSetup, ShinkenTest, LogCollectMixin):\n\n    # :todo: add a test for the local log file, too\n\n    def _prepare_logging(self):\n        self._collector = Collector()\n        self._stdout = sys.stdout\n        sys.stdout = StringIO()\n        logger = Log(name=None, log_set=True)\n        from shinken.log import defaultFormatter\n        from logging import StreamHandler\n        sh = StreamHandler(sys.stdout)\n        sh.setFormatter(defaultFormatter)\n        logger.addHandler(sh)\n        logger.load_obj(self._collector, \'Tiroler Schinken\')\n        return logger\n\n    def test_basic_logging_info(self):\n        logger = self._prepare_logging()\n        logger.setLevel(logging.INFO)\n        self.generic_tst(logger.info, \'Some log-message\',\n                         [1, 1],\n                         [r\'^\\[\\d+\\] INFO:\\s+\\[Tiroler Schinken\\] Some log-message\\n$\',\n                          r\'^\\[\\d+\\] INFO:\\s+\\[Tiroler Schinken\\] Some log-message$\'])\n\n    def test_human_timestamp_format(self):\n        logger = self._prepare_logging()\n        logger.setLevel(logging.INFO)\n        logger.set_human_format(True)\n        loglist = self.generic_tst(logger.info, \'Some ] log-message\',\n                         [1, 1],\n                         [r\'^\\[\\d+\\] INFO:\\s+\\[Tiroler Schinken\\] Some \\] log-message\\n$\',\n                          r\'^\\[[^\\]]+] INFO:\\s+\\[Tiroler Schinken\\] Some \\] log-message$\'])\n        # No TS for broker!\n        time.strptime(loglist[1][0].split(\' INFO: \', 1)[0], \'[%a %b %d %H:%M:%S %Y]\')\n        logger.set_human_format(False)\n\n    def test_reset_human_timestamp_format(self):\n        # ensure human timestamp format is set and working\n        self.test_human_timestamp_format()\n        # turn of human timestamp format\n        logger.set_human_format(False)\n        # test for normal format\n        self.test_basic_logging_info()\n\n\nif __name__ == \'__main__\':\n    unittest.main()\n', 'message': 'Fix: typo error in logging test\n', 'author_name': 'FORLOT Romain', 'lang': 'py'}