IXFR not working - Githubissues

realbugi commented 2 years ago

I'm trying to make ioc2rpz work with pdns recursors for IXFR rpz updates. Unfortunately pdns recursor is not getting any updates - sees new zone but it's empty. I have checked results with dig and they are empty too.

I don't know if that's related (I don't know erl) but I saw that ./db directory is always empty even if I change include/ioc2rpz.hrl variable SaveETS to true.

ioc2rpz is build from scratch from master branch.

ioc2rpz log after adding new line (not present before) to test.list source file:

loading hot sources []
Start incremental update Zone "test.rpz" serial 1637788440 full refresh time 60, Ctime 1637788512 cache <<"true">> status ready
Process PID <0.1217.0> incremental update "test.rpz" started
Updating zone "test.rpz" inc. Last IXFR update 60 seconds ago, last non-zero update 60 seconds ago
Source: "test", size: 2.73/MB (2858273), MD5: "5cfad58ebb171b53688713f9a66dd47e"
Source: "test", got 67817 indicators, clean time 0
Memory total 1420.3366088867188 before garbage collector. processes 231.7139129638672 binary 388.9349365234375
Memory total 1411.8892288208008 after garbage collector. processes 226.90637969970703 binary 385.6593704223633
Fetching zone "test.rpz" from ets
Finding new or updated records
Update ets. New 36806, DB 36805, Delta 1
Rebuilding AXFR zone "test.rpz". New IOCs 1
Zone "test.rpz", # of rules 73612, # of IOCs 36806
AXFR zone "test.rpz" was rebuilded. 73612 rules 36806 indicators. Parsed 36806 indicators.
Zone "test.rpz" records before 36805 after 36806.
Process PID <0.1217.0> incremental update "test.rpz" finished in 0 seconds
ioc2rpz tcp6_sup child started
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000202|DNS Query|3|src=172.17.0.1 spt=46270 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN" tsigkey="tkey_1."
Found Key ... Good timestamp ... Valid MAC
Zone "test.rpz", 0 rules, 0 IOCs
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000201|RPZ transfer success|3|src=172.17.0.1 spt=46270 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN"  tsigkey="tkey_1." transfer_time=4175

dig results:

; <<>> DiG 9.17.20-1+ubuntu20.04.1+isc+2-Ubuntu <<>> @127.0.0.1 -p5555 -y hmac-md5 test.rpz ixfr=1637788440
; (1 server found)
;; global options: +cmd
test.rpz.              604800  IN      SOA     test.testrpz.local. support.testrpz.local. 1637820240 120 60 60 60
test.rpz.              604800  IN      SOA     test.testrpz.local. support.testrpz.local. 1637788440 120 60 60 60
test.rpz.              604800  IN      SOA     test.testrpz.local. support.testrpz.local. 1637820240 120 60 60 60
test.rpz.              604800  IN      SOA     test.testrpz.local. support.testrpz.local. 1637820240 120 60 60 60
tkey_1.                 0       ANY     TSIG    hmac-md5.sig-alg.reg.int. 1637833043 300 16 [cut] 34619 NOERROR 0
;; Query time: 4124 msec
;; SERVER: 127.0.0.1#5555(127.0.0.1) (TCP)
;; WHEN: Thu Nov 25 10:37:27 CET 2021
;; XFR size: 4 records (messages 1, bytes 399)

ioc2rpz config:

{source,{"test","https://homeserver.local/rpztest/test.list","[:AXFR:]","^([A-Za-z0-9][A-Za-z0-9\-\._]+)"}}.
{rpz,{"test.rpz",120,60,60,60,"true","true","nodata",["tkey_1"],"fqdn",604800,60,["test"],[],[]}}.

Homas commented 2 years ago

If the full zone refresh time is more than incremental, it should work (I didn't touch that logic for some time). In ixfr request you should use the previous zone number to get the diff. I'll take a look.

Homas commented 2 years ago

Could you please test the following:

Start ioc2rpz and capture the first zone serial (serial1)
update the source and capture the new serial (serial2)
do zone transfer ixfr=serial1
do zone transfer ixfr=serial1 - 1 (any number below the first serial)
update the source and capture the serial (serial3)
repeat steps 3 and 4
do zone transfer ixfr=serial2
do zone transfer ixfr=serial2 - 1

and after that please share the results.

realbugi commented 2 years ago

Here are the results:

Start ioc2rpz and capture the first zone serial (serial1)

Source: "test", size: 1.55/MB (1629901), MD5: "d14baa3e435d9ff6b8d676e8686ece47"
Source: "test", got 38576 indicators, clean time 0
Memory total 60.37884521484375 before garbage collector. processes 13.609123229980469 binary 8.543113708496094
Memory total 56.25494384765625 after garbage collector. processes 12.323616027832031 binary 5.697296142578125
Live zone "test.rpz", 77152 rules, 38576 IOCs
Zone "test.rpz" updated in 0 seconds, new serial 1638867780, 77152 rules, 38576 indicators.

update the source and capture the new serial (serial2)

loading hot sources []
Start incremental update Zone "test.rpz" serial 1638867900 full refresh time 60, Ctime 1638867980 cache <<"true">> status ready
Process PID <0.594.0> incremental update "test.rpz" started
Updating zone "test.rpz" inc. Last IXFR update 60 seconds ago, last non-zero update 180 seconds ago
Source: "test", size: 1.55/MB (1629935), MD5: "acb6aedb162926d40fb5158f020086a3"
Source: "test", got 38577 indicators, clean time 0
Memory total 75.78250122070312 before garbage collector. processes 13.673492431640625 binary 14.143783569335938
Memory total 72.85916900634766 after garbage collector. processes 13.689590454101562 binary 11.07513427734375
Fetching zone "test.rpz" from ets
Finding new or updated records
Update ets. New 38577, DB 38576, Delta 1
Rebuilding AXFR zone "test.rpz". New IOCs 1
Zone "test.rpz", # of rules 77154, # of IOCs 38577
AXFR zone "test.rpz" was rebuilded. 77154 rules 38577 indicators. Parsed 38577 indicators.
Zone "test.rpz" records before 38576 after 38577.
Process PID <0.594.0> incremental update "test.rpz" finished in 0 seconds

do zone transfer ixfr=serial1 ixfr=1638867780

ioc2rpz tcp6_sup child started
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000202|DNS Query|3|src=172.17.0.1 spt=41956 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN" tsigkey="tkey_1."
Found Key ... Good timestamp ... Valid MAC
Zone "test.rpz", 0 rules, 0 IOCs
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000201|RPZ transfer success|3|src=172.17.0.1 spt=41956 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN"  tsigkey="tkey_1." transfer_time=27

DIG output empty

do zone transfer ixfr=serial1 - 1 (any number below the first serial) ixfr=1638867779

ioc2rpz tcp6_sup child started
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000202|DNS Query|3|src=172.17.0.1 spt=42240 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN" tsigkey="tkey_1."
Found Key ... Good timestamp ... Valid MAC
IXFR zone "test.rpz" serial 1638867780 request serial 1638867779
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000201|RPZ transfer success|3|src=172.17.0.1 spt=42240 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN"  tsigkey="tkey_1." transfer_time=35

DIG output:

; <<>> DiG 9.17.20-1+ubuntu20.04.1+isc+2-Ubuntu <<>> @127.0.0.1 -p5555 -y hmac-md5 test.rpz ixfr=1638867779
; (1 server found)
;; global options: +cmd
test.rpz.               604800  IN      SOA     ns1.testrpz.local. support.testrpz.local. 1638867960 120 60 60 60
test.rpz.               604800  IN      NS      ns1.testrpz.local.
domain1.test.rpz. 900 IN    CNAME   .
domain2.test.rpz. 900 IN CNAME .
domain3.test.rpz. 900 IN CNAME .
domain4.test.rpz. 900 IN CNAME .
domain5.test.rpz. 900   IN      CNAME   .
[...]

update the source and capture the serial (serial3)

loading hot sources []
Start incremental update Zone "test.rpz" serial 1638868380 full refresh time 60, Ctime 1638868460 cache <<"true">> status ready
Process PID <0.661.0> incremental update "test.rpz" started
Updating zone "test.rpz" inc. Last IXFR update 60 seconds ago, last non-zero update 480 seconds ago
Source: "test", size: 1.55/MB (1629969), MD5: "dfd866cbed016a035e40854f7a0913c6"
Source: "test", got 38578 indicators, clean time 0
Memory total 77.107666015625 before garbage collector. processes 13.775436401367188 binary 15.365737915039062
Memory total 73.61711120605469 after garbage collector. processes 13.807205200195312 binary 11.847457885742188
Fetching zone "test.rpz" from ets
Finding new or updated records
Update ets. New 38578, DB 38577, Delta 1
Rebuilding AXFR zone "test.rpz". New IOCs 1
Zone "test.rpz", # of rules 77156, # of IOCs 38578
AXFR zone "test.rpz" was rebuilded. 77156 rules 38578 indicators. Parsed 38578 indicators.
Zone "test.rpz" records before 38577 after 38578.
Process PID <0.661.0> incremental update "test.rpz" finished in 0 seconds

repeat steps 3 and 4 ixfr=1638868380

ioc2rpz tcp6_sup child started
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000202|DNS Query|3|src=172.17.0.1 spt=43490 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN" tsigkey="tkey_1."
Found Key ... Good timestamp ... Valid MAC
Zone "test.rpz", 0 rules, 0 IOCs
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000201|RPZ transfer success|3|src=172.17.0.1 spt=43490 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN"  tsigkey="tkey_1." transfer_time=36

DIG empty

ixfr=1638868379

ioc2rpz tcp6_sup child started
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000202|DNS Query|3|src=172.17.0.1 spt=43622 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN" tsigkey="tkey_1."
Found Key ... Good timestamp ... Valid MAC
Zone "test.rpz", 0 rules, 0 IOCs
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000201|RPZ transfer success|3|src=172.17.0.1 spt=43622 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN"  tsigkey="tkey_1." transfer_time=22

DIG empty

do zone transfer ixfr=serial2 ixfr=1638867900

ioc2rpz tcp6_sup child started
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000202|DNS Query|3|src=172.17.0.1 spt=44450 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN" tsigkey="tkey_1."
Found Key ... Good timestamp ... Valid MAC
Zone "test.rpz", 0 rules, 0 IOCs
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000201|RPZ transfer success|3|src=172.17.0.1 spt=44450 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN"  tsigkey="tkey_1." transfer_time=24

DIG empty

do zone transfer ixfr=serial2 - 1 ixfr=1638867899

ioc2rpz tcp6_sup child started
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000202|DNS Query|3|src=172.17.0.1 spt=44538 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN" tsigkey="tkey_1."
Found Key ... Good timestamp ... Valid MAC
Zone "test.rpz", 0 rules, 0 IOCs
CEF:0|ioc2rpz|ioc2rpz|1.2.0.0-2021073101|000201|RPZ transfer success|3|src=172.17.0.1 spt=44538 proto=tcp qname="test.rpz" qtype="IXFR" qclass="IN"  tsigkey="tkey_1." transfer_time=35

DIG empty

Homas commented 2 years ago

Thanks. I'll take a look.

Homas commented 2 years ago

I've just committed a fix to the dev branch. It is not fully tested yet so please validate it on your side. I'll check some other stuff and run it on the community site for some time before merging the dev branch to the master branch.

realbugi commented 2 years ago

Thank you.

I did the tests and here are the results:

added new domain to source - OK (IXFR reports new domain)
updated domain in source - FAILED (IXFR reports no updates) (I have updated line with domain in source list from 000.domain.com to 001.domain.com)
removed domain from source - FAILED (IXFR reports no updates)

Homas commented 2 years ago

When you updated a domain in the source file did you wait till the file was expired in a hot cache? From ioc2rpz perspective, you just added a new domain for the next incremental update.
ioc2rpz doesn't monitor the status of the whole file for the incremental updates. Imagine you have a file with 10m indicators, It will take a lot of resources to track the updates (add, delete) and deduplicate entries with every incremental update. So ioc2rpz removes indicators only:
- if an indicator has an expiration time;
- with the full zone update (incremental data will be lost).

realbugi commented 2 years ago

you are right. After another try I see that domain shows up - sorry,
oh ok, looks like I missed that. Good point for big lists and I'm aware how challenging task this could be. The use case for that functionality is because sources do update lists just to remove false positives and setting expiration time for all domains sooner or later will force recursor to do full zone update which just moves handling resources to it (recursor) even if those changes are relatively small. Maybe some kind of limit to how many incremental changes ioc2rpz will partially solve that?

Anyway @Homas - thank you.

Homas commented 2 years ago

With the current feature set you have 2 options:

Do the full zone update more frequently. Incremental updates always require more resources to rebuild a zone and maintain the change log (even on secondary DNS server, in some cases you can turn it off). I think that (I didn't test) if you have a zone with up to 100k rules there will be no issue at all to do AXFR even once an hour.
Looks like you expect that a full zone will be always in a source file. In that case you can add an expiration time equal your incremental zone update time. If your TI provider doesn't provide TTL or expiration time, you can generate it yourself. As an option you can use ioc2rpz feature to execute a script to generate a source file. E.g. take a look on the following source. {source,{"base.rpz","shell:/usr/bin/dig -y **KEYNAME**:**TSIGKEY** @**SERVER** **base.rpz.infoblox.local** axfr | /bin/grep -e CNAME | /bin/grep -v '*.' | /usr/bin/awk -F '.base.rpz' '{print $1}'","",none}}. A feed is generated on a fly from a source (in this case RPZ feed) and awk is used to "print" an IOC. It is very easy to add a current timestamp + "zone incremental update time" to the script output.

And as always you free to open an enhancement request :)

Homas / ioc2rpz

IXFR not working #39