The Tor Browser: testing/mozbase/mozlog/tests/test_logger.py@6474c204b198 (annotated)

testing/mozbase/mozlog/tests/test_logger.py@6474c204b198 (annotated)

testing/mozbase/mozlog/tests/test_logger.py

Wed, 31 Dec 2014 06:09:35 +0100

author: Michael Schloh von Bennewitz <michael@schloh.com>
date: Wed, 31 Dec 2014 06:09:35 +0100
changeset 0: 6474c204b198
permissions: -rw-r--r--

Cloned upstream origin tor-browser at tor-browser-31.3.0esr-4.5-1-build1
revision ID fc1c9ff7c1b2defdbc039f12214767608f46423f for hacking purpose.

 # This Source Code Form is subject to the terms of the Mozilla Public
 # License, v. 2.0. If a copy of the MPL was not distributed with this file,
 # You can obtain one at http://mozilla.org/MPL/2.0/.
 import datetime
 import json
 import socket
 import threading
 import time
 import unittest
 import mozfile
 import mozlog
 class ListHandler(mozlog.Handler):
     """Mock handler appends messages to a list for later inspection."""
     def __init__(self):
         mozlog.Handler.__init__(self)
         self.messages = []
     def emit(self, record):
         self.messages.append(self.format(record))
 class TestLogging(unittest.TestCase):
     """Tests behavior of basic mozlog api."""
     def test_logger_defaults(self):
         """Tests the default logging format and behavior."""
         default_logger = mozlog.getLogger('default.logger')
         self.assertEqual(default_logger.name, 'default.logger')
         self.assertEqual(len(default_logger.handlers), 1)
         self.assertTrue(isinstance(default_logger.handlers[0],
                                    mozlog.StreamHandler))
         f = mozfile.NamedTemporaryFile()
         list_logger = mozlog.getLogger('file.logger',
                                        handler=mozlog.FileHandler(f.name))
         self.assertEqual(len(list_logger.handlers), 1)
         self.assertTrue(isinstance(list_logger.handlers[0],
                                    mozlog.FileHandler))
         f.close()
         self.assertRaises(ValueError, mozlog.getLogger,
                           'file.logger', handler=ListHandler())
     def test_timestamps(self):
         """Verifies that timestamps are included when asked for."""
         log_name = 'test'
         handler = ListHandler()
         handler.setFormatter(mozlog.MozFormatter())
         log = mozlog.getLogger(log_name, handler=handler)
         log.info('no timestamp')
         self.assertTrue(handler.messages[-1].startswith('%s ' % log_name))
         handler.setFormatter(mozlog.MozFormatter(include_timestamp=True))
         log.info('timestamp')
         # Just verify that this raises no exceptions.
         datetime.datetime.strptime(handler.messages[-1][:23],
                                    '%Y-%m-%d %H:%M:%S,%f')
 class TestStructuredLogging(unittest.TestCase):
     """Tests structured output in mozlog."""
     def setUp(self):
         self.handler = ListHandler()
         self.handler.setFormatter(mozlog.JSONFormatter())
         self.logger = mozlog.MozLogger('test.Logger')
         self.logger.addHandler(self.handler)
         self.logger.setLevel(mozlog.DEBUG)
     def check_messages(self, expected, actual):
         """Checks actual for equality with corresponding fields in actual.
         The actual message should contain all fields in expected, and
         should be identical, with the exception of the timestamp field.
         The actual message should contain no fields other than the timestamp
         field and those present in expected."""
         self.assertTrue(isinstance(actual['_time'], (int, long)))
         for k, v in expected.items():
             self.assertEqual(v, actual[k])
         for k in actual.keys():
             if k != '_time':
                 self.assertTrue(expected.get(k) is not None)
     def test_structured_output(self):
         self.logger.log_structured('test_message',
                                    {'_level': mozlog.INFO,
                                     '_message': 'message one'})
         self.logger.log_structured('test_message',
                                    {'_level': mozlog.INFO,
                                     '_message': 'message two'})
         self.logger.log_structured('error_message',
                                    {'_level': mozlog.ERROR,
                                     'diagnostic': 'unexpected error'})
         message_one_expected = {'_namespace': 'test.Logger',
                                 '_level': 'INFO',
                                 '_message': 'message one',
                                 'action': 'test_message'}
         message_two_expected = {'_namespace': 'test.Logger',
                                 '_level': 'INFO',
                                 '_message': 'message two',
                                 'action': 'test_message'}
         message_three_expected = {'_namespace': 'test.Logger',
                                   '_level': 'ERROR',
                                   'diagnostic': 'unexpected error',
                                   'action': 'error_message'}
         message_one_actual = json.loads(self.handler.messages[0])
         message_two_actual = json.loads(self.handler.messages[1])
         message_three_actual = json.loads(self.handler.messages[2])
         self.check_messages(message_one_expected, message_one_actual)
         self.check_messages(message_two_expected, message_two_actual)
         self.check_messages(message_three_expected, message_three_actual)
     def test_unstructured_conversion(self):
         """ Tests that logging to a logger with a structured formatter
         via the traditional logging interface works as expected. """
         self.logger.info('%s %s %d', 'Message', 'number', 1)
         self.logger.error('Message number 2')
         self.logger.debug('Message with %s', 'some extras',
                           extra={'params': {'action': 'mozlog_test_output',
                                             'is_failure': False}})
         message_one_expected = {'_namespace': 'test.Logger',
                                 '_level': 'INFO',
                                 '_message': 'Message number 1'}
         message_two_expected = {'_namespace': 'test.Logger',
                                 '_level': 'ERROR',
                                 '_message': 'Message number 2'}
         message_three_expected = {'_namespace': 'test.Logger',
                                   '_level': 'DEBUG',
                                   '_message': 'Message with some extras',
                                   'action': 'mozlog_test_output',
                                   'is_failure': False}
         message_one_actual = json.loads(self.handler.messages[0])
         message_two_actual = json.loads(self.handler.messages[1])
         message_three_actual = json.loads(self.handler.messages[2])
         self.check_messages(message_one_expected, message_one_actual)
         self.check_messages(message_two_expected, message_two_actual)
         self.check_messages(message_three_expected, message_three_actual)
     def message_callback(self):
         if len(self.handler.messages) == 3:
             message_one_expected = {'_namespace': 'test.Logger',
                                     '_level': 'DEBUG',
                                     '_message': 'socket message one',
                                     'action': 'test_message'}
             message_two_expected = {'_namespace': 'test.Logger',
                                     '_level': 'DEBUG',
                                     '_message': 'socket message two',
                                     'action': 'test_message'}
             message_three_expected = {'_namespace': 'test.Logger',
                                       '_level': 'DEBUG',
                                       '_message': 'socket message three',
                                       'action': 'test_message'}
             message_one_actual = json.loads(self.handler.messages[0])
             message_two_actual = json.loads(self.handler.messages[1])
             message_three_actual = json.loads(self.handler.messages[2])
             self.check_messages(message_one_expected, message_one_actual)
             self.check_messages(message_two_expected, message_two_actual)
             self.check_messages(message_three_expected, message_three_actual)
     def test_log_listener(self):
         connection = '127.0.0.1', 0
         self.log_server = mozlog.LogMessageServer(connection,
                                                   self.logger,
                                                   message_callback=self.message_callback,
                                                   timeout=0.5)
         message_string_one = json.dumps({'_message': 'socket message one',
                                          'action': 'test_message',
                                          '_level': 'DEBUG'})
         message_string_two = json.dumps({'_message': 'socket message two',
                                          'action': 'test_message',
                                          '_level': 'DEBUG'})
         message_string_three = json.dumps({'_message': 'socket message three',
                                            'action': 'test_message',
                                            '_level': 'DEBUG'})
         message_string = message_string_one + '\n' + \
                          message_string_two + '\n' + \
                          message_string_three + '\n'
         server_thread = threading.Thread(target=self.log_server.handle_request)
         server_thread.start()
         host, port = self.log_server.server_address
         sock = socket.socket()
         sock.connect((host, port))
         # Sleeps prevent listener from receiving entire message in a single call
         # to recv in order to test reconstruction of partial messages.
         sock.sendall(message_string[:8])
         time.sleep(.01)
         sock.sendall(message_string[8:32])
         time.sleep(.01)
         sock.sendall(message_string[32:64])
         time.sleep(.01)
         sock.sendall(message_string[64:128])
         time.sleep(.01)
         sock.sendall(message_string[128:])
         server_thread.join()
 class Loggable(mozlog.LoggingMixin):
     """Trivial class inheriting from LoggingMixin"""
     pass
 class TestLoggingMixin(unittest.TestCase):
     """Tests basic use of LoggingMixin"""
     def test_mixin(self):
         loggable = Loggable()
         self.assertTrue(not hasattr(loggable, "_logger"))
         loggable.log(mozlog.INFO, "This will instantiate the logger")
         self.assertTrue(hasattr(loggable, "_logger"))
         self.assertEqual(loggable._logger.name, "test_logger.Loggable")
         self.assertRaises(ValueError, loggable.set_logger,
                           "not a logger")
         logger = mozlog.MozLogger('test.mixin')
         handler = ListHandler()
         logger.addHandler(handler)
         loggable.set_logger(logger)
         self.assertTrue(isinstance(loggable._logger.handlers[0],
                                    ListHandler))
         self.assertEqual(loggable._logger.name, "test.mixin")
         loggable.log(mozlog.WARN, 'message for "log" method')
         loggable.info('message for "info" method')
         loggable.error('message for "error" method')
         loggable.log_structured('test_message',
                                 params={'_message': 'message for ' + \
                                         '"log_structured" method'})
         expected_messages = ['message for "log" method',
                              'message for "info" method',
                              'message for "error" method',
                              'message for "log_structured" method']
         actual_messages = loggable._logger.handlers[0].messages
         self.assertEqual(expected_messages, actual_messages)
 if __name__ == '__main__':
     unittest.main()

The Tor Browser / annotate

testing/mozbase/mozlog/tests/test_logger.py@6474c204b198 (annotated)

testing/mozbase/mozlog/tests/test_logger.py