| 1 | # Tests for waeup.sirp.utils.logger |
|---|
| 2 | import logging |
|---|
| 3 | import os |
|---|
| 4 | import shutil |
|---|
| 5 | import tempfile |
|---|
| 6 | from zope.component import queryUtility |
|---|
| 7 | from zope.component.hooks import setSite, clearSite |
|---|
| 8 | from zope.interface.verify import verifyClass, verifyObject |
|---|
| 9 | from waeup.sirp.app import University |
|---|
| 10 | from waeup.sirp.testing import ( |
|---|
| 11 | FunctionalLayer, FunctionalTestCase, get_all_loggers, |
|---|
| 12 | remove_new_loggers, remove_logger) |
|---|
| 13 | |
|---|
| 14 | from waeup.sirp.utils.logger import ( |
|---|
| 15 | Logger, MAX_BYTES, BACKUP_COUNT, ILoggerCollector, LoggerCollector, |
|---|
| 16 | ILogger) |
|---|
| 17 | |
|---|
| 18 | class FakeComponent(object): |
|---|
| 19 | # A component that can use the Logger mixin-class |
|---|
| 20 | def do_something(self): |
|---|
| 21 | self.logger.info('msg from do_something') |
|---|
| 22 | |
|---|
| 23 | class LoggingComponent(FakeComponent, Logger): |
|---|
| 24 | # A component that supports logging by mixing in Logger |
|---|
| 25 | logger_name = 'sample.${sitename}' |
|---|
| 26 | logger_filename = 'sample.log' |
|---|
| 27 | |
|---|
| 28 | class LoggersTests(FunctionalTestCase): |
|---|
| 29 | |
|---|
| 30 | layer = FunctionalLayer |
|---|
| 31 | |
|---|
| 32 | def setUp(self): |
|---|
| 33 | super(LoggersTests, self).setUp() |
|---|
| 34 | self.old_loggers = get_all_loggers() |
|---|
| 35 | # Setup a sample site for each test |
|---|
| 36 | app = University() |
|---|
| 37 | self.dc_root = tempfile.mkdtemp() |
|---|
| 38 | self.dc_root2 = None |
|---|
| 39 | app['datacenter'].setStoragePath(self.dc_root) |
|---|
| 40 | |
|---|
| 41 | # Prepopulate the ZODB... |
|---|
| 42 | self.getRootFolder()['app'] = app |
|---|
| 43 | self.app = self.getRootFolder()['app'] |
|---|
| 44 | self.workdir = tempfile.mkdtemp() |
|---|
| 45 | return |
|---|
| 46 | |
|---|
| 47 | def tearDown(self): |
|---|
| 48 | super(LoggersTests, self).tearDown() |
|---|
| 49 | remove_new_loggers(self.old_loggers) |
|---|
| 50 | shutil.rmtree(self.workdir) |
|---|
| 51 | shutil.rmtree(self.dc_root) |
|---|
| 52 | clearSite() |
|---|
| 53 | return |
|---|
| 54 | |
|---|
| 55 | def clear_logger(self, logger): |
|---|
| 56 | del_list = [x for x in logger.handlers] |
|---|
| 57 | for handler in del_list: |
|---|
| 58 | logger.removeHandler(handler) |
|---|
| 59 | return |
|---|
| 60 | |
|---|
| 61 | def test_iface(self): |
|---|
| 62 | setSite(self.app) |
|---|
| 63 | logger = LoggingComponent() |
|---|
| 64 | verifyClass(ILogger, Logger) |
|---|
| 65 | verifyObject(ILogger, logger) |
|---|
| 66 | return |
|---|
| 67 | |
|---|
| 68 | def test_logger_prop_no_site(self): |
|---|
| 69 | # If not in a site, we will get a logger without handlers |
|---|
| 70 | logger = Logger().logger |
|---|
| 71 | self.assertTrue(isinstance(logger, logging.Logger)) |
|---|
| 72 | self.assertEqual(len(logger.handlers), 0) |
|---|
| 73 | return |
|---|
| 74 | |
|---|
| 75 | def test_site_no_site_name(self): |
|---|
| 76 | # If a site has not name we will get a logger anyway |
|---|
| 77 | setSite(self.app) |
|---|
| 78 | del self.app.__name__ |
|---|
| 79 | logger = Logger().logger |
|---|
| 80 | self.assertTrue(logger is not None) |
|---|
| 81 | return |
|---|
| 82 | |
|---|
| 83 | def test_get_logdir(self): |
|---|
| 84 | # We can get a logdir |
|---|
| 85 | setSite(self.app) |
|---|
| 86 | logger = Logger() |
|---|
| 87 | logdir = logger.logger_get_logdir() |
|---|
| 88 | expected_logdir = os.path.join( |
|---|
| 89 | self.app['datacenter'].storage, 'logs') |
|---|
| 90 | self.assertEqual(logdir, expected_logdir) |
|---|
| 91 | return |
|---|
| 92 | |
|---|
| 93 | def test_get_logdir_no_site(self): |
|---|
| 94 | # We cannot get a logdir without a site |
|---|
| 95 | logger = Logger() |
|---|
| 96 | logdir = logger.logger_get_logdir() |
|---|
| 97 | self.assertTrue(logdir is None) |
|---|
| 98 | return |
|---|
| 99 | |
|---|
| 100 | def test_get_logdir_no_datacenter(self): |
|---|
| 101 | # Having a site, is not enough. We also need a datacenter in it. |
|---|
| 102 | setSite(self.app) |
|---|
| 103 | del self.app['datacenter'] |
|---|
| 104 | logger = Logger() |
|---|
| 105 | logdir = logger.logger_get_logdir() |
|---|
| 106 | self.assertTrue(logdir is None) |
|---|
| 107 | return |
|---|
| 108 | |
|---|
| 109 | def test_get_logdir_create_dir(self): |
|---|
| 110 | # If the logdirectory does not exist, we will create it |
|---|
| 111 | setSite(self.app) |
|---|
| 112 | logger = Logger() |
|---|
| 113 | expected_logdir = os.path.join( |
|---|
| 114 | self.app['datacenter'].storage, 'logs') |
|---|
| 115 | if os.path.exists(expected_logdir): |
|---|
| 116 | shutil.rmtree(expected_logdir) |
|---|
| 117 | logdir = logger.logger_get_logdir() |
|---|
| 118 | exists_after = os.path.exists(expected_logdir) |
|---|
| 119 | self.assertEqual(logdir, expected_logdir) |
|---|
| 120 | self.assertTrue(exists_after is True) |
|---|
| 121 | return |
|---|
| 122 | |
|---|
| 123 | def test_get_logfile(self): |
|---|
| 124 | # We can get a logfile |
|---|
| 125 | setSite(self.app) |
|---|
| 126 | logger = Logger() |
|---|
| 127 | expected_filepath = os.path.join( |
|---|
| 128 | self.app['datacenter'].storage, 'logs', 'main.log') |
|---|
| 129 | path = logger.logger_get_logfile_path() |
|---|
| 130 | self.assertEqual(expected_filepath, path) |
|---|
| 131 | return |
|---|
| 132 | |
|---|
| 133 | def test_get_logfile_no_dir(self): |
|---|
| 134 | # We cannot get a logfilepath if there is no dir for it |
|---|
| 135 | setSite(self.app) |
|---|
| 136 | logger = Logger() |
|---|
| 137 | del self.app['datacenter'] |
|---|
| 138 | path = logger.logger_get_logfile_path() |
|---|
| 139 | self.assertTrue(path is None) |
|---|
| 140 | return |
|---|
| 141 | |
|---|
| 142 | def test_setup(self): |
|---|
| 143 | # We can setup a logger. |
|---|
| 144 | mylogger = logging.getLogger('test.sample') |
|---|
| 145 | setSite(self.app) |
|---|
| 146 | logger = Logger() |
|---|
| 147 | result = logger.logger_setup(mylogger) |
|---|
| 148 | self.assertEqual(len(result.handlers), 1) |
|---|
| 149 | handler = result.handlers[0] |
|---|
| 150 | self.assertEqual(handler.maxBytes, MAX_BYTES) |
|---|
| 151 | self.assertEqual(handler.backupCount, BACKUP_COUNT) |
|---|
| 152 | self.assertTrue(result.propagate is False) |
|---|
| 153 | return |
|---|
| 154 | |
|---|
| 155 | def test_setup_no_site(self): |
|---|
| 156 | # Without a site we get no logger from setup |
|---|
| 157 | mylogger = logging.getLogger('test.sample') |
|---|
| 158 | logger = Logger() |
|---|
| 159 | result = logger.logger_setup(mylogger) |
|---|
| 160 | self.assertTrue(result is None) |
|---|
| 161 | return |
|---|
| 162 | |
|---|
| 163 | def test_logfile_change(self): |
|---|
| 164 | # When the logfile location changes, logger_logfile_changed can react |
|---|
| 165 | setSite(self.app) |
|---|
| 166 | logger = Logger() |
|---|
| 167 | logger.logger.warn('Warning 1') # Log something to old logfile |
|---|
| 168 | filename1 = logger.logger.handlers[0].baseFilename |
|---|
| 169 | content1 = open(filename1, 'r').read() |
|---|
| 170 | # Now move the logfile |
|---|
| 171 | self.dc_root2 = tempfile.mkdtemp() |
|---|
| 172 | self.app['datacenter'].setStoragePath(self.dc_root2) |
|---|
| 173 | logger.logger_logfile_changed() |
|---|
| 174 | logger.logger.warn('Warning 2') # Log something to new logfile |
|---|
| 175 | filename2 = logger.logger.handlers[0].baseFilename |
|---|
| 176 | content2 = open(filename2, 'r').read() |
|---|
| 177 | self.assertTrue('Warning 1' in content1) |
|---|
| 178 | self.assertTrue('Warning 2' in content2) |
|---|
| 179 | self.assertTrue('Warning 1' not in content2) |
|---|
| 180 | self.assertTrue('Warning 2' not in content1) |
|---|
| 181 | self.assertTrue(filename1 != filename2) |
|---|
| 182 | return |
|---|
| 183 | |
|---|
| 184 | |
|---|
| 185 | class LoggersFunctionalTests(FunctionalTestCase): |
|---|
| 186 | # Check loggers with real components using them |
|---|
| 187 | |
|---|
| 188 | layer = FunctionalLayer |
|---|
| 189 | |
|---|
| 190 | def setUp(self): |
|---|
| 191 | super(LoggersFunctionalTests, self).setUp() |
|---|
| 192 | |
|---|
| 193 | # Setup a sample site for each test |
|---|
| 194 | app = University() |
|---|
| 195 | self.dc_root = tempfile.mkdtemp() |
|---|
| 196 | app['datacenter'].setStoragePath(self.dc_root) |
|---|
| 197 | |
|---|
| 198 | # Prepopulate the ZODB... |
|---|
| 199 | self.getRootFolder()['app'] = app |
|---|
| 200 | self.app = self.getRootFolder()['app'] |
|---|
| 201 | self.workdir = tempfile.mkdtemp() |
|---|
| 202 | |
|---|
| 203 | self.app['mycomponent'] = LoggingComponent() |
|---|
| 204 | self.component = self.app['mycomponent'] |
|---|
| 205 | setSite(self.app) |
|---|
| 206 | self.old_loggers = get_all_loggers() |
|---|
| 207 | return |
|---|
| 208 | |
|---|
| 209 | def tearDown(self): |
|---|
| 210 | super(LoggersFunctionalTests, self).tearDown() |
|---|
| 211 | remove_new_loggers(self.old_loggers) |
|---|
| 212 | shutil.rmtree(self.workdir) |
|---|
| 213 | shutil.rmtree(self.dc_root) |
|---|
| 214 | clearSite() |
|---|
| 215 | return |
|---|
| 216 | |
|---|
| 217 | def test_component_can_get_logger(self): |
|---|
| 218 | # Components can get a logger |
|---|
| 219 | logger = self.component.logger |
|---|
| 220 | self.assertTrue(logger is not None) |
|---|
| 221 | self.assertEqual(len(logger.handlers), 1) |
|---|
| 222 | self.assertEqual(logger.name, 'sample.app') |
|---|
| 223 | return |
|---|
| 224 | |
|---|
| 225 | def test_component_handler_setup(self): |
|---|
| 226 | # handlers of components are setup |
|---|
| 227 | handler = self.component.logger.handlers[0] |
|---|
| 228 | self.assertTrue(isinstance( |
|---|
| 229 | handler, logging.handlers.RotatingFileHandler)) |
|---|
| 230 | self.assertEqual(handler.maxBytes, MAX_BYTES) |
|---|
| 231 | self.assertEqual(handler.backupCount, BACKUP_COUNT) |
|---|
| 232 | self.assertTrue(handler.baseFilename.endswith('logs/sample.log')) |
|---|
| 233 | return |
|---|
| 234 | |
|---|
| 235 | def test_component_can_log(self): |
|---|
| 236 | # a method of some 'loggerized' instance can log like this. |
|---|
| 237 | self.component.logger.setLevel(logging.INFO) |
|---|
| 238 | self.component.do_something() |
|---|
| 239 | handler = logging.getLogger('sample.app').handlers[0] |
|---|
| 240 | logfile = handler.baseFilename |
|---|
| 241 | content = open(logfile, 'rb').read() |
|---|
| 242 | self.assertTrue(content.endswith(' - INFO - msg from do_something\n')) |
|---|
| 243 | return |
|---|
| 244 | |
|---|
| 245 | class LoggerCollectorTests(FunctionalTestCase): |
|---|
| 246 | |
|---|
| 247 | layer = FunctionalLayer |
|---|
| 248 | |
|---|
| 249 | def setUp(self): |
|---|
| 250 | super(LoggerCollectorTests, self).setUp() |
|---|
| 251 | self.old_loggers = get_all_loggers() |
|---|
| 252 | # Setup a sample site for each test |
|---|
| 253 | app = University() |
|---|
| 254 | self.dc_root = tempfile.mkdtemp() |
|---|
| 255 | app['datacenter'].setStoragePath(self.dc_root) |
|---|
| 256 | |
|---|
| 257 | # Prepopulate the ZODB... |
|---|
| 258 | self.getRootFolder()['app'] = app |
|---|
| 259 | self.app = self.getRootFolder()['app'] |
|---|
| 260 | self.workdir = tempfile.mkdtemp() |
|---|
| 261 | |
|---|
| 262 | self.app['mycomponent'] = LoggingComponent() |
|---|
| 263 | self.component = self.app['mycomponent'] |
|---|
| 264 | setSite(self.app) |
|---|
| 265 | |
|---|
| 266 | self.component = LoggingComponent() |
|---|
| 267 | |
|---|
| 268 | |
|---|
| 269 | return |
|---|
| 270 | |
|---|
| 271 | def tearDown(self): |
|---|
| 272 | super(LoggerCollectorTests, self).tearDown() |
|---|
| 273 | remove_new_loggers(self.old_loggers) |
|---|
| 274 | shutil.rmtree(self.workdir) |
|---|
| 275 | shutil.rmtree(self.dc_root) |
|---|
| 276 | clearSite() |
|---|
| 277 | return |
|---|
| 278 | |
|---|
| 279 | def test_ifaces(self): |
|---|
| 280 | collector = LoggerCollector() |
|---|
| 281 | verifyClass(ILoggerCollector, LoggerCollector) |
|---|
| 282 | verifyObject(ILoggerCollector, collector) |
|---|
| 283 | return |
|---|
| 284 | |
|---|
| 285 | def test_get_utility(self): |
|---|
| 286 | # We can get a logger collector via utility lookup |
|---|
| 287 | util1 = queryUtility(ILoggerCollector, default=None) |
|---|
| 288 | util2 = queryUtility(ILoggerCollector, default=None) |
|---|
| 289 | self.assertTrue(util1 is util2) |
|---|
| 290 | self.assertTrue(isinstance(util1, LoggerCollector)) |
|---|
| 291 | return |
|---|
| 292 | |
|---|
| 293 | def test_get_loggers(self): |
|---|
| 294 | # We can get loggers from a logger collector |
|---|
| 295 | collector = LoggerCollector() |
|---|
| 296 | result0 = collector.getLoggers(None) |
|---|
| 297 | result1 = collector.getLoggers('not-a-site') |
|---|
| 298 | result2 = collector.getLoggers(self.app) |
|---|
| 299 | collector.registerLogger(self.app, self.component) |
|---|
| 300 | result3 = collector.getLoggers(self.app) |
|---|
| 301 | self.assertEqual(result0, []) |
|---|
| 302 | self.assertEqual(result1, []) |
|---|
| 303 | self.assertEqual(result2, []) |
|---|
| 304 | self.assertEqual(result3, [self.component]) |
|---|
| 305 | self.assertTrue(result3[0] is self.component) |
|---|
| 306 | return |
|---|
| 307 | |
|---|
| 308 | def test_register_logger(self): |
|---|
| 309 | # We can register loggers by name |
|---|
| 310 | collector = LoggerCollector() |
|---|
| 311 | collector.registerLogger(None, self.component) # Should have no effect |
|---|
| 312 | collector.registerLogger(object(), self.component) # Same here |
|---|
| 313 | collector.registerLogger(self.app, self.component) |
|---|
| 314 | self.assertEqual(['app'], collector.keys()) |
|---|
| 315 | return |
|---|
| 316 | |
|---|
| 317 | def test_register_logger_double(self): |
|---|
| 318 | # Registering the same component twice gives one entry, not two |
|---|
| 319 | collector = LoggerCollector() |
|---|
| 320 | collector.registerLogger(self.app, self.component) |
|---|
| 321 | collector.registerLogger(self.app, self.component) |
|---|
| 322 | self.assertEqual(len(collector['app']), 1) |
|---|
| 323 | return |
|---|
| 324 | |
|---|
| 325 | def test_unregister_logger(self): |
|---|
| 326 | # We can also unregister loggers |
|---|
| 327 | collector = LoggerCollector() |
|---|
| 328 | collector.registerLogger(self.app, self.component) |
|---|
| 329 | collector.unregisterLogger(self.app, self.component) |
|---|
| 330 | result = collector.getLoggers(self.app) |
|---|
| 331 | self.assertEqual(result, []) |
|---|
| 332 | return |
|---|
| 333 | |
|---|
| 334 | def test_unregister_logger_invalid(self): |
|---|
| 335 | # We can cope with unregistration of non-existing entries. |
|---|
| 336 | collector = LoggerCollector() |
|---|
| 337 | collector.registerLogger(self.app, self.component) |
|---|
| 338 | collector.unregisterLogger(None, self.component) |
|---|
| 339 | collector.unregisterLogger(self.app, 'nonsense') |
|---|
| 340 | self.assertEqual(len(collector), 1) |
|---|
| 341 | return |
|---|
| 342 | |
|---|
| 343 | class LogfileChangeTests(FunctionalTestCase): |
|---|
| 344 | |
|---|
| 345 | layer = FunctionalLayer |
|---|
| 346 | |
|---|
| 347 | def setUp(self): |
|---|
| 348 | super(LogfileChangeTests, self).setUp() |
|---|
| 349 | remove_logger('waeup.sirp.app') # In case it lingers around |
|---|
| 350 | self.old_loggers = get_all_loggers() |
|---|
| 351 | # Setup a sample site for each test |
|---|
| 352 | app = University() |
|---|
| 353 | self.dc_root = tempfile.mkdtemp() |
|---|
| 354 | self.dc_root_new = None |
|---|
| 355 | app['datacenter'].setStoragePath(self.dc_root) |
|---|
| 356 | |
|---|
| 357 | # Prepopulate the ZODB... |
|---|
| 358 | self.getRootFolder()['app'] = app |
|---|
| 359 | self.app = self.getRootFolder()['app'] |
|---|
| 360 | self.workdir = tempfile.mkdtemp() |
|---|
| 361 | |
|---|
| 362 | self.app['mycomponent'] = LoggingComponent() |
|---|
| 363 | self.component = self.app['mycomponent'] |
|---|
| 364 | setSite(self.app) |
|---|
| 365 | |
|---|
| 366 | self.component = LoggingComponent() |
|---|
| 367 | return |
|---|
| 368 | |
|---|
| 369 | def tearDown(self): |
|---|
| 370 | super(LogfileChangeTests, self).tearDown() |
|---|
| 371 | remove_new_loggers(self.old_loggers) |
|---|
| 372 | shutil.rmtree(self.workdir) |
|---|
| 373 | shutil.rmtree(self.dc_root) |
|---|
| 374 | if self.dc_root_new is not None: |
|---|
| 375 | shutil.rmtree(self.dc_root_new) |
|---|
| 376 | clearSite() |
|---|
| 377 | return |
|---|
| 378 | |
|---|
| 379 | def test_storage_move(self): |
|---|
| 380 | # When a datacenter storage (its path) changes, we have to |
|---|
| 381 | # move the logfiles as well. |
|---|
| 382 | #return |
|---|
| 383 | filename1 = self.component.logger.handlers[0].baseFilename |
|---|
| 384 | self.dc_root_new = tempfile.mkdtemp() |
|---|
| 385 | self.app['datacenter'].setStoragePath(self.dc_root_new) |
|---|
| 386 | filename2 = self.component.logger.handlers[0].baseFilename |
|---|
| 387 | self.assertTrue(filename1 != filename2) |
|---|
| 388 | self.assertTrue(filename2.startswith(self.dc_root_new)) |
|---|
| 389 | return |
|---|
