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_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_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_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)