Firewall Log Display Descriptions Performance
-
Status: System logs: Settings Filter descriptions Dont load descriptions Display as column Display as second row Show the applied rule description below or in the firewall log rows. Displaying rule descriptions for all lines in the log might affect performance with large rule sets.Has anyone looked into the code to see if is an optimization opportunity for displaying the rule descriptions?
-
What triggers the existence of /tmp/rules.debug? It's existence causes extra debug code to execute in /etc/inc/filter_log.inc resulting in a noticable performance hit to Status: System logs: Firewall processing when there is a decent amount of firewall rules. Removing the file makes a very noticeable difference.
The timestamp on the file would indicate that it is created during start up.
There is a bunch of stuff in the file. What is it used for and is it needed? What will removing it affect?
-
The actual firewall log does not have rule descriptions, but does have the tracker id number of each rule.
rules.debug has a list of all the stuff in the rule set, including tracker id and description.
If you ask for rule descriptions to be displayed, then the GUI code reads rules.debug and builds an array of tracker id number to rule description. Then that array is used to lookup the description of each rule tracker id from the firewall log.I am a bit surprised that there is much of a performance. But I suppose if you have many, many rules then it will take time to read through rules.debug.
The alternative is to read through $config rules section and build the tracker id to description lookup array from there not sure if that would have much performance difference?
-
I'm getting the rule descriptions and tracker id even without the /tmp/rules.debug file. I seem to recall seeing a comment some where in the recent past about the rule descriptions being included.
The performance difference seems to be between these two commands. Reading the rules from the file is much slower. Taking about 2-3 seconds. While the other is nearly instant (imperceptible). You can run them from the command prompt and if you have enough rules you should be able to notice the difference.
/sbin/pfctl -vvPnf /tmp/rules.debug (about 22KB)
/sbin/pfctl -vvPsr (about 44KB)
What really puzzles me is that supposedly my /tmp is in ramdisk. So I'd think it would be just as fast maybe even faster.
-
For a comparison I placed rules.debug in a non ramdisk location and it has the same lack of performance but no worse.
Makes me wonder if /tmp really is in ramdisk. Dashboard says it is but how can I verify it?
/tmp (ufs in RAM): 3% of 116M
The main disk is this system is a USB flash drive (USB 2.0). So disk access performance is noticeable. But I would expect the ramdisk to be speedy.
Another data point. cat is just as fast on both (nearly instant). So it seems to have something to do with pfctl file access.
-
The rule descriptions are not included in the filter.log, so they would have to come from somewhere (config, rules.debug, pfctl output, etc)
Usually pfctl is used because it also gives the rule ID which is used for matching descriptions in cases where the tracker ID is not present for one reason or another.
The performance hit for descriptions is why the option defaults to off, though. It's expected that there will be an added delay with larger rulesets and/or large amounts of log data (e.g. set the limit to 1000+ lines)
-
The rule descriptions are not included in the filter.log, so they would have to come from somewhere (config, rules.debug, pfctl output, etc)
Right. pfctl -vvPsr includes the rule descriptions and is much faster than pfctl -vvPnf /tmp/rules.debug. About 2.5 seconds with my 22KB ~300 lines rules.debug file (supposedly in /tmp ramdisk). Nearly instant with pfctl -vvPsr.
Usually pfctl is used because it also gives the rule ID which is used for matching descriptions in cases where the tracker ID is not present for one reason or another.
Such as?
The performance hit for descriptions is why the option defaults to off, though.
Fine. No issue with what the default is.
It's expected that there will be an added delay with larger rulesets and/or large amounts of log data (e.g. set the limit to 1000+ lines)
This specific added delay is solely related to the number of rulesets. Is only experienced with reading from the rules.debug file (pfctl -vvPnf /tmp/rules.debug). The log data is not involved with that. Even if the log data were involved, clear the logs and the delay is still there. So size of log data is not relevant to the performance of the pfctl -vvPnf /tmp/rules.debug command that is being executed. Seemingly needlessly.
-
Right. pfctl -vvPsr includes the rule descriptions and is much faster than pfctl -vvPnf /tmp/rules.debug. About 2.5 seconds with my 22KB ~300 lines rules.debug file (supposedly in /tmp ramdisk). Nearly instant with pfctl -vvPsr.
It probably reloads from the file to be certain the data is current/accurate. I doubt the disk speed has anything to do with it. Reading a file that small would be fast no matter where it is, but processing it may not be.
Maybe you somehow have a hostname directly in there so it's forced to do DNS resolution? I'd be looking more into why your rules are loading slow than looking at it from a logging perspective.
Such as?
Rules without a tracker ID, rules inserted by things that don't support tracker IDs, and others I'm probably forgetting.
This specific added delay is solely related to the number of rulesets. Is only experienced with reading from the rules.debug file (pfctl -vvPnf /tmp/rules.debug). The log data is not involved with that. Even if the log data were involved, clear the logs and the delay is still there. So size of log data is not relevant to the performance of the pfctl -vvPnf /tmp/rules.debug command that is being executed. Seemingly needlessly.
I was speaking generally about its performance. Clearly the problem in your case is the rules loading slowly completely independently of the log processing, so you're chasing a red herring here.
-
These three lines cause noticable delay with the pfctl -vvPnf /tmp/rules.debug command.
The first one is common pfSense:
table <bogonsv6>persist file "/etc/bogonsv6" (about 1/2 second to process)The second two are custom to my config.
table <bogons_ipv6>persist file "/var/db/aliastables/Bogons_IPv6.txt" (about 1/2 second to process)
table <cipb_united_states_networks>persist file "/var/db/aliastables/CIPB_United_States_Networks.txt" (about 1 second to process)Then all the smaller ones for IPv4 etc add about another second.
Unless this pfctl -vvPnf /tmp/rules.debug method is necessary it should be avoided rather than being the default. Only use it if needed info is missing rather than always.</cipb_united_states_networks></bogons_ipv6></bogonsv6>
-
What would be the implications of eliminating table "persist file" lines from the pfctl -vvPnf input in these two /etc/inc/filter_log.inc functions?
function find_rule_by_number($rulenum, $trackernum, $type="block") {
function buffer_rules_load() {grep -v "persist file" /tmp/rules.debug | /sbin/pfctl -vvPnf -
Speeds it right up.
