Squashed commit of the following:

commit 46e0383625acfa59e723c390d0b5b2feed8a53aa
Author: Ad Schellevis <ad@opnsense.org>
Date:   Mon Aug 23 11:05:53 2021 +0200

    Firewall / Log - Live log : support rfc5424 format for https://github.com/opnsense/core/pull/5175

commit 0cf3030724d02181991436b324fe5fc70118d4d5
Author: Ad Schellevis <ad@opnsense.org>
Date:   Sat Aug 21 09:36:56 2021 +0200

    System logging - switch local logging to rfc5424 format.

    Allow custom destinations to choose for rfc5424. closes https://github.com/opnsense/core/issues/4911

commit a46e39bcecca6dab1d5a68a0e7f481ea42c16034
Author: Ad Schellevis <ad@opnsense.org>
Date:   Fri Aug 20 18:23:22 2021 +0200

    System logging - switch local logging to rfc5424 format.

    add severity filter to api and log pages

commit b0f38003d7745a01202ffca5e7b5b697ff211f1e
Author: Ad Schellevis <ad@opnsense.org>
Date:   Fri Aug 20 15:42:58 2021 +0200

    System logging - switch local logging to rfc5424 format.

    Split BaseLogFormat into a generic LogFormat and a child NewBaseLogFormat to be able to support both property and method based parsers to keep (external) plugins compatible.

commit 264513f148185faf4a4509bc19aa35739c9844f9
Author: Ad Schellevis <ad@opnsense.org>
Date:   Thu Aug 19 19:56:19 2021 +0200

    System logging - switch local logging to rfc5424 format.

    Refactor log parser (BaseLogFormat), since the plugins use this as well we might have to undo a bit or refactor those as well.
This commit is contained in:
Ad Schellevis 2021-08-23 13:15:51 +02:00
parent 6ebeb54fd6
commit 6cd8a97182
12 changed files with 278 additions and 64 deletions

View File

@ -43,6 +43,7 @@ class LogController extends ApiControllerBase
$scope = count($arguments) > 0 ? $arguments[0] : "";
$action = count($arguments) > 1 ? $arguments[1] : "";
$searchPhrase = '';
$severities = '';
// create filter to sanitize input data
$filter = new Filter([
'query' => function ($value) {
@ -64,9 +65,20 @@ class LogController extends ApiControllerBase
if ($this->request->getPost('searchPhrase', 'string', '') != "") {
$searchPhrase = $filter->sanitize($this->request->getPost('searchPhrase'), "query");
}
if ($this->request->getPost('severity', 'string', '') != "") {
$severities = $this->request->getPost('severity');
$severities = is_array($severities) ? implode(",", $severities) : $severities;
$severities = $filter->sanitize($severities, "query");
}
$response = $backend->configdpRun("system diag log", array($itemsPerPage,
($currentPage - 1) * $itemsPerPage, $searchPhrase, $module, $scope));
$response = $backend->configdpRun("system diag log", [
$itemsPerPage,
($currentPage - 1) * $itemsPerPage,
$searchPhrase,
$module,
$scope,
$severities
]);
$result = json_decode($response, true);
if ($result != null) {
$result['rowCount'] = count($result['rows']);
@ -80,7 +92,14 @@ class LogController extends ApiControllerBase
if ($this->request->get('searchPhrase', 'string', '') != "") {
$searchPhrase = $filter->sanitize($this->request->get('searchPhrase'), "query");
}
$response = $backend->configdpRun("system diag log", array(0, 0, $searchPhrase, $module, $scope));
if ($this->request->get('severity', 'string', '') != "") {
$severities = $this->request->get('severity');
$severities = is_array($severities) ? implode(",", $severities) : $severities;
$severities = $filter->sanitize($severities, "query");
}
$response = $backend->configdpRun("system diag log", [
0, 0, $searchPhrase, $module, $scope, $severities
]);
$this->response->setRawHeader("Content-Type: text/csv");
$this->response->setRawHeader("Content-Disposition: attachment; filename=" . $scope . ".log");
foreach (json_decode($response, true)['rows'] as $row) {

View File

@ -49,6 +49,12 @@
resource for tracking common issues.]]>
</help>
</field>
<field>
<id>destination.rfc5424</id>
<label>rfc5424</label>
<type>checkbox</type>
<help>Use rfc5424 formated messages for this destination.</help>
</field>
<field>
<id>destination.description</id>
<label>Description</label>

View File

@ -1,6 +1,6 @@
<model>
<mount>//OPNsense/Syslog</mount>
<version>1.0.0</version>
<version>1.0.1</version>
<items>
<general>
<enabled type="BooleanField">
@ -90,6 +90,10 @@
<Required>Y</Required>
<default>514</default>
</port>
<rfc5424 type="BooleanField">
<default>0</default>
<Required>Y</Required>
</rfc5424>
<description type="TextField">
<Required>N</Required>
</description>

View File

@ -34,7 +34,7 @@
rowCount:[20,50,100,200,500,1000,-1],
formatters:{
page: function (column, row) {
if ($("input.search-field").val() !== "") {
if ($("input.search-field").val() !== "" || $('#severity_filter').val().length > 0) {
return '<button type="button" class="btn btn-xs btn-default action-page bootgrid-tooltip" data-row-id="' +
row.rnum + '" title="{{ lang._('Go to page') }}"><span class="fa fa-arrow-right fa-fw"></span></button>';
} else {
@ -42,9 +42,18 @@
}
},
},
requestHandler: function(request){
if ( $('#severity_filter').val().length > 0) {
request['severity'] = $('#severity_filter').val();
}
return request;
},
},
search:'/api/diagnostics/log/{{module}}/{{scope}}'
});
$("#severity_filter").change(function(){
$('#grid-log').bootgrid('reload');
});
grid_log.on("loaded.rs.jquery.bootgrid", function(){
$(".action-page").click(function(event){
@ -52,6 +61,7 @@
$("#grid-log").bootgrid("search", "");
let new_page = parseInt((parseInt($(this).data('row-id')) / $("#grid-log").bootgrid("getRowCount")))+1;
$("input.search-field").val("");
$("#severity_filter").selectpicker('deselectAll');
// XXX: a bit ugly, but clearing the filter triggers a load event.
setTimeout(function(){
$("ul.pagination > li:last > a").data('page', new_page).click();
@ -83,12 +93,23 @@
// download (filtered) items
$("#exportbtn").click(function(event){
let download_link = "/api/diagnostics/log/{{module}}/{{scope}}/export";
let params = [];
if ($("input.search-field").val() !== "") {
download_link = download_link + "?searchPhrase=" + encodeURIComponent($("input.search-field").val());
params.push("searchPhrase=" + encodeURIComponent($("input.search-field").val()));
}
if ( $('#severity_filter').val().length > 0) {
params.push("severity=" + encodeURIComponent($('#severity_filter').val().join(",")));
}
if (params.length > 0) {
download_link = download_link + "?" + params.join("&");
}
$('<a></a>').attr('href',download_link).get(0).click();
});
updateServiceControlUI('{{service}}');
// move filter into action header
$("#severity_filter_container").detach().prependTo('#grid-log-header > .row > .actionBar > .actions');
});
</script>
@ -96,11 +117,29 @@
<div class="content-box-main">
<div class="table-responsive">
<div class="col-sm-12">
<div class="hidden">
<!-- filter per type container -->
<div id="severity_filter_container" class="btn-group">
<select id="severity_filter" data-title="{{ lang._('Severity') }}" class="selectpicker" multiple="multiple" data-width="200px">
<option value="Emergency">{{ lang._('Emergency') }}</option>
<option value="Alert">{{ lang._('Alert') }}</option>
<option value="Critical">{{ lang._('Critical') }}</option>
<option value="Error">{{ lang._('Error') }}</option>
<option value="Warning">{{ lang._('Warning') }}</option>
<option value="Notice">{{ lang._('Notice') }}</option>
<option value="Informational">{{ lang._('Informational') }}</option>
<option value="Debug">{{ lang._('Debug') }}</option>
</select>
</div>
</div>
<table id="grid-log" class="table table-condensed table-hover table-striped table-responsive" data-store-selection="true">
<thead>
<tr>
<th data-column-id="timestamp" data-width="11em" data-type="string">{{ lang._('Date') }}</th>
<th data-column-id="facility" data-type="string" data-visible="false">{{ lang._('Facility') }}</th>
<th data-column-id="severity" data-type="string" data-width="2em">{{ lang._('Severity') }}</th>
<th data-column-id="process_name" data-width="2em" data-type="string">{{ lang._('Process') }}</th>
<th data-column-id="pid" data-width="2em" data-type="numeric" data-visible="false">{{ lang._('PID') }}</th>
<th data-column-id="line" data-type="string">{{ lang._('Line') }}</th>
<th data-column-id="rnum" data-type="numeric" data-formatter="page" data-width="2em"></th>
</tr>

View File

@ -129,12 +129,21 @@ if __name__ == '__main__':
rule = dict()
metadata = dict()
# rule metadata (unique hash, hostname, timestamp)
log_ident = re.split('filterlog[^:]*:', record['line'])
tmp = log_ident[0].split()
if re.search('filterlog\[\d*\]:', record['line']):
# rfc3164 format
log_ident = re.split('filterlog[^:]*:', record['line'])
tmp = log_ident[0].split()
metadata['__host__'] = tmp.pop()
metadata['__timestamp__'] = ' '.join(tmp)
rulep = log_ident[1].strip().split(',')
else:
# rfc5424 format
tmp = record['line'].split()
metadata['__timestamp__'] = tmp[1].split('+')[0]
metadata['__host__'] = tmp[2]
rulep = tmp[-1].strip().split(',')
metadata['__digest__'] = md5(record['line'].encode()).hexdigest()
metadata['__host__'] = tmp.pop()
metadata['__timestamp__'] = ' '.join(tmp)
rulep = log_ident[1].strip().split(',')
update_rule(rule, metadata, rulep, fields_general)
if 'action' not in rule:

View File

@ -28,12 +28,16 @@ import glob
import importlib
import sys
class BaseLogFormat:
class LogFormat:
""" Log format handler
"""
def __init__(self, filename):
self._filename = filename
self._priority = 255
self._line = ""
def set_line(self, line):
self._line = line
@property
def name(self):
@ -51,6 +55,16 @@ class BaseLogFormat:
"""
return False
class BaseLogFormat(LogFormat):
""" Legacy log format handler
"""
@staticmethod
def match(line):
""" Does this formatter fit for the provided line
"""
return False
@staticmethod
def timestamp(line):
""" Extract timestamp from line
@ -70,6 +84,63 @@ class BaseLogFormat:
return ""
class NewBaseLogFormat(LogFormat):
""" log format handler
"""
@property
def timestamp(self):
""" Extract timestamp from line
"""
pass
@property
def line(self):
""" Return line (without timestamp)
"""
return line
@property
def process_name(self):
""" Return process name
"""
return ""
@property
def pid(self):
""" Return pid
"""
return None
@property
def facility(self):
""" syslog facility
"""
return None
@property
def severity(self):
""" syslog severity
"""
return None
@property
def severity_str(self):
severity = self.severity
options = {
0: 'Emergency',
1: 'Alert',
2: 'Critical',
3: 'Error',
4: 'Warning',
5: 'Notice',
6: 'Informational',
7: 'Debug'
}
if severity in options:
return options[severity]
return None
class FormatContainer:
def __init__(self, filename):
self._handlers = list()
@ -84,7 +155,8 @@ class FormatContainer:
for module_name in dir(sys.modules[__name__]):
for attribute_name in dir(getattr(sys.modules[__name__], module_name)):
cls = getattr(getattr(sys.modules[__name__], module_name), attribute_name)
if isinstance(cls, type) and issubclass(cls, BaseLogFormat) and cls != BaseLogFormat:
if isinstance(cls, type) and issubclass(cls, LogFormat)\
and cls not in (LogFormat, BaseLogFormat, NewBaseLogFormat):
all_handlers.append(cls(self._filename))
self._handlers = sorted(all_handlers, key=lambda k: k.prio)
@ -92,4 +164,5 @@ class FormatContainer:
def get_format(self, line):
for handler in self._handlers:
if handler.match(line):
handler.set_line(line)
return handler

View File

@ -25,12 +25,12 @@
"""
import re
import datetime
from . import BaseLogFormat
from . import NewBaseLogFormat
squid_ext_timeformat = r'.*(\[\d{1,2}/[A-Za-z]{3}/\d{4}:\d{1,2}:\d{1,2}:\d{1,2} \+\d{4}\]).*'
squid_timeformat = r'^(\d{4}/\d{1,2}/\d{1,2} \d{1,2}:\d{1,2}:\d{1,2}).*'
class SquidLogFormat(BaseLogFormat):
class SquidLogFormat(NewBaseLogFormat):
def __init__(self, filename):
super().__init__(filename)
self._priority = 100
@ -38,22 +38,22 @@ class SquidLogFormat(BaseLogFormat):
def match(self, line):
return self._filename.find('squid') > -1 and re.match(squid_timeformat, line) is not None
@staticmethod
def timestamp(line):
tmp = re.match(squid_timeformat, line)
@property
def timestamp(self):
tmp = re.match(squid_timeformat, self._line)
grp = tmp.group(1)
return datetime.datetime.strptime(grp, "%Y/%m/%d %H:%M:%S").isoformat()
@staticmethod
def process_name(line):
@property
def process_name(self):
return "squid"
@staticmethod
def line(line):
return line[19:].strip()
@property
def line(self):
return self._line[19:].strip()
class SquidExtLogFormat(BaseLogFormat):
class SquidExtLogFormat(NewBaseLogFormat):
def __init__(self, filename):
super().__init__(filename)
self._priority = 120
@ -61,24 +61,24 @@ class SquidExtLogFormat(BaseLogFormat):
def match(self, line):
return self._filename.find('squid') > -1 and re.match(squid_ext_timeformat, line) is not None
@staticmethod
def timestamp(line):
tmp = re.match(squid_ext_timeformat, line)
@property
def timestamp(self):
tmp = re.match(squid_ext_timeformat, self._line)
grp = tmp.group(1)
return datetime.datetime.strptime(grp[1:].split()[0], "%d/%b/%Y:%H:%M:%S").isoformat()
@staticmethod
def process_name(line):
@property
def process_name(self):
return "squid"
@staticmethod
def line(line):
tmp = re.match(squid_ext_timeformat, line)
@property
def line(self):
tmp = re.match(squid_ext_timeformat, self._line)
grp = tmp.group(1)
return line.replace(grp, '')
class SquidJsonLogFormat(BaseLogFormat):
class SquidJsonLogFormat(NewBaseLogFormat):
def __init__(self, filename):
super().__init__(filename)
self._priority = 140
@ -89,6 +89,7 @@ class SquidJsonLogFormat(BaseLogFormat):
def match(self, line):
return self._filename.find('squid') > -1 and line.find('"@timestamp"') > -1
@property
def timestamp(self, line):
tmp = line[line.find('"@timestamp"')+13:].split(',')[0].strip().strip('"')
try:
@ -97,10 +98,10 @@ class SquidJsonLogFormat(BaseLogFormat):
except ValueError:
return None
@staticmethod
def process_name(line):
@property
def process_name(self):
return "squid"
@staticmethod
def line(line):
return line
@property
def line(self):
return self._line

View File

@ -25,55 +25,96 @@
"""
import re
import datetime
from . import BaseLogFormat
from . import NewBaseLogFormat
class SysLogFormat(BaseLogFormat):
class SysLogFormat(NewBaseLogFormat):
def __init__(self, filename):
super(SysLogFormat, self).__init__(filename)
self._priority = 1
self._priority = 2
self._startup_timestamp = datetime.datetime.now()
@staticmethod
def match(line):
return len(line) > 15 and re.match(r'(?:[01]\d|2[0123]):(?:[012345]\d):(?:[012345]\d)', line[7:15])
def timestamp(self, line):
@property
def timestamp(self):
# syslog format, strip timestamp and return actual log data
ts = datetime.datetime.strptime("%s %s" % (self._startup_timestamp.year, line[0:15]), "%Y %b %d %H:%M:%S")
ts = datetime.datetime.strptime("%s %s" % (self._startup_timestamp.year, self._line[0:15]), "%Y %b %d %H:%M:%S")
ts = ts.replace(year=self._startup_timestamp.year)
if (self._startup_timestamp - ts).days < 0:
# likely previous year, (month for this year not reached yet)
ts = ts.replace(year=ts.year - 1)
return ts.isoformat()
@staticmethod
def line(line):
@property
def line(self):
# parse [date] [hostname] [process_name] [line] format
response = line[16:]
response = self._line[16:]
tmp = response.find(':')
return response[tmp+1:].strip() if tmp > -1 else response[response.find(' ')+1:].strip()
@staticmethod
def process_name(line):
response = line[16:]
@property
def process_name(self):
response = self._line[16:]
tmp = response.find(':')
return response[:tmp].strip().split()[-1] if tmp > -1 else ""
class SysLogFormatEpoch(BaseLogFormat):
class SysLogFormatEpoch(NewBaseLogFormat):
def __init__(self, filename):
super(SysLogFormatEpoch, self).__init__(filename)
self._priority = 2
self._priority = 3
@staticmethod
def match(line):
# looks like an epoch
return len(line) > 15 and line[0:10].isdigit() and line[10] == '.' and line[11:13].isdigit()
@staticmethod
def timestamp(line):
return datetime.datetime.fromtimestamp(float(line[0:13])).isoformat()
@property
def timestamp(self):
return datetime.datetime.fromtimestamp(float(self._line[0:13])).isoformat()
@property
def line(self):
return self._line[14:].strip()
class SysLogFormatRFC5424(NewBaseLogFormat):
def __init__(self, filename):
super().__init__(filename)
self._priority = 1
self._parts = list()
@staticmethod
def line(line):
return line[14:].strip()
def match(line):
return len(line) > 15 and line[0] == '<' and '>' in line[1:5] and line.find(']') > 0
def set_line(self, line):
super().set_line(line)
self._parts = self._line.split(maxsplit=5)
@property
def line(self):
return self._line.split(']', 1)[-1]
@property
def timestamp(self):
return self._parts[1].split('+', maxsplit=1)[0]
@property
def process_name(self):
return self._parts[3]
@property
def pid(self):
return self._parts[4]
@property
def facility(self):
return int(int(self._line[1:].split('>', 1)[0]) / 8)
@property
def severity(self):
tmp = int(self._line[1:].split('>', 1)[0])
return tmp - (int((tmp / 8)) * 8)

View File

@ -37,7 +37,7 @@ import sre_constants
import ujson
import datetime
import glob
from logformats import FormatContainer
from logformats import FormatContainer, BaseLogFormat
sys.path.insert(0, "/usr/local/opnsense/site-python")
from log_helper import reverse_log_reader, fetch_clog
import argparse
@ -51,6 +51,7 @@ if __name__ == '__main__':
parser.add_argument('--offset', help='begin at row number', default='')
parser.add_argument('--filename', help='log file name (excluding .log extension)', default='')
parser.add_argument('--module', help='module', default='core')
parser.add_argument('--severity', help='comma separated list of severities', default='')
inputargs = parser.parse_args()
result = {'filters': inputargs.filter, 'rows': [], 'total_rows': 0, 'origin': os.path.basename(inputargs.filename)}
@ -64,7 +65,8 @@ if __name__ == '__main__':
)
if os.path.isdir(log_basename):
# new syslog-ng local targets use an extra directory level
for filename in sorted(glob.glob("%s/%s_*.log" % (log_basename, log_basename.split('/')[-1].split('.')[0])), reverse=True):
filenames = glob.glob("%s/%s_*.log" % (log_basename, log_basename.split('/')[-1].split('.')[0]))
for filename in sorted(filenames, reverse=True):
log_filenames.append(filename)
# legacy log output is always stiched last
log_filenames.append("%s.log" % log_basename)
@ -73,6 +75,7 @@ if __name__ == '__main__':
limit = int(inputargs.limit) if inputargs.limit.isdigit() else 0
offset = int(inputargs.offset) if inputargs.offset.isdigit() else 0
severity = inputargs.severity.split(',') if inputargs.severity.strip() != '' else []
try:
filter = inputargs.filter.replace('*', '.*').lower()
if filter.find('*') == -1:
@ -99,18 +102,32 @@ if __name__ == '__main__':
record = {
'timestamp': None,
'parser': None,
'facility': 1,
'severity': 3,
'process_name': '',
'pid': None,
'rnum': row_number
}
frmt = format_container.get_format(rec['line'])
if frmt:
record['timestamp'] = frmt.timestamp(rec['line'])
record['process_name'] = frmt.process_name(rec['line'])
record['line'] = frmt.line(rec['line'])
record['parser'] = frmt.name
if issubclass(frmt.__class__, BaseLogFormat):
# backwards compatibility, old style log handler
record['timestamp'] = frmt.timestamp(rec['line'])
record['process_name'] = frmt.process_name(rec['line'])
record['line'] = frmt.line(rec['line'])
record['parser'] = frmt.name
else:
record['timestamp'] = frmt.timestamp
record['process_name'] = frmt.process_name
record['pid'] = frmt.pid
record['facility'] = frmt.facility
record['severity'] = frmt.severity_str
record['line'] = frmt.line
record['parser'] = frmt.name
else:
record['line'] = rec['line']
result['rows'].append(record)
if len(severity) == 0 or record['severity'] in severity:
result['rows'].append(record)
elif limit > 0 and result['total_rows'] > offset + limit:
# do not fetch data until end of file...
break

View File

@ -6,7 +6,7 @@ message:Show system activity
[diag.log]
command:/usr/local/opnsense/scripts/systemhealth/queryLog.py
parameters:--limit %s --offset %s --filter %s --module %s --filename %s
parameters:--limit %s --offset %s --filter %s --module %s --filename %s --severity %s
type:script_output
message:Show log

View File

@ -28,6 +28,9 @@ destination d_{{dest_key}} {
transport("{{destination.transport[:3]}}")
port({{destination.port}})
ip-protocol({{destination.transport[3]}})
{% if destination.rfc5424|default('0') == '1' %}
flags(syslog-protocol)
{% endif %}
persist-name("{{dest_key}}")
);
{% elif destination.transport in ['tls4', 'tls6'] %}

View File

@ -14,6 +14,7 @@ destination d_local_{{ local_config }} {
file(
"/var/log/{{local_config.replace('_', '/')}}/{{local_config.split('_')[-1]}}_${YEAR}${MONTH}${DAY}.log"
create-dirs(yes)
flags(syslog-protocol)
);
};
log {
@ -36,6 +37,7 @@ destination d_local_system {
file(
"/var/log/system/system_${YEAR}${MONTH}${DAY}.log"
create-dirs(yes)
flags(syslog-protocol)
);
};