Commit 764f829a authored by Christos Stavrakakis's avatar Christos Stavrakakis

Improve log msgs

parent d7b852fd
...@@ -122,7 +122,6 @@ DHCP_REQRESP = { ...@@ -122,7 +122,6 @@ DHCP_REQRESP = {
def get_indev(payload): def get_indev(payload):
try: try:
indev_ifindex = payload.get_physindev() indev_ifindex = payload.get_physindev()
logging.debug("get_physindev %s", indev_ifindex)
if indev_ifindex: if indev_ifindex:
logging.debug("Incomming packet from bridge %s", indev_ifindex) logging.debug("Incomming packet from bridge %s", indev_ifindex)
return indev_ifindex return indev_ifindex
...@@ -136,23 +135,26 @@ def get_indev(payload): ...@@ -136,23 +135,26 @@ def get_indev(payload):
return indev_ifindex return indev_ifindex
def get_binding(proxy, ifindex, mac): def get_binding(proxy, ifindex, mac):
try: try:
if proxy.mac_indexed_clients: if proxy.mac_indexed_clients:
logging.debug("get_binding for mac %s", mac) logging.debug("Getting binding for mac %s", mac)
b = proxy.clients[mac] b = proxy.clients[mac]
else: else:
logging.debug("get_binding for ifindex %s", ifindex) logging.debug("Getting binding for ifindex %s", ifindex)
b = proxy.clients[ifindex] b = proxy.clients[ifindex]
return b return b
except KeyError: except KeyError:
logging.debug("No client found for mac/ifindex %s/%s", mac, ifindex) logging.debug("No client found for mac/ifindex %s/%s", mac, ifindex)
return None return None
def parse_binding_file(path): def parse_binding_file(path):
""" Read a client configuration from a tap file """ Read a client configuration from a tap file
""" """
logging.info("Parsing binding file %s", path)
try: try:
iffile = open(path, 'r') iffile = open(path, 'r')
except EnvironmentError, e: except EnvironmentError, e:
...@@ -173,7 +175,7 @@ def parse_binding_file(path): ...@@ -173,7 +175,7 @@ def parse_binding_file(path):
def get_value(line): def get_value(line):
v = line.strip().split('=')[1] v = line.strip().split('=')[1]
if v == '': if v == '':
return None return None
return v return v
for line in iffile: for line in iffile:
...@@ -204,12 +206,13 @@ def parse_binding_file(path): ...@@ -204,12 +206,13 @@ def parse_binding_file(path):
except: except:
return None return None
class ClientFileHandler(pyinotify.ProcessEvent): class ClientFileHandler(pyinotify.ProcessEvent):
def __init__(self, server): def __init__(self, server):
pyinotify.ProcessEvent.__init__(self) pyinotify.ProcessEvent.__init__(self)
self.server = server self.server = server
def process_IN_DELETE(self, event): # pylint: disable=C0103 def process_IN_DELETE(self, event): # pylint: disable=C0103
""" Delete file handler """ Delete file handler
Currently this removes an interface from the watch list Currently this removes an interface from the watch list
...@@ -217,7 +220,7 @@ class ClientFileHandler(pyinotify.ProcessEvent): ...@@ -217,7 +220,7 @@ class ClientFileHandler(pyinotify.ProcessEvent):
""" """
self.server.remove_tap(event.name) 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 """ Add file handler
Currently this adds an interface to the watch list Currently this adds an interface to the watch list
...@@ -316,8 +319,8 @@ class Subnet(object): ...@@ -316,8 +319,8 @@ class Subnet(object):
return self._make_eui64("fe80::", mac) return self._make_eui64("fe80::", mac)
class VMNetProxy(object): # pylint: disable=R0902 class VMNetProxy(object): # pylint: disable=R0902
def __init__(self, data_path, dhcp_queue_num=None, # pylint: disable=R0913 def __init__(self, data_path, dhcp_queue_num=None, # pylint: disable=R0913
rs_queue_num=None, ns_queue_num=None, rs_queue_num=None, ns_queue_num=None,
dhcp_lease_lifetime=DEFAULT_LEASE_LIFETIME, dhcp_lease_lifetime=DEFAULT_LEASE_LIFETIME,
dhcp_lease_renewal=DEFAULT_LEASE_RENEWAL, dhcp_lease_renewal=DEFAULT_LEASE_RENEWAL,
...@@ -396,7 +399,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -396,7 +399,7 @@ class VMNetProxy(object): # pylint: disable=R0902
logging.info("Cleanup finished") logging.info("Cleanup finished")
def _setup_nfqueue(self, queue_num, family, callback): def _setup_nfqueue(self, queue_num, family, callback):
logging.debug("Setting up NFQUEUE for queue %d, AF %s", logging.info("Setting up NFQUEUE for queue %d, AF %s",
queue_num, family) queue_num, family)
q = nfqueue.queue() q = nfqueue.queue()
q.set_callback(callback) q.set_callback(callback)
...@@ -405,12 +408,13 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -405,12 +408,13 @@ class VMNetProxy(object): # pylint: disable=R0902
# This is mandatory for the queue to operate # This is mandatory for the queue to operate
q.set_mode(nfqueue.NFQNL_COPY_PACKET) q.set_mode(nfqueue.NFQNL_COPY_PACKET)
self.nfq[q.get_fd()] = q self.nfq[q.get_fd()] = q
logging.debug("Successfully set up NFQUEUE %d", queue_num)
def sendp(self, data, dev): def sendp(self, data, dev):
""" Send a raw packet using a layer-2 socket """ Send a raw packet using a layer-2 socket
""" """
logging.debug("%s", data) logging.debug("Sending raw packet %s", data)
if isinstance(data, BasePacket): if isinstance(data, BasePacket):
data = str(data) data = str(data)
...@@ -427,15 +431,16 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -427,15 +431,16 @@ class VMNetProxy(object): # pylint: disable=R0902
for path in glob.glob(os.path.join(self.data_path, "*")): for path in glob.glob(os.path.join(self.data_path, "*")):
self.add_tap(path) self.add_tap(path)
logging.debug("\n\n\n\n\n") logging.debug("%15s %20s %7s %15s", 'Client', 'MAC', 'TAP', 'IP')
logging.debug("%10s %20s %7s %15s", 'Client', 'MAC', 'TAP', 'IP')
for b in self.clients.values(): for b in self.clients.values():
logging.debug("%10s %20s %7s %15s", b.hostname, b.mac, b.tap, b.ip) logging.debug("%15s %20s %7s %15s", b.hostname, b.mac, b.tap, b.ip)
def get_ifindex(self, iface): def get_ifindex(self, iface):
""" Get the interface index from sysfs """ 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")) path = os.path.abspath(os.path.join(SYSFS_NET, iface, "ifindex"))
if not path.startswith(SYSFS_NET): if not path.startswith(SYSFS_NET):
return None return None
...@@ -466,11 +471,11 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -466,11 +471,11 @@ class VMNetProxy(object): # pylint: disable=R0902
return ifindex return ifindex
def get_iface_hw_addr(self, iface): def get_iface_hw_addr(self, iface):
""" Get the interface hardware address from sysfs """ 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")) path = os.path.abspath(os.path.join(SYSFS_NET, iface, "address"))
if not path.startswith(SYSFS_NET): if not path.startswith(SYSFS_NET):
return None return None
...@@ -532,8 +537,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -532,8 +537,7 @@ class VMNetProxy(object): # pylint: disable=R0902
except: except:
logging.debug("Client on %s disappeared!!!", tap) logging.debug("Client on %s disappeared!!!", tap)
def dhcp_response(self, i, payload): # pylint: disable=W0613,R0914
def dhcp_response(self, i, payload): # pylint: disable=W0613,R0914
""" Generate a reply to bnetfilter-queue-deva BOOTP/DHCP request """ Generate a reply to bnetfilter-queue-deva BOOTP/DHCP request
""" """
...@@ -546,7 +550,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -546,7 +550,7 @@ class VMNetProxy(object): # pylint: disable=R0902
resp = pkt.getlayer(BOOTP).copy() resp = pkt.getlayer(BOOTP).copy()
hlen = resp.hlen hlen = resp.hlen
mac = resp.chaddr[:hlen].encode("hex") 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 # Server responses are always BOOTREPLYs
resp.op = "BOOTREPLY" resp.op = "BOOTREPLY"
...@@ -564,7 +568,6 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -564,7 +568,6 @@ class VMNetProxy(object): # pylint: disable=R0902
payload.set_verdict(nfqueue.NF_ACCEPT) payload.set_verdict(nfqueue.NF_ACCEPT)
return return
# Signal the kernel that it shouldn't further process the packet # Signal the kernel that it shouldn't further process the packet
payload.set_verdict(nfqueue.NF_DROP) payload.set_verdict(nfqueue.NF_DROP)
...@@ -616,7 +619,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -616,7 +619,7 @@ class VMNetProxy(object): # pylint: disable=R0902
("lease_time", self.lease_lifetime), ("lease_time", self.lease_lifetime),
] ]
if subnet.gw: if subnet.gw:
dhcp_options += [("router", subnet.gw)] dhcp_options += [("router", subnet.gw)]
dhcp_options += [("name_server", x) for x in self.dhcp_nameservers] dhcp_options += [("name_server", x) for x in self.dhcp_nameservers]
elif req_type == DHCPINFORM: elif req_type == DHCPINFORM:
...@@ -629,7 +632,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -629,7 +632,7 @@ class VMNetProxy(object): # pylint: disable=R0902
elif req_type == DHCPRELEASE: elif req_type == DHCPRELEASE:
# Log and ignore # Log and ignore
logging.info("DHCPRELEASE from %s on %s", binding.mac, binding.tap ) logging.info("DHCPRELEASE from %s on %s", binding.mac, binding.tap)
return return
# Finally, always add the server identifier and end options # Finally, always add the server identifier and end options
...@@ -650,12 +653,12 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -650,12 +653,12 @@ class VMNetProxy(object): # pylint: disable=R0902
logging.warn("Unkown error during DHCP response on %s: %s", logging.warn("Unkown error during DHCP response on %s: %s",
binding.indev, str(e)) binding.indev, str(e))
def rs_response(self, i, payload): # pylint: disable=W0613 def rs_response(self, i, payload): # pylint: disable=W0613
""" Generate a reply to a BOOTP/DHCP request """ Generate a reply to a BOOTP/DHCP request
""" """
pkt = IPv6(payload.get_data()) pkt = IPv6(payload.get_data())
logging.debug("IN RS RESPONCE")
#logging.debug(pkt.show()) #logging.debug(pkt.show())
try: try:
mac = pkt.lladdr mac = pkt.lladdr
...@@ -663,7 +666,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -663,7 +666,7 @@ class VMNetProxy(object): # pylint: disable=R0902
logging.debug("Cannot obtain lladdr in rs") logging.debug("Cannot obtain lladdr in rs")
return return
logging.debug("rs for mac %s", mac) logging.debug("Generating an rs response for mac %s", mac)
indev = get_indev(payload) indev = get_indev(payload)
...@@ -687,15 +690,14 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -687,15 +690,14 @@ class VMNetProxy(object): # pylint: disable=R0902
subnet = binding.net6 subnet = binding.net6
if subnet.net is None: if subnet.net is None:
logging.debug("No IPv6 network assigned for the interface") logging.debug("No IPv6 network assigned for the interface")
return return
indevmac = self.get_iface_hw_addr(binding.indev) indevmac = self.get_iface_hw_addr(binding.indev)
ifll = subnet.make_ll64(indevmac) ifll = subnet.make_ll64(indevmac)
if ifll is None: if ifll is None:
return return
resp = Ether(src=indevmac)/\ resp = Ether(src=indevmac)/\
IPv6(src=str(ifll))/ICMPv6ND_RA(routerlifetime=14400)/\ IPv6(src=str(ifll))/ICMPv6ND_RA(routerlifetime=14400)/\
ICMPv6NDOptPrefixInfo(prefix=str(subnet.prefix), ICMPv6NDOptPrefixInfo(prefix=str(subnet.prefix),
...@@ -714,12 +716,12 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -714,12 +716,12 @@ class VMNetProxy(object): # pylint: disable=R0902
logging.warn("Unkown error during RA on %s: %s", logging.warn("Unkown error during RA on %s: %s",
binding.indev, str(e)) binding.indev, str(e))
def ns_response(self, i, payload): # pylint: disable=W0613 def ns_response(self, i, payload): # pylint: disable=W0613
""" Generate a reply to an ICMPv6 neighbor solicitation """ Generate a reply to an ICMPv6 neighbor solicitation
""" """
ns = IPv6(payload.get_data()) ns = IPv6(payload.get_data())
logging.debug("IN NS RESPONCE")
#logging.debug(ns.show()) #logging.debug(ns.show())
try: try:
mac = ns.lladdr mac = ns.lladdr
...@@ -727,7 +729,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -727,7 +729,7 @@ class VMNetProxy(object): # pylint: disable=R0902
logging.debug("Cannot obtain lladdr from ns") logging.debug("Cannot obtain lladdr from ns")
return return
logging.debug("dst %s tgt %s" , ns.dst, ns.tgt) logging.debug("Generating ns response, dst: %s tgt: %s", ns.dst, ns.tgt)
indev = get_indev(payload) indev = get_indev(payload)
...@@ -749,8 +751,8 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -749,8 +751,8 @@ class VMNetProxy(object): # pylint: disable=R0902
subnet = binding.net6 subnet = binding.net6
if subnet.net is None: if subnet.net is None:
logging.debug("No IPv6 network assigned for the interface") logging.debug("No IPv6 network assigned for the interface")
return return
indevmac = self.get_iface_hw_addr(binding.indev) indevmac = self.get_iface_hw_addr(binding.indev)
...@@ -790,7 +792,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -790,7 +792,7 @@ class VMNetProxy(object): # pylint: disable=R0902
for binding in self.clients.values(): for binding in self.clients.values():
tap = binding.tap tap = binding.tap
indev = binding.indev indev = binding.indev
mac = binding.mac # mac = binding.mac
subnet = binding.net6 subnet = binding.net6
if subnet.net is None: if subnet.net is None:
logging.debug("Skipping periodic RA on interface %s," logging.debug("Skipping periodic RA on interface %s,"
...@@ -834,7 +836,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -834,7 +836,7 @@ class VMNetProxy(object): # pylint: disable=R0902
# Yes, we are accessing _fd directly, but it's the only way to have a # Yes, we are accessing _fd directly, but it's the only way to have a
# single select() loop ;-) # single select() loop ;-)
iwfd = self.notifier._fd # pylint: disable=W0212 iwfd = self.notifier._fd # pylint: disable=W0212
start = time.time() start = time.time()
if self.ipv6_enabled: if self.ipv6_enabled:
...@@ -847,7 +849,7 @@ class VMNetProxy(object): # pylint: disable=R0902 ...@@ -847,7 +849,7 @@ class VMNetProxy(object): # pylint: disable=R0902
rlist, _, xlist = select(self.nfq.keys() + [iwfd], [], [], timeout) rlist, _, xlist = select(self.nfq.keys() + [iwfd], [], [], timeout)
if xlist: if xlist:
logging.warn("Warning: Exception on %s", logging.warn("Warning: Exception on %s",
", ".join([ str(fd) for fd in xlist])) ", ".join([str(fd) for fd in xlist]))
if rlist: if rlist:
if iwfd in rlist: if iwfd in rlist:
...@@ -910,7 +912,6 @@ if __name__ == "__main__": ...@@ -910,7 +912,6 @@ if __name__ == "__main__":
validator.functions["ip_addr_list"] = is_ip_list validator.functions["ip_addr_list"] = is_ip_list
config_spec = StringIO(CONFIG_SPEC) config_spec = StringIO(CONFIG_SPEC)
parser = optparse.OptionParser() parser = optparse.OptionParser()
parser.add_option("-c", "--config", dest="config_file", parser.add_option("-c", "--config", dest="config_file",
help="The location of the data files", metavar="FILE", help="The location of the data files", metavar="FILE",
...@@ -921,7 +922,6 @@ if __name__ == "__main__": ...@@ -921,7 +922,6 @@ if __name__ == "__main__":
dest="daemonize", default=True, dest="daemonize", default=True,
help="Do not daemonize, stay in the foreground") help="Do not daemonize, stay in the foreground")
opts, args = parser.parse_args() opts, args = parser.parse_args()
try: try:
...@@ -1017,10 +1017,10 @@ if __name__ == "__main__": ...@@ -1017,10 +1017,10 @@ if __name__ == "__main__":
# CAP_NET_ADMIN: we need to send nfqueue packet verdicts to a netlinkgroup # CAP_NET_ADMIN: we need to send nfqueue packet verdicts to a netlinkgroup
capng.capng_clear(capng.CAPNG_SELECT_BOTH) capng.capng_clear(capng.CAPNG_SELECT_BOTH)
capng.capng_update(capng.CAPNG_ADD, capng.capng_update(capng.CAPNG_ADD,
capng.CAPNG_EFFECTIVE|capng.CAPNG_PERMITTED, capng.CAPNG_EFFECTIVE | capng.CAPNG_PERMITTED,
capng.CAP_NET_ADMIN) capng.CAP_NET_ADMIN)
capng.capng_change_id(uid.pw_uid, uid.pw_gid, capng.capng_change_id(uid.pw_uid, uid.pw_gid,
capng.CAPNG_DROP_SUPP_GRP|capng.CAPNG_CLEAR_BOUNDING) capng.CAPNG_DROP_SUPP_GRP | capng.CAPNG_CLEAR_BOUNDING)
logging.info("Ready to serve requests") logging.info("Ready to serve requests")
try: try:
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment