Should I be using Unbound Python mode? Is it stable?
-
Update:
Last night I changed my pfB config from Unbound Python mode back to Unbound and immediately saw my disk usage (ufs) drop from 76% to 46%. This would appear to confirm that pfB Python mode was responsible for the excessive disk usage and that it is not ready for prime time yet... I don't have the time to be a Beta tester right now so I will have to wait this one out.
Unfortunately, with pfB Unbound mode, I'm back to no logging on the DNSBL count: 0 log entries logged since changing back to Unbound mode (Firewall/pfBlockerNG/Alerts/DNSBL Block). I started a thread about this a few months ago:
[https://forum.netgate.com/topic/164252/pfblockerng-devel-dnsbl-not-working-after-21-05-upgrade](link url)Hopefully in the next few months we will see a new version of pfBlockerng-devel that will address these issues.
-
@azdeltawye said in Should I be using Unbound Python mode? Is it stable?:
Update:
Last night I changed my pfB config from Unbound Python mode back to Unbound and immediately saw my disk usage (ufs) drop from 76% to 46%. This would appear to confirm that pfB Python mode was responsible for the excessive disk usage and that it is not ready for prime time yet... I don't have the time to be a Beta tester right now so I will have to wait this one out.
Unfortunately, with pfB Unbound mode, I'm back to no logging on the DNSBL count: 0 log entries logged since changing back to Unbound mode (Firewall/pfBlockerNG/Alerts/DNSBL Block). I started a thread about this a few months ago:
[https://forum.netgate.com/topic/164252/pfblockerng-devel-dnsbl-not-working-after-21-05-upgrade](link url)Hopefully in the next few months we will see a new version of pfBlockerng-devel that will address these issues.
Yeah, that issue certainly needs a fix - as does the sustained temporary writing to disk.
It would be such a shame if pfBlockerNG got a reputation for killing the small SG-xxxx boxes with very small eMMC’s and SSD’s because of wear.I hope @BBcan177 will return at some point and have a look at this tread. I’d be happy to help/provide additional data in identifying the source of the problem.
-
The reason why "Python mode" was invented, is spread out all over the forum, but the basic explanation is : people want more details, faster details, and more DNSBL control.
Also : faster unbound restart.The classic unbound log capabilities are not enough.
Even if you crank this one up to level 5 :
The needed info wouldn't be there.
But, just for fun, do it for yourself, activate level 5 unbound logging.
And keep an eye on this file /var/log/resolver.log
It will EAT your disk space - and as said, the needed info still sin't there.Also : log file parsing is slow. The python mode uses 'pre complied' code and is thus much faster.
Another major advantage is that unbound doesn't need to load in these mega byte size DNSBL feeds at restart. The python scripts parses these files now.The bottom line is : want DNSBL ? Throw resources on it. Or trim it down (use less feeds). And if you have less head room, keep watching for that ceiling.
-
@gertjan said in Should I be using Unbound Python mode? Is it stable?:
The bottom line is : want DNSBL ? Throw resources on it. Or trim it down (use less feeds). And if you have less head room, keep watching for that ceiling.
I do not disagree, And it does just that.
But you cannot argue that it should just fill the disk consistently (with no usable and asked for data) and it needs manual intervention, to regain your diskspace.
Also, you cannot argue there is a point in sustained writing to the disk with 100KB - 400KB/s when it’s data that is not stored for a reason (and asked for). That kind of dataflow should be kept in memory - if not for keeping the flash disk alive, then at least for the added speed and less use of ressources.
-
@keyser said in Should I be using Unbound Python mode? Is it stable?:
But you cannot argue that it should just fill the disk consistently (with no usable and asked for data) and it needs manual intervention, to regain your diskspace.
I showed above how "the data" is limited in size.
See here.
Conclusion : I don't have to do things manually.You work with RAM drives, right ?
Do you mean the log files aren't shortened in size by itself ?My files in /var/unbound/var/log/pfblockerng/ do grow also - of course.
Up until a certain point in time.
En when this event (the CRON delay) arrives, they are clipped to 40000 lines each.
So, these log files do not grow indefinitely.
Yours do ? Maybe a bug when RAM disks are used ?The files are not useless, they are used to build charts like these :
( which I tend to find a bit useless, I agree ^^ )
@keyser said in Should I be using Unbound Python mode? Is it stable?:
Also, you cannot argue there is a point in sustained writing to the disk with 100KB - 400KB/s when it’s data that is not stored for a reason (and asked for). That kind of data flow should be kept in memory - if not for keeping the flash disk alive, then at least for the added speed and less use of resources.
I got your point of view.
My hardware choice includes, amongs others, the storage aspect.Although my latest "Office PC" has only SSD drives, and it will (should ?!) last for some 4 to 5 years, and this is "Windows 10 Pro" driving it with a lot more as "100KB - 400KB/s".
-
@gertjan
The writing is not data that is put into the various log files to make up charts and what not. It’s not data that is used anywhere - it’s not persistent. None of my logfiles are growing - nor recieving new data (since I disabled all logging possible). I got the writing down to 150KB/s by removing a lot of DNS requests to Unbound. The 13Gb data currently written pr day by Unbound is not logged ANYWHERE - my 8Gb eMMC is 28% allocated consistently, and the logfiles contains way old data since nothing new is added to them.And no, my logfiles - with one exception - are not growing indefinitely, they are truncated just fine around the 20.000 lines marker as configured. The one Log file that has been growing indefinitely on me a few times (when logging was enabled) is the DNS_reply.log, and it’s by no means consistens. It seems it takes som kind of event to make it “skip” truncation, after which it starts growing. Then it grows and grows until the drive is full - the CRON job does not truncate it either.
I’m not using RAM drives - I was asking if you did because you did not see the same writing (which I no longer believe is the case, after you posted your system doing 200KB/s on average).
I agree that 200Kb/s is not an issue with a large SSD or a HDD. It’s only on small <32Gb eMMC/SDD drives it will become an issue. But there it will become a MAJOR issue.
-
@keyser said in Should I be using Unbound Python mode? Is it stable?:
(which I no longer believe is the case, after you posted your system doing 200KB/s on average).
I've another - non unbound related - log file, created by the FreeRadius packaga.
As I'm having a lot of captive portal users right now - and I'm using Freeadius for authentication and accounting,I'm doing some SQL logging.
This file, 438 Mega right now, grows to several Gbytes each week.
I maintain this file myself.And I use of course unbound+pfblockerng+python and do some minimal DNSBL filtering, and that logs also a bit.
[2.5.2-RELEASE][admin@pfsense.my-network.net]/var/log: ls -alt total 123912 -rw------- 1 freeradius freeradius 966333577 Aug 26 09:23 radius.log.old -rw-r--r-- 1 root wheel 438136155 Aug 26 09:23 sqltrace.sql -rw------- 1 root wheel 10211784 Aug 26 09:23 routing.log -rw------- 1 root wheel 7683335 Aug 26 09:23 filter.log -rw------- 1 root wheel 867277 Aug 26 09:23 auth.log -rw------- 1 root wheel 6300375 Aug 26 09:23 nginx.log -rw------- 1 root wheel 264584 Aug 26 09:23 system.log -rw------- 1 root wheel 230106 Aug 26 09:22 utx.log -rw-r--r-- 1 root wheel 591 Aug 26 09:22 utx.lastlogin -rw------- 1 root wheel 7118905 Aug 26 09:22 dhcpd.log -rw------- 1 root wheel 228 Aug 26 09:22 openvpn.status -rw------- 1 freeradius freeradius 16128 Aug 26 09:21 radutmp -rw------- 1 root wheel 840027 Aug 26 08:57 portalauth.log -rw------- 1 root wheel 66114 Aug 26 07:57 openvpn.log@keyser said in Should I be using Unbound Python mode? Is it stable?:
It seems it takes som kind of event to make it “skip” truncation, after which it starts growing.
So, this part fails ( ? ) :
/usr/local/pkg/pfblockerng/pfblockerng.inc : line 623 : function pfb_logger($log, $logtype)For every file, with the tail command, the last "number of lines" (20 000 or whatever you selected) are taken and streamed into a newly created 'temp' file.
This temp file is moved (== renamed) to the original file, like dns_reply.log
De temporary file is deleted => ?????? ( this is awkward - if you rename a.log to b.log, and you delete then a.log, this should be a no op as a.log doesn't exist any more ).This function gets executed every pfblockerNG 'CRON' time.
What about placing some 'log' info into it - so it logs to "/var/log/pfblockerng/pfblockerng.log", with some info about what log file it found (the for each loop) like the file being handled etc.
See also (here : short cut ) :
the CRON job did get executed regularly ?
-
@gertjan
I have given up running the setup that suffers the "filling disk issue".
My Internet needs to be up, and I need to spend a little less troubleshooting time on pfBolckerNG.I have also probably used 90% of my eMMC's advertised endurance on very heavy sustained writing from pfBlockerNG
-
@keyser Hi! I hear you. I am suffering also from some weird behaviour of pfblockerng and I also made a post about it. I don't see bbcann177 anywhere for some time now. I hope he has not abandoned the project.
The main issues I have with it are that reliability of unbound seem to drop when pfblockerng is enabled. Also the disable dynamic hostname registration when pfblockerng is enabled in python mode is getting a little long in the tooth...would've expected a fix by now. I still use pfblockerng for ip blocking and I have setup an Aduard home server for my DNSBL needs. I suggest you do the same :). -
SG-1100 24% of 7.0GiB - ufs
I try Undound Mode overnight:Unbound [21.05.1-RELEASE][xxx]/root: iostat -x extended device statistics device r/s w/s kr/s kw/s ms/r ms/w ms/o ms/t qlen %b flash/sp 0 0 0.0 0.0 2 0 0 2 0 0 mmcsd0 0 2 7.0 75.0 4 10 0 9 0 1 mmcsd0bo 0 0 0.0 0.0 0 0 0 0 0 0 mmcsd0bo 0 0 0.0 0.0 0 0 0 0 0 0 md0 0 0 0.0 0.0 0 0 0 0 0 0 Unbound python mode [21.05.1-RELEASE][xxx]/root: iostat -x extended device statistics device r/s w/s kr/s kw/s ms/r ms/w ms/o ms/t qlen %b flash/sp 0 0 0.0 0.0 2 0 0 2 0 0 mmcsd0 0 1 3.0 31.1 2 8 0 7 0 0 mmcsd0bo 0 0 0.0 0.0 0 0 0 0 0 0 mmcsd0bo 0 0 0.0 0.0 0 0 0 0 0 0 md0 0 0 0.0 0.0 0 0 0 0 0 0It writes some more to the disk, so i got back to python mode this morning.
-
@nocling said in Should I be using Unbound Python mode? Is it stable?:
SG-1100 24% of 7.0GiB - ufs
I try Undound Mode overnight:Unbound [21.05.1-RELEASE][xxx]/root: iostat -x extended device statistics device r/s w/s kr/s kw/s ms/r ms/w ms/o ms/t qlen %b flash/sp 0 0 0.0 0.0 2 0 0 2 0 0 mmcsd0 0 2 7.0 75.0 4 10 0 9 0 1 mmcsd0bo 0 0 0.0 0.0 0 0 0 0 0 0 mmcsd0bo 0 0 0.0 0.0 0 0 0 0 0 0 md0 0 0 0.0 0.0 0 0 0 0 0 0 Unbound python mode [21.05.1-RELEASE][xxx]/root: iostat -x extended device statistics device r/s w/s kr/s kw/s ms/r ms/w ms/o ms/t qlen %b flash/sp 0 0 0.0 0.0 2 0 0 2 0 0 mmcsd0 0 1 3.0 31.1 2 8 0 7 0 0 mmcsd0bo 0 0 0.0 0.0 0 0 0 0 0 0 mmcsd0bo 0 0 0.0 0.0 0 0 0 0 0 0 md0 0 0 0.0 0.0 0 0 0 0 0 0It writes some more to the disk, so i got back to python mode this morning.
You can’t use “iostat -x” as a measure unless you have rebooted your pfsense and waited at least an hour or two. It displays statistics since last boot, and LOADS of factors impact that.
You need to do some monitoring while running with commands like: “iostat -d 5 6” and “top -m io”Love the no fuss of using the official appliances :-)
-
I Reboot after the Ubound change and the iostat was after 8-9h overnight and 12-14h overday.
-
@nocling Yes, but that is going to be one BADLY skewed statistics because that includes all the writes from a boot, reinitialise logs and reconfiguration sequence. So that number will become a lot less over the coming days/weeks as the boot/initialize proces starts to become less significant in the average calculation.
-
@keyser said in Should I be using Unbound Python mode? Is it stable?:
You can’t use “iostat -x” as a measure unless you have rebooted your pfsense and waited at least an hour or two. It displays statistics since last boot, and LOADS of factors impact that.
You need to do some monitoring while running with commands like: “iostat -d 5 6” and “top -m io”Sorry - that should have said “before you waited at least a week or two”
-
@keyser Hmm, seems the diskfilling issue is not resolved by disabling DNS reply logging after all.
It just fills very slowly now as I’m not really logging anything.
I’ll do a more proper investigation now to see if I can find where the lost diskspace really goes. None of my log files are “oversized” now, and no files have aqquired the currently lost 100Mb space pr. Week in increased filesize.
So there is an issue with some kind of leakage to the filesystem that is not commited as visible/cleared until pfBlockerNG is restarted.
-
A good chunk of the daily lost space happens when the pfBlockerNG CRON job runs.
-
Mine seems to be fine.. SG-3100 21.05.1 UFS with DNS Reply Logging disabled in DNSBL.. Python mode btw..
[21.05.1-RELEASE][xxx]/root: iostat -x extended device statistics device r/s w/s kr/s kw/s ms/r ms/w ms/o ms/t qlen %b flash/sp 0 0 0.0 0.0 7 0 0 7 0 0 mmcsd0 0 2 0.4 50.1 2 3 0 3 0 0 mmcsd0bo 0 0 0.0 0.0 0 0 0 0 0 0 mmcsd0bo 0 0 0.0 0.0 0 0 0 0 0 0 md0 0 0 0.0 0.0 0 0 0 0 0 0 [21.05.1-RELEASE][xxx]/root: uptime 5:32PM up 5 days, 4:41, 2 users, load averages: 0.24, 0.42, 0.41 -
I did some tests on a system with 60+ days uptime and setup unbound with python mode. This is what I see when running the iostat command:
extended device statistics device r/s w/s kr/s kw/s ms/r ms/w ms/o ms/t qlen %b md0 0 0 0.0 0.0 0 0 0 0 0 0 ada0 0 22 0.0 330.1 0 0 1 4 0 1 pass0 0 0 0.0 0.0 0 0 0 0 0 0Do I need to worry?
-
@vjizzle Depends om how large your Sata SSD is.
It’s doing 330Kb writes pr. Second on average. That’s:
0,33Mb * 60sec * 60min * 24hours * 365 days = 10.4TB/year
If your SSD is 128Gb or bigger, it’s probably not an issue. But if it’s 32Gb Id think about it. 16Gb or smaller and I’d be very worried.
-
@keyser It is 120GB m2 ssd so I am safe I hope. I saw on Reddit that bbcan177 released a patch for the growing files on disk. I hope he can tackle the frequent writes as well.
