Maintained by: NLnet Labs

[Unbound-users] python module example documentation bug and crasher

Paul Wouters
Mon Jan 20 10:27:18 CET 2014


On Mon, 20 Jan 2014, W.C.A. Wijngaards wrote:

>> When loading that module, unbound always SERVFAIL's. Thinking that
>> this section was wrongly returning MODULE_ERROR:
>>
>> if event == MODULE_EVENT_PASS: log_info("pythonmod: event_pass")
>> qstate.ext_state[id] = MODULE_ERROR return True
>>
>> I changed it to MODULE_FINISHED. However, that lead to a crash in
>> unbound:

We fixed this in the current code. Our code now works, and actually
triggers an IPsec tunnel that established.

Attached for others to look at as example, although we still have more
work to do to make it work fully.

We are still wondering why there is some slowness between when the
ipsec tunnel comes up and the application sees the A recorc answer.
This seems to be about 9 seconds and we have no idea what unbound
is doing.

We would also still like to have something better than running
dns.resolver() that more natively goes back into the unbound code.

Paul
-------------- next part --------------
import sys, commands
sys.path.append("/usr/lib/python2.6/site-packages/")
import dns.resolver
import base64

myname = "rhel6.nohats.ca"
myip = "193.110.157.150"
mykey = ""
ipseckey = commands.getoutput("ipsec showhostkey --ipseckey")
if "IPSECKEY" in ipseckey:
   mykey = ipseckey.rsplit(" ")[-1]
   log_info("We found our IPSECKEY to be: %s"%mykey)
leftwhack = 'ipsec whack --label "%s leftrsasigkey"  --keyid "@%s" --pubkeyrsa "0s%s"'%(myname, myname, mykey)
log_info(leftwhack)
status, result = commands.getstatusoutput(leftwhack)
log_info("Status:%s, Output: %s"%(status,result))

def do_whack(qname, qtype, addr):
      global myname
      global myip
      global mykey
      global leftwhack
      if not mykey: 
         log_info("We failed to find our IPSECKEY on boot")
         return False

      try:
           ipseckeys = dns.resolver.query(qname, 'IPSECKEY')
      except:
               #log_info("No IPSECKEY found")
               return False

      log_info("do_whack: qname:%s qtype:%s addr:%s"%(qname, qtype, addr))
      try:
           for answer in ipseckeys:
               b64_answer = base64.b64encode(answer.key)
               log_info("IPSECKEY record found for '%s': %s"%(qname,b64_answer))
               rightwhack = 'ipsec whack --label "%s rightrsasigkey"  --keyid "@%s" --pubkeyrsa "0s%s"'%(qname,qname,b64_answer)
               addwhack = 'ipsec whack --name %s --encrypt --tunnel --pfs --rsasig --host "%s" --updown "ipsec _updown" --id @%s --to --host "%s" --updown "ipsec _updown" --id "@%s" --keyingtries "1" ' %(qname, myip, myname, addr, qname)
               upwhack = 'ipsec whack --initiate --name %s'%qname
               for cmd in ( rightwhack, addwhack, upwhack ):
                   log_info("CMD:%s"%cmd)
                   status, result = commands.getstatusoutput(cmd)
                   log_info("Status:%s, Output: %s"%(status,result))

      except:
               log_info(str(sys.exc_info()))
               return False

      return True



def dataHex(data, prefix=""):
    """Converts binary string data to display representation form"""
    res = ""
    for i in range(0, (len(data)+15)/16):
        res += "%s0x%02X | " % (prefix, i*16)
        d = map(lambda x:ord(x), data[i*16:i*16+17])
        for ch in d:
            res += "%02X " % ch
        for i in range(0,17-len(d)):
            res += "   "
        res += "| "
        for ch in d:
            if (ch < 32) or (ch > 127):
                res += ". "
            else:
                res += "%c " % ch
        res += "\n"
    return res

def init(id, cfg):
   global mykey
   log_info("pythonmod: init called, module id is %d port: %d script: %s" % (id, cfg.port, cfg.python_script))
   return True

def deinit(id):
   log_info("pythonmod: deinit called, module id is %d" % id)
   return True

def inform_super(id, qstate, superqstate, qdata):
   log_info("pythonmod: inform_super called, module id is %s, qstate:%s, superqstate:%s, qdata:%s" % (id, qstate, superqstate, qdata))
   return True

def operate(id, event, qstate, qdata):
   global myname
   global myip
   #log_info("pythonmod: operate called, id: %d, event:%s" % (id, strmodulevent(event)))

   if event == MODULE_EVENT_NEW or event == MODULE_EVENT_PASS:
            qstate.ext_state[id] = MODULE_WAIT_MODULE
            return True

   if event == MODULE_EVENT_MODDONE:
      #log_info("pythonmod: module we are waiting for is done")
      if not qstate.return_msg:
         qstate.ext_state[id] = MODULE_FINISHED 
         return True

      # key of msg: qinfo|rep|this
      # keys of msg.rep: an_numrrsets|ar_numrrsets|authoritative|flags|ns_numrrsets|prefetch_ttl|qdcount|ref|rrset_count|rrsets|security|this|ttl
      # keys of qstate.return_msg.rep.rrsets[i].entry: data|hash|key|lock|lru_next|lru_prev|overflow_next|this


      reply_packet = qstate.return_msg.rep
      msg = qstate.return_msg
      qname = msg.qinfo.qname_str
      qtype = msg.qinfo.qtype
      # log_info("|".join(dir(msg)))
      if qtype in ( 1, 28):
         #log_info("an_numrrsets=%s, qname=%s, qtype=%s"%(reply_packet.an_numrrsets, qname, qtype))
         for i in range(0,qstate.return_msg.rep.an_numrrsets):
                e = qstate.return_msg.rep.rrsets[i].rk
                d = qstate.return_msg.rep.rrsets[i].entry.data
                if e.type_str in ( "A", "AAAA"):
                  #log_info("i:%s, type:%s(%s), data:%s"%(i, e.type_str, ntohs(e.type), str(d.rr_data)))
                  for j in range(0,d.count):
                         #log_info(dataHex(d.rr_data[j]))
                         if ntohs(e.type) == 1: # A
                            x = d.rr_data[j]
                            Arecord = "%d.%d.%d.%d"%(ord(x[2]),ord(x[3]),ord(x[4]),ord(x[5]))
                            #log_info(Arecord)
                            do_whack(qname,qtype,Arecord)
                         elif ntohs(e.type) == 28: # AAAA
                            x = d.rr_data[j]
                            AAAArecord = "%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x"%(ord(x[2]),ord(x[3]),ord(x[4]),ord(x[5]),ord(x[6]),ord(x[7]),ord(x[8]),ord(x[9]),ord(x[10]),ord(x[11]),ord(x[12]),ord(x[13]),ord(x[14]),ord(x[15]),ord(x[16]),ord(x[17]))
                            #log_info(AAAArecord)
                            #do_whack(qname,qtype,AAAArecord)

      qstate.ext_state[id] = MODULE_FINISHED 
      return True

   log_err("pythonmod: BAD event")
   qstate.ext_state[id] = MODULE_ERROR
   return True

log_info("pythonmod: script loaded.")