postresolve function never processes rpz triggered requests

thinkwelltwd commented 4 years ago

Program: Recursor
Issue type: Bug report

Short description

postresolve lua hook never gets DNS Questions that were found in a response policy zone

Environment

Operating system: Centos 6 & 7
Software version: 4.3.3
Software source: PowerDNS repository

Steps to reproduce

/etc/pdns-recursor/recursor.conf

config-dir=/etc/pdns-recursor
setuid=pdns-recursor
setgid=pdns-recursor
forward-zones-file=/etc/pdns-recursor/forward-zones.conf
export-etc-hosts=on
lua-config-file=/etc/pdns-recursor/recursorconf.lua
lua-dns-script=/etc/pdns-recursor/lua_dns_script.lua
lowercase-outgoing=yes
webserver=yes
quiet=yes
local-address=127.0.0.1 10.5.5.1
local-port=53
loglevel=3

recursorconf.lua

rpzFile("/path/to/urlhaus/zone.conf", {defpol=Policy.Custom, defcontent="urlhaus.localblockpage.lan"})

lua_dns_script.lua

function prerpz(dq)
  pdnslog(dq.qname:toString() .. ' prerpz')
  return false
end

function postresolve(dq)
  pdnslog(dq.qname:toString() .. " postresolve" )
  return false
end

Expected behaviour

Log line when RPZ fired

Jul 31 19:48:39 system pdns_recursor: aite.me. prerpz
Jul 31 19:48:39 system pdns_recursor: aite.me. postresolve

Log lines of when no RPZ fired

Jul 31 19:49:11 system pdns_recursor: lxer.com. prerpz
Jul 31 19:49:11 system pdns_recursor: lxer.com. postresolve

Actual behaviour

There's no postresolve logline for the domains in the urlhaus RPZ, so no way of logging malware activity.

Log line when RPZ fired

Jul 31 19:48:39 system pdns_recursor: aite.me. prerpz

Log lines of when no RPZ fired

Jul 31 19:49:11 system pdns_recursor: lxer.com. prerpz
Jul 31 19:49:11 system pdns_recursor: lxer.com. postresolve

Question

Presumably postresolve logging would be the recommended approach to logging RPZ hits to a file for further activity reporting. I also tried dnstap config but wasn't able to get that working. In reading this issue it doesn't seem like dnstap in Recursor is ready for prime time.

phonedph1 commented 4 years ago

If you just need to do something to log them - the policy being applied is available in preresolve and you can just check dq.appliedPolicy.policyName ~= "" or similar.

thinkwelltwd commented 4 years ago

Indeed that is right; preresolve gets me what I want. I'd read over the hooks carefully and wondered what the postrpz hook was. Apparently it's preresolve and I suppose I should've intuited that.

If the docs could be changed from:

This function is called before any DNS resolution is attempted,

to:

This function is called after RPZs are applied and before any DNS resolution is attempted,

I'll leave the ticket open because the behaviour I'm seeing does not match the docs. postresolve should really be called...

Anyway, this does get me logging, so very many thanks @phonedph1!

rgacogne commented 4 years ago

postresolve should really be called...

I agree the documentation should be more explicit on that, but I don't think it really makes sense to call postresolve in that case since the RPZ hit prevents the resolution process from even starting.

PowerDNS / pdns