def test_base_logging_handler_ignore_low_severity_msg(dummy_log_record):
handler = BaseHandler(host='127.0.0.1', enabled_flag=True,
message_type='logstash', lvl='WARNING',
enabled_loggers=['awx', 'activity_stream', 'job_events', 'system_tracking'])
handler.setFormatter(LogstashFormatter())
sent_payloads = handler.emit(dummy_log_record)
assert len(sent_payloads) == 0
def test_base_logging_handler_emit_system_tracking(dummy_log_record):
handler = BaseHandler(host='127.0.0.1', indv_facts=True)
handler.setFormatter(LogstashFormatter())
dummy_log_record.name = 'awx.analytics.system_tracking'
dummy_log_record.msg = None
dummy_log_record.inventory_id = 11
dummy_log_record.host_name = 'my_lucky_host'
dummy_log_record.job_id = 777
dummy_log_record.ansible_facts = {
"ansible_kernel": "4.4.66-boot2docker",
"ansible_machine": "x86_64",
"ansible_swapfree_mb": 4663,
}
dummy_log_record.ansible_facts_modified = datetime.datetime.now(
tzutc()).isoformat()
sent_payloads = handler.emit(dummy_log_record)
assert len(sent_payloads) == 1
assert sent_payloads[0]['ansible_facts'] == dummy_log_record.ansible_facts
assert sent_payloads[0][
'ansible_facts_modified'] == dummy_log_record.ansible_facts_modified
assert sent_payloads[0]['level'] == 'INFO'
assert sent_payloads[0]['logger_name'] == 'awx.analytics.system_tracking'
assert sent_payloads[0]['job_id'] == dummy_log_record.job_id
assert sent_payloads[0]['inventory_id'] == dummy_log_record.inventory_id
assert sent_payloads[0]['host_name'] == dummy_log_record.host_name
def test_base_logging_handler_emit_system_tracking():
handler = BaseHandler(host='127.0.0.1', enabled_flag=True,
message_type='logstash', indv_facts=True, lvl='INFO',
enabled_loggers=['awx', 'activity_stream', 'job_events', 'system_tracking'])
handler.setFormatter(LogstashFormatter())
record = logging.LogRecord(
'awx.analytics.system_tracking', # logger name
20, # loglevel INFO
'./awx/some/module.py', # pathname
100, # lineno
None, # msg
tuple(), # args,
None # exc_info
)
record.inventory_id = 11
record.host_name = 'my_lucky_host'
record.ansible_facts = {
"ansible_kernel": "4.4.66-boot2docker",
"ansible_machine": "x86_64",
"ansible_swapfree_mb": 4663,
}
record.ansible_facts_modified = datetime.datetime.now(tzutc()).isoformat()
sent_payloads = handler.emit(record)
assert len(sent_payloads) == 1
assert sent_payloads[0]['ansible_facts'] == record.ansible_facts
assert sent_payloads[0]['level'] == 'INFO'
assert sent_payloads[0]['logger_name'] == 'awx.analytics.system_tracking'
def test_https_logging_handler_connection_error(connection_error_adapter,
dummy_log_record):
handler = HTTPSHandler(host='127.0.0.1', enabled_flag=True,
message_type='logstash', lvl='INFO',
enabled_loggers=['awx', 'activity_stream', 'job_events', 'system_tracking'])
handler.setFormatter(LogstashFormatter())
handler.session.mount('http://', connection_error_adapter)
buff = cStringIO.StringIO()
logging.getLogger('awx.main.utils.handlers').addHandler(
logging.StreamHandler(buff)
)
async_futures = handler.emit(dummy_log_record)
with pytest.raises(requests.exceptions.ConnectionError):
[future.result() for future in async_futures]
assert 'failed to emit log to external aggregator\nTraceback' in buff.getvalue()
# we should only log failures *periodically*, so causing *another*
# immediate failure shouldn't report a second ConnectionError
buff.truncate(0)
async_futures = handler.emit(dummy_log_record)
with pytest.raises(requests.exceptions.ConnectionError):
[future.result() for future in async_futures]
assert buff.getvalue() == ''
def test_https_logging_handler_emit_without_cred(http_adapter,
dummy_log_record,
message_type):
handler = HTTPSHandler(host='127.0.0.1',
enabled_flag=True,
message_type=message_type,
lvl='INFO',
enabled_loggers=[
'awx', 'activity_stream', 'job_events',
'system_tracking'
])
handler.setFormatter(LogstashFormatter())
handler.session.mount('http://', http_adapter)
async_futures = handler.emit(dummy_log_record)
[future.result() for future in async_futures]
assert len(http_adapter.requests) == 1
request = http_adapter.requests[0]
assert request.url == 'http://127.0.0.1/'
assert request.method == 'POST'
if message_type == 'logstash':
# A username + password weren't used, so this header should be missing
assert 'Authorization' not in request.headers
if message_type == 'splunk':
assert request.headers['Authorization'] == 'Splunk None'
def perform_test(self, custom_settings):
"""
Tests logging connectivity for given settings module.
@raises LoggingConnectivityException
"""
handler = self.get_handler(custom_settings=custom_settings,
force_create=True)
handler.setFormatter(LogstashFormatter())
logger = logging.getLogger(__file__)
fn, lno, func, _ = logger.findCaller()
record = logger.makeRecord('awx', 10, fn, lno, 'AWX Connection Test',
tuple(), None, func)
futures = handler.emit(record)
for future in futures:
try:
resp = future.result()
if not resp.ok:
if isinstance(resp, SocketResult):
raise LoggingConnectivityException(
'Socket error: {}'.format(resp.reason or ''))
else:
raise LoggingConnectivityException(': '.join(
[str(resp.status_code), resp.reason or '']))
except RequestException as e:
raise LoggingConnectivityException(str(e))
def test_udp_handler_send(dummy_log_record):
handler = UDPHandler(host='127.0.0.1', port=4399)
handler.setFormatter(LogstashFormatter())
with mock.patch('awx.main.utils.handlers._encode_payload_for_socket', return_value="des") as encode_mock,\
mock.patch.object(handler, 'socket') as socket_mock:
handler.emit(dummy_log_record)
encode_mock.assert_called_once_with(handler.format(dummy_log_record))
socket_mock.sendto.assert_called_once_with("des", ('127.0.0.1', 4399))
def test_udp_handler_send(dummy_log_record):
handler = UDPHandler(host='127.0.0.1', port=4399,
enabled_flag=True, message_type='splunk', lvl='INFO',
enabled_loggers=['awx', 'activity_stream', 'job_events', 'system_tracking'])
handler.setFormatter(LogstashFormatter())
with mock.patch('awx.main.utils.handlers._encode_payload_for_socket', return_value="des") as encode_mock,\
mock.patch.object(handler, 'socket') as socket_mock:
handler.emit(dummy_log_record)
encode_mock.assert_called_once_with(handler.format(dummy_log_record))
socket_mock.sendto.assert_called_once_with("des", ('127.0.0.1', 4399))
def test_log_from_job_event_object():
job = Job(id=4)
event = JobEvent(job_id=job.id)
formatter = LogstashFormatter()
data_for_log = formatter.reformat_data_for_log(
dict(python_objects=dict(job_event=event)), kind='job_events')
# Check entire body of data for any exceptions from getattr on event object
for fd in data_for_log:
if not isinstance(data_for_log[fd], basestring):
continue
assert 'Exception' not in data_for_log[fd], 'Exception delivered in data: {}'.format(data_for_log[fd])
# Verify existence of certain high-importance fields
for fd in ['changed', 'uuid', 'start_line', 'end_line', 'id', 'counter', 'host_name', 'stdout']:
assert fd in data_for_log
assert data_for_log['job'] == 4
def perform_test(cls, settings):
"""
Tests logging connectivity for the current logging settings.
"""
handler = cls.from_django_settings(settings)
handler.enabled_flag = True
handler.setFormatter(LogstashFormatter(settings_module=settings))
logger = logging.getLogger(__file__)
fn, lno, func = logger.findCaller()
record = logger.makeRecord('awx', 10, fn, lno, 'AWX Connection Test',
tuple(), None, func)
handler.emit(_encode_payload_for_socket(record))
def test_tcp_handler_log_exception(fake_socket, dummy_log_record):
handler = TCPHandler(host='127.0.0.1', port=4399, tcp_timeout=5)
handler.setFormatter(LogstashFormatter())
with mock.patch('socket.socket', return_value=fake_socket) as sok_init_mock,\
mock.patch('select.select', return_value=([], [], [])),\
mock.patch('awx.main.utils.handlers.logger') as logger_mock:
fake_socket.connect.side_effect = Exception("foo")
handler.emit(dummy_log_record)
sok_init_mock.assert_called_once_with(socket.AF_INET,
socket.SOCK_STREAM)
logger_mock.exception.assert_called_once()
fake_socket.close.assert_called_once()
assert not fake_socket.send.called
def test_tcp_handler_return_if_socket_unavailable(fake_socket, dummy_log_record):
handler = TCPHandler(host='127.0.0.1', port=4399, tcp_timeout=5,
enabled_flag=True, message_type='splunk', lvl='INFO',
enabled_loggers=['awx', 'activity_stream', 'job_events', 'system_tracking'])
handler.setFormatter(LogstashFormatter())
with mock.patch('socket.socket', return_value=fake_socket) as sok_init_mock,\
mock.patch('select.select', return_value=([], [], [])):
handler.emit(dummy_log_record)
sok_init_mock.assert_called_once_with(socket.AF_INET, socket.SOCK_STREAM)
fake_socket.connect.assert_called_once_with(('127.0.0.1', 4399))
fake_socket.setblocking.assert_called_once_with(0)
assert not fake_socket.send.called
fake_socket.close.assert_called_once()
def test_https_logging_handler_emit_splunk_with_creds(http_adapter,
dummy_log_record):
handler = HTTPSHandler(host='127.0.0.1', enabled_flag=True,
password='******', message_type='splunk', lvl='INFO',
enabled_loggers=['awx', 'activity_stream', 'job_events', 'system_tracking'])
handler.setFormatter(LogstashFormatter())
handler.session.mount('http://', http_adapter)
async_futures = handler.emit(dummy_log_record)
[future.result() for future in async_futures]
assert len(http_adapter.requests) == 1
request = http_adapter.requests[0]
assert request.headers['Authorization'] == 'Splunk pass'
def test_https_logging_handler_emit_splunk_with_creds(http_adapter,
dummy_log_record):
handler = HTTPSHandler(host='127.0.0.1',
password='******',
message_type='splunk')
handler.setFormatter(LogstashFormatter())
handler.session.mount('http://', http_adapter)
async_futures = handler.emit(dummy_log_record)
[future.result() for future in async_futures]
assert len(http_adapter.requests) == 1
request = http_adapter.requests[0]
assert request.headers['Authorization'] == 'Splunk pass'
def test_base_logging_handler_emit(dummy_log_record):
handler = BaseHandler(host='127.0.0.1', enabled_flag=True,
message_type='logstash', lvl='INFO',
enabled_loggers=['awx', 'activity_stream', 'job_events', 'system_tracking'])
handler.setFormatter(LogstashFormatter())
sent_payloads = handler.emit(dummy_log_record)
assert len(sent_payloads) == 1
body = json.loads(sent_payloads[0])
assert body['level'] == 'INFO'
assert body['logger_name'] == 'awx'
assert body['message'] == 'User joe logged in'
def test_tcp_handler_return_if_socket_unavailable(fake_socket,
dummy_log_record):
handler = TCPHandler(host='127.0.0.1', port=4399, tcp_timeout=5)
handler.setFormatter(LogstashFormatter())
with mock.patch('socket.socket', return_value=fake_socket) as sok_init_mock,\
mock.patch('select.select', return_value=([], [], [])):
handler.emit(dummy_log_record)
sok_init_mock.assert_called_once_with(socket.AF_INET,
socket.SOCK_STREAM)
fake_socket.connect.assert_called_once_with(('127.0.0.1', 4399))
fake_socket.setblocking.assert_called_once_with(0)
assert not fake_socket.send.called
fake_socket.close.assert_called_once()
def test_tcp_handler_log_exception(fake_socket, dummy_log_record):
handler = TCPHandler(host='127.0.0.1', port=4399, tcp_timeout=5,
enabled_flag=True, message_type='splunk', lvl='INFO',
enabled_loggers=['awx', 'activity_stream', 'job_events', 'system_tracking'])
handler.setFormatter(LogstashFormatter())
with mock.patch('socket.socket', return_value=fake_socket) as sok_init_mock,\
mock.patch('select.select', return_value=([], [], [])),\
mock.patch('awx.main.utils.handlers.logger') as logger_mock:
fake_socket.connect.side_effect = Exception("foo")
handler.emit(dummy_log_record)
sok_init_mock.assert_called_once_with(socket.AF_INET, socket.SOCK_STREAM)
logger_mock.exception.assert_called_once()
fake_socket.close.assert_called_once()
assert not fake_socket.send.called
def test_https_logging_handler_emit_logstash_with_creds(
http_adapter, dummy_log_record):
handler = HTTPSHandler(host='127.0.0.1',
username='******',
password='******',
message_type='logstash')
handler.setFormatter(LogstashFormatter())
handler.session.mount('http://', http_adapter)
async_futures = handler.emit(dummy_log_record)
[future.result() for future in async_futures]
assert len(http_adapter.requests) == 1
request = http_adapter.requests[0]
assert request.headers['Authorization'] == 'Basic %s' % base64.b64encode(
"user:pass")
def test_https_logging_handler_emit_without_cred(https_adapter,
dummy_log_record,
message_type):
handler = HTTPSHandler(host='127.0.0.1', message_type=message_type)
handler.setFormatter(LogstashFormatter())
handler.session.mount('https://', https_adapter)
async_futures = handler.emit(dummy_log_record)
[future.result() for future in async_futures]
assert len(https_adapter.requests) == 1
request = https_adapter.requests[0]
assert request.url == 'https://127.0.0.1/'
assert request.method == 'POST'
if message_type == 'logstash':
# A username + password weren't used, so this header should be missing
assert 'Authorization' not in request.headers
if message_type == 'splunk':
assert request.headers['Authorization'] == 'Splunk None'
def perform_test(cls, settings):
"""
Tests logging connectivity for the current logging settings.
@raises LoggingConnectivityException
"""
handler = cls.from_django_settings(settings)
handler.enabled_flag = True
handler.setFormatter(LogstashFormatter(settings_module=settings))
logger = logging.getLogger(__file__)
fn, lno, func = logger.findCaller()
record = logger.makeRecord('awx', 10, fn, lno, 'AWX Connection Test',
tuple(), None, func)
futures = handler.emit(record)
for future in futures:
try:
resp = future.result()
if not resp.ok:
raise LoggingConnectivityException(': '.join(
[str(resp.status_code), resp.reason or '']))
except RequestException as e:
raise LoggingConnectivityException(str(e))
