def test_request_is_https_false(self):
"""Check that if a log line does not contains the SSL port on it, is
not reported as a https connection.
"""
self.http_request = 'GET /domain:80/to/image HTTP/1.1'
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertTrue(log_line.valid)
self.assertFalse(log_line.is_https())
def test_request_is_https_false(self):
"""Check that if a log line does not contains the SSL port on it, is
not reported as a https connection.
"""
self.http_request = 'GET /domain:80/to/image HTTP/1.1'
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertTrue(log_line.valid)
self.assertFalse(log_line.is_https())
def test_filter_status_code(self):
"""Test that the status_code filter works as expected."""
filter_func = filters.filter_status_code('404')
self.status = '404'
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertTrue(filter_func(log_line))
self.status = '200'
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertFalse(filter_func(log_line))
def test_dot_on_process_name(self):
"""Checks that process names can have a dot on it"""
self.process_name_and_pid = 'localhost.localdomain haproxy[2345]:'
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertTrue(log_line.valid)
def test_filter_response_size(self):
"""Test that the size filter works as expected."""
# does not matter if the filter parameter has a leading sign plus
# or not, it should return the same results.
filter_func_1 = filters.filter_response_size('400')
filter_func_2 = filters.filter_response_size('+400')
results_1 = []
results_2 = []
for size in (
'300',
'+399',
'+598',
'401',
):
self.bytes = size
raw_line = self._build_test_string()
log_line = Line(raw_line)
results_1.append(filter_func_1(log_line))
results_2.append(filter_func_2(log_line))
self.assertEqual(results_1, [
False,
False,
True,
True,
])
self.assertEqual(results_1, results_2)
def test_unused_values(self):
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertEqual(log_line.captured_request_cookie, None)
self.assertEqual(log_line.captured_response_cookie, None)
self.assertEqual(log_line.termination_state, None)
def test_nixos_syslog(self):
"""Check that the NixOS timestamp at the beginning can also be parsed
"""
self.syslog_date = '2017-07-06T14:29:39+02:00'
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertTrue(log_line.valid)
def test_unparseable_http_request(self):
self.http_request = 'something'
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertEqual(log_line.http_request_method, 'invalid')
self.assertEqual(log_line.http_request_path, 'invalid')
self.assertEqual(log_line.http_request_protocol, 'invalid')
def test_invalid(self):
"""Check that if a log line can not be parsed with the regular
expression, 'valid' is False.
"""
self.bytes = 'wrooooong'
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertFalse(log_line.valid)
def test_no_captured_headers(self):
"""Check that if a log line does not have any captured headers, the
line is still valid.
"""
self.headers = ''
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertTrue(log_line.valid)
def test_strip_syslog_valid_hostname_slug(self):
"""Checks that if the hostname added to syslog slug is still valid
line
"""
self.http_request = 'GET / HTTP/1.1'
self.process_name_and_pid = 'ip-192-168-1-1 haproxy[28029]:'
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertTrue(log_line.valid)
def test_request_is_front_page(self):
"""Check that if a request is for the front page the request path is
correctly stored.
"""
self.http_request = 'GET / HTTP/1.1'
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertTrue(log_line.valid)
self.assertEqual('/', log_line.http_request_path)
def test_http_request_values(self):
method = 'GET'
path = '/path/to/image'
protocol = 'HTTP/1.1'
self.http_request = '{0} {1} {2}'.format(method, path, protocol)
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertEqual(log_line.http_request_method, method)
self.assertEqual(log_line.http_request_path, path)
self.assertEqual(log_line.http_request_protocol, protocol)
def test_filter_http_method(self):
"""Test that the http_method filter works as expected."""
filter_func = filters.filter_http_method('GET')
results = []
for http_method in ('GET', 'POST', 'PUT', 'GET'):
self.http_request = '{0} /something HTTP/1.1'.format(http_method)
raw_line = self._build_test_string()
log_line = Line(raw_line)
results.append(filter_func(log_line))
self.assertEqual(results, [True, False, False, True])
def test_filter_status_code_family(self):
"""Test that the status_code_family filter works as expected."""
filter_func = filters.filter_status_code_family('4')
results = []
for status in ('404', '503', '401'):
self.status = status
raw_line = self._build_test_string()
log_line = Line(raw_line)
results.append(filter_func(log_line))
self.assertEqual(results, [True, False, True])
def test_filter_backend(self):
"""Test that the backend filter works as expected."""
filter_func = filters.filter_backend('default')
results = []
for backend_name in ('default', 'anonymous', 'registered'):
self.backend_name = backend_name
raw_line = self._build_test_string()
log_line = Line(raw_line)
results.append(filter_func(log_line))
self.assertEqual(results, [True, False, False])
def test_filter_frontend(self):
"""Test that the frontend filter works as expected."""
filter_func = filters.filter_frontend('loadbalancer')
results = []
for frontend_name in ('loadbalancer', 'other', 'loadbalancer'):
self.frontend_name = frontend_name
raw_line = self._build_test_string()
log_line = Line(raw_line)
results.append(filter_func(log_line))
self.assertEqual(results, [True, False, True])
def test_filter_server(self):
"""Test that the server filter works as expected."""
filter_func = filters.filter_server('instance8')
results = []
for server_name in ('instance7', 'instance', 'instance8'):
self.server_name = server_name
raw_line = self._build_test_string()
log_line = Line(raw_line)
results.append(filter_func(log_line))
self.assertEqual(results, [False, False, True])
def test_request_and_response_captured_headers(self):
"""Check that if a log line does have both request and response headers
captured, both are parsed correctly.
"""
request_headers = '{something}'
response_headers = '{something_else}'
self.headers = ' {0} {1}'.format(request_headers, response_headers)
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertTrue(log_line.valid)
self.assertEqual(log_line.captured_request_headers, request_headers)
self.assertEqual(log_line.captured_response_headers, response_headers)
def test_filter_wait_on_queues(self):
"""Check that filter_wait_on_queues filter works as expected"""
filter_func = filters.filter_wait_on_queues('50')
results = []
for waiting_time in (45, 13000, 4566):
self.tw = waiting_time
raw_line = self._build_test_string()
log_line = Line(raw_line)
results.append(filter_func(log_line))
self.assertEqual(results, [True, False, False])
def test_filter_slow_requests(self):
"""Check that filter_slow_requests filter works as expected."""
filter_func = filters.filter_slow_requests('10000')
results = []
for response_time in (45, 13000, 4566):
self.tr = response_time
raw_line = self._build_test_string()
log_line = Line(raw_line)
results.append(filter_func(log_line))
self.assertEqual(results, [False, True, False])
def test_filter_ip(self):
"""Check that filter_ip filter works as expected."""
ip_one = '1.2.3.4'
ip_two = '2.3.4.5'
self.headers = ' {{{0}}} '.format(ip_one)
raw_line = self._build_test_string()
log_line = Line(raw_line)
filter_func_ip_one = filters.filter_ip(ip_one)
filter_func_ip_two = filters.filter_ip(ip_two)
self.assertTrue(filter_func_ip_one(log_line))
self.assertFalse(filter_func_ip_two(log_line))
def test_filter_ip_range(self):
"""Check that filter_ip_range filter works as expected."""
filter_func = filters.filter_ip_range('1.2.3')
ips = ('1.2.3.4', '2.3.4.5', '1.2.3.6')
results = []
for ip in ips:
self.headers = ' {{{0}}} '.format(ip)
raw_line = self._build_test_string()
log_line = Line(raw_line)
results.append(filter_func(log_line))
self.assertEqual(results, [True, False, True])
def parse_data(self, logfile):
"""Parse data from data stream and replace object lines.
:param logfile: [required] Log file data stream.
:type logfile: str
"""
for line in logfile:
stripped_line = line.strip()
parsed_line = Line(stripped_line)
if parsed_line.valid:
self._valid_lines.append(parsed_line)
else:
self._invalid_lines.append(stripped_line)
self.total_lines = len(self._valid_lines) + len(self._invalid_lines)
def test_filter_ssl(self):
"""Check that filter_path filter works as expected."""
filter_func = filters.filter_ssl()
method = 'GET'
protocol = 'HTTP/1.1'
paths = ('/ssl_path:443/image', '/something/else', '/another:443/ssl')
results = []
for path in paths:
self.http_request = '{0} {1} {2}'.format(method, path, protocol)
raw_line = self._build_test_string()
log_line = Line(raw_line)
results.append(filter_func(log_line))
self.assertEqual(results, [True, False, True])
def __call__(self, *args, **kwargs):
self.data.update(**kwargs)
self.data['client_ip_and_port'] = '{client_ip}:{client_port}'.format(
**self.data)
self.data[
'server_names'] = '{frontend_name} {backend_name}/{server_name}'.format(
**self.data)
self.data['timers'] = '{tq}/{tw}/{tc}/{tr}/{tt}'.format(**self.data)
self.data['status_and_bytes'] = '{status} {bytes}'.format(**self.data)
self.data[
'connections_and_retries'] = '{act}/{fe}/{be}/{srv}/{retries}'.format(
**self.data)
self.data['queues'] = '{queue_server}/{queue_backend}'.format(
**self.data)
log_line = self.line_format.format(**self.data)
return Line(log_line)
def test_filter_time_frame_start_and_delta(self):
"""Test that if empty strings are passed to filter_time_frame all log
lines are accepted.
"""
filter_func = filters.filter_time_frame('29/Jun/2012:15', '30m')
results = []
for accept_date in (
'09/Dec/2013:10:53:42.33',
'19/Jan/2014:12:39:16.63',
'29/Jun/2012:15:27:23.66',
):
self.accept_date = accept_date
raw_line = self._build_test_string()
log_line = Line(raw_line)
results.append(filter_func(log_line))
self.assertEqual(results, [False, False, True])
def test_default_values(self):
raw_line = self._build_test_string()
log_line = Line(raw_line)
self.assertEqual(raw_line, log_line.raw_line)
self.assertEqual(self.client_ip, log_line.client_ip)
self.assertEqual(self.client_port, log_line.client_port)
self.assertTrue(log_line.raw_accept_date in self.accept_date)
self.assertEqual(self.frontend_name, log_line.frontend_name)
self.assertEqual(self.backend_name, log_line.backend_name)
self.assertEqual(self.server_name, log_line.server_name)
self.assertEqual(self.tq, log_line.time_wait_request)
self.assertEqual(self.tw, log_line.time_wait_queues)
self.assertEqual(self.tc, log_line.time_connect_server)
self.assertEqual(self.tr, log_line.time_wait_response)
self.assertEqual(self.tt, log_line.total_time)
self.assertEqual(self.status, log_line.status_code)
self.assertEqual(self.bytes, log_line.bytes_read)
self.assertEqual(self.act, log_line.connections_active)
self.assertEqual(self.fe, log_line.connections_frontend)
self.assertEqual(self.be, log_line.connections_backend)
self.assertEqual(self.srv, log_line.connections_server)
self.assertEqual(self.retries, log_line.retries)
self.assertEqual(self.queue_server, log_line.queue_server)
self.assertEqual(self.queue_backend, log_line.queue_backend)
self.assertEqual(
self.headers.strip(),
log_line.captured_request_headers,
)
self.assertEqual(None, log_line.captured_response_headers)
self.assertEqual(self.http_request, log_line.raw_http_request)
self.assertTrue(log_line.valid)
def update_metrics(self, raw_line):
try:
raw_line = JOURNAL_REGEX.sub('', raw_line.strip())
line = Line(raw_line.strip())
except Exception as e:
self.processing_errors.inc()
logging.exception("%s (line parsing error): %s" % (e, raw_line))
return
if not line.valid:
self.processing_errors.inc()
logging.debug("Failed to parse line: %s" % raw_line)
return
try:
for metric_updater in self.metric_updaters:
metric_updater(line)
except Exception as e:
self.processing_errors.inc()
logging.exception("%s (error updating metrics): %s" %
(e, raw_line))
def test_timer(log_content):
expected = {
"haproxy_log_session_duration_milliseconds_count": {
"cache.api.finn.no-backend": 11.0,
"statistics": 2.0
},
"haproxy_log_session_duration_milliseconds_sum": {
"cache.api.finn.no-backend": 19.0,
"statistics": 0.0
}
}
t = timer("session_duration_milliseconds",
["frontend_name", "backend_name"], DEFAULT_TIMER_BUCKETS)
for raw_line in log_content.splitlines():
raw_line = JOURNAL_REGEX.sub('', raw_line.strip())
line = Line(raw_line.strip())
if line.valid:
t(line)
for metric in REGISTRY.collect():
for name, labels, value in metric.samples:
if name in expected:
assert value == expected[name][labels["backend_name"]]
def __call__(self, *args, **kwargs):
self.data.update(**kwargs)
self.data['client_ip_and_port'] = '{client_ip}:{client_port}'.format(
**self.data)
self.data[
'http_server_names'] = '{http_frontend_name} {http_backend_name}/{http_server_name}'.format(
**self.data)
self.data[
'tcp_server_names'] = '{tcp_frontend_name} {tcp_backend_name}/{tcp_server_name}'.format(
**self.data)
self.data['http_timers'] = '{Tq}/{Tw}/{Tc}/{Tr}/{Ta}'.format(
**self.data)
self.data['tcp_timers'] = '{Tw}/{Tc}/{Tt}'.format(**self.data)
self.data[
'http_status_and_bytes'] = '{http_status_code} {http_bytes_read}'.format(
**self.data)
self.data['tcp_bytes_read'] = self.data['tcp_bytes_read']
self.data[
'connections_and_retries'] = '{actconn}/{feconn}/{beconn}/{srv_conn}/{retries}'.format(
**self.data)
self.data['queues'] = '{srv_queue}/{backend_queue}'.format(**self.data)
log_line = self.line_format.format(**self.data)
return Line(log_line)
