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_multiple_iterations(self, logger):
"""
If the predicate returns something falsey followed by something truthy,
then ``loop_until`` returns it immediately.
"""
result = object()
results = [None, False, result]
expected_results = results[:-1]
def predicate():
return results.pop(0)
clock = Clock()
d = loop_until(clock, predicate)
clock.advance(0.1)
self.assertNoResult(d)
clock.advance(0.1)
self.assertEqual(self.successResultOf(d), result)
action = LoggedAction.of_type(logger.messages, LOOP_UNTIL_ACTION)[0]
assertContainsFields(self, action.start_message, {"predicate": predicate})
assertContainsFields(self, action.end_message, {"result": result})
self.assertTrue(action.succeeded)
messages = LoggedMessage.of_type(logger.messages, LOOP_UNTIL_ITERATION_MESSAGE)
self.assertEqual(action.children, messages)
self.assertEqual([messages[0].message["result"], messages[1].message["result"]], expected_results)
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 test_boto_ec2response_error(self, logger):
"""
1. Invalid parameters to Boto's EBS API calls
raise the right exception after logging to Eliot.
2. Verify Eliot log output for expected message fields
from logging decorator for boto.exception.EC2Exception
originating from boto.ec2.connection.EC2Connection.
"""
# Test 1: Create volume with size 0.
# Raises: ClientError
self.assertRaises(ClientError, self.api.create_volume,
dataset_id=uuid4(), size=0,)
# Test 2: Set EC2 connection zone to an invalid string.
# Raises: ClientError
self.api.zone = u'invalid_zone'
self.assertRaises(
ClientError,
self.api.create_volume,
dataset_id=uuid4(),
size=self.minimum_allocatable_size,
)
# Validate decorated method for exception logging
# actually logged to ``Eliot`` logger.
expected_message_keys = {AWS_CODE.key, AWS_MESSAGE.key,
AWS_REQUEST_ID.key}
for logged in LoggedAction.of_type(logger.messages, AWS_ACTION,):
key_subset = set(key for key in expected_message_keys
if key in logged.end_message.keys())
self.assertEqual(expected_message_keys, key_subset)
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 test_iterates(self, logger):
"""
If the predicate returns something falsey followed by something truthy,
then ``loop_until`` returns it immediately.
"""
result = object()
results = [None, result]
def predicate():
return results.pop(0)
clock = Clock()
d = loop_until(clock, predicate)
self.assertNoResult(d)
clock.advance(0.1)
self.assertEqual(
self.successResultOf(d),
result)
action = LoggedAction.of_type(logger.messages, LOOP_UNTIL_ACTION)[0]
assertContainsFields(self, action.start_message, {
'predicate': predicate,
})
assertContainsFields(self, action.end_message, {
'result': result,
})
self.assertTrue(action.succeeded)
message = LoggedMessage.of_type(
logger.messages, LOOP_UNTIL_ITERATION_MESSAGE)[0]
self.assertEqual(action.children, [message])
assertContainsFields(self, message.message, {
'result': None,
})
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 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 assertSearchLogging2(self, logger):
"""
The two put actions are logged, followed by the two get actions.
"""
[put1, put2] = LoggedAction.of_type(logger.messages, LOG_SEARCH_PUT)
assertContainsFields(
self, put1.start_message,
{'searchClass': SearchClasses.EXACT,
'environment': u'e',
'indexType': u'i',
'searchType': u'type1',
'result': u'result1'})
assertContainsFields(
self, put1.end_message,
{'searchValue': u'value'})
self.assertTrue(put1.succeeded)
assertContainsFields(
self, put2.start_message,
{'searchClass': SearchClasses.PREFIX,
'environment': u'e',
'indexType': u'i',
'searchType': u'type2',
'result': u'result2'})
assertContainsFields(
self, put2.end_message,
{'searchValue': u'value'})
self.assertTrue(put2.succeeded)
[get1, get2] = LoggedAction.of_type(logger.messages, LOG_SEARCH_GET)
assertContainsFields(
self, get1.start_message,
{'searchClass': SearchClasses.EXACT,
'environment': u'e',
'indexType': u'i',
'searchValue': u'value',
'searchType': None})
assertContainsFields(self, get1.end_message, {'results': [u'result1']})
self.assertTrue(get1.succeeded)
assertContainsFields(
self, get2.start_message,
{'searchClass': SearchClasses.PREFIX,
'environment': u'e',
'indexType': u'i',
'searchValue': u'va',
'searchType': None})
assertContainsFields(self, get2.end_message, {'results': [u'result2']})
self.assertTrue(get2.succeeded)
def assertSearchLogging(self, logger):
"""
The put action is logged, followed by the get action, followed by the
delete, followed by the second get.
"""
[put] = LoggedAction.of_type(logger.messages, LOG_SEARCH_PUT)
assertContainsFields(
self, put.start_message,
{'searchClass': SearchClasses.EXACT,
'environment': u'someenv',
'indexType': u'someindex',
'result': u'result',
'searchType': u'type'})
assertContainsFields(
self, put.end_message,
{'searchValue': u'somevalue'})
self.assertTrue(put.succeeded)
[delete] = LoggedAction.of_type(logger.messages, LOG_SEARCH_DELETE)
assertContainsFields(
self, delete.start_message,
{'searchClass': SearchClasses.EXACT,
'environment': u'someenv',
'indexType': u'someindex',
'result': u'result',
'searchType': u'type'})
self.assertTrue(delete.succeeded)
[get1, get2] = LoggedAction.of_type(logger.messages, LOG_SEARCH_GET)
assertContainsFields(
self, get1.start_message,
{'searchClass': SearchClasses.EXACT,
'environment': u'someenv',
'indexType': u'someindex',
'searchValue': u'somevalue',
'searchType': None})
assertContainsFields(self, get1.end_message, {'results': [u'result']})
self.assertTrue(get1.succeeded)
assertContainsFields(
self, get2.start_message,
{'searchClass': SearchClasses.EXACT,
'environment': u'someenv',
'indexType': u'someindex',
'searchValue': u'somevalue',
'searchType': None})
assertContainsFields(self, get2.end_message, {'results': []})
self.assertTrue(get2.succeeded)
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 assert_context_preserved(self, logger):
"""
Logging in the method running in the thread pool is child of caller's
Eliot context.
"""
parent = assertHasAction(self, logger, LOG_IN_CALLER, True, {})
# in-between we expect a eliot:remote_task...
self.assertIn(parent.children[0].children[0],
LoggedAction.of_type(logger.messages, LOG_IN_SPY))
def test_run_successful_test(self, logger):
"""
Running a test with the Eliot reporter logs an action.
"""
reporter = make_reporter()
test = make_successful_test()
test.run(reporter)
[action] = LoggedAction.of_type(logger.serialize(), TEST)
assertContainsFields(self, action.start_message, {"test": test.id()})
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_successful_test(self, logger):
"""
Starting and stopping a test logs a whole action.
"""
reporter = make_reporter()
test = make_successful_test()
reporter.startTest(test)
reporter.stopTest(test)
[action] = LoggedAction.of_type(logger.serialize(), TEST)
assertContainsFields(self, action.start_message, {"test": test.id()})
def assertLookupLogging(self, logger):
"""
The put action is logged, followed by the get action.
"""
[put] = LoggedAction.of_type(logger.messages, LOG_LOOKUP_PUT)
assertContainsFields(
self, put.start_message,
{'environment': u'someenv',
'indexType': u'sometype',
'key': u'somekey'})
assertContainsFields(self, put.end_message, {'value': b'data'})
self.assertTrue(put.succeeded)
[get] = LoggedAction.of_type(logger.messages, LOG_LOOKUP_GET)
assertContainsFields(
self, get.start_message,
{'environment': u'someenv',
'indexType': u'sometype',
'key': u'somekey'})
assertContainsFields(self, get.end_message, {'value': b'data'})
self.assertTrue(get.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 assertMissingGetLogging(self, logger):
"""
When a I{GET} results in I{Not found}, a successful action is logged
with a C{None} value.
"""
[get] = LoggedAction.of_type(logger.messages, LOG_LOOKUP_GET)
assertContainsFields(
self, get.start_message,
{'environment': u'someenv',
'indexType': u'sometype',
'key': u'somekey'})
assertContainsFields(self, get.end_message, {'value': None})
self.assertTrue(get.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_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_partial_predicate(self, logger):
"""
Predicate can be a functools.partial function.
"""
result = object()
def check():
return result
predicate = partial(check)
clock = Clock()
d = loop_until(clock, predicate)
self.assertEqual(self.successResultOf(d), result)
[action] = LoggedAction.of_type(logger.messages, LOOP_UNTIL_ACTION)
assertContainsFields(self, action.start_message, {"predicate": predicate})
assertContainsFields(self, action.end_message, {"action_status": "succeeded", "result": result})
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 test_immediate_success(self, logger):
"""
If the predicate returns something truthy immediately, then
``loop_until`` returns a deferred that has already fired with that
value.
"""
result = object()
def predicate():
return result
clock = Clock()
d = loop_until(clock, predicate)
self.assertEqual(self.successResultOf(d), result)
action = LoggedAction.of_type(logger.messages, LOOP_UNTIL_ACTION)[0]
assertContainsFields(self, action.start_message, {"predicate": predicate})
assertContainsFields(self, action.end_message, {"action_status": "succeeded", "result": result})
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"),
})
async def test_blueprint_stop_failure(bootsteps_graph,
mock_execution_order_strategy_class,
logger):
mock_step1 = create_mock_step("step1")
mock_step2 = create_start_stop_mock_step("step2")
mock_step3 = create_mock_step("step3")
mock_step4 = create_start_stop_mock_step("step4",
mock_class=TrioCoroutineMock)
mock_step4.stop.side_effect = expected_exception = RuntimeError(
"Expected Failure")
mock_step5 = create_mock_step("step5")
mock_step6 = create_mock_step("step6",
spec=AsyncStep,
mock_class=TrioCoroutineMock)
# We're using a parent mock simply to record the order of calls to different
# steps
m = Mock()
m.attach_mock(mock_step1, "mock_step1")
m.attach_mock(mock_step2, "mock_step2")
m.attach_mock(mock_step3, "mock_step3")
m.attach_mock(mock_step4, "mock_step4")
m.attach_mock(mock_step5, "mock_step5")
m.attach_mock(mock_step6, "mock_step6")
expected_execution_order = [
[m.mock_step1, m.mock_step2],
[m.mock_step3, m.mock_step4, m.mock_step5],
[m.mock_step6],
]
mock_iterator = MagicMock()
mock_iterator.__iter__.return_value = expected_execution_order
reversed_func = Mock(return_value=reversed(expected_execution_order))
mock_iterator.__reversed__ = reversed_func
mock_execution_order_strategy_class.return_value = mock_iterator
blueprint = Blueprint(
bootsteps_graph,
name="Test",
execution_order_strategy_class=mock_execution_order_strategy_class,
)
with pytest.raises(RuntimeError):
async with trio.open_nursery() as nursery:
nursery.start_soon(blueprint.stop)
with trio.fail_after(1):
assert (await blueprint.state_changes_receive_channel.receive() ==
BlueprintState.TERMINATING)
with trio.fail_after(1):
assert await blueprint.state_changes_receive_channel.receive() == (
BlueprintState.FAILED,
expected_exception,
)
mock_execution_order_strategy_class.assert_called_once_with(
blueprint._steps)
assert_parallelized_steps_are_in_order(m.method_calls,
[[call.mock_step4.stop()]])
mock_step1.assert_not_called()
mock_step2.stop.assert_not_called()
mock_step3.assert_not_called()
mock_step5.assert_not_called()
mock_step6.assert_not_called()
logged_actions = LoggedAction.of_type(logger.messages,
"bootsteps:blueprint:stop")
assert len(logged_actions) == 1
logged_action = logged_actions[0]
assert_log_message_field_equals(logged_action.start_message, "name",
blueprint.name)
assert_logged_action_failed(logged_action)
messages = LoggedMessage.of_type(logger.messages,
"bootsteps:blueprint:next_bootsteps")
assert len(messages) == 1, messages
assert_log_message_field_equals(messages[0].message, "name",
blueprint.name)
assert_log_message_field_equals(messages[0].message, "next_bootsteps",
[m.mock_step4])
logged_actions = LoggedAction.of_type(
logger.messages, "bootsteps:blueprint:executing_bootstep")
assert len(logged_actions) == 1
start_messages = [
logged_action.start_message for logged_action in logged_actions
]
assert_field_equals_in_any_message(start_messages, "bootstep",
m.mock_step4.stop)
assert_logged_action_failed(logged_actions[0])
async def test_blueprint_start(bootsteps_graph,
mock_execution_order_strategy_class, logger):
mock_step1 = create_mock_step("step1")
mock_step2 = create_start_stop_mock_step("step2")
mock_step3 = create_mock_step("step3")
mock_step4 = create_start_stop_mock_step("step4",
mock_class=TrioCoroutineMock)
mock_step5 = create_mock_step("step5")
mock_step6 = create_mock_step("step6",
spec=AsyncStep,
mock_class=TrioCoroutineMock)
# We're using a parent mock simply to record the order of calls to different
# steps
m = Mock()
m.attach_mock(mock_step1, "mock_step1")
m.attach_mock(mock_step2, "mock_step2")
m.attach_mock(mock_step3, "mock_step3")
m.attach_mock(mock_step4, "mock_step4")
m.attach_mock(mock_step5, "mock_step5")
m.attach_mock(mock_step6, "mock_step6")
expected_execution_order = [
[m.mock_step1, m.mock_step2],
[m.mock_step3, m.mock_step4, m.mock_step5],
[m.mock_step6],
]
mock_iterator = MagicMock()
mock_iterator.__iter__.return_value = expected_execution_order
mock_execution_order_strategy_class.return_value = mock_iterator
blueprint = Blueprint(
bootsteps_graph,
name="Test",
execution_order_strategy_class=mock_execution_order_strategy_class,
)
async with trio.open_nursery() as nursery:
nursery.start_soon(blueprint.start)
with trio.fail_after(1):
assert (await blueprint.state_changes_receive_channel.receive() ==
BlueprintState.RUNNING)
with trio.fail_after(1):
assert (await blueprint.state_changes_receive_channel.receive() ==
BlueprintState.COMPLETED)
mock_execution_order_strategy_class.assert_called_once_with(
blueprint._steps)
assert_parallelized_steps_are_in_order(
m.method_calls,
[
[call.mock_step1(), call.mock_step2.start()],
[call.mock_step3(),
call.mock_step4.start(),
call.mock_step5()],
[call.mock_step6()],
],
)
mock_step6.assert_awaited_once_with()
mock_step4.start.assert_awaited_once_with()
logged_actions = LoggedAction.of_type(logger.messages,
"bootsteps:blueprint:start")
assert len(logged_actions) == 1
logged_action = logged_actions[0]
assert_log_message_field_equals(logged_action.start_message, "name",
blueprint.name)
assert_logged_action_succeeded(logged_action)
messages = LoggedMessage.of_type(logger.messages,
"bootsteps:blueprint:next_bootsteps")
assert len(messages) == 3
assert_log_message_field_equals(messages[0].message, "name",
blueprint.name)
assert_log_message_field_equals(messages[0].message, "next_bootsteps",
[m.mock_step1, m.mock_step2])
assert_log_message_field_equals(messages[1].message, "name",
blueprint.name)
assert_log_message_field_equals(
messages[1].message,
"next_bootsteps",
[m.mock_step3, m.mock_step4, m.mock_step5],
)
assert_log_message_field_equals(messages[2].message, "name",
blueprint.name)
assert_log_message_field_equals(messages[2].message, "next_bootsteps",
[m.mock_step6])
logged_actions = LoggedAction.of_type(
logger.messages, "bootsteps:blueprint:executing_bootstep")
assert len(logged_actions) == 6
start_messages = [
logged_action.start_message for logged_action in logged_actions
]
assert_field_equals_in_any_message(start_messages, "bootstep",
m.mock_step1)
assert_field_equals_in_any_message(start_messages, "bootstep",
m.mock_step2.start)
assert_field_equals_in_any_message(start_messages, "bootstep",
m.mock_step3)
assert_field_equals_in_any_message(start_messages, "bootstep",
m.mock_step4.start)
assert_field_equals_in_any_message(start_messages, "bootstep",
m.mock_step5)
assert_field_equals_in_any_message(start_messages, "bootstep",
m.mock_step6)
assert_logged_action_succeeded(logged_actions[0])
assert_logged_action_succeeded(logged_actions[1])
assert_logged_action_succeeded(logged_actions[2])
assert_logged_action_succeeded(logged_actions[3])
assert_logged_action_succeeded(logged_actions[4])
assert_logged_action_succeeded(logged_actions[5])
