def test_start(self):
yield self.assert_status('stopped')
lc = LogCatcher()
with lc:
yield self.rtr_helper.start_router(self.router)
self.assertEqual(lc.messages(), [
u"Starting router '%s' for user 'test-0-user'." % self.router.key,
])
yield self.assert_status('running')
def test_start(self):
yield self.assert_status('stopped')
lc = LogCatcher()
with lc:
yield self.rtr_helper.start_router(self.router)
self.assertEqual(lc.messages(), [
u"Starting router '%s' for user 'test-0-user'." % self.router.key,
])
yield self.assert_status('running')
def test_publish_status_disabled(self):
transport = yield self.tx_helper.get_transport({
'transport_name': 'foo',
'worker_name': 'foo',
'publish_status': False
})
with LogCatcher() as lc:
msg = yield transport.publish_status(status='down',
component='foo',
type='bar',
message='baz')
self.assertEqual(msg['status'], 'down')
self.assertEqual(msg['component'], 'foo')
self.assertEqual(msg['type'], 'bar')
self.assertEqual(msg['message'], 'baz')
msgs = self.tx_helper.get_dispatched_statuses('foo.status')
self.assertEqual(msgs, [])
[log] = lc.logs
self.assertEqual(
log['message'][0],
"Status publishing disabled for transport 'foo', "
"ignoring status %r" % (msg, ))
self.assertEqual(log['system'], 'foo')
def test_echo_non_ascii(self):
content = u'Zoë destroyer of Ascii'
with LogCatcher() as log:
yield self.app_helper.make_dispatch_inbound(content)
[reply] = self.app_helper.get_dispatched_outbound()
self.assertEqual(log.messages(),
['User message: Zo\xc3\xab destroyer of Ascii'])
def test_submit_and_deliver_with_missing_id_lookup(self):
def r_failing_get(third_party_id):
return succeed(None)
self.transport.r_get_id_for_third_party_id = r_failing_get
# Startup
yield self.startTransport()
yield self.transport._block_till_bind
# Next the Client submits a SMS to the Server
# and recieves an ack and a delivery_report
lc = LogCatcher(message="Failed to retrieve message id")
with lc:
msg = yield self.tx_helper.make_dispatch_outbound("hello world")
# We need the user_message_id to check the ack
user_message_id = msg["message_id"]
[ack] = yield self.tx_helper.wait_for_dispatched_events(1)
self.assertEqual(ack['message_type'], 'event')
self.assertEqual(ack['event_type'], 'ack')
self.assertEqual(ack['transport_name'], self.tx_helper.transport_name)
self.assertEqual(ack['user_message_id'], user_message_id)
# check that failure to send delivery report was logged
[warning] = lc.logs
expected_msg = (
"Failed to retrieve message id for delivery report. Delivery"
" report from %s discarded.") % (self.tx_helper.transport_name, )
self.assertEqual(warning['message'], (expected_msg, ))
def test_outbound_non_reply_logs_error(self):
msg = TransportUserMessage(to_addr="1234",
from_addr="5678",
transport_name="test_infobip",
transport_type="ussd",
transport_metadata={})
with LogCatcher() as logger:
self.broker.publish_message("vumi", "test_infobip.outbound", msg)
yield self.broker.kick_delivery()
[error, logged_failure] = logger.errors
expected_error = ("Infobip transport cannot process outbound message"
" that is not a reply.")
twisted_failure = logged_failure['failure']
self.assertEqual(self.flushLoggedErrors(PermanentFailure),
[twisted_failure])
failure = twisted_failure.value
self.assertEqual(failure.failure_code, FailureMessage.FC_PERMANENT)
self.assertEqual(str(failure), expected_error)
[errmsg] = error['message']
expected_logged_error = "'" + expected_error.replace('.', ':')
self.assertTrue(errmsg.startswith(expected_logged_error))
[msg] = yield self.broker.wait_messages("vumi",
"test_infobip.failures", 1)
self.assertEqual(msg['failure_code'], "permanent")
last_line = msg['reason'].splitlines()[-1].strip()
self.assertTrue(last_line.endswith(expected_error))
def test_client_disconnect_without_answer(self):
self.worker = yield self.create_worker()
factory = yield self.esl_helper.mk_server()
factory.add_fixture(
EslCommand("api originate /sofia/gateway/yogisip"
" 100 XML default elcid +1234 60"),
FixtureApiResponse("+OK uuid-1234"))
msg = self.tx_helper.make_outbound('foobar',
'12345',
'54321',
session_event='new')
client = yield self.esl_helper.mk_client(self.worker, 'uuid-1234')
with LogCatcher(log_level=logging.WARN) as lc:
yield self.tx_helper.dispatch_outbound(msg)
self.assertEqual(lc.messages(), [])
events = yield self.tx_helper.get_dispatched_events()
self.assertEqual(events, [])
client.sendDisconnectEvent()
[nack] = yield self.tx_helper.wait_for_dispatched_events(1)
self.assertEqual(nack['event_type'], 'nack')
self.assertEqual(nack['nack_reason'], 'Unanswered Call')
self.assertEqual(nack['user_message_id'], msg['message_id'])
def test_speech_invalid_url_list(self):
valid_url = u'http://example.com/speech_url_test1.ogg'
invalid_url1 = 7
invalid_url2 = 8
with LogCatcher(log_level=logging.WARN) as lc:
[reg] = yield self.tx_helper.wait_for_dispatched_inbound(1)
self.tx_helper.clear_dispatched_inbound()
msg = yield self.tx_helper.make_dispatch_reply(
reg,
'speech url test',
helper_metadata={
'voice': {
'speech_url': [
invalid_url1,
valid_url,
invalid_url2,
]
}
})
[log] = lc.messages()
self.assertEqual(
log, 'Invalid URL list %r' %
([invalid_url1, valid_url, invalid_url2], ))
[nack] = yield self.tx_helper.get_dispatched_events()
self.assertEqual(nack['user_message_id'], msg['message_id'])
self.assertEqual(nack['event_type'], 'nack')
self.assertEqual(
nack['nack_reason'], 'Invalid URL list %r' %
([invalid_url1, valid_url, invalid_url2], ))
def test_unboundEvent(self):
self.proto.uniquecallid = "abc-1234"
with LogCatcher() as lc:
self.proto.unboundEvent({"some": "data"}, "custom_event")
self.assertEqual(lc.messages(), [
"[abc-1234] Unbound event 'custom_event'",
])
def test_tracking_own_messages(self):
with LogCatcher() as lc:
tweet = self.twitter.new_tweet('arnold', self.user.id_str)
tweet = tweet.to_dict(self.twitter)
self.assertTrue(any(
"Tracked own tweet:" in msg for msg in lc.messages()))
def test_handle_remote_logout(self):
cmd = ServerLogout(ip='127.0.0.1')
with LogCatcher() as logger:
yield self.send(cmd)
[warning] = logger.messages()
self.assertEqual(warning,
"Received remote logout command: %r" % (cmd, ))
def test_inbound_own_tweet(self):
with LogCatcher() as lc:
self.twitter.new_tweet('hello', self.user.id_str)
self.assertTrue(any(
"Received own tweet on user stream" in msg
for msg in lc.messages()))
def test_populate_conversation_buckets(self):
worker = yield self.get_metrics_worker()
user_helper = yield self.vumi_helper.make_user(u'acc1')
conv1 = yield self.make_conv(user_helper, u'conv1', started=True)
conv2a = yield self.make_conv(user_helper, u'conv2a', started=True)
conv2b = yield self.make_conv(user_helper, u'conv2b', started=True)
conv4 = yield self.make_conv(user_helper, u'conv4', started=True)
for conv in [conv1, conv2a, conv2b, conv4]:
self.conversation_names[conv.key] = conv.name
self.assert_conversations_bucketed(worker, {})
with LogCatcher(message='Scheduled') as lc:
yield worker.populate_conversation_buckets()
[log_msg] = lc.messages()
self.assert_conversations_bucketed(worker, {
1: [conv1],
2: [conv2a, conv2b],
4: [conv4],
})
# We may have tombstone keys from accounts created (and deleted) by
# previous tests, so we replace the account count in the log message
# we're asserting on.
log_msg = re.sub(r'in \d account', 'in 1 account', log_msg)
self.assertEqual(
log_msg, "Scheduled metrics commands for"
" 4 conversations in 1 accounts.")
def test_start(self):
conversation = yield self.setup_conversation()
with LogCatcher() as lc:
yield self.app_helper.start_conversation(conversation)
self.assertTrue("Starting javascript sandbox conversation "
"(key: u'%s')." %
conversation.key in lc.messages())
def test_user_message_no_javascript(self):
conv = yield self.setup_conversation(config={})
yield self.app_helper.start_conversation(conv)
with LogCatcher() as lc:
yield self.app_helper.make_dispatch_inbound("inbound", conv=conv)
self.assertTrue("No JS for conversation: %s" %
(conv.key, ) in lc.messages())
def test_connection_lost(self):
with LogCatcher() as logger:
self.vb.connectionLost("test loss of connection")
[logmsg] = logger.messages()
self.assertEqual(logmsg,
'Disconnected (nickname was: %s).' % self.nick)
self.assertEqual(logger.errors, [])
def test_send_jsbox_command_configured_delivery_class(self):
group = yield self.app_helper.create_group(u'group')
contact1 = yield self.app_helper.create_contact(msisdn=u'+271',
twitter_handle=u'@a',
name=u'a',
surname=u'a',
groups=[group])
contact2 = yield self.app_helper.create_contact(msisdn=u'+272',
twitter_handle=u'@b',
name=u'b',
surname=u'b',
groups=[group])
config = self.mk_conv_config(app=self.APPS['cmd'] %
{'method': 'on_inbound_message'},
delivery_class='twitter')
conv = yield self.setup_conversation(config=config, groups=[group])
yield self.app_helper.start_conversation(conv)
with LogCatcher(message='msg') as lc:
yield self.send_send_jsbox_command(conv)
[msg1,
msg2] = sorted([json.loads(m).get('msg') for m in lc.messages()],
key=lambda msg: msg['from_addr'])
self.assertEqual(msg1['from_addr'], contact1.twitter_handle)
self.assertEqual(msg2['from_addr'], contact2.twitter_handle)
def test_track_stream_for_non_tweet(self):
with LogCatcher() as lc:
self.transport.handle_track_stream({'foo': 'bar'})
self.assertEqual(
lc.messages(),
["Received non-tweet from tracking stream: {'foo': 'bar'}"])
def test_default_outbound_handler(self):
conn = yield self.mk_connector(connector_name='foo', setup=True)
with LogCatcher() as lc:
conn.default_outbound_handler(
self.msg_helper.make_outbound("outbound"))
[log] = lc.messages()
self.assertTrue(log.startswith("No outbound handler for 'foo'"))
def test_handle_ssmi_error(self):
with LogCatcher() as logger:
self.transport.ssmi_errback("foo", baz="bar")
[error] = logger.errors
self.assertEqual(
error["message"][0],
repr("Got error from SSMI:"
" ('foo',), {'baz': 'bar'}"))
def test_handle_inbound_sms(self):
with LogCatcher() as logger:
self.transport.sms_callback("foo", baz="bar")
[error] = logger.errors
self.assertEqual(
error["message"][0],
repr("Got SMS from SSMI but SMSes not supported:"
" ('foo',), {'baz': 'bar'}"))
def test_post_inbound_message_dns_lookup_error(self):
self._patch_http_request_full(DNSLookupError)
with LogCatcher(message='DNS lookup error') as lc:
yield self.app_helper.make_dispatch_inbound('in 1',
message_id='1',
conv=self.conversation)
[dns_log] = lc.messages()
self.assertTrue(self.mock_push_server.url in dns_log)
def test_post_inbound_message_connection_refused_error(self):
self._patch_http_request_full(ConnectionRefusedError)
with LogCatcher(message='Connection refused') as lc:
yield self.app_helper.make_dispatch_inbound('in 1',
message_id='1',
conv=self.conversation)
[dns_log] = lc.messages()
self.assertTrue(self.mock_push_server.url in dns_log)
def test_post_inbound_message_timeout(self):
self._patch_http_request_full(HttpTimeoutError)
with LogCatcher(message='Timeout') as lc:
yield self.app_helper.make_dispatch_inbound('in 1',
message_id='1',
conv=self.conversation)
[timeout_log] = lc.messages()
self.assertTrue(self.mock_push_server.url in timeout_log)
def test_user_stream_for_unsupported_message(self):
with LogCatcher() as lc:
self.transport.handle_user_stream({'foo': 'bar'})
self.assertEqual(
lc.messages(),
["Received a user stream message that we do not handle: "
"{'foo': 'bar'}"])
def test_handle_inbound_sms(self):
cmd = MoMessage(msisdn='foo', message='bar', sequence='1')
with LogCatcher() as logger:
yield self.send(cmd)
[warning] = logger.messages()
self.assertEqual(
warning,
"Received unsupported message, dropping: %r." % (cmd, ))
def test_inbound_own_follow(self):
with LogCatcher() as lc:
someone = self.twitter.new_user('someone', 'someone')
self.twitter.add_follow(self.user.id_str, someone.id_str)
self.assertTrue(any(
"Received own follow on user stream" in msg
for msg in lc.messages()))
def test_process_command_start(self):
yield self.app_helper.get_app_worker(self.APP_CONFIG)
conv = yield self.app_helper.create_conversation(
config=self.CONV_CONFIG)
with LogCatcher() as lc:
yield self.app_helper.start_conversation(conv)
self.assertTrue("Starting RapidSMS conversation "
"(key: u'%s')." % conv.key
in lc.messages())
def test_hash_truncating(self):
expected_user_hash = hashlib.sha256('+41791234567' + 'foo').hexdigest()
expected_entry = 'WIKI\t%s\tsphex\tussd\t\tstart\tNone' % (
expected_user_hash[:64])
yield self.setup_application({'user_hash_char_limit': 64})
with LogCatcher() as log:
yield self.start_session()
[entry] = log.logs
self.assertTrue(expected_entry in entry['message'])
def test_ack(self):
conversation = yield self.setup_conversation()
yield self.app_helper.start_conversation(conversation)
msg = yield self.app_helper.make_stored_outbound(conversation, "foo")
with LogCatcher(message="Ignoring") as lc:
yield self.app_helper.make_dispatch_ack(msg, conv=conversation)
self.assertEqual(
lc.messages(),
["Ignoring event for conversation: %s" % (conversation.key, )])
def assert_config_error(self, config, errmsg):
sm = ScheduleManager(config)
with LogCatcher() as logger:
self.assertEqual(None, sm.get_next(None))
[err] = logger.errors
self.assertEqual(err['why'], 'Error processing schedule.')
self.assertEqual(err['failure'].value.args[0], errmsg)
[f] = self.flushLoggedErrors(ValueError)
self.assertEqual(f, err['failure'])
def test_simple_catching(self):
lc = LogCatcher()
with lc:
log.info("Test")
self.assertEqual(lc.messages(), ["Test"])
def test_system_filtering(self):
lc = LogCatcher(system="^ab")
with lc:
log.info("Test 1", system="abc")
log.info("Test 2", system="def")
self.assertEqual(lc.messages(), ["Test 1"])
def test_message_filtering(self):
lc = LogCatcher(message="^Keep")
with lc:
log.info("Keep this")
log.info("Discard this")
self.assertEqual(lc.messages(), ["Keep this"])
def test_message_concatenation(self):
lc = LogCatcher()
with lc:
log.info("Part 1", "Part 2")
self.assertEqual(lc.messages(), ["Part 1 Part 2"])
