def test_error_handling(): """ Check that exceptions in json_GET result in a 500 response code. """ def err_observer(event): # type: (dict) -> None assert event["isError"] failure = event["failure"] assert isinstance(failure, Failure) exception = failure.value assert isinstance(exception, TypeError) assert event["context"] == { 'data': {}, 'headers': {}, 'method': b'GET', 'query_string': b'http:dummy/', 'url': b'http://dummy/' } err_observer.called = True log.addObserver(err_observer) for resource in [SyncBrokenPage(), AsyncBrokenPage()]: request = MyDummyRequest([b"/"]) err_observer.called = False yield _render(resource, request) assert request.responseCode == 500 assert err_observer.called is True, "Error handler not called for {}".format( type(resource).__name__) log.removeObserver(err_observer)
def _test_level(self, level, messages_number): observer = LevelFileLogObserver(self.log_file, level) log.addObserver(observer) self.LOG.debug('test debug') self.LOG.info('test info') self.LOG.warning('test warning') self.LOG.error('test error') self.LOG.critical('test critical') log.removeObserver(observer) with open(self.log_path) as f: lines = [line.strip() for line in f.readlines()] self.assertEqual(len(lines), messages_number) for line in lines: m = re.match(self.rx, line) self.assertIsNotNone(m) time, level_name, system, entry_text = m.groups() time = datetime.strptime(time, "%Y-%m-%d %H:%M:%S") entry_level = logging.getLevelName(level_name) self.assertGreaterEqual(entry_level, level) self.assertEqual(system, __name__) text = "test {0}".format(level_name.lower()) self.assertEqual(entry_text, text)
def main(self): """Parse arguments and run the script's main function via ``react``.""" observer = None try: if not self.log_directory.exists(): self.log_directory.makedirs() log_path = self.log_directory.child( b"%s-%d.log" % (os.path.basename(self.sys_module.argv[0]), os.getpid())) log_file = log_path.open("a") observer = FileLogObserver(log_file).emit addObserver(observer) msg("Arguments: %s" % (self.sys_module.argv,)) except (OSError, IOError): pass options = self._parse_options(self.sys_module.argv[1:]) # XXX: We shouldn't be using this private _reactor API. See # https://twistedmatrix.com/trac/ticket/6200 and # https://twistedmatrix.com/trac/ticket/7527 self._react(self.script.main, (options,), _reactor=self._reactor) # Not strictly necessary, but nice cleanup for tests: if observer is not None: removeObserver(observer) log_file.close()
def test_send_catch_log(self): test_signal = object() handlers_called = set() def log_received(event): handlers_called.add(log_received) assert "error_handler" in event['message'][0] assert event['logLevel'] == log.ERROR txlog.addObserver(log_received) dispatcher.connect(self.error_handler, signal=test_signal) dispatcher.connect(self.ok_handler, signal=test_signal) result = yield defer.maybeDeferred(self._get_result, test_signal, arg='test', handlers_called=handlers_called) assert self.error_handler in handlers_called assert self.ok_handler in handlers_called assert log_received in handlers_called self.assertEqual(result[0][0], self.error_handler) self.assert_(isinstance(result[0][1], Failure)) self.assertEqual(result[1], (self.ok_handler, "OK")) txlog.removeObserver(log_received) self.flushLoggedErrors() dispatcher.disconnect(self.error_handler, signal=test_signal) dispatcher.disconnect(self.ok_handler, signal=test_signal)
def test_default_item_completed(self): item = dict(name='name') assert self.pipe.item_completed([], item, self.info) is item # Check that failures are logged by default fail = Failure(Exception()) results = [(True, 1), (False, fail)] events = [] txlog.addObserver(events.append) new_item = self.pipe.item_completed(results, item, self.info) txlog.removeObserver(events.append) self.flushLoggedErrors() assert new_item is item assert len(events) == 1 assert events[0]['logLevel'] == log.ERROR assert events[0]['failure'] is fail # disable failure logging and check again self.pipe.LOG_FAILED_RESULTS = False events = [] txlog.addObserver(events.append) new_item = self.pipe.item_completed(results, item, self.info) txlog.removeObserver(events.append) self.flushLoggedErrors() assert new_item is item assert len(events) == 0
def test_send_catch_log(self): test_signal = object() handlers_called = set() def log_received(event): handlers_called.add(log_received) assert "error_handler" in event['message'][0] assert event['logLevel'] == log.ERROR txlog.addObserver(log_received) dispatcher.connect(self.error_handler, signal=test_signal) dispatcher.connect(self.ok_handler, signal=test_signal) result = yield defer.maybeDeferred(self._get_result, test_signal, arg='test', \ handlers_called=handlers_called) assert self.error_handler in handlers_called assert self.ok_handler in handlers_called assert log_received in handlers_called self.assertEqual(result[0][0], self.error_handler) self.assert_(isinstance(result[0][1], Failure)) self.assertEqual(result[1], (self.ok_handler, "OK")) txlog.removeObserver(log_received) self.flushLoggedErrors() dispatcher.disconnect(self.error_handler, signal=test_signal) dispatcher.disconnect(self.ok_handler, signal=test_signal)
def _remove(self): self._added -= 1 if self._added == 0: log.removeObserver(self.gotEvent) log._flushErrors = self._oldFE log._ignore = self._oldIE log._clearIgnores = self._oldCI
def _tearDownLogFile(self): if self._logFileObserver is not None: log.removeObserver(self._logFileObserver.emit) self._logFileObserver = None if self._logFileObject is not None: self._logFileObject.close() self._logFileObject = None
def main(self): """Parse arguments and run the script's main function via ``react``.""" observer = None try: if not self.log_directory.exists(): self.log_directory.makedirs() log_path = self.log_directory.child( b"%s-%d.log" % (os.path.basename(self.sys_module.argv[0]), os.getpid())) log_file = log_path.open("a") observer = FileLogObserver(log_file).emit addObserver(observer) msg("Arguments: %s" % (self.sys_module.argv, )) except (OSError, IOError): pass options = self._parse_options(self.sys_module.argv[1:]) # XXX: We shouldn't be using this private _reactor API. See # https://twistedmatrix.com/trac/ticket/6200 and # https://twistedmatrix.com/trac/ticket/7527 self._react(self.script.main, (options, ), _reactor=self._reactor) # Not strictly necessary, but nice cleanup for tests: if observer is not None: removeObserver(observer) log_file.close()
def reloadConfig(): global debugFile if debugFile: debugFile.close() try: config._debugLevel = int(config.debugLevel.strip()) except ValueError: config._debugLevel = 0 config.debugLevel = "0" if config._debugLevel > 0: if len(config.debugFile) > 0: try: debugFile = open(config.debugFile, "a") log.msg("Reopened log file.") except IOError: log.discardLogs() # Give up debugFile = sys.__stdout__ return else: debugFile = sys.__stdout__ try: log.removeObserver(observer) except ValueError: pass log.startLoggingWithObserver(observer) else: log.discardLogs()
def stop(self): """ Remove all log observers previously set up by L{AppLogger.start}. """ log.msg("Server Shut Down.") if self._observer is not None: log.removeObserver(self._observer) self._observer = None
def stop(self): """ Print twistd stop log message. """ log.msg("Server Shut Down.") if self._observer is not None: log.removeObserver(self._observer) self._observer = None
def _exit(self, reactor): self.triggered = True log.removeObserver(self._failure_observer) try: reactor.stop() except error.ReactorNotRunning: pass
def tearDown(self): """ Ensure the log observer added by L{setUp} is removed. """ try: log.removeObserver(self.receiver._emit) except ValueError: # The test removed it already. pass
def signal_handler(self, signo, frame): try: log.msg('Rotating log %s' % self.log_filename) log.removeObserver(self.log_observer.emit) self.log_file.close() self.setup_log(self.log_filename) except: msg = "Error in signal_handler:\n%s" % traceback.format_exc() print msg mail.error(msg)
def test_error_logged_if_deferred_not_supported(self): test_handler = lambda: defer.Deferred() log_events = [] txlog.addObserver(log_events.append) dispatcher.connect(test_handler, test_signal) self.manager.send(test_signal) self.failUnless(log_events) self.failUnless('Cannot return deferreds from signal handler' in str(log_events)) txlog.removeObserver(log_events.append) dispatcher.disconnect(test_handler, test_signal)
def test_write_to_logfile(self): with TemporaryDirectory() as tmpdir: o = log.CarbonLogObserver() o.log_to_dir(tmpdir) addObserver(o) log.creates('😀😀😀😀 test !!!!') removeObserver(o) with open(path.join(tmpdir, 'creates.log')) as logfile: read_line = logfile.readline() self.assertRegexpMatches(read_line, '.*😀😀😀😀 test !!!!')
def test_error_logged_if_deferred_not_supported(self): test_handler = lambda: defer.Deferred() log_events = [] txlog.addObserver(log_events.append) dispatcher.connect(test_handler, test_signal) self.manager.send(test_signal) self.failUnless(log_events) self.failUnless( 'Cannot return deferreds from signal handler' in str(log_events)) txlog.removeObserver(log_events.append) dispatcher.disconnect(test_handler, test_signal)
def remove_log_observer(self, observer=False): """ Remove a twisted.log observer @type observer: method @param observer: The name of the method specified in add_log_observer. If False, the last known log observer added will be removed """ if observer: log.removeObserver(observer) else: log.removeObserver(self.log_observer)
def test_error_logged_if_deferred_not_supported(self): test_signal = object() test_handler = lambda: defer.Deferred() log_events = [] txlog.addObserver(log_events.append) dispatcher.connect(test_handler, test_signal) send_catch_log(test_signal) self.assertTrue(log_events) self.assertIn("Cannot return deferreds from signal handler", str(log_events)) txlog.removeObserver(log_events.append) self.flushLoggedErrors() dispatcher.disconnect(test_handler, test_signal)
def stop_observe(self,task): name = id(task.protocol) try: pd, observer = self._log_observers[name] log.removeObserver(observer) pd.callback(True) del self._log_observers[name] except KeyError: pass except: traceback.print_exc()
def stopService(self): log.msg("Stopping %s" % self) service.MultiService.stopService(self) if self.periodic_task: self.periodic_task.stop() self.periodic_task = None if self.log_task: self.log_task.stop() self.log_task = None log.removeObserver(self.emit)
def test_error_logged_if_deferred_not_supported(self): test_signal = object() test_handler = lambda: defer.Deferred() log_events = [] txlog.addObserver(log_events.append) dispatcher.connect(test_handler, test_signal) send_catch_log(test_signal) self.failUnless(log_events) self.failUnless( "Cannot return deferreds from signal handler" in str(log_events)) txlog.removeObserver(log_events.append) self.flushLoggedErrors() dispatcher.disconnect(test_handler, test_signal)
def test_connectionLost(self): self.connectionLost = False def observer(event): self.assertTrue(event["isError"]) self.assertTrue(event["message"]) self.connectionLost = True try: log.addObserver(observer) self.message.connectionLost() self.assertTrue(self.connectionLost) self.assertIdentical(self.message.lines, None) finally: log.removeObserver(observer)
def disable(self): if not self.enabled: return if self.periodic_task: self.periodic_task.stop() self.periodic_task = None if self.log_task: self.log_task.stop() self.log_task = None log.removeObserver(self.emit) self.enabled = False
def emit(self, level, message, **kwargs): def observer(eventDict): self.eventDict = eventDict twistedLogging.addObserver(observer) super(TestLogger, self).emit(level, message, **kwargs) twistedLogging.removeObserver(observer) self.emitted = { "level" : level, "message": message, "kwargs" : kwargs, }
def init(outfile="stdout", level=logging.INFO): global original_twisted_msg root_logger = logging.getLogger() nox_logger = logging.getLogger("nox") nox_logger.setLevel(level) nice_logger = logging.getLogger("nice") nice_logger.setLevel(level) file_logging = False if outfile != "stdout" and outfile != "stderr": file_handler = logging.FileHandler(outfile) file_handler.setLevel(logging.DEBUG) file_formatter = logging.Formatter('%(name)s: %(message)s') file_handler.setFormatter(file_formatter) root_logger.addHandler(file_handler) file_logging = True if platform.system() != 'Windows': # all non-Windows platforms are supporting ANSI escapes so we use them con_handler = ColoredConsoleHandler() con_formatter = logging.Formatter( '\x1b[1;33m%(name)s:\x1b[0m %(message)s') else: con_handler = StreamHandler() con_formatter = logging.Formatter('%(name)s: %(message)s') con_handler.setFormatter(con_formatter) if file_logging: con_handler.setLevel(logging.ERROR) else: con_handler.setLevel(level) nox_logger.addHandler(con_handler) nice_logger.addHandler(con_handler) stats_logger = logging.getLogger("stats") stats_logger.setLevel(logging.DEBUG) stats_handler = ColoredConsoleHandler() stats_handler.setFormatter(con_formatter) stats_logger.addHandler(stats_handler) if twisted: original_twisted_msg = log.msg log.msg = custom_twisted_msg observer = log.PythonLoggingObserver(loggerName="nox.app") observer.start() log.removeObserver(log.theLogPublisher.observers[0]) root_logger.info("---> Log start <---")
def close(self, flush_writer=True): def set_disconnected(): self._writer = None self._set_state(State.disconnected) try: twisted_log.removeObserver(self.on_twisted_log) except ValueError: # it should be safe to call close() multiple times, # in this case we are not registered as the observer anymore pass d = self._close_writer(flush_writer) d.addCallback(defer.drop_param, set_disconnected) return d
def test_badUsernameOrPassword_XForwarded(self): class FakeLogObserver(object): messages = [] def emit(self, eventDict): if "log_legacy" in eventDict: self.messages.append(eventDict["log_legacy"]) blo = FakeLogObserver() addObserver(blo.emit) self.addCleanup(lambda: removeObserver(blo.emit)) request = SimpleRequest(self.site, "GET", "/protected") request.headers.setHeader( "authorization", ("basic", "gooduser:badpass".encode("base64"))) request.headers.setRawHeaders("x-forwarded-for", ("10.0.1.1", )) d = self.assertFailure(self.checkSecurity(request), HTTPError) def expectWwwAuth(err): self.failUnless(err.response.headers.hasHeader("WWW-Authenticate"), "No WWW-Authenticate header present.") self.assertTrue("fwd=10.0.1.1" in str(blo.messages[0])) d.addCallback(self.assertErrorResponse, responsecode.UNAUTHORIZED, expectWwwAuth) return d
def init(outfile="stdout", level=logging.INFO): global original_twisted_msg root_logger = logging.getLogger() nox_logger = logging.getLogger("nox") nox_logger.setLevel(level) nice_logger = logging.getLogger("nice") nice_logger.setLevel(level) file_logging = False if outfile != "stdout" and outfile != "stderr": file_handler = logging.FileHandler(outfile) file_handler.setLevel(logging.DEBUG) file_formatter = logging.Formatter('%(name)s: %(message)s') file_handler.setFormatter(file_formatter) root_logger.addHandler(file_handler) file_logging = True if platform.system() !='Windows': # all non-Windows platforms are supporting ANSI escapes so we use them con_handler = ColoredConsoleHandler() con_formatter = logging.Formatter('\x1b[1;33m%(name)s:\x1b[0m %(message)s') else: con_handler = StreamHandler() con_formatter = logging.Formatter('%(name)s: %(message)s') con_handler.setFormatter(con_formatter) if file_logging: con_handler.setLevel(logging.ERROR) else: con_handler.setLevel(level) nox_logger.addHandler(con_handler) nice_logger.addHandler(con_handler) stats_logger = logging.getLogger("stats") stats_logger.setLevel(logging.DEBUG) stats_handler = ColoredConsoleHandler() stats_handler.setFormatter(con_formatter) stats_logger.addHandler(stats_handler) if twisted: original_twisted_msg = log.msg log.msg = custom_twisted_msg observer = log.PythonLoggingObserver(loggerName="nox.app") observer.start() log.removeObserver(log.theLogPublisher.observers[0]) root_logger.info("---> Log start <---")
def test_publish_callback_exception(self): """ Ensure we handle an exception from the user code. """ handler = ApplicationSession() MockTransport(handler) error_instance = RuntimeError("we have a problem") got_err_d = Deferred() def observer(kw): if kw['isError'] and 'failure' in kw: fail = kw['failure'] fail.trap(RuntimeError) if error_instance == fail.value: got_err_d.callback(True) log.addObserver(observer) def boom(): raise error_instance try: sub = yield handler.subscribe(boom, u'com.myapp.topic1') # MockTransport gives us the ack reply and then we do our # own event message publish = yield handler.publish( u'com.myapp.topic1', options=types.PublishOptions(acknowledge=True, exclude_me=False), ) msg = message.Event(sub.id, publish.id) handler.onMessage(msg) # we know it worked if our observer worked and did # .callback on our Deferred above. self.assertTrue(got_err_d.called) # ...otherwise trial will fail the test anyway self.flushLoggedErrors() finally: log.removeObserver(observer)
def _test_level(self, level, messages_number): observer = CollectingObserver(level) log.addObserver(observer) self.LOG.debug('test debug') self.LOG.info('test info') self.LOG.warning('test warning') self.LOG.error('test error') self.LOG.critical('test critical') log.removeObserver(observer) self.assertEqual(len(observer.log), messages_number) for entry in observer.log: self.assertGreaterEqual(entry['level'], level) text = "test {0}".format( logging.getLevelName(entry['level']).lower()) self.assertEqual(entry['text'], text) self.assertEqual(entry['system'], __name__)
def testTerminateRace(self): """Test that buffered messages are flushed when the connection is terminated.""" yield self.connect(self.get_body_node(connect=True)) def log_observer(event): self.failIf(event['isError'], event) log.addObserver(log_observer) # Simultaneously cause a stream error (server->client closed) and send a terminate # from the client to the server. Both sides are closing the connection at once. # Make sure the connection closes cleanly without logging any errors ("Unhandled # Error"), and the client receives a terminate in response. try: self.server_protocol.triggerStreamError() yield self.proxy.send(self.get_body_node(type='terminate')) except httpb_client.HTTPBNetworkTerminated as e: self.assertEqual(e.body_tag.getAttribute('condition', None), 'remote-stream-error') finally: log.removeObserver(log_observer)
def emit(self, level, format=None, **kwargs): if False: print "*"*60 print "level =", level print "format =", format for key, value in kwargs.items(): print key, "=", value print "*"*60 def observer(event): self.event = event twistedLogging.addObserver(observer) try: Logger.emit(self, level, format, **kwargs) finally: twistedLogging.removeObserver(observer) self.emitted = { "level": level, "format": format, "kwargs": kwargs, }
def _test(self, args, expectFailure=True): request = FakeRequest(args) try: self.calledWithError = False def observer(event): self.assertTrue(event["isError"]) self.assertTrue(event["message"]) self.calledWithError = True log.addObserver(observer) body = self.resource.render_POST(request) self.assertEqual(body, "") if expectFailure: self.assertTrue(self.calledWithError) self.assertIdentical(self.payload, None) else: self.assertFalse(self.calledWithError) self.assertNotIdentical(self.payload, None) finally: log.removeObserver(observer)
def emit(self, level, format=None, **kwargs): if False: print "*" * 60 print "level =", level print "format =", format for key, value in kwargs.items(): print key, "=", value print "*" * 60 def observer(event): self.event = event twistedLogging.addObserver(observer) try: Logger.emit(self, level, format, **kwargs) finally: twistedLogging.removeObserver(observer) self.emitted = { "level": level, "format": format, "kwargs": kwargs, }
def test_badUsernameOrPassword_XForwarded(self): class FakeLogObserver(object): messages = [] def emit(self, eventDict): if "log_legacy" in eventDict: self.messages.append(eventDict["log_legacy"]) blo = FakeLogObserver() addObserver(blo.emit) self.addCleanup(lambda: removeObserver(blo.emit)) request = SimpleRequest(self.site, "GET", "/protected") request.headers.setHeader( "authorization", ("basic", "gooduser:badpass".encode("base64")) ) request.headers.setRawHeaders("x-forwarded-for", ("10.0.1.1",)) d = self.assertFailure(self.checkSecurity(request), HTTPError) def expectWwwAuth(err): self.failUnless(err.response.headers.hasHeader("WWW-Authenticate"), "No WWW-Authenticate header present.") self.assertTrue("fwd=10.0.1.1" in str(blo.messages[0])) d.addCallback(self.assertErrorResponse, responsecode.UNAUTHORIZED, expectWwwAuth) return d
def tearDown(self): """ Remove all installed observers. """ for observer in self.observers: log.removeObserver(observer)
def tearDown(self): log.removeObserver(self.messages.append) return gatherResults([ maybeDeferred(p.stopListening) for p in self.ports])
def stopReactor(ignored): log.removeObserver(logConnectionLostMsg) reactor.stop()
def stop(self): removeObserver(self.emit)
def remove(self): fileobj, observer = self.observers.pop() log.removeObserver(observer.emit) fileobj.close()
def tearDown(self): log.removeObserver(self.resultLogs.append)
def stop(self): """ Stop observing log events. """ removeObserver(self.emit)
def tearDown(self): log.removeObserver(self.c.append)
def _remove(self): self._added -= 1 if self._added == 0: log.removeObserver(self.gotEvent)
def stop(self): """Stop observing log events.""" log.removeObserver(self.emit)
def tearDown(self): """ Clean up the resource file and the log observer. """ self.file.close() log.removeObserver(self.catcher.append)