def _assertTracebackLogged(self, logger): """ Assert that a traceback for an L{ArbitraryException} was logged as a child of a L{REQUEST} action. """ # Get rid of it so it doesn't fail the test later. tracebacks = logger.flushTracebacks(exceptionType) if len(tracebacks) > 1: self.fail("Multiple tracebacks: %s" % tracebacks) traceback = tracebacks[0] # Verify it contains what it's supposed to contain. assertContainsFields(self, traceback, { u"exception": exceptionType, u"message_type": u"eliot:traceback", # Just assume the traceback it contains is correct. The code # that generates that string isn't part of this unit, anyway. }) # Verify that it is a child of one of the request actions. for request in LoggedAction.ofType(logger.messages, REQUEST): if LoggedMessage(traceback) in request.descendants(): break else: self.fail( "Traceback was logged outside of the context of a request " "action.")
def validate(case, logger): assertHasAction(case, logger, parent_action_type, succeeded=True) # Remember what the docstring said? Ideally this would inspect the # children of the action returned by assertHasAction but the interfaces # don't seem to line up. iptables = LoggedAction.ofType(logger.messages, IPTABLES) case.assertNotEqual(iptables, [])
def assert_nested_logging(self, combo, action_type, logger): """ All the underlying ``IStateChange`` will be run in Eliot context in which the sequential ``IStateChange`` is run, even if they are not run immediately. :param combo: ``sequentially`` or ``in_parallel``. :param action_type: ``eliot.ActionType`` we expect to be parent of sub-changes' log entries. :param logger: A ``MemoryLogger`` where messages go. """ actions = [ControllableAction(result=Deferred()), ControllableAction(result=succeed(None))] for action in actions: self.patch(action, "_logger", logger) run_state_change(combo(actions), None) # For sequentially this will ensure second action doesn't # automatically run in context of LOG_ACTION: actions[0].result.callback(None) parent = assertHasAction(self, logger, action_type, succeeded=True) self.assertEqual( dict(messages=parent.children, length=len(parent.children)), dict( messages=LoggedAction.ofType( logger.messages, CONTROLLABLE_ACTION_TYPE), length=2))
def test_error_sending(self, logger): """ An error sending to one agent does not prevent others from being notified. """ control_amp_service = build_control_amp_service(self) self.patch(control_amp_service, 'logger', logger) connected_protocol = ControlAMP(control_amp_service) # Patching is bad. # https://clusterhq.atlassian.net/browse/FLOC-1603 connected_protocol.callRemote = lambda *args, **kwargs: succeed({}) error = ConnectionLost() disconnected_protocol = ControlAMP(control_amp_service) results = [succeed({}), fail(error)] # Patching is bad. # https://clusterhq.atlassian.net/browse/FLOC-1603 disconnected_protocol.callRemote = ( lambda *args, **kwargs: results.pop(0)) control_amp_service.connected(disconnected_protocol) control_amp_service.connected(connected_protocol) control_amp_service.node_changed(NodeState(hostname=u"1.2.3.4")) actions = LoggedAction.ofType(logger.messages, LOG_SEND_TO_AGENT) self.assertEqual( [action.end_message["exception"] for action in actions if not action.succeeded], [u"twisted.internet.error.ConnectionLost"])
def actuallyAssert(self, logger): request = LoggedAction.ofType(logger.messages, REQUEST)[0] assertContainsFields(self, request.startMessage, { u"request_path": path.decode("ascii"), u"method": method, }) return request
def assertOutputLogging(self, logger): """ The L{IOutputExecutor} is invoked in the FSM's transition action context. """ loggedTransition = LoggedAction.ofType( logger.messages, LOG_FSM_TRANSITION)[0] loggedAnimal = LoggedMessage.ofType(logger.messages, LOG_ANIMAL)[0] self.assertIn(loggedAnimal, loggedTransition.children)
def test_read_headers_fails(capture_logging): unparseable = io.BytesIO(b'21:' b'missing trailing null' b',') with pytest.raises(RuntimeError), capture_logging() as logger: receiver.read_headers(unparseable) fail_actions = LoggedAction.ofType(logger.messages, types.SCGI_PARSE) assert fail_actions and not fail_actions[0].succeeded
def test_read_headers_succeeds(capture_logging): parseable = io.BytesIO(SPEC_REQUEST_HEADERS) expected = {'CONTENT_LENGTH': '27', 'SCGI': '1', 'REQUEST_METHOD': 'POST', 'REQUEST_URI': '/deepthought'} with capture_logging() as logger: assert receiver.read_headers(parseable) == expected actions = LoggedAction.ofType(logger.messages, types.SCGI_PARSE) assert actions and actions[0].succeeded
def test_responseResultContainsIncident(self, logger): """ If the decorated function raises an exception, the HTTP response body is a json-encoded object with a item set to an incident identifier. """ request = dummyRequest(b"GET", b"/foo/exception", Headers(), b"") app = self.application(logger, None) self.render(app.app.resource(), request) logger.flushTracebacks(ArbitraryException) incident = loads(request._responseBody) action = LoggedAction.ofType(logger.messages, REQUEST)[0] # First message in action was action start with task_level /1, so # next task_level is /2: self.assertEqual(u"{}@/2".format(action.startMessage[u"task_uuid"]), incident)
def test_read_headers_succeeds_with_latin_1(capture_logging): latin1 = io.BytesIO() latin1.writelines([b'29:' b'CONTENT_LENGTH', _NULL, b'1', _NULL, b'X_LATIN_1', _NULL, b'\xbf', _NULL, b',']) latin1.seek(0) expected = {'CONTENT_LENGTH': '1', 'X_LATIN_1': u'\N{INVERTED QUESTION MARK}'} with capture_logging() as logger: assert receiver.read_headers(latin1) == expected actions = LoggedAction.ofType(logger.messages, types.SCGI_PARSE) assert actions and actions[0].succeeded
def test_responseResultContainsIncident(self, logger): """ If the decorated function raises an exception, the HTTP response body is a json-encoded object with a item set to an incident identifier. """ request = dummyRequest(b"GET", b"/foo/exception", Headers(), b"") app = self.application(logger, None) self.render(app.app.resource(), request) logger.flushTracebacks(ArbitraryException) incident = loads(request._responseBody) action = LoggedAction.ofType(logger.messages, REQUEST)[0] # First message in action was action start with task_level /1, so # next task_level is /2: self.assertEqual( u"{}@/2".format(action.startMessage[u"task_uuid"]), incident)
def test_app_returns_empty_iterable( capture_logging, processor_with_environ, outstream): expected_environ = {'PATH_INFO': 'blah'} expected_response = _OK_STATUS_HEADERS_PREPARED def hello_world(environ, start_response): assert expected_environ == environ start_response(_OK_STATUS, _OK_HEADERS) return [] with capture_logging() as logger: processor_with_environ(expected_environ).run_app(hello_world) assert outstream.getvalue() == expected_response fail_actions = LoggedAction.ofType(logger.messages, types.WSGI_REQUEST) assert fail_actions and fail_actions[0].succeeded
def test_serialized_task(self, logger): """ If the ``X-Eliot-Task-Id`` header containers a serialized task level, it is used as a parent of the logged actions from the handler. """ parent = ActionType("parent", [], []) with parent() as context: task_id = context.serialize_task_id() app = self.Application() app.logger = logger request = dummyRequest(b"GET", b"/foo/bar", Headers({b"X-Eliot-Task-Id": [task_id]}), b"") render(app.app.resource(), request) logged_parent = LoggedAction.ofType(logger.messages, parent)[0] child = _assertRequestLogged(b"/foo/bar")(self, logger) self.assertIn(child, logged_parent.descendants())
def test_responseResultContainsIncident(self, logger): """ If the decorated function raises an exception, the HTTP response body is a json-encoded object with a C{u"result"} item set to an incident identifier. """ request = dummyRequest(b"GET", b"/foo/exception", Headers(), b"") app = self.application(logger, None) self.render(app.app.resource(), request) logger.flushTracebacks(ArbitraryException) response = loads(request._responseBody) incident = response[u"result"] action = LoggedAction.ofType(logger.messages, REQUEST)[0] self.assertEqual( u",".join(( action.startMessage[u"task_uuid"], action.startMessage[u"task_level"])), incident)
def assertTransitionLogging(self, logger): """ State transitions by L{IFiniteStateMachine} are logged. """ loggedTransition = LoggedAction.ofType( logger.messages, LOG_FSM_TRANSITION)[0] assertContainsFields( self, loggedTransition.startMessage, {u"fsm_identifier": u"<AnimalWorld>", u"fsm_state": u"<MoreState=amber>", u"fsm_rich_input": u"<Gravenstein>", u"fsm_input": u"<Input=apple>", }) self.assertTrue(loggedTransition.succeeded) assertContainsFields(self, loggedTransition.endMessage, {u"fsm_next_state": u"<MoreState=blue>", u"fsm_output": [u"<Output=aardvark>"], })
def test_serialized_task(self, logger): """ If the ``X-Eliot-Task-Id`` header containers a serialized task level, it is used as a parent of the logged actions from the handler. """ parent = ActionType("parent", [], []) with parent() as context: task_id = context.serialize_task_id() app = self.Application() app.logger = logger request = dummyRequest( b"GET", b"/foo/bar", Headers({b"X-Eliot-Task-Id": [task_id]}), b"") render(app.app.resource(), request) logged_parent = LoggedAction.ofType(logger.messages, parent)[0] child = _assertRequestLogged(b"/foo/bar")(self, logger) self.assertIn(child, logged_parent.descendants())
def some_iptables_logged(parent_action_type): """ Create a validator which assert that some ``IPTABLES`` actions got logged. They should be logged as children of a ``parent_action_type`` action (but this function will not verify that). No other assertions are made about the particulars of the message because that would be difficult (by virtue of requiring we duplicate the exact iptables commands from the implementation here, in the tests, which is tedious and produces fragile tests). """ def validate(case, logger): assertHasAction(case, logger, parent_action_type, succeeded=True) # Remember what the docstring said? Ideally this would inspect the # children of the action returned by assertHasAction but the interfaces # don't seem to line up. iptables = LoggedAction.ofType(logger.messages, IPTABLES) case.assertNotEqual(iptables, [])
def assertTransitionLogging(self, logger): """ State transitions by L{IFiniteStateMachine} are logged. """ loggedTransition = LoggedAction.ofType(logger.messages, LOG_FSM_TRANSITION)[0] assertContainsFields( self, loggedTransition.startMessage, { u"fsm_identifier": u"<AnimalWorld>", u"fsm_state": u"<MoreState=amber>", u"fsm_rich_input": u"<Gravenstein>", u"fsm_input": u"<Input=apple>", }) self.assertTrue(loggedTransition.succeeded) assertContainsFields( self, loggedTransition.endMessage, { u"fsm_next_state": u"<MoreState=blue>", u"fsm_output": [u"<Output=aardvark>"], })
def got_response(_): parent = LoggedAction.ofType(logger.messages, my_action)[0] child = LoggedAction.ofType(logger.messages, JSON_REQUEST)[0] self.assertIn(child, list(parent.descendants()))
def actuallyAssert(self, logger): request = LoggedAction.ofType(logger.messages, REQUEST)[0] assertContainsFields(self, request.startMessage, { u"request_path": repr(path).decode("ascii"), })