testing/mozbase/mozlog/tests/test_structured.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.

michael@0 1 import argparse
michael@0 2 import os
michael@0 3 import time
michael@0 4 import unittest
michael@0 5 import StringIO
michael@0 6 import json
michael@0 7
michael@0 8 from mozlog.structured import (
michael@0 9 commandline,
michael@0 10 reader,
michael@0 11 structuredlog,
michael@0 12 )
michael@0 13
michael@0 14
michael@0 15 class TestHandler(object):
michael@0 16 def __init__(self):
michael@0 17 self.last_item = None
michael@0 18
michael@0 19 def __call__(self, data):
michael@0 20 self.last_item = data
michael@0 21
michael@0 22
michael@0 23 class BaseStructuredTest(unittest.TestCase):
michael@0 24 def setUp(self):
michael@0 25 self.logger = structuredlog.StructuredLogger("test")
michael@0 26 self.handler = TestHandler()
michael@0 27 self.logger.add_handler(self.handler)
michael@0 28
michael@0 29 @property
michael@0 30 def last_item(self):
michael@0 31 return self.handler.last_item
michael@0 32
michael@0 33 def assert_log_equals(self, expected, actual=None):
michael@0 34 if actual is None:
michael@0 35 actual = self.last_item
michael@0 36
michael@0 37 all_expected = {"pid": os.getpid(),
michael@0 38 "thread": "MainThread",
michael@0 39 "source": "test"}
michael@0 40 specials = set(["time"])
michael@0 41
michael@0 42 all_expected.update(expected)
michael@0 43 for key, value in all_expected.iteritems():
michael@0 44 self.assertEqual(actual[key], value)
michael@0 45
michael@0 46 self.assertEquals(set(all_expected.keys()) | specials, set(actual.keys()))
michael@0 47
michael@0 48
michael@0 49 class TestStructuredLog(BaseStructuredTest):
michael@0 50 def test_suite_start(self):
michael@0 51 self.logger.suite_start(["test"])
michael@0 52 self.assert_log_equals({"action": "suite_start",
michael@0 53 "tests":["test"]})
michael@0 54
michael@0 55 def test_suite_end(self):
michael@0 56 self.logger.suite_end()
michael@0 57 self.assert_log_equals({"action": "suite_end"})
michael@0 58
michael@0 59 def test_start(self):
michael@0 60 self.logger.test_start("test1")
michael@0 61 self.assert_log_equals({"action": "test_start",
michael@0 62 "test":"test1"})
michael@0 63
michael@0 64 self.logger.test_start(("test1", "==", "test1-ref"))
michael@0 65 self.assert_log_equals({"action": "test_start",
michael@0 66 "test":("test1", "==", "test1-ref")})
michael@0 67
michael@0 68 def test_status(self):
michael@0 69 self.logger.test_status("test1", "subtest name", "fail", expected="FAIL", message="Test message")
michael@0 70 self.assert_log_equals({"action": "test_status",
michael@0 71 "subtest": "subtest name",
michael@0 72 "status": "FAIL",
michael@0 73 "message": "Test message",
michael@0 74 "test":"test1"})
michael@0 75
michael@0 76 def test_status_1(self):
michael@0 77 self.logger.test_status("test1", "subtest name", "fail")
michael@0 78 self.assert_log_equals({"action": "test_status",
michael@0 79 "subtest": "subtest name",
michael@0 80 "status": "FAIL",
michael@0 81 "expected": "PASS",
michael@0 82 "test":"test1"})
michael@0 83
michael@0 84 def test_status_2(self):
michael@0 85 self.assertRaises(ValueError, self.logger.test_status, "test1", "subtest name", "XXXUNKNOWNXXX")
michael@0 86
michael@0 87 def test_end(self):
michael@0 88 self.logger.test_end("test1", "fail", message="Test message")
michael@0 89 self.assert_log_equals({"action": "test_end",
michael@0 90 "status": "FAIL",
michael@0 91 "expected": "OK",
michael@0 92 "message": "Test message",
michael@0 93 "test":"test1"})
michael@0 94
michael@0 95 def test_end_1(self):
michael@0 96 self.logger.test_end("test1", "PASS", expected="PASS", extra={"data":123})
michael@0 97 self.assert_log_equals({"action": "test_end",
michael@0 98 "status": "PASS",
michael@0 99 "extra": {"data": 123},
michael@0 100 "test":"test1"})
michael@0 101
michael@0 102 def test_end_2(self):
michael@0 103 self.assertRaises(ValueError, self.logger.test_end, "test1", "XXXUNKNOWNXXX")
michael@0 104
michael@0 105 def test_process(self):
michael@0 106 self.logger.process_output(1234, "test output")
michael@0 107 self.assert_log_equals({"action": "process_output",
michael@0 108 "process": 1234,
michael@0 109 "data": "test output"})
michael@0 110
michael@0 111 def test_log(self):
michael@0 112 for level in ["critical", "error", "warning", "info", "debug"]:
michael@0 113 getattr(self.logger, level)("message")
michael@0 114 self.assert_log_equals({"action": "log",
michael@0 115 "level": level.upper(),
michael@0 116 "message": "message"})
michael@0 117
michael@0 118 def test_logging_adapter(self):
michael@0 119 import logging
michael@0 120 logging.basicConfig(level="DEBUG")
michael@0 121 old_level = logging.root.getEffectiveLevel()
michael@0 122 logging.root.setLevel("DEBUG")
michael@0 123
michael@0 124 std_logger = logging.getLogger("test")
michael@0 125 std_logger.setLevel("DEBUG")
michael@0 126
michael@0 127 logger = structuredlog.std_logging_adapter(std_logger)
michael@0 128
michael@0 129 try:
michael@0 130 for level in ["critical", "error", "warning", "info", "debug"]:
michael@0 131 getattr(logger, level)("message")
michael@0 132 self.assert_log_equals({"action": "log",
michael@0 133 "level": level.upper(),
michael@0 134 "message": "message"})
michael@0 135 finally:
michael@0 136 logging.root.setLevel(old_level)
michael@0 137
michael@0 138 def test_add_remove_handlers(self):
michael@0 139 handler = TestHandler()
michael@0 140 self.logger.add_handler(handler)
michael@0 141 self.logger.info("test1")
michael@0 142
michael@0 143 self.assert_log_equals({"action": "log",
michael@0 144 "level": "INFO",
michael@0 145 "message": "test1"})
michael@0 146
michael@0 147 self.assert_log_equals({"action": "log",
michael@0 148 "level": "INFO",
michael@0 149 "message": "test1"}, actual=handler.last_item)
michael@0 150
michael@0 151 self.logger.remove_handler(handler)
michael@0 152 self.logger.info("test2")
michael@0 153
michael@0 154 self.assert_log_equals({"action": "log",
michael@0 155 "level": "INFO",
michael@0 156 "message": "test2"})
michael@0 157
michael@0 158 self.assert_log_equals({"action": "log",
michael@0 159 "level": "INFO",
michael@0 160 "message": "test1"}, actual=handler.last_item)
michael@0 161
michael@0 162 def test_wrapper(self):
michael@0 163 file_like = structuredlog.StructuredLogFileLike(self.logger)
michael@0 164
michael@0 165 file_like.write("line 1")
michael@0 166
michael@0 167 self.assert_log_equals({"action": "log",
michael@0 168 "level": "INFO",
michael@0 169 "message": "line 1"})
michael@0 170
michael@0 171 file_like.write("line 2\n")
michael@0 172
michael@0 173 self.assert_log_equals({"action": "log",
michael@0 174 "level": "INFO",
michael@0 175 "message": "line 2"})
michael@0 176
michael@0 177 file_like.write("line 3\r")
michael@0 178
michael@0 179 self.assert_log_equals({"action": "log",
michael@0 180 "level": "INFO",
michael@0 181 "message": "line 3"})
michael@0 182
michael@0 183 file_like.write("line 4\r\n")
michael@0 184
michael@0 185 self.assert_log_equals({"action": "log",
michael@0 186 "level": "INFO",
michael@0 187 "message": "line 4"})
michael@0 188
michael@0 189 class TestCommandline(unittest.TestCase):
michael@0 190 def test_setup_logging(self):
michael@0 191 parser = argparse.ArgumentParser()
michael@0 192 commandline.add_logging_group(parser)
michael@0 193 args = parser.parse_args(["--log-raw=/tmp/foo"])
michael@0 194 logger = commandline.setup_logging("test", args, {})
michael@0 195 self.assertEqual(len(logger.handlers), 1)
michael@0 196
michael@0 197 class TestReader(unittest.TestCase):
michael@0 198 def to_file_like(self, obj):
michael@0 199 data_str = "\n".join(json.dumps(item) for item in obj)
michael@0 200 return StringIO.StringIO(data_str)
michael@0 201
michael@0 202 def test_read(self):
michael@0 203 data = [{"action": "action_0", "data": "data_0"},
michael@0 204 {"action": "action_1", "data": "data_1"}]
michael@0 205
michael@0 206 f = self.to_file_like(data)
michael@0 207 self.assertEquals(data, list(reader.read(f)))
michael@0 208
michael@0 209 def test_imap_log(self):
michael@0 210 data = [{"action": "action_0", "data": "data_0"},
michael@0 211 {"action": "action_1", "data": "data_1"}]
michael@0 212
michael@0 213 f = self.to_file_like(data)
michael@0 214
michael@0 215 def f_action_0(item):
michael@0 216 return ("action_0", item["data"])
michael@0 217
michael@0 218 def f_action_1(item):
michael@0 219 return ("action_1", item["data"])
michael@0 220
michael@0 221 res_iter = reader.imap_log(reader.read(f),
michael@0 222 {"action_0": f_action_0,
michael@0 223 "action_1": f_action_1})
michael@0 224 self.assertEquals([("action_0", "data_0"), ("action_1", "data_1")],
michael@0 225 list(res_iter))
michael@0 226
michael@0 227 def test_each_log(self):
michael@0 228 data = [{"action": "action_0", "data": "data_0"},
michael@0 229 {"action": "action_1", "data": "data_1"}]
michael@0 230
michael@0 231 f = self.to_file_like(data)
michael@0 232
michael@0 233 count = {"action_0":0,
michael@0 234 "action_1":0}
michael@0 235
michael@0 236 def f_action_0(item):
michael@0 237 count[item["action"]] += 1
michael@0 238
michael@0 239 def f_action_1(item):
michael@0 240 count[item["action"]] += 2
michael@0 241
michael@0 242 reader.each_log(reader.read(f),
michael@0 243 {"action_0": f_action_0,
michael@0 244 "action_1": f_action_1})
michael@0 245
michael@0 246 self.assertEquals({"action_0":1, "action_1":2}, count)
michael@0 247
michael@0 248 def test_handler(self):
michael@0 249 data = [{"action": "action_0", "data": "data_0"},
michael@0 250 {"action": "action_1", "data": "data_1"}]
michael@0 251
michael@0 252 f = self.to_file_like(data)
michael@0 253
michael@0 254 test = self
michael@0 255 class ReaderTestHandler(reader.LogHandler):
michael@0 256 def __init__(self):
michael@0 257 self.action_0_count = 0
michael@0 258 self.action_1_count = 0
michael@0 259
michael@0 260 def action_0(self, item):
michael@0 261 test.assertEquals(item["action"], "action_0")
michael@0 262 self.action_0_count += 1
michael@0 263
michael@0 264 def action_1(self, item):
michael@0 265 test.assertEquals(item["action"], "action_1")
michael@0 266 self.action_1_count += 1
michael@0 267
michael@0 268 handler = ReaderTestHandler()
michael@0 269 reader.handle_log(reader.read(f), handler)
michael@0 270
michael@0 271 self.assertEquals(handler.action_0_count, 1)
michael@0 272 self.assertEquals(handler.action_1_count, 1)
michael@0 273
michael@0 274 if __name__ == "__main__":
michael@0 275 unittest.main()

mercurial