def test_logging_level(nsproxy):
"""
Logging with different log levels should result in different logs being
filled.
"""
agent = run_agent('agent')
agent.set_attr(_DEBUG=True)
logger = run_logger('logger')
agent.set_logger(logger)
i = 0
while not len(logger.get_attr('log_history')):
i += 1
agent.log_info(i)
assert logger_received(logger, message=r'\): %s' % i, position=-1)
before = len(logger.get_attr('log_history'))
agent.log_info('some information')
agent.log_warning('some warning')
agent.log_error('some error')
agent.log_debug('some debug')
# Log values
assert logger_received(logger, 'some information', 'log_history_info', -1)
assert logger_received(logger, 'some warning', 'log_history_warning', -1)
assert logger_received(logger, 'some error', 'log_history_error', -1)
assert logger_received(logger, 'some debug', 'log_history_debug', -1)
# Log sizes
assert len(logger.get_attr('log_history_info')) == 1 + before
assert len(logger.get_attr('log_history_warning')) == 1
assert len(logger.get_attr('log_history_error')) == 1
assert len(logger.get_attr('log_history_debug')) == 1
def test_wait_timeout(nsproxy):
"""
Asynchronous request-reply pattern when exceeding the maximum wait.
"""
client, server = async_client_server()
logger = run_logger('logger')
client.set_logger(logger)
sync_agent_logger(client, logger)
client.send('async', 'foo', wait=0.5)
assert len(client.get_attr('_pending_requests')) == 1
assert logger_received(
logger,
log_name='log_history_warning',
message='not receive req',
timeout=1,
)
assert len(client.get_attr('_pending_requests')) == 0
server.unsafe.set_attr(blocked=False)
assert logger_received(
logger,
log_name='log_history_warning',
message='Received response for an unknown request!',
)
assert server.get_attr('received') == ['foo']
assert client.get_attr('received') == []
def test_logging_level(nsproxy):
"""
Logging with different log levels should result in different logs being
filled.
"""
agent = run_agent('agent')
agent.set_attr(_DEBUG=True)
logger = run_logger('logger')
agent.set_logger(logger)
i = 0
while not len(logger.get_attr('log_history')):
i += 1
agent.log_info(i)
assert logger_received(logger, message='\): %s' % i, position=-1)
before = len(logger.get_attr('log_history'))
agent.log_info('some information')
agent.log_warning('some warning')
agent.log_error('some error')
agent.log_debug('some debug')
# Log values
assert logger_received(logger, 'some information', 'log_history_info', -1)
assert logger_received(logger, 'some warning', 'log_history_warning', -1)
assert logger_received(logger, 'some error', 'log_history_error', -1)
assert logger_received(logger, 'some debug', 'log_history_debug', -1)
# Log sizes
assert len(logger.get_attr('log_history_info')) == 1 + before
assert len(logger.get_attr('log_history_warning')) == 1
assert len(logger.get_attr('log_history_error')) == 1
assert len(logger.get_attr('log_history_debug')) == 1
def test_unknown(nsproxy):
"""
When receiving a response for an unknow request (or an already processed
request), a warning should be logged and handler should not be executed.
"""
def late_reply(agent, request):
agent.received.append(request)
time.sleep(1)
return 'x' + request
def receive(agent, response):
agent.received.append(response)
server = run_agent('server')
client = run_agent('client')
logger = run_logger('logger')
server.set_attr(received=[])
client.set_attr(received=[])
client.set_logger(logger)
sync_agent_logger(client, logger)
addr = server.bind('ASYNC_REP', alias='replier', handler=late_reply)
client.connect(addr, alias='async', handler=receive)
client.send('async', 'foo')
# Manually remove the pending request before it is received
client.set_attr(_pending_requests={})
time.sleep(1.1)
assert server.get_attr('received') == ['foo']
assert client.get_attr('received') == []
assert logger_received(logger,
log_name='log_history_warning',
message='Received response for an unknown request!')
def test_logger_received(agent_logger):
"""
The function `logger_received` should return `False` if the message is
not received after a timeout.
"""
a0, logger = agent_logger
assert not logger_received(logger, 'asdf', log_name='log_history_error')
def test_multiple_yield(nsproxy):
"""
A replier must only make use of yield once.
"""
def yield_twice(agent, message):
yield message
yield 'Derp'
logger = run_logger('logger')
a0 = run_agent('a0')
a1 = run_agent('a1')
a0.set_logger(logger)
sync_agent_logger(agent=a0, logger=logger)
addr = a0.bind('REP', handler=yield_twice)
a1.connect(addr, alias='request')
response = a1.send_recv('request', 'Hello world!')
# Response is received successfully
assert response == 'Hello world!'
# Replier should crash
assert logger_received(logger,
log_name='log_history_error',
message='yielded more than once')
assert agent_dies(a0, nsproxy)
def test_logger_received(agent_logger):
"""
The function `logger_received` should return `False` if the message is
not received after a timeout.
"""
a0, logger = agent_logger
assert not logger_received(logger, 'asdf', log_name='log_history_error')
def test_logger_received_newline(agent_logger):
"""
The `'.'` special character in `logger_received` regular expressions
should match newline characters too.
"""
a0, logger = agent_logger
a0.log_info('foo\nbar')
assert logger_received(logger, message='foo.*bar')
def test_logger_received_newline(agent_logger):
"""
The `'.'` special character in `logger_received` regular expressions
should match newline characters too.
"""
a0, logger = agent_logger
a0.log_info('foo\nbar')
assert logger_received(logger, message='foo.*bar')
def test_sync_agent_logger(agent_logger):
"""
After synchronizing and agent and a logger, a message logged should
always be received by the logger.
"""
a0, logger = agent_logger
a0.log_info('asdf')
assert logger_received(logger, message='asdf')
def test_sync_agent_logger(agent_logger):
"""
After synchronizing and agent and a logger, a message logged should
always be received by the logger.
"""
a0, logger = agent_logger
a0.log_info('asdf')
assert logger_received(logger, message='asdf')
def test_wait(nsproxy):
"""
Asynchronous request-reply pattern maximum wait.
When a client makes a request, it can also set a maximum wait time and
a function to be executed in case the message is not received after that
period.
"""
server = run_agent('server', base=ServerLate)
client = run_agent('client', base=Client)
logger = run_logger('logger')
client.set_logger(logger)
sync_agent_logger(client, logger)
# Connect clients
server_addr = server.addr('publish')
client.connect(server_addr, alias='sub', handler=append_received)
# Publish from server
server.each(0, 'publish')
# Wait for client to receive some data
n = 10
assert wait_agent_attr(client, length=n)
# Response received in time
fast = 0
client.send('sub', fast, handler=append_received, wait=0.5)
time.sleep(0.2)
assert server.get_attr('received') == [fast]
assert 'x' + str(fast) in client.get_attr('received')
# Response not received in time
slow = 1
client.send('sub', slow, handler=append_received, wait=0.1)
assert logger_received(
logger,
log_name='log_history_warning',
message='not receive req',
timeout=0.5,
)
assert server.get_attr('received') == [fast, slow]
assert 'x' + str(slow) not in client.get_attr('received')
# Response not received in time with error handler
slow = 1
client.send('sub',
slow,
handler=append_received,
wait=0.1,
on_error=on_error)
assert wait_agent_attr(client, name='error_log', length=1, timeout=0.5)
assert server.get_attr('received') == [fast, slow]
assert 'x' + str(slow) not in client.get_attr('received')
def test_log_levels(nsproxy):
"""
Test different log levels: info, warning, error and debug. Debug messages
are only to be logged if `_DEBUG` attribute is set in the agent.
"""
logger = run_logger('logger')
agent = run_agent('a0')
agent.set_logger(logger)
sync_agent_logger(agent, logger)
# Log info
message = str(uuid4())
agent.log_info(message)
assert logger_received(logger, message, log_name='log_history_info')
# Log warning
message = str(uuid4())
agent.log_warning(message)
assert logger_received(logger, message, log_name='log_history_warning')
# Log error
message = str(uuid4())
agent.log_error(message)
assert logger_received(logger, message, log_name='log_history_error')
# Log debug
message = str(uuid4())
agent.set_attr(_DEBUG=True)
agent.log_debug(message)
assert logger_received(logger, message, log_name='log_history_debug')
message = str(uuid4())
agent.set_attr(_DEBUG=False)
agent.log_debug(message)
assert not logger_received(logger, message, log_name='log_history_debug')
message = str(uuid4())
agent.set_attr(_DEBUG=True)
agent.log_debug(message)
assert logger_received(logger, message, log_name='log_history_debug')
def test_wait_timeout(nsproxy):
"""
Asynchronous request-reply pattern when exceeding the maximum wait.
"""
client, server = async_client_server()
logger = run_logger('logger')
client.set_logger(logger)
sync_agent_logger(client, logger)
client.send('async', 'foo', wait=.5)
assert len(client.get_attr('_pending_requests')) == 1
assert logger_received(logger,
log_name='log_history_warning',
message='not receive req',
timeout=1)
assert len(client.get_attr('_pending_requests')) == 0
server.unsafe.set_attr(blocked=False)
assert logger_received(logger,
log_name='log_history_warning',
message='Received response for an unknown request!')
assert server.get_attr('received') == ['foo']
assert client.get_attr('received') == []
def test_wait(nsproxy):
"""
Asynchronous request-reply pattern maximum wait.
When a client makes a request, it can also set a maximum wait time and
a function to be executed in case the message is not received after that
period.
"""
server = run_agent('server', base=ServerLate)
client = run_agent('client', base=Client)
logger = run_logger('logger')
client.set_logger(logger)
sync_agent_logger(client, logger)
# Connect clients
server_addr = server.addr('publish')
client.connect(server_addr, alias='sub', handler=append_received)
# Publish from server
server.each(0, 'publish')
# Wait for client to receive some data
n = 10
assert wait_agent_attr(client, length=n)
# Response received in time
fast = 0
client.send('sub', fast, handler=append_received, wait=0.5)
time.sleep(0.2)
assert server.get_attr('received') == [fast]
assert 'x' + str(fast) in client.get_attr('received')
# Response not received in time
slow = 1
client.send('sub', slow, handler=append_received, wait=0.1)
assert logger_received(logger,
log_name='log_history_warning',
message='not receive req',
timeout=0.5)
assert server.get_attr('received') == [fast, slow]
assert 'x' + str(slow) not in client.get_attr('received')
# Response not received in time with error handler
slow = 1
client.send('sub', slow, handler=append_received, wait=0.1,
on_error=on_error)
assert wait_agent_attr(client, name='error_log', length=1, timeout=0.5)
assert server.get_attr('received') == [fast, slow]
assert 'x' + str(slow) not in client.get_attr('received')
def test_running_exception(nsproxy):
"""
An exception that occurs while the agent is running should stop the
agent and log an error message as well.
"""
logger = run_logger('logger')
agent = run_agent('crasher')
agent.set_logger(logger)
assert agent.is_running()
# Make sure agent and logger are connected
sync_agent_logger(agent, logger)
# Raise an exception
with pytest.raises(RuntimeError):
agent.raise_exception()
message = 'User raised an exception'
assert logger_received(logger, message, log_name='log_history_error')
assert not agent.is_running()
def test_unknown(nsproxy):
"""
When receiving a response for an unknown request (or an already processed
request), a warning should be logged and handler should not be executed.
"""
client, server = async_client_server()
logger = run_logger('logger')
client.set_logger(logger)
sync_agent_logger(client, logger)
client.send('async', 'foo')
assert wait_agent_attr(server, value=['foo'], timeout=.1)
# Manually remove the pending request before it is received
client.set_attr(_pending_requests={})
server.unsafe.set_attr(blocked=False)
assert logger_received(logger,
log_name='log_history_warning',
message='Received response for an unknown request!')
assert len(client.get_attr('received')) == 0
def test_unknown(nsproxy, server_client_late_reply_return):
"""
When receiving a response for an unknow request (or an already processed
request), a warning should be logged and handler should not be executed.
"""
server, client = server_client_late_reply_return
logger = run_logger('logger')
client.set_logger(logger)
sync_agent_logger(client, logger)
client.send('async', 'foo')
# Manually remove the pending request before it is received
client.set_attr(_pending_requests={})
time.sleep(1.1)
assert server.get_attr('received') == ['foo']
assert client.get_attr('received') == []
assert logger_received(logger,
log_name='log_history_warning',
message='Received response for an unknown request!')
def test_unknown(nsproxy):
"""
When receiving a response for an unknown request (or an already processed
request), a warning should be logged and handler should not be executed.
"""
client, server = async_client_server()
logger = run_logger('logger')
client.set_logger(logger)
sync_agent_logger(client, logger)
client.send('async', 'foo')
assert wait_agent_attr(server, value=['foo'], timeout=.1)
# Manually remove the pending request before it is received
client.set_attr(_pending_requests={})
server.unsafe.set_attr(blocked=False)
assert logger_received(logger,
log_name='log_history_warning',
message='Received response for an unknown request!')
assert len(client.get_attr('received')) == 0
def test_logger_received_count(agent_logger):
"""
The function `logger_received` actually returns an integer with the total
number of matches.
"""
a0, logger = agent_logger
a0.log_info('foo bar')
a0.log_info('foo beer')
a0.log_info('foo asdf bar')
# Make sure logger receives the last message
assert logger_received(logger, message='foo asdf bar')
# Start counting...
assert logger_received(logger, message='foo') == 3
assert logger_received(logger, message='foo b') == 2
assert logger_received(logger, message='foo beer') == 1
assert logger_received(logger, message='bar') == 2
assert logger_received(logger, message='foo.*bar') == 2
def test_logger_received_count(agent_logger):
"""
The function `logger_received` actually returns an integer with the total
number of matches.
"""
a0, logger = agent_logger
a0.log_info('foo bar')
a0.log_info('foo beer')
a0.log_info('foo asdf bar')
# Make sure logger receives the last message
assert logger_received(logger, message='foo asdf bar')
# Start counting...
assert logger_received(logger, message='foo') == 3
assert logger_received(logger, message='foo b') == 2
assert logger_received(logger, message='foo beer') == 1
assert logger_received(logger, message='bar') == 2
assert logger_received(logger, message='foo.*bar') == 2
def test_multiple_yield(nsproxy):
"""
A replier must only make use of yield once.
"""
def yield_twice(agent, message):
yield message
yield 'Derp'
logger = run_logger('logger')
a0 = run_agent('a0')
a1 = run_agent('a1')
a0.set_logger(logger)
sync_agent_logger(agent=a0, logger=logger)
addr = a0.bind('REP', handler=yield_twice)
a1.connect(addr, alias='request')
response = a1.send_recv('request', 'Hello world!')
# Response is received successfully
assert response == 'Hello world!'
# Replier should crash
assert logger_received(logger, log_name='log_history_error',
message='yielded more than once')
def test_wait(nsproxy):
"""
Asynchronous request-reply pattern maximum wait.
"""
def late_reply(agent, delay):
agent.received.append(delay)
time.sleep(delay)
return 'x' + str(delay)
def receive(agent, response):
agent.received.append(response)
server = run_agent('server')
client = run_agent('client')
logger = run_logger('logger')
server.set_attr(received=[])
client.set_attr(received=[])
client.set_logger(logger)
sync_agent_logger(client, logger)
addr = server.bind('ASYNC_REP', alias='replier', handler=late_reply)
client.connect(addr, alias='async', handler=receive)
# Response received in time
client.send('async', 1, wait=2)
time.sleep(1.1)
assert server.get_attr('received') == [1]
assert client.get_attr('received') == ['x1']
# Response not received in time
client.send('async', 2, wait=1)
assert logger_received(logger,
log_name='log_history_warning',
message='not receive req',
timeout=1.1)
assert server.get_attr('received') == [1, 2]
assert client.get_attr('received') == ['x1']
def test_wait(nsproxy, server_client_late_reply_delay):
"""
Asynchronous request-reply pattern maximum wait.
"""
server, client = server_client_late_reply_delay
logger = run_logger('logger')
client.set_logger(logger)
sync_agent_logger(client, logger)
# Response received in time
client.send('async', 1, wait=2)
time.sleep(1.1)
assert server.get_attr('received') == [1]
assert client.get_attr('received') == ['x1']
# Response not received in time
client.send('async', 2, wait=1)
assert logger_received(logger,
log_name='log_history_warning',
message='not receive req',
timeout=1.1)
assert server.get_attr('received') == [1, 2]
assert client.get_attr('received') == ['x1']
def test_logger_received_position(agent_logger):
"""
The function `logger_received` should accept a parameter to specify the
exact position where the regular expression should be matching.
"""
a0, logger = agent_logger
a0.log_info('m0')
a0.log_info('m1')
a0.log_info('m2')
# Any position
assert logger_received(logger, message='m2')
assert logger_received(logger, message='m1')
assert logger_received(logger, message='m0')
# -1 position
assert logger_received(logger, message='m2', position=-1, timeout=0.1)
assert not logger_received(logger, message='m1', position=-1, timeout=0.1)
assert not logger_received(logger, message='m0', position=-1, timeout=0.1)
# -2 position
assert not logger_received(logger, message='m2', position=-2, timeout=0.1)
assert logger_received(logger, message='m1', position=-2, timeout=0.1)
assert not logger_received(logger, message='m0', position=-2, timeout=0.1)
# 0 position (important to test vs. None)
assert not logger_received(logger, message='m2', position=0, timeout=0.1)
assert not logger_received(logger, message='m1', position=0, timeout=0.1)
assert not logger_received(logger, message='m0', position=0, timeout=0.1)
def test_logger_received_position(agent_logger):
"""
The function `logger_received` should accept a parameter to specify the
exact position where the regular expression should be matching.
"""
a0, logger = agent_logger
a0.log_info('m0')
a0.log_info('m1')
a0.log_info('m2')
# Any position
assert logger_received(logger, message='m2')
assert logger_received(logger, message='m1')
assert logger_received(logger, message='m0')
# -1 position
assert logger_received(logger, message='m2', position=-1, timeout=0.1)
assert not logger_received(logger, message='m1', position=-1, timeout=0.1)
assert not logger_received(logger, message='m0', position=-1, timeout=0.1)
# -2 position
assert not logger_received(logger, message='m2', position=-2, timeout=0.1)
assert logger_received(logger, message='m1', position=-2, timeout=0.1)
assert not logger_received(logger, message='m0', position=-2, timeout=0.1)
# 0 position (important to test vs. None)
assert not logger_received(logger, message='m2', position=0, timeout=0.1)
assert not logger_received(logger, message='m1', position=0, timeout=0.1)
assert not logger_received(logger, message='m0', position=0, timeout=0.1)
