X-Git-Url: https://code.grnet.gr/git/snf-nfdhcpd/blobdiff_plain/883eb77ef87fe6575ee469d97f7c2448173548de..98804a5e1ce89e34e2a8206693009099babe6d1d:/nfdhcpd diff --git a/nfdhcpd b/nfdhcpd index c2ecb00..c66c435 100755 --- a/nfdhcpd +++ b/nfdhcpd @@ -20,6 +20,8 @@ # import os +import signal +import errno import re import sys import glob @@ -28,18 +30,18 @@ import logging import logging.handlers import threading import traceback -import subprocess import daemon import daemon.runner import daemon.pidlockfile import nfqueue import pyinotify +import setproctitle from lockfile import LockTimeout import IPy import socket -from select import select +import select from socket import AF_INET, AF_INET6 from scapy.data import ETH_P_ALL @@ -51,6 +53,10 @@ from scapy.layers.inet6 import IPv6, ICMPv6ND_RA, ICMPv6ND_NA, \ ICMPv6NDOptPrefixInfo, \ ICMPv6NDOptRDNSS from scapy.layers.dhcp import BOOTP, DHCP +from scapy.layers.dhcp6 import DHCP6_Reply, DHCP6OptDNSServers, \ + DHCP6OptServerId, DHCP6OptClientId, \ + DUID_LLT, DHCP6_InfoRequest, DHCP6OptDNSDomains + DEFAULT_CONFIG = "/etc/nfdhcpd/nfdhcpd.conf" DEFAULT_PATH = "/var/run/ganeti-dhcpd" @@ -64,7 +70,7 @@ LOG_FILENAME = "nfdhcpd.log" SYSFS_NET = "/sys/class/net" -LOG_FORMAT = "%(asctime)-15s %(levelname)-6s %(message)s" +LOG_FORMAT = "%(asctime)-15s %(levelname)-8s %(message)s" # Configuration file specification (see configobj documentation) CONFIG_SPEC = """ @@ -88,7 +94,9 @@ enable_ipv6 = boolean(default=True) ra_period = integer(min=1, max=4294967295) rs_queue = integer(min=0, max=65535) ns_queue = integer(min=0, max=65535) +dhcp_queue = integer(min=0, max=65535) nameservers = ip_addr_list(family=6) +domains = force_list(default=None) """ @@ -122,41 +130,30 @@ DHCP_REQRESP = { def get_indev(payload): try: indev_ifindex = payload.get_physindev() - logging.debug("get_physindev %s", indev_ifindex) if indev_ifindex: - logging.debug("Incomming packet from bridge %s", indev_ifindex) + logging.debug(" - Incoming packet from bridge with ifindex %s", + indev_ifindex) return indev_ifindex except AttributeError: #TODO: return error value - logging.debug("No get_physindev supported") + logging.debug("No get_physindev() supported") return 0 indev_ifindex = payload.get_indev() - logging.debug("Incomming packet from tap %s", indev_ifindex) + logging.debug(" - Incoming packet from tap with ifindex %s", indev_ifindex) return indev_ifindex -def get_binding(proxy, ifindex, mac): - try: - if proxy.mac_indexed_clients: - logging.debug("get_binding for mac %s", mac) - b = proxy.clients[mac] - else: - logging.debug("get_binding for ifindex %s", ifindex) - b = proxy.clients[ifindex] - return b - except KeyError: - logging.debug("No client found for mac/ifindex %s/%s", mac, ifindex) - return None def parse_binding_file(path): """ Read a client configuration from a tap file """ + logging.info("Parsing binding file %s", path) try: iffile = open(path, 'r') except EnvironmentError, e: - logging.warn("Unable to open binding file %s: %s", path, str(e)) + logging.warn(" - Unable to open binding file %s: %s", path, str(e)) return None tap = os.path.basename(path) @@ -173,7 +170,7 @@ def parse_binding_file(path): def get_value(line): v = line.strip().split('=')[1] if v == '': - return None + return None return v for line in iffile: @@ -197,19 +194,21 @@ def parse_binding_file(path): eui64 = get_value(line) try: - client = Client(tap=tap, mac=mac, ip=ip, - hostname=hostname, indev=indev, subnet=subnet, - gateway=gateway, subnet6=subnet6, gateway6=gateway6, eui64=eui64 ) - return client - except: + return Client(tap=tap, mac=mac, ip=ip, hostname=hostname, + indev=indev, subnet=subnet, gateway=gateway, + subnet6=subnet6, gateway6=gateway6, eui64=eui64 ) + except ValueError: + logging.warning(" - Cannot add client for host %s and IP %s on tap %s", + hostname, ip, tap) return None + class ClientFileHandler(pyinotify.ProcessEvent): def __init__(self, server): pyinotify.ProcessEvent.__init__(self) self.server = server - def process_IN_DELETE(self, event): # pylint: disable=C0103 + def process_IN_DELETE(self, event): # pylint: disable=C0103 """ Delete file handler Currently this removes an interface from the watch list @@ -217,7 +216,7 @@ class ClientFileHandler(pyinotify.ProcessEvent): """ self.server.remove_tap(event.name) - def process_IN_CLOSE_WRITE(self, event): # pylint: disable=C0103 + def process_IN_CLOSE_WRITE(self, event): # pylint: disable=C0103 """ Add file handler Currently this adds an interface to the watch list @@ -227,8 +226,10 @@ class ClientFileHandler(pyinotify.ProcessEvent): class Client(object): - def __init__(self, tap=None, indev=None, mac=None, ip=None, hostname=None, - subnet=None, gateway=None, subnet6=None, gateway6=None, eui64=None ): + def __init__(self, tap=None, indev=None, + mac=None, ip=None, hostname=None, + subnet=None, gateway=None, + subnet6=None, gateway6=None, eui64=None): self.mac = mac self.ip = ip self.hostname = hostname @@ -241,10 +242,44 @@ class Client(object): self.gateway6 = gateway6 self.net6 = Subnet(net=subnet6, gw=gateway6, dev=tap) self.eui64 = eui64 + self.open_socket() def is_valid(self): - return self.mac is not None and self.ip is not None\ - and self.hostname is not None + return self.mac is not None and self.hostname is not None + + + def open_socket(self): + + logging.info(" - Opening L2 socket and binding to %s", self.tap) + try: + s = socket.socket(socket.AF_PACKET, socket.SOCK_RAW, ETH_P_ALL) + s.setsockopt(socket.SOL_SOCKET, socket.SO_RCVBUF, 0) + s.bind((self.tap, ETH_P_ALL)) + self.socket = s + except socket.error, e: + logging.warning(" - Cannot open socket %s", e) + + + def sendp(self, data): + + if isinstance(data, BasePacket): + data = str(data) + + logging.debug(" - Sending raw packet %r", data) + + try: + count = self.socket.send(data, socket.MSG_DONTWAIT) + except socket.error, e: + logging.warn(" - Send with MSG_DONTWAIT failed: %s", str(e)) + self.socket.close() + self.open_socket() + raise e + + ldata = len(data) + logging.debug(" - Sent %d bytes on %s", count, self.tap) + if count != ldata: + logging.warn(" - Truncated msg: %d/%d bytes sent", + count, ldata) class Subnet(object): @@ -252,8 +287,9 @@ class Subnet(object): if isinstance(net, str): try: self.net = IPy.IP(net) - except: - raise Exception + except ValueError, e: + logging.warning(" - IPy error: %s", e) + raise e else: self.net = net self.gw = gw @@ -316,14 +352,15 @@ class Subnet(object): return self._make_eui64("fe80::", mac) -class VMNetProxy(object): # pylint: disable=R0902 - def __init__(self, data_path, dhcp_queue_num=None, # pylint: disable=R0913 - rs_queue_num=None, ns_queue_num=None, +class VMNetProxy(object): # pylint: disable=R0902 + def __init__(self, data_path, dhcp_queue_num=None, # pylint: disable=R0913 + rs_queue_num=None, ns_queue_num=None, dhcpv6_queue_num=None, dhcp_lease_lifetime=DEFAULT_LEASE_LIFETIME, dhcp_lease_renewal=DEFAULT_LEASE_RENEWAL, - dhcp_domain='', + dhcp_domain=None, dhcp_server_ip=DHCP_DUMMY_SERVER_IP, dhcp_nameservers=None, - ra_period=DEFAULT_RA_PERIOD, ipv6_nameservers=None): + ra_period=DEFAULT_RA_PERIOD, ipv6_nameservers=None, + dhcpv6_domains=None): try: getattr(nfqueue.payload, 'get_physindev') @@ -346,6 +383,11 @@ class VMNetProxy(object): # pylint: disable=R0902 else: self.ipv6_nameservers = ipv6_nameservers + if dhcpv6_domains is None: + self.dhcpv6_domains = [] + else: + self.dhcpv6_domains = dhcpv6_domains + self.ipv6_enabled = False self.clients = {} @@ -353,9 +395,6 @@ class VMNetProxy(object): # pylint: disable=R0902 #self.ifaces = {} #self.v6nets = {} self.nfq = {} - self.l2socket = socket.socket(socket.AF_PACKET, - socket.SOCK_RAW, ETH_P_ALL) - self.l2socket.setsockopt(socket.SOL_SOCKET, socket.SO_RCVBUF, 0) # Inotify setup self.wm = pyinotify.WatchManager() @@ -367,36 +406,51 @@ class VMNetProxy(object): # pylint: disable=R0902 # NFQUEUE setup if dhcp_queue_num is not None: - self._setup_nfqueue(dhcp_queue_num, AF_INET, self.dhcp_response) + self._setup_nfqueue(dhcp_queue_num, AF_INET, self.dhcp_response, 0) if rs_queue_num is not None: - self._setup_nfqueue(rs_queue_num, AF_INET6, self.rs_response) + self._setup_nfqueue(rs_queue_num, AF_INET6, self.rs_response, 10) self.ipv6_enabled = True if ns_queue_num is not None: - self._setup_nfqueue(ns_queue_num, AF_INET6, self.ns_response) + self._setup_nfqueue(ns_queue_num, AF_INET6, self.ns_response, 10) + self.ipv6_enabled = True + + if dhcpv6_queue_num is not None: + self._setup_nfqueue(dhcpv6_queue_num, AF_INET6, self.dhcpv6_response, 10) self.ipv6_enabled = True + def get_binding(self, ifindex, mac): + try: + if self.mac_indexed_clients: + logging.debug(" - Getting binding for mac %s", mac) + b = self.clients[mac] + else: + logging.debug(" - Getting binding for ifindex %s", ifindex) + b = self.clients[ifindex] + return b + except KeyError: + logging.debug(" - No client found for mac / ifindex %s / %s", + mac, ifindex) + return None + def _cleanup(self): """ Free all resources for a graceful exit """ logging.info("Cleaning up") - logging.debug("Closing netfilter queues") - for q in self.nfq.values(): + logging.debug(" - Closing netfilter queues") + for q, _ in self.nfq.values(): q.close() - logging.debug("Closing socket") - self.l2socket.close() - - logging.debug("Stopping inotify watches") + logging.debug(" - Stopping inotify watches") self.notifier.stop() - logging.info("Cleanup finished") + logging.info(" - Cleanup finished") - def _setup_nfqueue(self, queue_num, family, callback): - logging.debug("Setting up NFQUEUE for queue %d, AF %s", + def _setup_nfqueue(self, queue_num, family, callback, pending): + logging.info("Setting up NFQUEUE for queue %d, AF %s", queue_num, family) q = nfqueue.queue() q.set_callback(callback) @@ -404,22 +458,8 @@ class VMNetProxy(object): # pylint: disable=R0902 q.set_queue_maxlen(5000) # This is mandatory for the queue to operate q.set_mode(nfqueue.NFQNL_COPY_PACKET) - self.nfq[q.get_fd()] = q - - def sendp(self, data, dev): - """ Send a raw packet using a layer-2 socket - - """ - logging.debug("%s", data) - if isinstance(data, BasePacket): - data = str(data) - - self.l2socket.bind((dev, ETH_P_ALL)) - count = self.l2socket.send(data) - ldata = len(data) - if count != ldata: - logging.warn("Truncated send on %s (%d/%d bytes sent)", - dev, count, ldata) + self.nfq[q.get_fd()] = (q, pending) + logging.debug(" - Successfully set up NFQUEUE %d", queue_num) def build_config(self): self.clients.clear() @@ -427,15 +467,14 @@ class VMNetProxy(object): # pylint: disable=R0902 for path in glob.glob(os.path.join(self.data_path, "*")): self.add_tap(path) - logging.debug("\n\n\n\n\n") - logging.debug("%10s %20s %7s %15s", 'Client', 'MAC', 'TAP', 'IP') - for b in self.clients.values(): - logging.debug("%10s %20s %7s %15s", b.hostname, b.mac, b.tap, b.ip) + self.print_clients() def get_ifindex(self, iface): """ Get the interface index from sysfs """ + logging.debug(" - Getting ifindex for interface %s from sysfs", iface) + path = os.path.abspath(os.path.join(SYSFS_NET, iface, "ifindex")) if not path.startswith(SYSFS_NET): return None @@ -445,7 +484,7 @@ class VMNetProxy(object): # pylint: disable=R0902 try: f = open(path, 'r') except EnvironmentError: - logging.debug("%s is probably down, removing", iface) + logging.debug(" - %s is probably down, removing", iface) self.remove_tap(iface) return ifindex @@ -455,10 +494,10 @@ class VMNetProxy(object): # pylint: disable=R0902 try: ifindex = int(ifindex) except ValueError, e: - logging.warn("Failed to get ifindex for %s, cannot parse sysfs" - " output '%s'", iface, ifindex) + logging.warn(" - Failed to get ifindex for %s, cannot parse" + " sysfs output '%s'", iface, ifindex) except EnvironmentError, e: - logging.warn("Error reading %s's ifindex from sysfs: %s", + logging.warn(" - Error reading %s's ifindex from sysfs: %s", iface, str(e)) self.remove_tap(iface) finally: @@ -466,11 +505,11 @@ class VMNetProxy(object): # pylint: disable=R0902 return ifindex - def get_iface_hw_addr(self, iface): """ Get the interface hardware address from sysfs """ + logging.debug(" - Getting mac for iface %s", iface) path = os.path.abspath(os.path.join(SYSFS_NET, iface, "address")) if not path.startswith(SYSFS_NET): return None @@ -479,14 +518,14 @@ class VMNetProxy(object): # pylint: disable=R0902 try: f = open(path, 'r') except EnvironmentError: - logging.debug("%s is probably down, removing", iface) + logging.debug(" - %s is probably down, removing", iface) self.remove_tap(iface) return addr try: addr = f.readline().strip() except EnvironmentError, e: - logging.warn("Failed to read hw address for %s from sysfs: %s", + logging.warn(" - Failed to read hw address for %s from sysfs: %s", iface, str(e)) finally: f.close() @@ -499,54 +538,65 @@ class VMNetProxy(object): # pylint: disable=R0902 """ tap = os.path.basename(path) - logging.debug("Updating configuration for %s", tap) + logging.info("Updating configuration for %s", tap) b = parse_binding_file(path) if b is None: return ifindex = self.get_ifindex(b.tap) if ifindex is None: - logging.warn("Stale configuration for %s found", tap) + logging.warn(" - Stale configuration for %s found", tap) else: if b.is_valid(): if self.mac_indexed_clients: self.clients[b.mac] = b + k = b.mac else: self.clients[ifindex] = b - logging.debug("Added client:") - logging.debug("%5s: %10s %20s %7s %15s", - ifindex, b.hostname, b.mac, b.tap, b.ip) + k = ifindex + logging.info(" - Added client:") + logging.info(" + %10s | %20s %20s %10s %20s %40s", + k, b.hostname, b.mac, b.tap, b.ip, b.eui64) def remove_tap(self, tap): """ Cleanup clients on a removed interface """ try: - for k in self.clients.keys(): - b = self.clients[k] - if self.clients[k].tap == tap: - logging.debug("Removing client on interface %s", tap) - logging.debug("%10s %20s %7s %15s", - b.hostname, b.mac, b.tap, b.ip) + for k, cl in self.clients.items(): + if cl.tap == tap: + logging.info("Removing client %s and closing socket on %s", + cl.hostname, cl.tap) + logging.info(" - %10s | %20s %20s %10s %20s %40s", + k, cl.hostname, cl.mac, cl.tap, cl.ip, cl.eui64) + cl.socket.close() del self.clients[k] except: logging.debug("Client on %s disappeared!!!", tap) - def dhcp_response(self, i, payload): # pylint: disable=W0613,R0914 + def dhcp_response(self, arg1, arg2=None): # pylint: disable=W0613,R0914 """ Generate a reply to bnetfilter-queue-deva BOOTP/DHCP request """ + logging.info(" * Processing pending DHCP request") + # Workaround for supporting both squeezy's nfqueue-bindings-python + # and wheezy's python-nfqueue because for some reason the function's + # signature has changed and has broken compatibility + # See bug http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=718894 + if arg2: + payload = arg2 + else: + payload = arg1 # Decode the response - NFQUEUE relays IP packets pkt = IP(payload.get_data()) - logging.debug("IN DHCP RESPONCE") #logging.debug(pkt.show()) # Get the client MAC address resp = pkt.getlayer(BOOTP).copy() hlen = resp.hlen mac = resp.chaddr[:hlen].encode("hex") - mac, _ = re.subn(r'([0-9a-fA-F]{2})', r'\1:', mac, hlen-1) + mac, _ = re.subn(r'([0-9a-fA-F]{2})', r'\1:', mac, hlen - 1) # Server responses are always BOOTREPLYs resp.op = "BOOTREPLY" @@ -554,31 +604,40 @@ class VMNetProxy(object): # pylint: disable=R0902 indev = get_indev(payload) - binding = get_binding(self, indev, mac) + binding = self.get_binding(indev, mac) if binding is None: # We don't know anything about this interface, so accept the packet # and return - logging.debug("Ignoring DHCP request on unknown iface %d", indev) + logging.debug(" - Ignoring DHCP request on unknown iface %s", indev) # We don't know what to do with this packet, so let the kernel # handle it payload.set_verdict(nfqueue.NF_ACCEPT) return - # Signal the kernel that it shouldn't further process the packet payload.set_verdict(nfqueue.NF_DROP) if mac != binding.mac: - logging.warn("Recieved spoofed DHCP request for mac %s from tap %s", mac, indev) + logging.warn(" - Recieved spoofed DHCP request: mac %s, indev %s", + mac, indev) return + if not binding.ip: + logging.info(" - No IP found in binding file.") + return + + logging.info(" - Generating DHCP response:" + " host %s, mac %s, tap %s, indev %s", + binding.hostname, mac, binding.tap, indev) + + resp = Ether(dst=mac, src=self.get_iface_hw_addr(binding.indev))/\ IP(src=DHCP_DUMMY_SERVER_IP, dst=binding.ip)/\ UDP(sport=pkt.dport, dport=pkt.sport)/resp subnet = binding.net if not DHCP in pkt: - logging.warn("Invalid request from %s on %s, no DHCP" + logging.warn(" - Invalid request from %s on %s, no DHCP" " payload found", binding.mac, binding.tap) return @@ -590,7 +649,7 @@ class VMNetProxy(object): # pylint: disable=R0902 if type(opt) is tuple and opt[0] == "requested_addr": requested_addr = opt[1] - logging.info("%s from %s on %s", DHCP_TYPES.get(req_type, "UNKNOWN"), + logging.info(" - %s from %s on %s", DHCP_TYPES.get(req_type, "UNKNOWN"), binding.mac, binding.tap) if self.dhcp_domain: @@ -600,7 +659,7 @@ class VMNetProxy(object): # pylint: disable=R0902 if req_type == DHCPREQUEST and requested_addr != binding.ip: resp_type = DHCPNAK - logging.info("Sending DHCPNAK to %s on %s: requested %s" + logging.info(" - Sending DHCPNAK to %s on %s: requested %s" " instead of %s", binding.mac, binding.tap, requested_addr, binding.ip) @@ -616,7 +675,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ("lease_time", self.lease_lifetime), ] if subnet.gw: - dhcp_options += [("router", subnet.gw)] + dhcp_options += [("router", subnet.gw)] dhcp_options += [("name_server", x) for x in self.dhcp_nameservers] elif req_type == DHCPINFORM: @@ -629,7 +688,8 @@ class VMNetProxy(object): # pylint: disable=R0902 elif req_type == DHCPRELEASE: # Log and ignore - logging.info("DHCPRELEASE from %s on %s", binding.mac, binding.tap ) + logging.info(" - DHCPRELEASE from %s on %s", + binding.hostname, binding.tap) return # Finally, always add the server identifier and end options @@ -640,38 +700,120 @@ class VMNetProxy(object): # pylint: disable=R0902 ] resp /= DHCP(options=dhcp_options) - logging.info("%s to %s (%s) on %s", DHCP_TYPES[resp_type], mac, + logging.info(" - %s to %s (%s) on %s", DHCP_TYPES[resp_type], mac, binding.ip, binding.tap) try: - self.sendp(resp, binding.indev) + binding.sendp(resp) except socket.error, e: - logging.warn("DHCP response on %s failed: %s", binding.indev, str(e)) + logging.warn(" - DHCP response on %s (%s) failed: %s", + binding.tap, binding.hostname, str(e)) except Exception, e: - logging.warn("Unkown error during DHCP response on %s: %s", - binding.indev, str(e)) + logging.warn(" - Unkown error during DHCP response on %s (%s): %s", + binding.tap, binding.hostname, str(e)) + + def dhcpv6_response(self, arg1, arg2=None): # pylint: disable=W0613 + + logging.info(" * Processing pending DHCPv6 request") + # Workaround for supporting both squeezy's nfqueue-bindings-python + # and wheezy's python-nfqueue because for some reason the function's + # signature has changed and has broken compatibility + # See bug http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=718894 + if arg2: + payload = arg2 + else: + payload = arg1 + pkt = IPv6(payload.get_data()) + indev = get_indev(payload) - def rs_response(self, i, payload): # pylint: disable=W0613 + #TODO: figure out how to find the src mac + mac = None + binding = self.get_binding(indev, mac) + if binding is None: + # We don't know anything about this interface, so accept the packet + # and return + logging.debug(" - Ignoring dhcpv6 request for mac %s", mac) + # We don't know what to do with this packet, so let the kernel + # handle it + payload.set_verdict(nfqueue.NF_ACCEPT) + return + + # Signal the kernel that it shouldn't further process the packet + payload.set_verdict(nfqueue.NF_DROP) + + subnet = binding.net6 + + if subnet.net is None: + logging.debug(" - No IPv6 network assigned for tap %s", binding.tap) + return + + indevmac = self.get_iface_hw_addr(binding.indev) + ifll = subnet.make_ll64(indevmac) + if ifll is None: + return + + ofll = subnet.make_ll64(binding.mac) + if ofll is None: + return + + logging.info(" - Generating DHCPv6 response for host %s (mac %s) on tap %s", + binding.hostname, binding.mac, binding.tap) + + if self.dhcpv6_domains: + domains = self.dhcpv6_domains + else: + domains = [binding.hostname.split('.', 1)[-1]] + + # We do this in order not to caclulate optlen ourselves + dnsdomains = str(DHCP6OptDNSDomains(dnsdomains=domains)) + dnsservers = str(DHCP6OptDNSServers(dnsservers=self.ipv6_nameservers)) + + resp = Ether(src=indevmac, dst=binding.mac)/\ + IPv6(tc=192, src=str(ifll), dst=str(ofll))/\ + UDP(sport=pkt.dport, dport=pkt.sport)/\ + DHCP6_Reply(trid=pkt[DHCP6_InfoRequest].trid)/\ + DHCP6OptClientId(duid=pkt[DHCP6OptClientId].duid)/\ + DHCP6OptServerId(duid=DUID_LLT(lladdr=indevmac, timeval=time.time()))/\ + DHCP6OptDNSDomains(dnsdomains)/\ + DHCP6OptDNSServers(dnsservers) + + try: + binding.sendp(resp) + except socket.error, e: + logging.warn(" - DHCPv6 on %s (%s) failed: %s", + binding.tap, binding.hostname, str(e)) + except Exception, e: + logging.warn(" - Unkown error during DHCPv6 on %s (%s): %s", + binding.tap, binding.hostname, str(e)) + + + def rs_response(self, arg1, arg2=None): # pylint: disable=W0613 """ Generate a reply to a BOOTP/DHCP request """ + logging.info(" * Processing pending RS request") + # Workaround for supporting both squeezy's nfqueue-bindings-python + # and wheezy's python-nfqueue because for some reason the function's + # signature has changed and has broken compatibility + # See bug http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=718894 + if arg2: + payload = arg2 + else: + payload = arg1 pkt = IPv6(payload.get_data()) - logging.debug("IN RS RESPONCE") #logging.debug(pkt.show()) try: mac = pkt.lladdr except: - logging.debug("Cannot obtain lladdr in rs") + logging.debug(" - Cannot obtain lladdr in rs") return - logging.debug("rs for mac %s", mac) - indev = get_indev(payload) - binding = get_binding(self, indev, mac) + binding = self.get_binding(indev, mac) if binding is None: # We don't know anything about this interface, so accept the packet # and return - logging.debug("Ignoring router solicitation on for mac %s", mac) + logging.debug(" - Ignoring router solicitation on for mac %s", mac) # We don't know what to do with this packet, so let the kernel # handle it payload.set_verdict(nfqueue.NF_ACCEPT) @@ -681,23 +823,26 @@ class VMNetProxy(object): # pylint: disable=R0902 payload.set_verdict(nfqueue.NF_DROP) if mac != binding.mac: - logging.warn("Recieved spoofed RS request for mac %s from tap %s", mac, tap) + logging.warn(" - Received spoofed RS request: mac %s, tap %s", + mac, binding.tap) return subnet = binding.net6 if subnet.net is None: - logging.debug("No IPv6 network assigned for the interface") - return + logging.debug(" - No IPv6 network assigned for tap %s", binding.tap) + return indevmac = self.get_iface_hw_addr(binding.indev) ifll = subnet.make_ll64(indevmac) if ifll is None: return + logging.info(" - Generating RA for host %s (mac %s) on tap %s", + binding.hostname, mac, binding.tap) resp = Ether(src=indevmac)/\ - IPv6(src=str(ifll))/ICMPv6ND_RA(routerlifetime=14400)/\ + IPv6(src=str(ifll))/ICMPv6ND_RA(O=1, routerlifetime=14400)/\ ICMPv6NDOptPrefixInfo(prefix=str(subnet.prefix), prefixlen=subnet.prefixlen) @@ -705,37 +850,47 @@ class VMNetProxy(object): # pylint: disable=R0902 resp /= ICMPv6NDOptRDNSS(dns=self.ipv6_nameservers, lifetime=self.ra_period * 3) - logging.info("RA on %s for %s", binding.indev, subnet.net) try: - self.sendp(resp, binding.indev) + binding.sendp(resp) except socket.error, e: - logging.warn("RA on %s failed: %s", binding.indev, str(e)) + logging.warn(" - RA on %s (%s) failed: %s", + binding.tap, binding.hostname, str(e)) except Exception, e: - logging.warn("Unkown error during RA on %s: %s", - binding.indev, str(e)) + logging.warn(" - Unkown error during RA on %s (%s): %s", + binding.tap, binding.hostname, str(e)) - def ns_response(self, i, payload): # pylint: disable=W0613 + def ns_response(self, arg1, arg2=None): # pylint: disable=W0613 """ Generate a reply to an ICMPv6 neighbor solicitation """ + + logging.info(" * Processing pending NS request") + # Workaround for supporting both squeezy's nfqueue-bindings-python + # and wheezy's python-nfqueue because for some reason the function's + # signature has changed and has broken compatibility + # See bug http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=718894 + if arg2: + payload = arg2 + else: + payload = arg1 + ns = IPv6(payload.get_data()) - logging.debug("IN NS RESPONCE") #logging.debug(ns.show()) try: mac = ns.lladdr except: - logging.debug("Cannot obtain lladdr from ns") + logging.debug(" - Cannot obtain lladdr from ns") return - logging.debug("dst %s tgt %s" , ns.dst, ns.tgt) indev = get_indev(payload) - binding = get_binding(self, indev, mac) + binding = self.get_binding(indev, mac) if binding is None: # We don't know anything about this interface, so accept the packet # and return - logging.debug("Ignoring neighbour solicitation for eui64 %s", ns.tgt) + logging.debug(" - Ignoring neighbour solicitation for eui64 %s", + ns.tgt) # We don't know what to do with this packet, so let the kernel # handle it payload.set_verdict(nfqueue.NF_ACCEPT) @@ -744,13 +899,14 @@ class VMNetProxy(object): # pylint: disable=R0902 payload.set_verdict(nfqueue.NF_DROP) if mac != binding.mac: - logging.warn("Recieved spoofed NS request for mac %s from tap %s", mac, tap) + logging.warn(" - Received spoofed NS request" + " for mac %s from tap %s", mac, binding.tap) return subnet = binding.net6 if subnet.net is None: - logging.debug("No IPv6 network assigned for the interface") - return + logging.debug(" - No IPv6 network assigned for the interface") + return indevmac = self.get_iface_hw_addr(binding.indev) @@ -759,24 +915,25 @@ class VMNetProxy(object): # pylint: disable=R0902 return if not (subnet.net.overlaps(ns.tgt) or str(ns.tgt) == str(ifll)): - logging.debug("Received NS for a non-routable IP (%s)", ns.tgt) - payload.set_verdict(nfqueue.NF_ACCEPT) + logging.debug(" - Received NS for a non-routable IP (%s)", ns.tgt) return 1 - logging.debug("na ether %s %s", binding.mac, ns.src) + logging.info(" - Generating NA for host %s (mac %s) on tap %s", + binding.hostname, mac, binding.tap) + resp = Ether(src=indevmac, dst=binding.mac)/\ IPv6(src=str(ifll), dst=ns.src)/\ ICMPv6ND_NA(R=1, O=0, S=1, tgt=ns.tgt)/\ ICMPv6NDOptDstLLAddr(lladdr=indevmac) - logging.info("NA on %s for %s", binding.indev, ns.tgt) try: - self.sendp(resp, binding.indev) + binding.sendp(resp) except socket.error, e: - logging.warn("NA on %s failed: %s", binding.indev, str(e)) + logging.warn(" - NA on %s (%s) failed: %s", + binding.tap, binding.hostname, str(e)) except Exception, e: - logging.warn("Unkown error during periodic NA on %s: %s", - binding.indev, str(e)) + logging.warn(" - Unkown error during periodic NA to %s (%s): %s", + binding.tap, binding.hostname, str(e)) def send_periodic_ra(self): # Use a separate thread as this may take a _long_ time with @@ -784,16 +941,16 @@ class VMNetProxy(object): # pylint: disable=R0902 threading.Thread(target=self._send_periodic_ra).start() def _send_periodic_ra(self): - logging.debug("Sending out periodic RAs") + logging.info("Sending out periodic RAs") start = time.time() i = 0 for binding in self.clients.values(): tap = binding.tap indev = binding.indev - mac = binding.mac + # mac = binding.mac subnet = binding.net6 if subnet.net is None: - logging.debug("Skipping periodic RA on interface %s," + logging.debug(" - Skipping periodic RA on interface %s," " as it is not IPv6-connected", tap) continue indevmac = self.get_iface_hw_addr(indev) @@ -801,21 +958,22 @@ class VMNetProxy(object): # pylint: disable=R0902 if ifll is None: continue resp = Ether(src=indevmac)/\ - IPv6(src=str(ifll))/ICMPv6ND_RA(routerlifetime=14400)/\ + IPv6(src=str(ifll))/ICMPv6ND_RA(O=1, routerlifetime=14400)/\ ICMPv6NDOptPrefixInfo(prefix=str(subnet.prefix), prefixlen=subnet.prefixlen) if self.ipv6_nameservers: resp /= ICMPv6NDOptRDNSS(dns=self.ipv6_nameservers, lifetime=self.ra_period * 3) try: - self.sendp(resp, indev) + binding.sendp(resp) except socket.error, e: - logging.warn("Periodic RA on %s failed: %s", tap, str(e)) + logging.warn(" - Periodic RA on %s (%s) failed: %s", + tap, binding.hostname, str(e)) except Exception, e: - logging.warn("Unkown error during periodic RA on %s: %s", - tap, str(e)) + logging.warn(" - Unkown error during periodic RA on %s (%s):" + " %s", tap, binding.hostname, str(e)) i += 1 - logging.debug("Sent %d RAs in %.2f seconds", i, time.time() - start) + logging.info(" - Sent %d RAs in %.2f seconds", i, time.time() - start) def serve(self): """ Safely perform the main loop, freeing all resources upon exit @@ -834,7 +992,7 @@ class VMNetProxy(object): # pylint: disable=R0902 # Yes, we are accessing _fd directly, but it's the only way to have a # single select() loop ;-) - iwfd = self.notifier._fd # pylint: disable=W0212 + iwfd = self.notifier._fd # pylint: disable=W0212 start = time.time() if self.ipv6_enabled: @@ -844,10 +1002,17 @@ class VMNetProxy(object): # pylint: disable=R0902 timeout = None while True: - rlist, _, xlist = select(self.nfq.keys() + [iwfd], [], [], timeout) + try: + rlist, _, xlist = select.select(self.nfq.keys() + [iwfd], + [], [], timeout) + except select.error, e: + if e[0] == errno.EINTR: + logging.debug("select() got interrupted") + continue + if xlist: logging.warn("Warning: Exception on %s", - ", ".join([ str(fd) for fd in xlist])) + ", ".join([str(fd) for fd in xlist])) if rlist: if iwfd in rlist: @@ -857,9 +1022,14 @@ class VMNetProxy(object): # pylint: disable=R0902 self.notifier.process_events() rlist.remove(iwfd) + logging.debug("Pending requests on fds %s", rlist) + for fd in rlist: try: - self.nfq[fd].process_pending() + q, num = self.nfq[fd] + cnt = q.process_pending(num) + logging.debug(" * Processed %d requests on NFQUEUE" + " with fd %d", cnt, fd) except RuntimeError, e: logging.warn("Error processing fd %d: %s", fd, str(e)) except Exception, e: @@ -875,6 +1045,14 @@ class VMNetProxy(object): # pylint: disable=R0902 self.send_periodic_ra() timeout = self.ra_period - (time.time() - start) + def print_clients(self): + logging.info("%10s %20s %20s %10s %20s %40s", + 'Key', 'Client', 'MAC', 'TAP', 'IP', 'IPv6') + for k, cl in self.clients.items(): + logging.info("%10s | %20s %20s %10s %20s %40s", + k, cl.hostname, cl.mac, cl.tap, cl.ip, cl.eui64) + + if __name__ == "__main__": import capng @@ -910,7 +1088,6 @@ if __name__ == "__main__": validator.functions["ip_addr_list"] = is_ip_list config_spec = StringIO(CONFIG_SPEC) - parser = optparse.OptionParser() parser.add_option("-c", "--config", dest="config_file", help="The location of the data files", metavar="FILE", @@ -921,7 +1098,6 @@ if __name__ == "__main__": dest="daemonize", default=True, help="Do not daemonize, stay in the foreground") - opts, args = parser.parse_args() try: @@ -943,6 +1119,30 @@ if __name__ == "__main__": ", ".join(section_list)) sys.exit(1) + try: + uid = getpwuid(config["general"].as_int("user")) + except ValueError: + uid = getpwnam(config["general"]["user"]) + + # Keep only the capabilities we need + # CAP_NET_ADMIN: we need to send nfqueue packet verdicts to a netlinkgroup + # CAP_NET_RAW: we need to reopen socket in case the buffer gets full + # CAP_SETPCAP: needed by capng_change_id() + capng.capng_clear(capng.CAPNG_SELECT_BOTH) + capng.capng_update(capng.CAPNG_ADD, + capng.CAPNG_EFFECTIVE | capng.CAPNG_PERMITTED, + capng.CAP_NET_ADMIN) + capng.capng_update(capng.CAPNG_ADD, + capng.CAPNG_EFFECTIVE | capng.CAPNG_PERMITTED, + capng.CAP_NET_RAW) + capng.capng_update(capng.CAPNG_ADD, + capng.CAPNG_EFFECTIVE | capng.CAPNG_PERMITTED, + capng.CAP_SETPCAP) + # change uid + capng.capng_change_id(uid.pw_uid, uid.pw_gid, + capng.CAPNG_DROP_SUPP_GRP | \ + capng.CAPNG_CLEAR_BOUNDING) + logger = logging.getLogger() if opts.debug: logger.setLevel(logging.DEBUG) @@ -951,14 +1151,21 @@ if __name__ == "__main__": if opts.daemonize: logfile = os.path.join(config["general"]["logdir"], LOG_FILENAME) - handler = logging.handlers.RotatingFileHandler(logfile, - maxBytes=2097152) + handler = logging.handlers.WatchedFileHandler(logfile) else: handler = logging.StreamHandler() handler.setFormatter(logging.Formatter(LOG_FORMAT)) logger.addHandler(handler) + # Rename this process so 'ps' output looks like + # this is a native executable. + # NOTE: due to a bug in python-setproctitle, one cannot yet + # set individual values for command-line arguments, so only show + # the name of the executable instead. + # setproctitle.setproctitle("\x00".join(sys.argv)) + setproctitle.setproctitle(sys.argv[0]) + if opts.daemonize: pidfile = daemon.pidlockfile.TimeoutPIDLockFile( config["general"]["pidfile"], 10) @@ -967,12 +1174,11 @@ if __name__ == "__main__": logger.warning("Removing stale PID lock file %s", pidfile.path) pidfile.break_lock() - d = daemon.DaemonContext(pidfile=pidfile, + umask=0022, stdout=handler.stream, stderr=handler.stream, files_preserve=[handler.stream]) - d.umask = 0022 try: d.open() except (daemon.pidlockfile.AlreadyLocked, LockTimeout): @@ -981,6 +1187,8 @@ if __name__ == "__main__": sys.exit(1) logging.info("Starting up") + logging.info("Running as %s (uid:%d, gid: %d)", + config["general"]["user"], uid.pw_uid, uid.pw_gid) proxy_opts = {} if config["dhcp"].as_bool("enable_dhcp"): @@ -995,35 +1203,28 @@ if __name__ == "__main__": if config["ipv6"].as_bool("enable_ipv6"): proxy_opts.update({ + "dhcpv6_queue_num": config["ipv6"].as_int("dhcp_queue"), "rs_queue_num": config["ipv6"].as_int("rs_queue"), "ns_queue_num": config["ipv6"].as_int("ns_queue"), "ra_period": config["ipv6"].as_int("ra_period"), "ipv6_nameservers": config["ipv6"]["nameservers"], + "dhcpv6_domains": config["ipv6"]["domains"], }) # pylint: disable=W0142 proxy = VMNetProxy(data_path=config["general"]["datapath"], **proxy_opts) - # Drop all capabilities except CAP_NET_RAW and change uid - try: - uid = getpwuid(config["general"].as_int("user")) - except ValueError: - uid = getpwnam(config["general"]["user"]) + logging.info("Ready to serve requests") - logging.debug("Setting capabilities and changing uid") - logging.debug("User: %s, uid: %d, gid: %d", - config["general"]["user"], uid.pw_uid, uid.pw_gid) - # Keep only the capabilities we need - # CAP_NET_ADMIN: we need to send nfqueue packet verdicts to a netlinkgroup - capng.capng_clear(capng.CAPNG_SELECT_BOTH) - capng.capng_update(capng.CAPNG_ADD, - capng.CAPNG_EFFECTIVE|capng.CAPNG_PERMITTED, - capng.CAP_NET_ADMIN) - capng.capng_change_id(uid.pw_uid, uid.pw_gid, - capng.CAPNG_DROP_SUPP_GRP|capng.CAPNG_CLEAR_BOUNDING) + def debug_handler(signum, _): + logging.debug('Received signal %d. Printing proxy state...', signum) + proxy.print_clients() + + # Set the signal handler for debuging clients + signal.signal(signal.SIGUSR1, debug_handler) + signal.siginterrupt(signal.SIGUSR1, False) - logging.info("Ready to serve requests") try: proxy.serve() except Exception: